search

ZoneMinder / zoneminder

ZoneMinder is a free, open source Closed-circuit television software application developed for Linux which supports IP, USB and Analog cameras.
http://www.zoneminder.com/
GNU General Public License v2.0
5.12k stars 1.22k forks source link

H264 passthrough event metadata at end of video file #2984

Closed okgo88 closed 3 years ago

okgo88 commented 4 years ago

Describe Your Environment

If the issue concerns a camera

Describe the bug In previous versions of Zoneminder, playing events from "H264 passthrough" recorded cameras would start immediately, allow scrubbing, and basically stream the requested segments in a very pleasant way. In more current versions of Zoneminder the videos need to download completely (minutes to hours depending on the connection) before they will be viewable. I've narrowed down the problem to the metadata of the video being placed at the end of the .mp4 event file vs at the front. Executing "ffmpeg -i input.mp4 -codec copy -movflags faststart -f mp4 output.mp4" on any finished video clip will result in proper web playback as described in the first sentence. I've attempted to add the "faststart" parameter into the various ffmpeg parameters fields of Zoneminder but nothing seems to have any effect on the resulting event video.

Best I can narrow it down from apt logs and archived video, the change happened to Zoneminder sometime between April (I have a good clip from 4/9) and May (the oldest bad archived clip I have is on 5/2) of 2020, and I had updated between 1.34.8 to 1.34.10 between that date span.

To Reproduce Steps to reproduce the behavior:

  1. Record any video from a camera in H264 passthrough mode.
  2. Attempt to play video event recorded in "H264 passthrough" mode in any web browser.
  3. Observe that the file needs to download completely to be played properly.

Expected behavior Events played back from "H264 passthrough" recorded cameras would start immediately, allow scrubbing, and basically stream the segments requested in a very pleasant way.

Debug Logs

welcome[bot] commented 4 years ago

Thanks for opening your first issue here! Just a reminder, this forum is for Bug Reports only. Be sure to follow the issue template!

connortechnology commented 4 years ago

In 1.34.17 we now default to movflags=frag_keyframe which may fix this issue. Also you can specify other values in the EncoderParams field so you should be able to experiment and try different values.

Tamahome-M commented 4 years ago

I have the same problem, updating to the ZoneMinder v1.34.19 version did not fix the problem with the long start of playback in the browser.

connortechnology commented 4 years ago

.19 just gives us the ability to change the setting. So next step is to try different values. So go to Monitor->Storage->Encoder Parameters add an entry movflags=frag_keyframe

You can try just abouthing from https://ffmpeg.org/ffmpeg-formats.html

Tamahome-M commented 4 years ago

Unfortunately, adding "movflags=frag_keyframe" had no effect. Also tried "movflags=frag_keyframe+faststart" and "movflags=faststart" .. By the way, should the ongoing event show in the browser?

connortechnology commented 4 years ago

The ongoing event SHOULD show in browser and play, but might not depending on movflags. Please post debug zmc logs.

