Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Current Development version likely to have breaking changes
Post Reply
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

I have some cameras where enabling the ONVIF Event Listener causes capturing (RTSP) to stop. Other cameras work correctly. I cloned a monitor and on the cloned monitor, if I enable the ONVIF Event Listener, capturing stops. It continues from the same source on the original monitor. I disabled authentication on both the camera and in the monitor to eliminate that as part of the issue.

What is the best way to debug this?

The cameras that don't work correctly are from Vikylin, supposed to be a Hikvision clone.

Regards,

Mark
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

I've found a way to get ONVIF events. I created another monitor for the same camera. The camera is set up for no authentication on RTSP, Authentication on ONVIF, and disabled Hikvision functionality. The monitor is set up with Capturing enabled, but not Decoding, ONVIF enabled, with authentication, and Amcrest functionality disabled. The order of these selections also seemed to make a difference, but I could not determine a consistent pattern. The original capture / analyse monitor for the same camera remains operational.

With this setup, at least some ONVIF events are detected by the second monitor. So, I think there is some subtle interaction with these cameras.

Regards,

Mark
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

One more observation: If I set up the second monitors for a camera, after a day or two they will begin recording continuously, believing there is an event all fo the time. They record the default max 6000 frames and start again, filling up the disk. I have to restart Zoneminder to stop this action.

Regards,

Mark
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

I enabled some debugging on the channel that started continuously reporting ONVIF events. There are triggers on but no offs. Anything else I should be looking for in the logs?

cat /var/log/zoneminder/zmc_m9.log | grep ONVIF | grep Triggered
01/06/24 03:05:56.805789 zmc_m9[63212].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 03:06:06.804948 zmc_m9[63212].INF-zm_monitor.cpp/1851 [Triggered off ONVIF]
01/06/24 03:08:15.197594 zmc_m9[63212].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 08:47:16.230701 zmc_m9[63212].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 11:13:49.067630 zmc_m9[144020].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 11:13:49.068914 zmc_m9[143869].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704564829.067630, 'zmc_m9', 0, 144020, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5471]
01/06/24 11:13:59.071713 zmc_m9[144020].INF-zm_monitor.cpp/1851 [Triggered off ONVIF]
01/06/24 11:13:59.072993 zmc_m9[143869].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704564839.071713, 'zmc_m9', 0, 144020, 0, 'INF', 'Triggered off ONVIF', 'zm_monitor.cpp', 1851 ), thread_id: 5471]
01/06/24 11:19:26.048483 zmc_m9[144020].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 11:19:26.049645 zmc_m9[143869].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704565166.048483, 'zmc_m9', 0, 144020, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5471]
01/06/24 15:56:13.679239 zmc_m9[144020].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 15:56:13.680358 zmc_m9[143869].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704581773.679239, 'zmc_m9', 0, 144020, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5471]
01/06/24 16:23:12.693605 zmc_m9[144020].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 16:23:12.694721 zmc_m9[143869].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704583392.693605, 'zmc_m9', 0, 144020, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5471]
01/06/24 16:36:01.169918 zmc_m9[144020].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 16:36:01.171096 zmc_m9[143869].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704584161.169918, 'zmc_m9', 0, 144020, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5471]

A working channel has ons and offs, partial shown below:

01/06/24 16:30:00.752074 zmc_m2[143972].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 16:30:00.753649 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704583800.752074, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5493]
01/06/24 16:30:01.752240 zmc_m2[143972].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 16:30:01.754070 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704583801.752240, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5493]
01/06/24 16:30:41.621943 zmc_m2[143972].INF-zm_monitor.cpp/1851 [Triggered off ONVIF]
01/06/24 16:30:41.621968 zmc_m2[143972].INF-zm_monitor.cpp/1851 [Triggered off ONVIF]
01/06/24 16:30:41.623500 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704583841.621943, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered off ONVIF', 'zm_monitor.cpp', 1851 ), thread_id: 5493]
01/06/24 16:30:41.624468 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704583841.621968, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered off ONVIF', 'zm_monitor.cpp', 1851 ), thread_id: 5493]
01/06/24 16:35:58.102957 zmc_m2[143972].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 16:35:58.104473 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704584158.102957, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5493]
01/06/24 16:35:59.103073 zmc_m2[143972].INF-zm_monitor.cpp/1844 [Triggered on ONVIF]
01/06/24 16:35:59.104390 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704584159.103073, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered on ONVIF', 'zm_monitor.cpp', 1844 ), thread_id: 5493]
01/06/24 16:36:37.341832 zmc_m2[143972].INF-zm_monitor.cpp/1851 [Triggered off ONVIF]
01/06/24 16:36:37.341853 zmc_m2[143972].INF-zm_monitor.cpp/1851 [Triggered off ONVIF]
01/06/24 16:36:37.343045 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704584197.341832, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered off ONVIF', 'zm_monitor.cpp', 1851 ), thread_id: 5493]
01/06/24 16:36:37.343898 zmc_m2[143901].DB1-zm_db.cpp/202 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1704584197.341853, 'zmc_m2', 0, 143972, 0, 'INF', 'Triggered off ONVIF', 'zm_monitor.cpp', 1851 ), thread_id: 5493]

Regards,

Mark
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

Since updating to 1.37.50 multiple cameras are now recording 6000 or so frames on events even though the alarm frames are much less.

Regards,

Mark
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

I tried various combinations of authentication and no authentication on this camera. If I have both ONVIF events and RTSP streaming enabled in the same monitor, RTSP streaming does not start:

zoneminder-1.37.51-1.15.20240217gitgdef378fe1.fc39.x86_64

RTSP and ONVIF, no authentication or authentication with correct user and password, streaming fails:

02/19/24 13:17:36.968716 zmc_m6[542682].DB2-zm_ffmpeg.cpp/68 [Starting connection attempt to X.X.X.X port 554]
02/19/24 13:17:36.968781 zmc_m6[542682].DB1-zm_ffmpeg_camera.cpp/627 [Received terminate in cb]
02/19/24 13:17:36.968811 zmc_m6[542682].ERR-zm_ffmpeg_camera.cpp/359 [Unable to open input rtsp://X.X.X.X/stream0 due to: Immediate exit requested]

RTSP and ONVIF, authentication with incorrect user, streaming fails:

02/19/24 13:31:10.529879 zmc_m6[544626].DB2-zm_ffmpeg.cpp/68 [Starting connection attempt to X.X.X.X port 554]
02/19/24 13:31:10.530467 zmc_m6[544626].DB2-zm_ffmpeg.cpp/68 [Successfully connected to X.X.X.X port 554]
02/19/24 13:31:10.606098 zmc_m6[544626].WAR-zm_ffmpeg.cpp/68 [method DESCRIBE failed: 401 Unauthorized]
02/19/24 13:31:10.606196 zmc_m6[544626].DB3-zm_ffmpeg.cpp/68 [CSeq: 3
02/19/24 13:31:10.606239 zmc_m6[544626].ERR-zm_ffmpeg_camera.cpp/359 [Unable to open input rtsp://X.X.X.X/stream0 due to: Server returned 401 Unauthorized (authorization failed)]

RTSP Only, streaming succeeds:

02/19/24 13:37:49.133331 zmc_m6[545548].DB2-zm_ffmpeg.cpp/68 [Starting connection attempt to X.X.X.X port 554]
02/19/24 13:37:49.133605 zmc_m6[545548].DB2-zm_ffmpeg.cpp/68 [Successfully connected to X.X.X.X port 554]
02/19/24 13:37:49.209116 zmc_m6[545548].DB2-zm_ffmpeg.cpp/68 [SDP:
02/19/24 13:37:49.209155 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [Failed to parse interval end specification '']
02/19/24 13:37:49.209192 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [video codec set to: h264]
02/19/24 13:37:49.209197 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [RTP Profile IDC: 64 Profile IOP: 0 Level: 33]
02/19/24 13:37:49.209200 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [RTP Packetization Mode: 0]
02/19/24 13:37:49.209204 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [Extradata set to 0x55dda0999fd0 (size: 33)]
02/19/24 13:37:49.209213 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [audio codec set to: pcm_alaw]
02/19/24 13:37:49.209215 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [audio samplerate set to: 8000]
02/19/24 13:37:49.209218 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [audio channels set to: 1]
02/19/24 13:37:49.212932 zmc_m6[545548].DB2-zm_ffmpeg.cpp/68 [setting jitter buffer size to 0]
02/19/24 13:37:49.215457 zmc_m6[545548].DB2-zm_ffmpeg.cpp/68 [setting jitter buffer size to 0]
02/19/24 13:37:49.215482 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [hello state=0]
02/19/24 13:37:49.239132 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [Failed to parse interval end specification '']
02/19/24 13:37:49.240706 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [nal_unit_type: 7(SPS), nal_ref_idc: 3]
02/19/24 13:37:49.240722 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [nal_unit_type: 8(PPS), nal_ref_idc: 3]
02/19/24 13:37:49.240734 zmc_m6[545548].DB3-zm_ffmpeg.cpp/68 [Decoding VUI]

Regards,

Mark
User avatar
iconnor
Posts: 2936
Joined: Fri Oct 29, 2010 1:43 am
Location: Toronto
Contact:

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by iconnor »

The received terminate in cb typically means that the process was killed, likely by zmwatch. You might want to turn it off or adjust its settings.

I can't think of how there would be any interaction between onvif and rtsp streaming. Unfortunately you've trimmed the logs to much for there to be any useful info.
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

iconnor wrote: Wed Feb 21, 2024 3:27 pm The received terminate in cb typically means that the process was killed, likely by zmwatch. You might want to turn it off or adjust its settings.

I can't think of how there would be any interaction between onvif and rtsp streaming. Unfortunately you've trimmed the logs to much for there to be any useful info.
The logs are massive, several GB uncompressed. I can post it somewhere and send a DM if it will help.

Regards,

Mark
dougmccrary
Posts: 1256
Joined: Sat Aug 31, 2019 7:35 am
Location: San Diego

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by dougmccrary »

I'd say you could clear the logs, then run zm until the error and stop it. That should be enough...
User avatar
iconnor
Posts: 2936
Joined: Fri Oct 29, 2010 1:43 am
Location: Toronto
Contact:

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by iconnor »

I really just need 30 or 40 more lines on either side of what you gave.
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

I edited the monitor and enabled ONVIF from a previously capturing monitor. Here is the log after that, sanitized for IP address:

02/22/24 18:32:34.486053 zmc_m6[545548].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO Monitor_Status (MonitorId,Status) VALUES (6, 'NotRunning') ON DUPLICATE KEY UPDATE Status='NotRunning', thread_id: 177620]
02/22/24 18:32:34.486066 zmc_m6[545548].DB1-zm_monitor.cpp/3402 [Stopping packetqueue]
02/22/24 18:32:34.486069 zmc_m6[545548].DB1-zm_monitor.cpp/3408 [Decoder stopping]
02/22/24 18:32:34.486072 zmc_m6[545548].DB1-zm_monitor.cpp/3410 [Decoder stopped]
02/22/24 18:32:34.486074 zmc_m6[545548].DB1-zm_monitor.cpp/3415 [Analysis stopped]
02/22/24 18:32:34.486112 zmc_m6[545548].DB1-zmc.cpp/388 [Cleared monitors]
02/22/24 18:32:34.486130 zmc_m6[545548].DB1-zmc.cpp/392 [terminating]
02/22/24 18:32:34.492890 zmc_m6[545548].DB1-zm_db.cpp/109 [Closing database. Connection id was 177620]
02/22/24 18:32:35.849923 zmc_m6[1102224].DB1-zm_logger.cpp/225 [LogOpts: level=DB3 effective=DB3, screen=OFF, database=INF, logfile=DB9->/var/log/zoneminder/zmc_m6.log, syslog=WAR]
02/22/24 18:32:35.849988 zmc_m6[1102224].DB1-zm_utils.cpp/228 [Detected a x86\x86-64 processor with AVX2]
02/22/24 18:32:35.850507 zmc_m6[1102224].DB2-zm_storage.cpp/61 [Loading Storage for 2 using SELECT `Id`, `Name`, `Path`, `Type`, `Scheme` FROM `Storage` WHERE `Id`=2]
02/22/24 18:32:35.850576 zmc_m6[1102224].DB1-zm_storage.cpp/79 [Loaded Storage area 2 'NewStorage']
02/22/24 18:32:35.850579 zmc_m6[1102224].DB1-zm_monitor.cpp/400 [Have camera type Ffmpeg]
02/22/24 18:32:35.850584 zmc_m6[1102224].DB3-zm_monitor.cpp/492 [Decoding: 5 savejpegs 0 videowriter 2]
02/22/24 18:32:35.850589 zmc_m6[1102224].DB1-zm_packetqueue.cpp/739 [Setting pre_event_video_packet_count to 5]
02/22/24 18:32:35.850592 zmc_m6[1102224].DB1-zm_packetqueue.cpp/733 [Setting max_video_packet_count to 0]
02/22/24 18:32:35.850605 zmc_m6[1102224].DB2-zm_camera.cpp/69 [New camera id: 6 width: 3840 line size: 15360 height: 2160 colours: 4 subpixelorder: 8 capture: 1, size: 33177600]
02/22/24 18:32:35.850616 zmc_m6[1102224].INF-zm_ffmpeg.cpp/83 [Enabling ffmpeg logs, as LOG_DEBUG+LOG_FFMPEG are enabled in options]
02/22/24 18:32:35.850667 zmc_m6[1102224].DB2-zmc.cpp/218 [1 monitors loaded]
02/22/24 18:32:35.850670 zmc_m6[1102224].INF-zmc.cpp/221 [Starting Capture version 1.37.51]
02/22/24 18:32:35.850682 zmc_m6[1102224].DB3-zm_monitor.cpp/2468 [Reloading zones for monitor CAM6 have 0]
02/22/24 18:32:35.851172 zmc_m6[1102228].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1708651955.850616, 'zmc_m6', 0, 1102224, 0, 'INF', 'Enabling ffmpeg logs, as LOG_DEBUG+LOG_FFMPEG are enabled in options', 'zm_ffmpeg.cpp', 83 ), thread_id: 194091]
02/22/24 18:32:35.851578 zmc_m6[1102228].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1708651955.850670, 'zmc_m6', 0, 1102224, 0, 'INF', 'Starting Capture version 1.37.51', 'zmc.cpp', 221 ), thread_id: 194091]
02/22/24 18:32:35.851746 zmc_m6[1102224].DB1-zm_zone.cpp/842 [Got 1 zones for monitor CAM6]
02/22/24 18:32:35.851751 zmc_m6[1102224].DB3-zm_zone.cpp/770 [Got coordinate 0,0 from polygon string]
02/22/24 18:32:35.851754 zmc_m6[1102224].DB3-zm_zone.cpp/770 [Got coordinate 2365,0 from polygon string]
02/22/24 18:32:35.851756 zmc_m6[1102224].DB3-zm_zone.cpp/770 [Got coordinate 2367,207 from polygon string]
02/22/24 18:32:35.851765 zmc_m6[1102224].DB3-zm_zone.cpp/770 [Got coordinate 3824,203 from polygon string]
02/22/24 18:32:35.851767 zmc_m6[1102224].DB3-zm_zone.cpp/770 [Got coordinate 3839,2159 from polygon string]
02/22/24 18:32:35.851770 zmc_m6[1102224].DB3-zm_zone.cpp/770 [Got coordinate 0,2159 from polygon string]
02/22/24 18:32:35.851772 zmc_m6[1102224].DB3-zm_zone.cpp/782 [Successfully parsed polygon string 0,2159]
02/22/24 18:32:35.901221 zmc_m6[1102224].DB1-zm_monitor.cpp/2470 [Reloading zones for monitor CAM6 have 1]
02/22/24 18:32:35.901236 zmc_m6[1102224].DB1-zm_monitor.cpp/864 [SharedData=856 TriggerData=560 zone_count 1 * sizeof int 4 VideoStoreData=4128 timestamps=48 images=3x33177600 = 99532800 analysis images=3x33177600 = 99532800 image_format = 3x4 = 12 total=199071272]
02/22/24 18:32:35.901324 zmc_m6[1102224].DB3-zm_monitor.cpp/897 [Success opening mmap file at (/dev/shm/zm.mmap.6)]
02/22/24 18:32:35.901336 zmc_m6[1102224].DB3-zm_monitor.cpp/930 [MMap file size is 0]
02/22/24 18:32:35.901344 zmc_m6[1102224].DB1-zm_monitor.cpp/935 [Unable to map file /dev/shm/zm.mmap.6 (199071272 bytes) to locked memory, trying unlocked]
02/22/24 18:32:35.901356 zmc_m6[1102224].DB1-zm_monitor.cpp/938 [Mapped file /dev/shm/zm.mmap.6 (199071272 bytes) to unlocked memory]
02/22/24 18:32:35.901370 zmc_m6[1102224].DB3-zm_monitor.cpp/973 [Aligning shared memory images to the next 64 byte boundary 0x7f83982275dc to 0x7f8398227600 moved 36 bytes]
02/22/24 18:32:36.055333 zmc_m6[1102224].DB1-zm_monitor.cpp/2476 [Reloading linked monitors for monitor CAM6, '']
02/22/24 18:32:36.055370 zmc_m6[1102224].DB1-zm_monitor.cpp/1059 [Starting ONVIF]
02/22/24 18:32:36.056347 zmc_m6[1102224].DB1-zm_monitor.cpp/1087 [ONVIF Endpoint: http://X.X.X.X.56/onvif/event_service/Events]
02/22/24 18:32:36.861382 zmc_m6[1102224].DB1-zm_monitor.cpp/1103 [ONVIF :soap_wsa_request OK ]
02/22/24 18:32:56.206187 zmc_m6[1102224].DB1-zm_monitor.cpp/1110 [Good Initial ONVIF Pull0 (null), (null)]
02/22/24 18:32:56.206261 zmc_m6[1102224].DB1-zm_monitor.cpp/1123 [ONVIF :soap_wsa_request OK]
02/22/24 18:32:56.212018 zmc_m6[1102224].DB1-zm_monitor.cpp/1132 [Good Initial ONVIF Renew 0 (null), (null)]
02/22/24 18:32:56.212035 zmc_m6[1102224].DB3-zm_monitor.cpp/1179 [Success connecting]
02/22/24 18:32:56.212964 zmc_m6[1102224].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO Monitor_Status (MonitorId,Status,CaptureFPS,AnalysisFPS,CaptureBandwidth) VALUES (6, 'Running',0,0,0) ON DUPLICATE KEY UPDATE Status='Running',CaptureFPS=0,AnalysisFPS=0,CaptureBandwidth=0, thread_id: 194091]
02/22/24 18:32:56.212986 zmc_m6[1102224].DB1-zm_ffmpeg_camera.cpp/177 [Priming capture from rtsp://X.X.X.X.56/stream0]
02/22/24 18:32:56.213017 zmc_m6[1102224].DB1-zm_ffmpeg_camera.cpp/344 [Calling avformat_open_input for rtsp://X.X.X.X.56/stream0]
02/22/24 18:32:56.213068 zmc_m6[1102224].DB1-zm_ffmpeg_camera.cpp/354 [Rebuilt URI with encoded parameters: 'rtsp://admin:LetsSee117@X.X.X.X.56/stream0']
02/22/24 18:32:56.213219 zmc_m6[1102224].DB3-zm_ffmpeg.cpp/68 [No default whitelist set]
02/22/24 18:32:56.213250 zmc_m6[1102224].DB3-zm_ffmpeg.cpp/68 [Original list of addresses:]
02/22/24 18:32:56.213259 zmc_m6[1102224].DB3-zm_ffmpeg.cpp/68 [Address X.X.X.X.56 port 554]
02/22/24 18:32:56.213266 zmc_m6[1102224].DB3-zm_ffmpeg.cpp/68 [Interleaved list of addresses:]
02/22/24 18:32:56.213273 zmc_m6[1102224].DB3-zm_ffmpeg.cpp/68 [Address X.X.X.X.56 port 554]
02/22/24 18:32:56.213281 zmc_m6[1102224].DB2-zm_ffmpeg.cpp/68 [Starting connection attempt to X.X.X.X.56 port 554]
02/22/24 18:32:56.213388 zmc_m6[1102224].DB1-zm_ffmpeg_camera.cpp/627 [Received terminate in cb]
02/22/24 18:32:56.213422 zmc_m6[1102224].ERR-zm_ffmpeg_camera.cpp/359 [Unable to open input rtsp://X.X.X.X.56/stream0 due to: Immediate exit requested]
02/22/24 18:32:56.214007 zmc_m6[1102228].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1708651976.213422, 'zmc_m6', 0, 1102224, -2, 'ERR', 'Unable to open input rtsp://X.X.X.X.56/stream0 due to: Immediate exit requested', 'zm_ffmpeg_camera.cpp', 359 ), thread_id: 194091]
02/22/24 18:32:56.214562 zmc_m6[1102224].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO Monitor_Status (MonitorId,Status) VALUES (6, 'NotRunning') ON DUPLICATE KEY UPDATE Status='NotRunning', thread_id: 194091]
02/22/24 18:32:56.214582 zmc_m6[1102224].DB1-zmc.cpp/388 [Cleared monitors]
02/22/24 18:32:56.214607 zmc_m6[1102224].DB1-zmc.cpp/392 [terminating]
02/22/24 18:32:56.214615 zmc_m6[1102224].DB1-zm_db.cpp/109 [Closing database. Connection id was 194091]
02/22/24 18:33:01.374132 zmc_m6[1102296].DB1-zm_logger.cpp/225 [LogOpts: level=DB3 effective=DB3, screen=OFF, database=INF, logfile=DB9->/var/log/zoneminder/zmc_m6.log, syslog=WAR]
02/22/24 18:33:01.374176 zmc_m6[1102296].DB1-zm_utils.cpp/228 [Detected a x86\x86-64 processor with AVX2]
02/22/24 18:33:01.374618 zmc_m6[1102296].DB2-zm_storage.cpp/61 [Loading Storage for 2 using SELECT `Id`, `Name`, `Path`, `Type`, `Scheme` FROM `Storage` WHERE `Id`=2]
02/22/24 18:33:01.374673 zmc_m6[1102296].DB1-zm_storage.cpp/79 [Loaded Storage area 2 'NewStorage']
02/22/24 18:33:01.374677 zmc_m6[1102296].DB1-zm_monitor.cpp/400 [Have camera type Ffmpeg]
02/22/24 18:33:01.374682 zmc_m6[1102296].DB3-zm_monitor.cpp/492 [Decoding: 5 savejpegs 0 videowriter 2]
02/22/24 18:33:01.374697 zmc_m6[1102296].DB1-zm_packetqueue.cpp/739 [Setting pre_event_video_packet_count to 5]
02/22/24 18:33:01.374699 zmc_m6[1102296].DB1-zm_packetqueue.cpp/733 [Setting max_video_packet_count to 0]
02/22/24 18:33:01.374707 zmc_m6[1102296].DB2-zm_camera.cpp/69 [New camera id: 6 width: 3840 line size: 15360 height: 2160 colours: 4 subpixelorder: 8 capture: 1, size: 33177600]
02/22/24 18:33:01.374718 zmc_m6[1102296].INF-zm_ffmpeg.cpp/83 [Enabling ffmpeg logs, as LOG_DEBUG+LOG_FFMPEG are enabled in options]
02/22/24 18:33:01.374746 zmc_m6[1102296].DB2-zmc.cpp/218 [1 monitors loaded]
02/22/24 18:33:01.374748 zmc_m6[1102296].INF-zmc.cpp/221 [Starting Capture version 1.37.51]
02/22/24 18:33:01.374823 zmc_m6[1102296].DB3-zm_monitor.cpp/2468 [Reloading zones for monitor CAM6 have 0]
02/22/24 18:33:01.375584 zmc_m6[1102297].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1708651981.374718, 'zmc_m6', 0, 1102296, 0, 'INF', 'Enabling ffmpeg logs, as LOG_DEBUG+LOG_FFMPEG are enabled in options', 'zm_ffmpeg.cpp', 83 ), thread_id: 194107]
02/22/24 18:33:01.376073 zmc_m6[1102297].DB1-zm_db.cpp/205 [Success running sql query INSERT INTO `Logs` ( `TimeKey`, `Component`, `ServerId`, `Pid`, `Level`, `Code`, `Message`, `File`, `Line` ) VALUES ( 1708651981.374748, 'zmc_m6', 0, 1102296, 0, 'INF', 'Starting Capture version 1.37.51', 'zmc.cpp', 221 ), thread_id: 194107]
02/22/24 18:33:01.376212 zmc_m6[1102296].DB1-zm_zone.cpp/842 [Got 1 zones for monitor CAM6]
02/22/24 18:33:01.376218 zmc_m6[1102296].DB3-zm_zone.cpp/770 [Got coordinate 0,0 from polygon string]
02/22/24 18:33:01.376220 zmc_m6[1102296].DB3-zm_zone.cpp/770 [Got coordinate 2365,0 from polygon string]
02/22/24 18:33:01.376223 zmc_m6[1102296].DB3-zm_zone.cpp/770 [Got coordinate 2367,207 from polygon string]
02/22/24 18:33:01.376225 zmc_m6[1102296].DB3-zm_zone.cpp/770 [Got coordinate 3824,203 from polygon string]
02/22/24 18:33:01.376227 zmc_m6[1102296].DB3-zm_zone.cpp/770 [Got coordinate 3839,2159 from polygon string]
02/22/24 18:33:01.376230 zmc_m6[1102296].DB3-zm_zone.cpp/770 [Got coordinate 0,2159 from polygon string]
02/22/24 18:33:01.376232 zmc_m6[1102296].DB3-zm_zone.cpp/782 [Successfully parsed polygon string 0,2159]
02/22/24 18:33:01.429653 zmc_m6[1102296].DB1-zm_monitor.cpp/2470 [Reloading zones for monitor CAM6 have 1]
02/22/24 18:33:01.429679 zmc_m6[1102296].DB1-zm_monitor.cpp/864 [SharedData=856 TriggerData=560 zone_count 1 * sizeof int 4 VideoStoreData=4128 timestamps=48 images=3x33177600 = 99532800 analysis images=3x33177600 = 99532800 image_format = 3x4 = 12 total=199071272]
02/22/24 18:33:01.429721 zmc_m6[1102296].DB3-zm_monitor.cpp/897 [Success opening mmap file at (/dev/shm/zm.mmap.6)]
02/22/24 18:33:01.429729 zmc_m6[1102296].DB3-zm_monitor.cpp/930 [MMap file size is 199071272]
02/22/24 18:33:01.429742 zmc_m6[1102296].DB1-zm_monitor.cpp/935 [Unable to map file /dev/shm/zm.mmap.6 (199071272 bytes) to locked memory, trying unlocked]
02/22/24 18:33:01.429766 zmc_m6[1102296].DB1-zm_monitor.cpp/938 [Mapped file /dev/shm/zm.mmap.6 (199071272 bytes) to unlocked memory]
02/22/24 18:33:01.429771 zmc_m6[1102296].DB3-zm_monitor.cpp/973 [Aligning shared memory images to the next 64 byte boundary 0x7f73c02275dc to 0x7f73c0227600 moved 36 bytes]
02/22/24 18:33:01.516186 zmc_m6[1102296].DB1-zm_monitor.cpp/2476 [Reloading linked monitors for monitor CAM6, '']
02/22/24 18:33:01.516218 zmc_m6[1102296].DB1-zm_monitor.cpp/1059 [Starting ONVIF]
02/22/24 18:33:01.517623 zmc_m6[1102296].DB1-zm_monitor.cpp/1087 [ONVIF Endpoint: http://X.X.X.X.56/onvif/event_service/Events]
02/22/24 18:33:01.570320 zmc_m6[1102296].DB1-zm_monitor.cpp/1103 [ONVIF :soap_wsa_request OK ]

Regards,

Mark
User avatar
iconnor
Posts: 2936
Joined: Fri Oct 29, 2010 1:43 am
Location: Toronto
Contact:

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by iconnor »

The onvif setup is taking over 20 seconds. So zmwatch is killing the camera before it can even try to capture.
We will need to move the code around so that onvif doesn't delay capture.

In the meantime, increase your Options->System->WATCH_MAX_DELAY
marklg
Posts: 22
Joined: Sun Dec 17, 2023 1:43 am

Re: Enabling ONVIF Event Listener Causes Capturing (RTSP) to Stop

Post by marklg »

Upping it to 60 seconds worked. It appears I had to restart for the new number to be used. Thanks. This has solved a long standing issue.

Mark
Post Reply