silvanmelchior / RPi_Cam_Web_Interface

A web interface for the RPi Cam
MIT License
1.54k stars 493 forks source link

permanently busy files after fhd splitting #350

Open shinji2009 opened 7 years ago

shinji2009 commented 7 years ago

hi getting permanently busy files often, their corresponding h264 files are not deleted. this in only at 1920x1080, after swich to 1280x720 no problems. raspbian jessie lite. 2 x rpi3b. gpu mem 144mb, 2 x 32 gb sdhc

two first logs, "SIGINT/SIGTERM received, stopping" when busy files are created. according to log it looks like it is because of splitting. (Video Split (seconds, default 0=off)). it was set to 300. i have tried 600 secs for example but no effect. often splitting is ok, but when it create a permanently busy file, it is always after splitting. there is another "SIGINT/SIGTERM received, stopping" error in the log but theres no splitting before it, permanently busy file was not created and everything looks good. last third log is about it.

[2017/06/01 19:27:01] Stop capture requested [2017/06/01 19:27:01] Send ca 0 {2017/06/01 19:27:01} Capturing stopped {2017/06/01 19:27:01} Add /var/www/html/media/vi_87024_20170601_192422.mp4 to Box Queue at pos 7 {2017/06/01 19:27:01} DEBUG 3 {2017/06/01 19:27:02} Start boxing /var/www/html/media/vi_87024_20170601_192422.mp4.h264 to /var/www/html/media/vi_87024_20170601_192422.mp4 Queue pos 7 {2017/06/01 19:27:17} send smd 1 [2017/06/01 19:27:17] Start capture requested from Pipe [2017/06/01 19:27:17] Send ca 1 {2017/06/01 19:27:17} Capturing with split of 300 seconds {2017/06/01 19:27:25} Capturing started {2017/06/01 19:28:03} Watchdog detected problem. Stopping{2017/06/01 19:28:04} SIGINT/SIGTERM received, stopping {2017/06/01 19:28:04} Capturing stopped {2017/06/01 19:28:04} Add /var/www/html/media/vi_87025_20170601_192717.mp4 to Box Queue at pos 8 {2017/06/01 19:28:10} RaspiMJPEG Version 5.8.02 {2017/06/01 19:28:10} recommended video buffer size 65536 {2017/06/01 19:28:10} h264 size set to 131072 {2017/06/01 19:28:10} recommended video buffers 1 {2017/06/01 19:28:10} h264 buffers set to recommended 1 {2017/06/01 19:28:10} Set up internal detect width=121 height=68 {2017/06/01 19:28:10} Opening FIFO 0 /var/www/html/FIFO 7 {2017/06/01 19:28:10} Opening FIFO 1 /var/www/html/FIFO11 8 {2017/06/01 19:28:10} MJPEG streaming, ready to receive commands {2017/06/01 19:28:10} send smd 9 {2017/06/01 19:28:10} Starting command loop

