Live View Fails [SOLVED]

[mfitch]

Hello! I'm having an issue where the live view from my one and only camera is failing to show. The feed is partially loaded and then errors, then the next frame is again partially loaded and fails again. I upgraded from version 1.36.5 to the latest version (1.36.12) today hoping to fix the issue but it didn't. My system had been running great for a while (that I noticed) up until about two weeks ago I'd say. Recorded playback is fine.

My setup:
- I'm running this in a Docker container using ubuntu:hirsute as a base
- My CPU load is usually around 1.6 so I think CPU is ok
- My SHM is listed as 3% so I think memory is ok
- I only use 1 camera right now:
. 1080P, 10FPS, 24 bit color
. configured as ffmpeg source (rtsp, TCP)
. 'Camera Passthrough' mode
. Camera is configured to send already encoded H.264 video
. In order to help zmNinja playback, I enabled these configurations in the 'Storage' tab, 'Optional Encode Parameters': movflags=frag_custom+dash+delay_moov
. Disabling those encoding parameters didn't seem to help

Logs:
The web log shows:

getStreamCmdResponse stream error: Socket /run/zm/zms-945815s.sock does not exist. This file is created by zms, and since it does not exist, either zms did not run, or zms exited early. Please check your zms logs and ensure that CGI is enabled in apache and check that the PATH_ZMS is set correctly. Make sure that ZM is actually recording. If you are trying to view a live stream and the capture process (zmc) is not running then zms will exit. Please go to http://zoneminder.readthedocs.io/en/lat ... window-etc for more information. - checkStreamForErrors()

I turned on debugging level 3 for zmc and zms. I think zms is terminating while trying to load the feed. Here is a debug log excerpt:

01/07/22 08:33:30.056706 zms_m1[3443].DB2-zm_stream.h/217 [Setting replay_rate 100]
01/07/22 08:33:30.058361 zms_m1[3443].DB2-zm_storage.cpp/62 [Loading Storage for 1 using SELECT `Id`, `Name`, `Path`, `Type`, `Scheme` FROM `Storage` WHERE `Id`=1]
01/07/22 08:33:30.059577 zms_m1[3443].DB1-zm_storage.cpp/80 [Loaded Storage area 1 'Default']
01/07/22 08:33:30.059654 zms_m1[3443].DB1-zm_monitor.cpp/493 [Have camera type File]
01/07/22 08:33:30.059667 zms_m1[3443].DB1-zm_monitor.cpp/2336 [Reloading linked monitors for monitor FrontPorch, '(null)']
01/07/22 08:33:30.059687 zms_m1[3443].DB3-zm_monitor.cpp/570 [Decoding enabled: 1 function 5 Mocord savejpegs 0 videowriter 2]
01/07/22 08:33:30.059703 zms_m1[3443].DB1-zm_packetqueue.cpp/660 [Setting pre_event_video_packet_count to 0]
01/07/22 08:33:30.059714 zms_m1[3443].DB1-zm_packetqueue.cpp/654 [Setting max_video_packet_count to 135]
01/07/22 08:33:30.059726 zms_m1[3443].DB1-zm_monitor.cpp/658 [mem.size(8) SharedData=760 TriggerData=560 VideoStoreData=4128 timestamps=48 images=3x6220800 = 18662400 total=18667960]
01/07/22 08:33:30.059742 zms_m1[3443].DB1-zm_monitor.cpp/694 [Loaded monitor 1(FrontPorch), 0 zones]
01/07/22 08:33:30.059783 zms_m1[3443].DB3-zm_monitor.cpp/917 [Connecting to monitor. Purpose is 0]
01/07/22 08:33:30.059833 zms_m1[3443].DB3-zm_monitor.cpp/930 [Success opening mmap file at (/dev/shm/zm.mmap.1)]
01/07/22 08:33:30.059854 zms_m1[3443].DB3-zm_monitor.cpp/963 [MMap file size is 18667960]
01/07/22 08:33:30.062125 zms_m1[3443].DB3-zm_monitor.cpp/1004 [Aligning shared memory images to the next 64 byte boundary]
01/07/22 08:33:30.062201 zms_m1[3443].DB2-zm_camera.cpp/68 [New camera id: 1 width: 1920 line size: 5760 height: 1080 colours: 3 subpixelorder: 6 capture: 0]
01/07/22 08:33:30.062246 zms_m1[3443].DB3-zm_monitor.cpp/1014 [Allocated 3 3 image buffers]
01/07/22 08:33:30.062265 zms_m1[3443].DB3-zm_monitor.cpp/1067 [Success connecting]
01/07/22 08:33:30.062299 zms_m1[3443].DB1-zm_stream.cpp/329 [Trying to open the lock on /run/zm/zms-922806.lock]
01/07/22 08:33:30.062316 zms_m1[3443].DB3-zm_stream.cpp/337 [SOCKS dir /run/zm already exists]
01/07/22 08:33:30.062360 zms_m1[3443].DB1-zm_stream.cpp/352 [We have obtained a lock on /run/zm/zms-922806.lock fd: 6]
01/07/22 08:33:30.062393 zms_m1[3443].DB3-zm_stream.cpp/359 [Have socket 7]
01/07/22 08:33:30.062415 zms_m1[3443].DB3-zm_stream.cpp/381 [Binding to /run/zm/zms-922806s.sock]
01/07/22 08:33:30.062536 zms_m1[3443].DB3-zm_stream.cpp/392 [comms open at /run/zm/zms-922806s.sock]
01/07/22 08:33:30.062609 zms_m1[3443].DB3-zm_monitor.h/442 [Shared data is valid, checking heartbeat 1641562410 - 1641562410 = 0 < 5.000000]
01/07/22 08:33:30.062648 zms_m1[3443].DB3-zm_stream.cpp/98 [FPS:9.82, MaxFPS:30.00, BaseFPS:9.82, EffectiveFPS:9.82, FrameMod:1, replay_rate(100)]
01/07/22 08:33:30.062733 zms_m1[3443].DB2-zm_monitorstream.cpp/561 [Not using playback_buffer]
01/07/22 08:33:30.062752 zms_m1[3443].DB3-zm_monitor.h/442 [Shared data is valid, checking heartbeat 1641562410 - 1641562410 = 0 < 5.000000]
01/07/22 08:33:30.062770 zms_m1[3443].DB2-zm_monitorstream.cpp/695 [Sending frame index: 1: frame_mod: 1 frame count: 0 paused(0) delayed(0)]
01/07/22 08:33:30.062786 zms_m1[3443].DB3-zm_stream.cpp/162 [Scaling by 100, zooming by 100 = magnifying by 100(100)
Last scaling by 100, zooming by 100 = magnifying by 100(100)
Base image width = 1920, height = 1080
Virtual image width = 1920, height = 1080
Last virtual image width = 1920, height = 1080
Actual image width = 1920, height = 1080
Last actual image width = 1920, height = 1080
Display image width = 1920, height = 1080
Last display image width = 1920, height = 1080
Send image width = 1920, height = 1080
Last send image width = 1920, height = 1080
]
01/07/22 08:33:30.062803 zms_m1[3443].DB3-zm_stream.cpp/196 [Real image width = 1920, height = 1080]
01/07/22 08:33:30.101059 zms_m1[3443].DB3-zm_monitorstream.cpp/798 [Sleeping for 50925us]
01/07/22 08:33:30.152141 zms_m1[3443].DB3-zm_monitor.h/442 [Shared data is valid, checking heartbeat 1641562410 - 1641562410 = 0 < 5.000000]
01/07/22 08:33:30.152238 zms_m1[3443].DB3-zm_monitorstream.cpp/789 [Waiting for capture last_write_index=1]
01/07/22 08:33:30.152253 zms_m1[3443].DB3-zm_monitorstream.cpp/798 [Sleeping for 50925us]
01/07/22 08:33:30.203279 zms_m1[3443].DB3-zm_monitor.h/442 [Shared data is valid, checking heartbeat 1641562410 - 1641562410 = 0 < 5.000000]
01/07/22 08:33:30.203409 zms_m1[3443].DB2-zm_monitorstream.cpp/695 [Sending frame index: 2: frame_mod: 1 frame count: 1 paused(0) delayed(0)]
01/07/22 08:33:30.203436 zms_m1[3443].DB3-zm_stream.cpp/162 [Scaling by 100, zooming by 100 = magnifying by 100(100)
Last scaling by 100, zooming by 100 = magnifying by 100(100)
Base image width = 1920, height = 1080
Virtual image width = 1920, height = 1080
Last virtual image width = 1920, height = 1080
Actual image width = 1920, height = 1080
Last actual image width = 1920, height = 1080
Display image width = 1920, height = 1080
Last display image width = 1920, height = 1080
Send image width = 1920, height = 1080
Last send image width = 1920, height = 1080
]
01/07/22 08:33:30.203461 zms_m1[3443].DB3-zm_stream.cpp/196 [Real image width = 1920, height = 1080]
01/07/22 08:33:30.235251 zms_m1[3443].DB2-zm_monitorstream.cpp/704 [sendFrame failed, quiting.]
01/07/22 08:33:30.240044 zms_m1[3443].DB1-zms.cpp/342 [Terminating]

Does anyone know what I could do to try and troubleshoot? Thank you!

[mfitch]

After getting a good tip from Isaac Connor, which was:

sendFrame is failing.. meaning it tried to write the jpeg out to the socket and got an error.

he prompted me to check out some of the networking I had set up. My installation includes an nginx reverse proxy, which was giving an error when trying to view live streams:

failed (13: Permission denied) while reading upstream, client: <IP>, server: <URL>,
request: "GET /zm/cgi-bin/nph-zms?scale=100&mode=jpeg&maxfps=30&monitor=1&auth=<AUTH KEY>&connkey=<CONN KEY>&rand=<RAND VALUE> HTTP/2.0", upstream: "http://<IP>:8080/zm/cgi
-bin/nph-zms?scale=100&mode=jpeg&maxfps=30&monitor=1&auth=<AUTH KEY>&connkey=<CONN KEY>&rand=<RAND VALUE>", host: "<URL>", referrer: "https://<URL>/zm/inde
x.php?view=watch&mid=1"

After looking at my nginx reverse proxy configuration, I found that I was including a Basic Auth header for _only_ the live stream page for some reason. I commented out that line, restarted nginx, and it works now! Here's my nginx config snippet that works:

location /zm/cgi-bin/nph-zms {
include /config/nginx/proxy.conf;
proxy_buffering off;
proxy_pass http://<URL>:8080/zm/cgi-bin/nph-zms;
# proxy_set_header Authorization "Basic $arg_basicauth";
}

Not sure what I was thinking with that one. A big thank you to Isaac Connor and Jonathan Bennett for helping me with this!