Motion video capture sometimes does not stop when video split

[emjas92]

I am seeing an occasional issue at night where the video capture continues for a long time after movement has ended and the picture is completely black. This is happening with video split on or off. #523 sounds similar.

My relevant config is:

exposure_mode night
video_width 1296
video_height 972
video_fps 10
video_split 300
image_width 1296
image_height 972
motion_external 0
motion_startframes 2
motion_stopframes 100
video_buffer 5000 (in /etc/raspimjpeg)

Here is my log where the video starts at 2021/04/19 23:23:27 and runs for 5 and a half hours until another motion event occurs at 05:00:57. 20210420-074400-scheduleLog.txt

I think that this does not happen when there is some sort of light in frame (such as a dim solar light). Could there be a bug with motion detection and completely black frames? I don't have a sample at the moment, but I can post one when it happens again.

I also notice that the pre-event buffer sometimes captures 5-10 minutes of black frames before motion happens. I assume that's because the buffer is based on frame size and not time.

Appreciate any advice.

[roberttidey]

I am not aware of an issue with black frames causing a motion stop problem but as I normally disable motion detect during periods of darkness on unilluminated cameras (see scheduler controls to do this automatically) then I wouldn't have seen this anyway.

I can't see an obvious cause in the code but I'll investigate further.

I would advise adding motion parameter monitoring into the annotation. Use %c and %f to monitor change values and changed frames counts. When in capture then changed frame count increments if the change value is below the threshold (default 250) and decrements by 2 if is above. So with your motion_stopframes 100 you need a run of 100 quiet frames to trigger a stop or a bit more if there is an occasional blip.

If you see change values close to your threshold of 250 in the dark then you might want to increase the threshold. You may also want to consider reducing the number of stop frames.

The pre-buffer does indeed work on size. With dark frames the video compression will be very high and so more frames will fit.

Again you can adjust the pre-buffer size automatically using the scheduler to reduce its size during dark periods.

[emjas92]

Thanks for your reply.

I'll look at changing the pre-buffer and stop frames using the schedule (I didn't even realize pre-buffer was available there). I've set %c %f for now and will monitor it. It doesn't happen every night.

In case you are interested: I have PIR security lights outside so I keep motion detection active at night. My camera looks down my driveway and I've masked out the road at the end, but I still want to capture movement from the end of the driveway up into/out of the motion-sensitive area - therefore I'm using 'large' pre-buffer/stop frames.

[emjas92]

I have some samples of the video capture not stopping, and this time the frames were not pitch black.

sample-1.zip - 2021/04/24 06:43:14 - log shows Reset motion state and no detected motion in the video segments. sample-2.zip - 2021/04/28 18:44:52 - log shows weird capture sequence, with two Capturing with split of 300 seconds at 18:46

Are you able to shed any light on this?

[roberttidey]

I'll check into those logs

[emjas92]

I may have found the problem.

I'm using the end_vid macro to process the .h264 recording myself, and by default this macro is run synchronously.

This can clearly be seen in the schedule log and the video segments' annotation times.

{2021/04/30 17:30:31} Stopping video from timer
{2021/04/30 17:30:31} Capturing stopped
{2021/04/30 17:30:31} Executing macro /var/www/rpicam/macros/end_vid.sh "/var/www/rpicam/media/20210430_172531_0000.h264"
{2021/04/30 17:30:31} DEBUG 3

there's a long pause here while end_vid.sh is running...

{2021/04/30 17:32:07} Restarting next split of 300 seconds
{2021/04/30 17:32:07} Capturing started
{2021/04/30 17:37:07} Stopping video from timer
{2021/04/30 17:37:07} Capturing stopped
{2021/04/30 17:37:07} Executing macro /var/www/rpicam/macros/end_vid.sh "/var/www/rpicam/media/20210430_173207_0000.h264" 

It would seem this is causing a problem when a new motion event is triggered while another video is being processed.

first event has finished...

{2021/04/30 12:56:06} Executing macro /var/www/rpicam/macros/motion_event.sh "0"
{2021/04/30 12:56:06} send smd 0
[2021/04/30 12:56:06] Stop capture requested
[2021/04/30 12:56:06] Send ca 0
{2021/04/30 12:56:07} Capturing stopped
{2021/04/30 12:56:07} Executing macro /var/www/rpicam/macros/end_vid.sh "/var/www/rpicam/media/20210430_125556_0000.h264"
{2021/04/30 12:56:07} DEBUG 3

second event fired, but end_vid.sh is still running...

{2021/04/30 12:56:14} Executing macro /var/www/rpicam/macros/motion_event.sh "1"
{2021/04/30 12:56:14} send smd 1
[2021/04/30 12:56:14] Start capture requested from Pipe
[2021/04/30 12:56:14] Send ca 1
{2021/04/30 12:56:21} Reset motion state                 <-- this is unexpected
{2021/04/30 12:56:21} Capturing with split of 300 seconds

I have now set the end_vid macro to be asynchronous with &end_vid.sh and I'll see how it goes.

[roberttidey]

That sounds like a plausible explanation. In general macros are best executed asynchronously unless there is a good reason not to and in those cases the macro needs to be quick.

[emjas92]

Closing as there's been no re-occurrences after changing the macro command