Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

raspi-cam-srv seems to be frozen sometimes #28

Open
hinkel opened this issue Sep 6, 2024 · 20 comments
Open

raspi-cam-srv seems to be frozen sometimes #28

hinkel opened this issue Sep 6, 2024 · 20 comments

Comments

@hinkel
Copy link

hinkel commented Sep 6, 2024

Hi,
Sometimes the program seems to be frozen , no record of photo and is not possible to get out from recording modus with the stop button from Trigger Control Panel , the only way is to reboot the Raspberry pi5 and hope it will work again.
Thanks for any help.
image

@signag
Copy link
Owner

signag commented Sep 8, 2024

Hi,
to analyze this, I would need a little bit more of information.
Perhaps you can make a screenshot of the Info screen.
Also, the Debian version (cat /etc/debian_version or lsb_release -a) and the kernel version (uname -r) would be interesting (I should have added this to the Info screen).

Just one hint if you are using Pi Zero W or Pi Zero 2 W:
Some time ago, I tried to use Bookworm on these devices when this was made available.
However, I was not very happy with that. I apparently saw the system stalled.

Therefore, I returned to Bullseye on the Pi Zero systems. This works fine and is stable with raspiCamSrv, also in the long term tests.

@signag
Copy link
Owner

signag commented Sep 8, 2024

With V2.10.2, the Info screen includes all necessary information.

@hinkel
Copy link
Author

hinkel commented Sep 9, 2024

Hi,
the new info screen shot, _____ issue is the same
Capture d'écran 2024-09-09 194642

after this , I reboot the Raspberry pi 5 and issue was gone.
Then by powering off and on the Raspberry pi 5 the issue came again.

Capture d'écran 2024-09-09 201956

Reboot and error is gone

Capture d'écran 2024-09-09 202951

also there are 26 photos

Capture d’écran 2024-09-09 203351
but 44 photos in storage

Capture d'écran 2024-09-09 204133

@hinkel
Copy link
Author

hinkel commented Sep 9, 2024

also the photo logfile
log_rasp5.txt

@hinkel
Copy link
Author

hinkel commented Sep 9, 2024

Eventually the raspi-cam-srv needs more delay to be launch after powering on the Raspberry pi 5 ?

@signag
Copy link
Owner

signag commented Sep 9, 2024

From your Info screen, I see that you are using an actual environment, which is the same as I am using on a Pi5.
However, I have the trigger process running for several days and it never has stopped.

Your screenshots show that you have the trigger thread active but not the live stream thread.

Normally, the trigger thread keeps the live stream thread alive, because the MJPEG photos from the live stream are used to detect motion by comparing successive images.

In a correct behavior, the status indicators always look like this when the motion capture process is active:
image

So, when in your case the status indicator for the live stram is off, this means that the live stream is not active,
As a consequence, the motion capture thread will seem frozen because it always waits for the next image.

The question now is why the live stream has stopped in your case.
I have never got this situation while testing and practicing.

Could you please do the following:

  1. In the Settings screen, deactivate Start server with stored Configuration if it was activated
  2. On the Trigger/Control screen, deactivate Automatic Start with Server and Submit the change
  3. Restart the Flask server (sudo systemctl restart raspiCamSrv.service)
    (It should not be necessary to reboot the Pi)
  4. From the client reconnect to raspiCamSrv
  5. Start the trigger process
  6. Observe the indicator for the live stream. It should always stay active
  7. Do what you have done before when you arrived at a situation with a frozen trigger process
  8. Find the situation when the live stream process stops

Thanks

@signag
Copy link
Owner

signag commented Sep 9, 2024

also there are 26 photos but 44 photos in storage

The calender shows the number of events and not the number of photos.

Depending on your settings, there may be multiple photos per event.
You can see this in your log file.

@signag
Copy link
Owner

signag commented Sep 9, 2024

Looking at your log file, I saw that you are using the Background Subtraction algorithm.

I have just started a long term test using your parameters, to see whether I get the same issues as you got.

However as you can see from the performance study on page Triggered Capture of Videos and Photos, Background Subtraction has a higher CPU load although it is far from being critical.

Probably, you could also see if you have similar issues when using the 'Mean Square Diff' algo.

@signag
Copy link
Owner

signag commented Sep 9, 2024

Eventually the raspi-cam-srv needs more delay to be launch after powering on the Raspberry pi 5 ?

I do not think so.
When testing, I also test rebooting the machine with the option to automatically start motion capture with start of the Flask server and I had never issues with that.