{2017/06/01 19:15:48} Finished boxing /var/www/html/media/vi_87014_20170601_191531.mp4 from Box Queue at pos 9 [2017/06/01 19:15:49] Scheduled management tasks. Next at 1496319649 {2017/06/01 19:15:49} Removed item from Box Queue [2017/06/01 19:15:49] Purged 10 Files {2017/06/01 19:16:00} send smd 1 [2017/06/01 19:16:00] Start capture requested from Pipe [2017/06/01 19:16:00] Send ca 1 {2017/06/01 19:16:00} Capturing with split of 300 seconds {2017/06/01 19:16:00} Capturing started {2017/06/01 19:17:58} send smd 0 [2017/06/01 19:17:58] Stop capture requested [2017/06/01 19:17:58] Send ca 0 {2017/06/01 19:17:58} Capturing stopped {2017/06/01 19:17:58} Add /var/www/html/media/vi_87015_20170601_191600.mp4 to Box Queue at pos 10 {2017/06/01 19:17:58} DEBUG 3 {2017/06/01 19:17:58} Start boxing /var/www/html/media/vi_87015_20170601_191600.mp4.h264 to /var/www/html/media/vi_87015_20170601_191600.mp4 Queue pos 10 {2017/06/01 19:18:01} send smd 1 [2017/06/01 19:18:01] Start capture requested from Pipe [2017/06/01 19:18:01] Send ca 1 {2017/06/01 19:18:01} Capturing with split of 300 seconds {2017/06/01 19:18:01} Capturing started {2017/06/01 19:18:14} Watchdog detected problem. Stopping{2017/06/01 19:18:25} SIGINT/SIGTERM received, stopping {2017/06/01 19:18:27} Capturing stopped {2017/06/01 19:18:27} Add /var/www/html/media/vi_87016_20170601_191801.mp4 to Box Queue at pos 11 {2017/06/01 19:18:32} RaspiMJPEG Version 5.8.02 {2017/06/01 19:18:32} recommended video buffer size 65536 {2017/06/01 19:18:32} h264 size set to 131072 {2017/06/01 19:18:32} recommended video buffers 1 {2017/06/01 19:18:32} h264 buffers set to recommended 1 {2017/06/01 19:18:32} Set up internal detect width=121 height=68 {2017/06/01 19:18:32} Opening FIFO 0 /var/www/html/FIFO 7 {2017/06/01 19:18:32} Opening FIFO 1 /var/www/html/FIFO11 8 {2017/06/01 19:18:32} MJPEG streaming, ready to receive commands {2017/06/01 19:18:32} send smd 9 {2017/06/01 19:18:32} Starting command loop [2017/06/01 19:18:32] Reload parameters command requested {2017/06/01 19:18:33} DEBUG 3 {2017/06/01 19:18:33} send smd 1 [2017/06/01 19:18:34] Scheduler loop is started [2017/06/01 19:18:34] Start capture request ignored, day period not initialised yet [2017/06/01 19:18:42] New period detected 0 [2017/06/01 19:18:42] Send md 1 {2017/06/01 19:18:42} send smd 0 {2017/06/01 19:18:43} Internal motion detection started

[2017/06/01 18:23:27] Send ca 1 {2017/06/01 18:23:27} Capturing with split of 300 seconds {2017/06/01 18:23:27} Capturing started {2017/06/01 18:24:56} send smd 0 [2017/06/01 18:24:56] Stop capture requested [2017/06/01 18:24:56] Send ca 0 {2017/06/01 18:24:56} Capturing stopped {2017/06/01 18:24:56} Add /var/www/html/media/vi_86940_20170601_182327.mp4 to Box Queue at pos 12 {2017/06/01 18:24:56} DEBUG 3 {2017/06/01 18:24:57} Start boxing /var/www/html/media/vi_86940_20170601_182327.mp4.h264 to /var/www/html/media/vi_86940_20170601_182327.mp4 Queue pos 12 {2017/06/01 18:24:57} send smd 1 [2017/06/01 18:24:58] Start capture requested from Pipe [2017/06/01 18:25:23] Send ca 1 {2017/06/01 18:25:02} send smd 0 {2017/06/01 18:25:16} Watchdog detected problem. Stopping{2017/06/01 18:25:24} send smd 1 [2017/06/01 18:25:25] Stop capture requested [2017/06/01 18:25:29] Send ca 0 [2017/06/01 18:25:31] Start capture requested from Pipe [2017/06/01 18:25:31] Send ca 1 {2017/06/01 18:25:31} SIGINT/SIGTERM received, stopping {2017/06/01 18:25:37} RaspiMJPEG Version 5.8.02 {2017/06/01 18:25:37} recommended video buffer size 65536 {2017/06/01 18:25:37} h264 size set to 131072 {2017/06/01 18:25:37} recommended video buffers 1 {2017/06/01 18:25:37} h264 buffers set to recommended 1 {2017/06/01 18:25:37} Set up internal detect width=121 height=68 {2017/06/01 18:25:37} Opening FIFO 0 /var/www/html/FIFO 7 {2017/06/01 18:25:37} Opening FIFO 1 /var/www/html/FIFO11 8 {2017/06/01 18:25:37} MJPEG streaming, ready to receive commands {2017/06/01 18:25:37} send smd 9 {2017/06/01 18:25:37} Starting command loop [2017/06/01 18:25:37] Reload parameters command requested [2017/06/01 18:25:37] Scheduler loop is started {2017/06/01 18:25:37} DEBUG 3 [2017/06/01 18:25:38] New period detected 0 [2017/06/01 18:25:38] Send md 1 {2017/06/01 18:25:38} Internal motion detection started {2017/06/01 18:25:38} recommended video buffer size 65536 {2017/06/01 18:25:38} h264 size set to 131072 {2017/06/01 18:25:38} recommended video buffers 1 {2017/06/01 18:25:38} h264 buffers set to recommended 1 {2017/06/01 18:25:39} Set up internal detect width=121 height=68 {2017/06/01 18:25:39} DEBUG 3 [2017/06/01 18:25:40] Scheduled management tasks. Next at 1496316638 [2017/06/01 18:25:40] Purged 6 Files {2017/06/01 18:25:40} send smd 1