Tamahome-M commented 4 years ago 
Sep 10 14:48:15 nat zms_m20[8615]: DB1 [zms_m20] [Got QUERY command, sending STATUS]
Sep 10 14:48:16 nat zmc_m20[8403]: INF [zmc_m20] [Zad_Vhod: images:2400 - Capturing at 25.00 fps, capturing bandwidth 43720bytes/sec]
Sep 10 14:48:17 nat zmc_m17[7198]: WAR [zmc_m17] [ImageBufferCount 90 is too small. Needs to be at least 101. Either increase it or decrease time between keyframes]
Sep 10 14:48:17 nat zms[8622]: DB1 [zms] [LogOpts: level=DB1 effective=DB1, screen=OFF, database=ERR, logfile=DB1->/var/log/zm/zm_debug.log.08622, syslog=DB9]
Sep 10 14:48:17 nat zms[8622]: DB1 [zms] [Query: mode=jpeg&frame=1&scale=0&rate=100&maxfps=25&replay=none&source=event&event=162323&connkey=5926&rand=1599738497&auth=edf84e5db6d1cb3ab3f8aba6013fb20e]
Sep 10 14:48:17 nat zms[8622]: DB1 [zms] [Unknown parameter passed to zms rand=1599738497]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [LogOpts: level=DB1 effective=DB1, screen=OFF, database=ERR, logfile=DB1->/var/log/zm/zm_debug.log.08622, syslog=DB9]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Attempting to authenticate user from auth string '*CUT*']
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [AUTH_HASH_TTL is 6]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Checking auth_key '*CUT*' -> auth_md5 '*CUT*' == '*CUT*']
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Authenticated user 'admin']
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Detected a x86\x86-64 processor with AVX2]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Got 1 for v4l_captures_per_frame]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [ffmpegcamera: width 2560 height 1440 linesize 10240 colours 4 imagesize 14745600]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [encoder params # Lines beginning with # are a comment 
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [monitor purpose=0]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [mem.size(8) SharedData=600 TriggerData=560 VideoStoreData=4128 timestamps=1920 images=120x14745600 = 1769472000 total=1769479272]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Loaded Storage area 3 'VideoCam6.4Tb']
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Storage path: /mnt/6.4T/VideoCam]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Monitor Zad_Vhod has function 5,
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Got 1 zones for monitor Zad_Vhod]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Loaded monitor 20(Zad_Vhod), 1 zones]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Loaded Storage area 3 'VideoCam6.4Tb']
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Loading video file from /mnt/6.4T/VideoCam/20/2020-09-10/162323/162323-video.mp4]
Sep 10 14:48:17 nat zms_e162323[8622]: INF [zms_e162323] [Enabling ffmpeg logs, as LOG_DEBUG+LOG_FFMPEG are enabled in options]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Dumping stream index i(0) index(0)]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [    Stream #0:0]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [language (und)]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [frames:32, frame_size:0 stream timebase: 1/90000]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [codec: h264]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [25.07 fps]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [90k stream tb numerator]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [ (default)]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Using codec (h264) for stream 0]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Using codec (aac) for stream 1]
Sep 10 14:48:17 nat zms_e162323[8622]: ERR [zms_e162323] [Invalid frame id specified. 1 > 0]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Trying to open the lock on /var/run/zm/zms-005926.lock]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [We have obtained a lock on /var/run/zm/zms-005926.lock fd: 7]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [replay rate(100) in_event(1) time_to_event(0.000000)=curr_stream_time(1599738403.000000)-frame timestamp:0.000000]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [analyze file /mnt/6.4T/VideoCam/20/2020-09-10/162323/00001-analyse.jpg not found will try to stream from other]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [capture file /mnt/6.4T/VideoCam/20/2020-09-10/162323/00001-capture.jpg not found either]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from ffmpeg]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from stream 0 at 0.000000]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from stream 0 at seektarget: 0]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from stream 0 at 0]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [resulting video frame: format 12 yuvj420p 1920x1080 linesize:1920x960 pts: 878400]
Sep 10 14:48:17 nat zms_e162323[8622]: DB1 [zms_e162323] [resulting video frame: format 12 yuvj420p 1920x1080 linesize:1920x960 pts: 882000]
Sep 10 14:48:17 nat zms_e162323[8622]: INF [zms_e162323] [deprecated pixel format used, make sure you did set range correctly]
Sep 10 14:48:18 nat zms_e162323[8622]: DB1 [zms_e162323] [Got SCALE command, to 33]
Sep 10 14:48:18 nat zms_e162323[8622]: DB1 [zms_e162323] [Size of msg 24]
Sep 10 14:48:18 nat zms_e162323[8622]: DB1 [zms_e162323] [Got QUERY command, sending STATUS]
Sep 10 14:48:18 nat zms_e162323[8622]: DB1 [zms_e162323] [Size of msg 24]
Sep 10 14:48:18 nat zmc_m16[7174]: INF [zmc_m16] [Kotel: images:12100 - Capturing at 20.00 fps, capturing bandwidth 124449bytes/sec]
Sep 10 14:48:18 nat zmc_m14[7149]: WAR [zmc_m14] [ImageBufferCount 90 is too small. Needs to be at least 201. Either increase it or decrease time between keyframes]
Sep 10 14:48:18 nat zmc_m15[7162]: WAR [zmc_m15] [ImageBufferCount 120 is too small. Needs to be at least 201. Either increase it or decrease time between keyframes]
Sep 10 14:48:19 nat zmc_m18[7212]: INF [zmc_m18] [Kyxnya: images:14700 - Capturing at 20.00 fps, capturing bandwidth 372185bytes/sec]
Sep 10 14:48:19 nat zms_m20[8615]: WAR [zms_m20] [Frame send time 216 msec too slow, throttling maxfps to 16.67]
Sep 10 14:48:19 nat zms_m20[8615]: DB1 [zms_m20] [Got QUERY command, sending STATUS]
Sep 10 14:48:20 nat zmc_m14[7149]: INF [zmc_m14] [Zad Dvor: images:12240 - Capturing at 20.00 fps, capturing bandwidth 119161bytes/sec]
Sep 10 14:48:20 nat zmc_m20[8403]: WAR [zmc_m20] [ImageBufferCount 120 is too small. Needs to be at least 251. Either increase it or decrease time between keyframes]
Sep 10 14:48:21 nat zmc_m17[7198]: INF [zmc_m17] [Koridor: images:15300 - Capturing at 25.00 fps, capturing bandwidth 560169bytes/sec]
Sep 10 14:48:21 nat zmc_m17[7198]: WAR [zmc_m17] [ImageBufferCount 90 is too small. Needs to be at least 101. Either increase it or decrease time between keyframes]
Sep 10 14:48:21 nat zms_e162323[8622]: DB1 [zms_e162323] [Got QUERY command, sending STATUS]
Sep 10 14:48:21 nat zms_e162323[8622]: DB1 [zms_e162323] [Size of msg 24]
Sep 10 14:48:22 nat zmc_m13[7137]: ERR [zmc_m13] [Unable to open input rtsp://192.168.1.2:554/user=admin&password=&channel=1&stream=0?.sdp due to: No route to host]
Sep 10 14:48:22 nat zmc_m13[7137]: ERR [zmc_m13] [Failed to prime capture of initial monitor]
Sep 10 14:48:22 nat zms_m20[8615]: DB1 [zms_m20] [Got QUERY command, sending STATUS]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [analyze file /mnt/6.4T/VideoCam/20/2020-09-10/162323/00000-analyse.jpg not found will try to stream from other]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [capture file /mnt/6.4T/VideoCam/20/2020-09-10/162323/00000-capture.jpg not found either]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from ffmpeg]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from stream 0 at 0.000000]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from stream 0 at seektarget: 0]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [Getting frame from stream 0 at 0]
Sep 10 14:48:22 nat zms_e162323[8622]: DB1 [zms_e162323] [resulting video frame: format 12 yuvj420p 1920x1080 linesize:1920x960 pts: 885600]
Sep 10 14:48:22 nat zms_e162323[8622]: INF [zms_e162323] [deprecated pixel format used, make sure you did set range correctly]
Sep 10 14:48:23 nat zmc_m16[7174]: INF [zmc_m16] [Kotel: images:12200 - Capturing at 20.00 fps, capturing bandwidth 124338bytes/sec]
Sep 10 14:48:23 nat zmc_m21[7259]: ERR [zmc_m21] [Unable to open input rtsp://192.168.1.13:554/user=admin&password=&channel=1&stream=0?.sdp due to: No route to host]
Sep 10 14:48:23 nat zmc_m21[7259]: ERR [zmc_m21] [Failed to prime capture of initial monitor]
Sep 10 14:48:23 nat zmc_m18[7212]: INF [zmc_m18] [Kyxnya: images:14800 - Capturing at 25.00 fps, capturing bandwidth 476546bytes/sec]
Sep 10 14:48:23 nat zmc_m15[7162]: INF [zmc_m15] [Pered Dvor: images:12300 - Capturing at 20.00 fps, capturing bandwidth 123041bytes/sec]
incompetent-nerd commented 3 years ago

Unfortunately, adding "movflags=frag_keyframe" had no effect. Also tried "movflags=frag_keyframe+faststart" and "movflags=faststart" .. By the way, should the ongoing event show in the browser?

This worked for me: movflags=frag_custom+dash+delay_moov

Tamahome-M commented 3 years ago

This worked for me: movflags=frag_custom+dash+delay_moov I tried your parameters, but they did not work for me, it even got worse.

Although if you open a file via sftp, then it is played almost instantly and on a slow 3G channel.

okgo88 commented 3 years ago

Unfortunately, adding "movflags=frag_keyframe" had no effect. Also tried "movflags=frag_keyframe+faststart" and "movflags=faststart" .. By the way, should the ongoing event show in the browser?

This worked for me: movflags=frag_custom+dash+delay_moov

This also worked for me :)

dodexahedron commented 3 years ago

This worked for me: movflags=frag_custom+dash+delay_moov

Another upvote for this one, if anybody comes looking.

fennec622 commented 3 years ago

This worked for me: movflags=frag_custom+dash+delay_moov

Another upvote for this one, if anybody comes looking.

For chrome it's ok

But same problem on safari mac or ios with movflags=frag_custom+dash+delay_moov

Do you know another option ?

thanks

incompetent-nerd commented 3 years ago

I went into each monitor and under storage/optional encoder parameters, I added the following line: movflags=faststart So now I have only the above line and nothing else.

Now, all my devices (Chrome, Firefox, Edge, ZMNinja on Windows/IOS/Android) all work like before, i.e. playing begins immediately. One thing I have noticed is sometimes my event durations are not 10 minutes long. Sometimes they are 15 minutes, sometimes they are 2 minutes, etc... Not sure why. I recall trying this setting a few months ago and it didn't do anything, so I'm not sure if anything was changed in the most recent builds or not.