Also, if raspiCamServ hangs and you cannot get control, it is normally not necessary to reboot the Pi.
It should be sufficient to restart the service.

@hinkel
Copy link
Author

hinkel commented Sep 10, 2024

Looking at your log file, I saw that you are using the Background Subtraction algorithm.

yes because the detection is very fine, better than the 'Mean Square Diff' algo

Probably, you could also see if you have similar issues when using the 'Mean Square Diff' algo.

going back to the 'Mean Square Diff' algo and there was no issue , raspi-cam-srv doing well again.

@hinkel
Copy link
Author

hinkel commented Sep 10, 2024

Could you please do the following:

  1. In the Settings screen, deactivate Start server with stored Configuration if it was activated

this helped to get start with default parameter i guess but not resolve the issue

  1. On the Trigger/Control screen, deactivate Automatic Start with Server and Submit the change

this help to not have the issue but than the trigger start must be manual

  1. Restart the Flask server (sudo systemctl restart raspiCamSrv.service)(It should not be necessary to reboot the Pi)

this was clearing all my configuration, I had to set all parameters again

  1. From the client reconnect to raspiCamSrv
  2. Start the trigger process
  3. Observe the indicator for the live stream. It should always stay active
  4. Do what you have done before when you arrived at a situation with a frozen trigger process
  5. Find the situation when the live stream process stops

live stream process stop by various action like submit or Save configuration and so on..

Background Subtraction algorithm seems causing the issue

@signag
Copy link
Owner

signag commented Sep 11, 2024

Could you please report one specific and reproducible action after which the livestream stops when motion capture with Background Subtraction is active.

I tried everything, I could imagin (Taking photo, raw photo, video, photo series. Also changing all kinds of trigger parameters) ... and the live stream has never stopped.
My motion capture process with Background Subtraction and the same parameters as in your case, is now running since about 2 days without interruption and has captured about 200 events. Everything without any problem.
I have also successfully tested automatic start with the server.

So, I would really be interested to see how you get the live stream to stop so that I can implement a more robust protection.

Thanks

@hinkel
Copy link
Author

hinkel commented Sep 11, 2024

Hi,
the issue occur by powering on, the Raspberry pi 5, with automatic start, with server, and using Background Subtraction algorithm, also having the Pi5 connected with HDMI Port to TV screen and Ethernet cable.
Now I tested without any HDMI Port connected and Ethernet cable, the issue does not came again.

Probably the CPU is overload with calculation on start (Power on first time) and cause the issue.

Hope you can replicate this !

Thanks for your help.

@hinkel
Copy link
Author

hinkel commented Sep 11, 2024

Hi, the issue occur by powering on, the Raspberry pi 5, with automatic start, with server, and using Background Subtraction algorithm, also having the Pi5 connected with HDMI Port to TV screen and Ethernet cable. Now I tested without any HDMI Port connected and Ethernet cable, the issue does not came again.