roberttidey commented 7 years ago

As you are using video splitting, it would be worth seeing if enabling video buffering (camera settings) makes a difference.

Another user was having issues with video split and changing the buffer form 0 to 2000 (2 seconds) solved that for him.

With video split the camera is stopped then started again very quickly which may be the cause. The use of video buffering changes the timing a bit. I am investigating fixes other than configuring the video buffer.

shinji2009 commented 7 years ago

Buffer was set to 3000 from the beginning. set to 2000, testing

roberttidey commented 7 years ago

If you had it set to 3000 this is probably not the issue. I am doing some more testing to see if I can replicate.

shinji2009 commented 7 years ago

any good news?) 2000 cause permanently busy files sometimes too. was trying 10 and 5 fps. maybe sudden stops of capturing have something with fhd splitting also? i am using /etc/raspimjpeg motion_detection true, but

{2017/06/07 14:33:42} Capturing with split of 300 seconds {2017/06/07 14:33:42} Capturing started {2017/06/07 14:35:09} send smd 0 [2017/06/07 14:35:09] Stop capture requested [2017/06/07 14:35:09] Send ca 0 {2017/06/07 14:35:09} Capturing stopped {2017/06/07 14:35:09} Add /var/www/html/media/vi_93828_20170607_143342.mp4 to Box Queue at pos 4 {2017/06/07 14:35:09} DEBUG 3 {2017/06/07 14:35:09} send smd 1 {2017/06/07 14:35:10} Start boxing /var/www/html/media/vi_93828_20170607_143342.mp4.h264 to /var/www/html/media/vi_93828_20170607_143342.mp4 Queue pos 4 [2017/06/07 14:35:11] Start capture requested from Pipe [2017/06/07 14:35:11] Send ca 1 {2017/06/07 14:35:11} Capturing with split of 300 seconds {2017/06/07 14:35:11} Capturing started {2017/06/07 14:35:29} Watchdog detected problem. Stopping{2017/06/07 14:35:29} SIGINT/SIGTERM received, stopping {2017/06/07 14:35:33} Capturing stopped {2017/06/07 14:35:33} Add /var/www/html/media/vi_93829_20170607_143511.mp4 to Box Queue at pos 5 [2017/06/07 14:37:33] Scheduled management tasks. Next at 1496821353 [2017/06/07 14:37:33] Purged 2 Files [2017/06/07 14:42:34] Scheduled management tasks. Next at 1496821654 [2017/06/07 14:47:35] Scheduled management tasks. Next at 1496821955 [2017/06/07 14:52:36] Scheduled management tasks. Next at 1496822256 [2017/06/07 14:57:37] Scheduled management tasks. Next at 1496822557 [2017/06/07 15:02:38] Scheduled management tasks. Next at 1496822858 [2017/06/07 15:07:39] Scheduled management tasks. Next at 1496823159 [2017/06/07 15:12:40] Scheduled management tasks. Next at 1496823460 [2017/06/07 15:17:41] Scheduled management tasks. Next at 1496823761 [2017/06/07 15:22:42] Scheduled management tasks. Next at 1496824062 [2017/06/07 15:27:43] Scheduled management tasks. Next at 1496824363 [2017/06/07 15:32:44] Scheduled management tasks. Next at 1496824664 [2017/06/07 15:37:45] Scheduled management tasks. Next at 1496824965 [2017/06/07 15:42:46] Scheduled management tasks. Next at 1496825266 [2017/06/07 15:47:47] Scheduled management tasks. Next at 1496825567

roberttidey commented 7 years ago

So far I have not seen the problem here, but I am still checking.

In the latest version I have added an extra feature where a delay is put in immediately after stopping (like during a split). This may help let the MMAL interface clean up before starting the next capture of the split.

The delay is controlled by a parameter in the /etc/raspimjpeg config file, stop_pause. By default it is set to 100000 (100mSec).

Try this version to see if it helps and if necessary try increasing the value to say 300000. You need to stop and start the camera software for any change to be recognised.

shinji2009 commented 7 years ago

same, even with 300000. also get this message after installation.

2305

[2017/06/09 16:22:58] Stop capture requested [2017/06/09 16:22:58] Send ca 0 {2017/06/09 16:22:58} Capturing stopped {2017/06/09 16:22:58} Add /var/www/html/media/vi_95889_20170609_162229.mp4 to Box Queue at pos 27 {2017/06/09 16:22:58} DEBUG 3 {2017/06/09 16:23:00} Start boxing /var/www/html/media/vi_95889_20170609_162229.mp4.h264 to /var/www/html/media/vi_95889_20170609_162229.mp4 Queue pos 27 {2017/06/09 16:23:01} send smd 1 [2017/06/09 16:23:01] Start capture requested from Pipe [2017/06/09 16:23:01] Send ca 1 {2017/06/09 16:23:01} Capturing with split of 300 seconds {2017/06/09 16:23:01} Capturing started {2017/06/09 16:23:01} Finished boxing /var/www/html/media/vi_95889_20170609_162229.mp4 from Box Queue at pos 27 {2017/06/09 16:23:01} Removed item from Box Queue {2017/06/09 16:23:48} Watchdog detected problem. Stopping{2017/06/09 16:23:49} SIGINT/SIGTERM received, stopping {2017/06/09 16:23:49} Capturing stopped {2017/06/09 16:23:49} Add /var/www/html/media/vi_95890_20170609_162301.mp4 to Box Queue at pos 28 {2017/06/09 16:23:49} DEBUG 3 {2017/06/09 16:23:49} send smd 0 [2017/06/09 16:23:49] Stop capture requested [2017/06/09 16:23:49] Send ca 0 {2017/06/09 16:23:50} Executing macro /var/www/html/macros/startstop.sh "stop" {2017/06/09 16:23:55} RaspiMJPEG Version 5.8.03 {2017/06/09 16:23:55} Executing macro /var/www/html/macros/startstop.sh "start" {2017/06/09 16:23:55} recommended video buffer size 65536 {2017/06/09 16:23:55} h264 size set to 131072 {2017/06/09 16:23:55} recommended video buffers 1 {2017/06/09 16:23:55} h264 buffers set to recommended 1 [2017/06/09 16:23:55] Scheduled management tasks. Next at 1497000535

roberttidey commented 7 years ago

Don't worry about the permission denied message. That is due to a new optional macro script. It defaults to not being allowed to run until user chooses. I have made a small adjustment to prevent this confusing people.

On the actual problem, I am checking some more items to try to get it to fail for me. THere are a couple of things you could try which might help track it down.

1 There is an optional MMAL logging facility which logs activity on the MMAL call backs. To activate this you need to edit the config file /etc/raspimjpeg THere is a setting called mmal_log (around line 55). Set it to the value suggested in the comment and restart the software. This causes the callback activity to be logged. Leave it running till it fails and then grab the /dev/shm/mjpeg/mmallogfile together with the scheduleLog. Restore the mmal_log setting for normal use as that logs grows fairly quickly.

2) You said I think this failure only occurs for the FD resolution. I just wanted to see how that depended. Could you try setting the resolution to 1728 x 972 and 1536 x 864 to see if they have the problem.

shinji2009 commented 7 years ago

1728 x 972 cause permanently busy file 1536 x 864 cause permanently busy files

busy files created at 2017-06-12 13:55:12 and 12:54:37

sorry for some reason github tell me that it don't support my zips so i uplad logs here. http://my-files.ru/jez2sw if it's not ok please tell me how to upload zips here

shinji2009 commented 7 years ago

wipe sd card clean and check it for errors three times with different software. install everything from scratch. try to use recording only. 1280*720 10fps. {2017/07/17 09:48:03} Watchdog detected problem. Stopping{2017/07/17 09:48:13} SIGINT/SIGTERM received, stopping. ((( maybe its just a defective chinese rpis or/and camera modules?

roberttidey commented 7 years ago

Maybe but I suspect not.

It is worth checking two hardware related items that often cause problems.

1) Make sure the connections to the camera are OK. THe tiny ribbon connector on the camera module itself can also become loose causing intermittent connections.

2) 5V power at the Raspberry is important. The camera and GPU operation puts extra stress on the power. In particular you must have both a good quality PSU and a good quality short USB power lead. Many USB cables have a high resistance (> 0.2Ohm and can cause substantial voltage drop down the cable no matter how good the PSU.

shinji2009 commented 7 years ago

1 and 2 has been checked before. i am using good cables and adapters 5v >=2a

shinji2009 commented 7 years ago

just in case was tested with atx power supply 5.2v 20a - same thing)

pishotta commented 7 years ago

I may have missed something, but what kind of rpi is this? A 3, or a zero?

roberttidey commented 7 years ago

The software runs on any Pi from zero up to 3. I have several cameras running on Zero with no problem, but it is best not too have any other processes on them which take significant resources.

Is it still the case that the problem is resolution dependent? So lower resolutions are still OK?

pishotta commented 7 years ago

I too have it running on both 3’s and 0’s quite well, but have had to be a bit careful on the zero. It can get swamped if it tries to do too much at the same time. I noticed from his logs that the watchdog timer was kicking in. Thought that might indicate some kind of resource problem triggering resets. I had that happen a few times when I got overly ambitious on my zero, which is why I was asking. Simultaneous capturing, boxing, splitting, motion detection (particularly if external MD and at higher resolutions) might demand more resources than a zero could easily and promptly supply. Just a thought, if he happens to be using a zero.

From: roberttidey [mailto:notifications@github.com] Sent: Friday, July 21, 2017 3:45 AM To: silvanmelchior/RPi_Cam_Web_Interface Cc: Fred Pishotta; Comment Subject: Re: [silvanmelchior/RPi_Cam_Web_Interface] permanently busy files after fhd splitting (#350)

The software runs on any Pi from zero up to 3. I have several cameras running on Zero with no problem, but it is best not too have any other processes on them which take significant resources.

Is it still the case that the problem is resolution dependent? So lower resolutions are still OK?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/silvanmelchior/RPi_Cam_Web_Interface/issues/350#issuecomment-316929856 , or mute the thread https://github.com/notifications/unsubscribe-auth/AKLlDTysLu7SNWagTPjq58BYXGdPk4esks5sQFcDgaJpZM4Nt3Oh . https://github.com/notifications/beacon/AKLlDYaV_nQBPY3xDV1J0aqz8CTbWCcKks5sQFcDgaJpZM4Nt3Oh.gif

shinji2009 commented 7 years ago

i can't catch this error at 720p in motion detection mode, but i catch it in record video mode at 720p. maybe it is not resolution dependent. more likely overall load issue. i don't have any other software installed on rpis. now testing at 576p record video mode.

shinji2009 commented 7 years ago

can't catch this error at 576p record video mode.

pishotta commented 7 years ago

You might try increasing the "watchdog" values under Camera Settings. I believe the default values are "Watchdog, default interval 3s, errors 3". As a test, try interval = 30s and errors = 5. If that helps, you can tune them back down.