I tested more and issue is still present :(

Reboot will always help
Capture d’écran 2024-09-11 213221

@signag
Copy link
Owner

signag commented Sep 12, 2024

If it is related to automatic start, it could be that there is an uissue with the saved configuration.
Probably, it needs to be updated in case you have saved it for an older version of raspiCamSrv.

I recommend trying to use Store Configuration in the Settings screen and then try a reboot.

@signag
Copy link
Owner

signag commented Sep 12, 2024

Also, the live stream thread will normally not disappear without a trace.
You could check the system log with with sudo journalctl -e after you saw that the thread is no longer active.

Alternatively, you could activate logging to a log file (See Logging)

A suitable configuration for your case could be:

    # Configure loggers
    logsPath = os.path.dirname(app.instance_path) + "/logs"
    os.makedirs(logsPath, exist_ok=True)
    logFile = logsPath + "/raspiCamSrv.log"
    Path(logFile).touch(exist_ok=True)
    filehandler = logging.FileHandler(logFile)
    filehandler.setFormatter(app.logger.handlers[0].formatter)
    for logger in(
        app.logger,
        logging.getLogger("werkzeug"),
        logging.getLogger("raspiCamSrv.db"),
        logging.getLogger("raspiCamSrv.auth"),
        logging.getLogger("raspiCamSrv.auth_su"),
        logging.getLogger("raspiCamSrv.camCfg"),
        logging.getLogger("raspiCamSrv.camera_pi"),
        logging.getLogger("raspiCamSrv.config"),
        logging.getLogger("raspiCamSrv.home"),
        logging.getLogger("raspiCamSrv.images"),
        logging.getLogger("raspiCamSrv.info"),
        logging.getLogger("raspiCamSrv.settings"),
        logging.getLogger("raspiCamSrv.photoseries"),
        logging.getLogger("raspiCamSrv.photoseriesCfg"),
        logging.getLogger("raspiCamSrv.trigger"),
        logging.getLogger("raspiCamSrv.motionDetector"),
        logging.getLogger("raspiCamSrv.motionAlgoIB"),
        logging.getLogger("raspiCamSrv.webcam"),
        logging.getLogger("raspiCamSrv.sun"),
    ):
        logger.setLevel(logging.ERROR)

    #>>>>> Uncomment the following line in order to log to the log file
    app.logger.addHandler(filehandler)

    #>>>>> Explicitely set specific log levels. Leave "werkzeug" at INFO
    logging.getLogger("werkzeug").setLevel(logging.INFO)
    #logging.getLogger("raspiCamSrv.auth").setLevel(logging.ERROR)
    #logging.getLogger("raspiCamSrv.camCfg").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.camera_pi").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.images").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.webcam").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.trigger").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.photoseriesCfg").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.photoseries").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.sun").setLevel(logging.DEBUG)
    #logging.getLogger("raspiCamSrv.motionAlgoIB").setLevel(logging.DEBUG)
    
    #>>>>> Set log level for picamera2 (DEBUG, INFO, WARNING, ERROR)
    Picamera2.set_logging(Picamera2.ERROR)
    #>>>>> Uncomment the following line to let Picamera2 log to the log file
    logging.getLogger("picamera2").addHandler(filehandler)
        
    #>>>>> Set log level for libcamera (0:DEBUG, 1:INFO, 2:WARNING, 3:ERROR, 4:FATAL)
    os.environ["LIBCAMERA_LOG_LEVELS"] = "*:3"

If no errors can be seen there, you could use DEBUG logging for camera_pi:

    logging.getLogger("raspiCamSrv.camera_pi").setLevel(logging.DEBUG)

If you cannot interpret the log file, you can send it to me.

@hinkel
Copy link
Author

hinkel commented Sep 13, 2024

error after powering on with automatic start with server, and using Background Subtraction algorithm

ia@raspberrypia:~ $ sudo journalctl -e
Sep 13 09:42:33 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:>
Sep 13 09:42:55 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:>
Sep 13 09:42:55 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:>
Sep 13 09:42:55 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:>
Sep 13 09:43:02 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:43:>
Sep 13 09:43:02 raspberrypia kernel: rp1-cfe 1f00110000.csi: Using a link rate >
Sep 13 09:43:26 raspberrypia flask[941]: [2024-09-13 09:43:26,730] ERROR in mot>
Sep 13 09:43:31 raspberrypia flask[941]: [2024-09-13 09:43:31,863] ERROR in mot>
Sep 13 09:43:34 raspberrypia flask[941]: [2024-09-13 09:43:34,842] ERROR in mot>
Sep 13 09:43:36 raspberrypia flask[941]: [2024-09-13 09:43:36,904] ERROR in mot>
Sep 13 09:43:39 raspberrypia flask[941]: [2024-09-13 09:43:39,886] ERROR in mot>
Sep 13 09:43:41 raspberrypia flask[941]: [2024-09-13 09:43:41,951] ERROR in mot>
Sep 13 09:43:44 raspberrypia flask[941]: [2024-09-13 09:43:44,932] ERROR in mot>
Sep 13 09:43:46 raspberrypia flask[941]: [2024-09-13 09:43:46,997] ERROR in mot>
Sep 13 09:43:49 raspberrypia flask[941]: [2024-09-13 09:43:49,980] ERROR in mot>
Sep 13 09:43:52 raspberrypia flask[941]: [2024-09-13 09:43:52,044] ERROR in mot>
Sep 13 09:43:55 raspberrypia flask[941]: [2024-09-13 09:43:55,024] ERROR in mot>
Sep 13 09:43:57 raspberrypia flask[941]: [2024-09-13 09:43:57,088] ERROR in mot>
Sep 13 09:44:00 raspberrypia flask[941]: [2024-09-13 09:44:00,070] ERROR in mot>
Sep 13 09:44:02 raspberrypia flask[941]: [2024-09-13 09:44:02,139] ERROR in mot>
Sep 13 09:44:05 raspberrypia flask[941]: [2024-09-13 09:44:05,114] ERROR in mot>
Sep 13 09:44:05 raspberrypia sudo[2881]: pia : TTY=pts/0 ; PWD=/home/pia ;>
Sep 13 09:44:05 raspberrypia sudo[2881]: pam_unix(sudo:session): session opened>
lines 978-1000/1000 (END)
Sep 13 09:42:33 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:33] "GET /favicon.ico HTTP/1.1" 404 -
Sep 13 09:42:55 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:55] "GET /auth/login HTTP/1.1" 200 -
Sep 13 09:42:55 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:55] "GET /static/w3.css HTTP/1.1" 304 -
Sep 13 09:42:55 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:42:55] "GET /favicon.ico HTTP/1.1" 404 -
Sep 13 09:43:02 raspberrypia flask[941]: 192.168xxxxxx - - [13/Sep/2024 09:43:02] "POST /auth/login HTTP/1.1" 302 -
Sep 13 09:43:02 raspberrypia kernel: rp1-cfe 1f00110000.csi: Using a link rate of 900 Mbps
Sep 13 09:43:26 raspberrypia flask[941]: [2024-09-13 09:43:26,730] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:31 raspberrypia flask[941]: [2024-09-13 09:43:31,863] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:34 raspberrypia flask[941]: [2024-09-13 09:43:34,842] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:36 raspberrypia flask[941]: [2024-09-13 09:43:36,904] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:39 raspberrypia flask[941]: [2024-09-13 09:43:39,886] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:41 raspberrypia flask[941]: [2024-09-13 09:43:41,951] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:44 raspberrypia flask[941]: [2024-09-13 09:43:44,932] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:46 raspberrypia flask[941]: [2024-09-13 09:43:46,997] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:49 raspberrypia flask[941]: [2024-09-13 09:43:49,980] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:52 raspberrypia flask[941]: [2024-09-13 09:43:52,044] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:55 raspberrypia flask[941]: [2024-09-13 09:43:55,024] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:43:57 raspberrypia flask[941]: [2024-09-13 09:43:57,088] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:44:00 raspberrypia flask[941]: [2024-09-13 09:44:00,070] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:44:02 raspberrypia flask[941]: [2024-09-13 09:44:02,139] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:44:05 raspberrypia flask[941]: [2024-09-13 09:44:05,114] ERROR in motionDetector: Motion detection thread did not stop within 5 sec
Sep 13 09:44:05 raspberrypia sudo[2881]: pia : TTY=pts/0 ; PWD=/home/pia ; USER=root ; COMMAND=/usr/bin/journalctl -e
Sep 13 09:44:05 raspberrypia sudo[2881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
~

@hinkel
Copy link
Author

hinkel commented Sep 13, 2024

loose the live view

Sep 13 13:49:32 raspberrypia flask[946]: [2024-09-13 13:49:32,080] ERROR in motionDetector: Exception in _motionThread: SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 14073312>
Sep 13 13:49:55 raspberrypia flask[946]: [2024-09-13 13:49:55,979] ERROR in motionDetector: Exception in _motionThread: SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 14073311>

Triggered capture stopped with error:
Error in motionDetector._motionThread: Error in motion detection: SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 140733117821312 and this is thread id 140733126275456.

@signag
Copy link
Owner

signag commented Sep 13, 2024

Hi,

unfortunately, I cannot really learn much from these logs since they do not cover a time range from the start of the Flask server to the time when the error occurred.

Also, I have tried to reproduce this, but whatever I did, there was no error and the motion capture process with background subtraction continued successfully after a restart of the Raspberry Pi.

It would help if you could give me

  • a clear description of your environment
  • and a step by step description of what you do to reproduce the failure

For a complete log, you should

  • remember the time when you restarted the server
  • after the failure connect via ssh and make the window fullscreen
  • enter sudo journalctl | grep flask
  • then scroll back to the time when the server was restarted
  • copy the entire log from there to the end

@hinkel
Copy link
Author

hinkel commented Sep 13, 2024

automatic start with server, and using Background Subtraction algorithm

raspiCamSrv.log

At 19H07 I delete the log file and power off hardware Rpi5

at 19H11 I power on hardware Rpi5 and the clock take time to get right you can see in the log that there is a jump beetween 19H08 and 19H11 seems this cause the problem

at 19H12 I login on raspi-cam-srv and click on Trigger/Control/ Stop button 3 or 4 times but no success

at 19H15 I Reboot the Rpi5

at 19H17 I login on raspi-cam-srv and click on Trigger/Control/ Stop button and this was OK

This test was done using little change in software raspiCamSrv V2.10.2.test see there https://github.com/hinkel/raspi-cam-srv/commits/main/

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants