ZMC Processes Restarting

[noogs]

Soon after upgrade to Zoneminder 1.35.16 I have started to experience issues with ZMC processes restarting. I have debug logging turned on and there are no errors in the ZMC logs explaining what is going on. ZMA, ZMS, and ZMWatch logs all seem indicate issues accessing the zmc processes. At first I thought this was a shared memory issue so I increased the RAM assigned to this VM to have 8GB and thus by default 4GB of shared memory and I can see that total memory utilization seems to be sitting around 2GB so I don't think this is a shared memory problem anymore.

There are two possible causes to this mess and one is much more likely. I upgraded to 1.35.16 this morning and didn't immediately notice any issues but after I tried adding another camera, I started to really notice the problem. To try to determine one way or the other I removed the new camera, and the issues remained.

As a side note, I know there are errors in the logs below about resolution. Everything worked fine with these resolution settings before the upgrade and setting them to match the camera does not resolve the issue.

ZMC Log:

Code: Select all

01/23/21 19:12:56.460886 zmc_m1[17113].INF-zmc.cpp/223 [Starting Capture version 1.35.16]
01/23/21 19:12:58.519441 zmc_m1[17113].WAR-zm_ffmpeg_camera.cpp/657 [Monitor dimensions are 1280x720 but camera is sending 1920x1080]
01/23/21 19:12:58.558362 zmc_m1[17113].INF-zm_monitor.cpp/2640 [Basement: images:1 - Capturing at 0.50 fps, capturing bandwidth 39583bytes/sec]
01/23/21 19:13:03.346219 zmc_m1[17113].INF-zm_monitor.cpp/2640 [Basement: images:100 - Capturing at 20.00 fps, capturing bandwidth 208993bytes/sec]
01/23/21 19:13:11.575856 zmc_m1[17113].INF-zm_monitor.cpp/2640 [Basement: images:200 - Capturing at 12.50 fps, capturing bandwidth 139665bytes/sec]
01/23/21 19:14:12.585203 zmc_m1[17232].INF-zmc.cpp/223 [Starting Capture version 1.35.16]
01/23/21 19:14:14.540614 zmc_m1[17232].WAR-zm_ffmpeg_camera.cpp/657 [Monitor dimensions are 1280x720 but camera is sending 1920x1080]
01/23/21 19:14:14.586014 zmc_m1[17232].INF-zm_monitor.cpp/2640 [Basement: images:1 - Capturing at 0.50 fps, capturing bandwidth 39536bytes/sec]
01/23/21 19:14:19.448798 zmc_m1[17232].INF-zm_monitor.cpp/2640 [Basement: images:100 - Capturing at 20.00 fps, capturing bandwidth 207757bytes/sec]
01/23/21 19:15:28.310146 zmc_m1[17366].INF-zmc.cpp/223 [Starting Capture version 1.35.16]
01/23/21 19:15:30.225114 zmc_m1[17366].WAR-zm_ffmpeg_camera.cpp/657 [Monitor dimensions are 1280x720 but camera is sending 1920x1080]
01/23/21 19:15:30.273210 zmc_m1[17366].INF-zm_monitor.cpp/2640 [Basement: images:1 - Capturing at 0.50 fps, capturing bandwidth 39485bytes/sec]
01/23/21 19:15:35.033208 zmc_m1[17366].INF-zm_monitor.cpp/2640 [Basement: images:100 - Capturing at 20.00 fps, capturing bandwidth 208544bytes/sec]
01/23/21 19:16:43.190088 zmc_m1[17500].INF-zmc.cpp/223 [Starting Capture version 1.35.16]
01/23/21 19:16:45.104288 zmc_m1[17500].WAR-zm_ffmpeg_camera.cpp/657 [Monitor dimensions are 1280x720 but camera is sending 1920x1080]
01/23/21 19:16:45.142699 zmc_m1[17500].INF-zm_monitor.cpp/2640 [Basement: images:1 - Capturing at 0.50 fps, capturing bandwidth 39720bytes/sec]
01/23/21 19:17:34.450123 zmc_m1[17592].INF-zmc.cpp/223 [Starting Capture version 1.35.16]
01/23/21 19:17:36.359202 zmc_m1[17592].WAR-zm_ffmpeg_camera.cpp/657 [Monitor dimensions are 1280x720 but camera is sending 1920x1080]
01/23/21 19:17:36.403024 zmc_m1[17592].INF-zm_monitor.cpp/2640 [Basement: images:1 - Capturing at 0.50 fps, capturing bandwidth 39523bytes/sec]
01/23/21 19:17:41.172462 zmc_m1[17592].INF-zm_monitor.cpp/2640 [Basement: images:100 - Capturing at 20.00 fps, capturing bandwidth 214062bytes/sec]
01/23/21 19:18:41.078716 zmc_m1[17720].INF-zmc.cpp/223 [Starting Capture version 1.35.16]
01/23/21 19:18:42.998251 zmc_m1[17720].WAR-zm_ffmpeg_camera.cpp/657 [Monitor dimensions are 1280x720 but camera is sending 1920x1080]
01/23/21 19:18:43.038580 zmc_m1[17720].INF-zm_monitor.cpp/2640 [Basement: images:1 - Capturing at 0.50 fps, capturing bandwidth 39751bytes/sec]

ZMA Log:

Code: Select all

01/23/21 19:12:00.574604 zma_m1[16876].INF-zm_monitor.cpp/1356 [Basement: 600 - Analysing at 11.11 fps]
01/23/21 19:12:55.987051 zma_m1[16876].INF-zm_monitor.cpp/784 [Basement: image_count:685 - Closing event 225805, shutting down]
01/23/21 19:12:56.358894 zma_m1[17112].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:12:59.374952 zma_m1[17112].INF-zma.cpp/136 [In mode 5/1, warming up]
01/23/21 19:12:59.568425 zma_m1[17112].INF-zm_monitor.cpp/1588 [Basement: 001 - Opening new event 225810, section start]
01/23/21 19:13:07.972485 zma_m1[17112].INF-zm_monitor.cpp/1356 [Basement: 100 - Analysing at 12.50 fps]
01/23/21 19:14:07.139623 zma_m1[17112].INF-zm_monitor.cpp/784 [Basement: image_count:131 - Closing event 225810, shutting down]
01/23/21 19:14:07.529461 zma_m1[17214].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:14:08.533866 zma_m1[17214].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:14:09.540977 zma_m1[17214].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:14:10.562551 zma_m1[17214].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:14:11.570576 zma_m1[17214].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:14:15.590706 zma_m1[17214].INF-zma.cpp/136 [In mode 5/1, warming up]
01/23/21 19:14:15.777874 zma_m1[17214].INF-zm_monitor.cpp/1588 [Basement: 001 - Opening new event 225812, section start]
01/23/21 19:15:18.605299 zma_m1[17214].INF-zm_monitor.cpp/784 [Basement: image_count:92 - Closing event 225812, shutting down]
01/23/21 19:15:19.032216 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:20.036238 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:21.044149 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:22.190132 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:23.199743 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:24.207421 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:25.215491 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:26.435445 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:27.445894 zma_m1[17346].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:15:30.462004 zma_m1[17346].INF-zma.cpp/136 [In mode 5/1, warming up]
01/23/21 19:15:30.476846 zma_m1[17346].INF-zm_monitor.cpp/1588 [Basement: 001 - Opening new event 225815, section start]
01/23/21 19:16:30.934510 zma_m1[17346].INF-zm_monitor.cpp/784 [Basement: image_count:92 - Closing event 225815, shutting down]
01/23/21 19:16:45.298030 zma_m1[17503].INF-zma.cpp/136 [In mode 5/1, warming up]
01/23/21 19:16:45.319730 zma_m1[17503].INF-zm_monitor.cpp/1588 [Basement: 001 - Opening new event 225819, section start]
01/23/21 19:17:33.932260 zma_m1[17503].INF-zm_monitor.cpp/784 [Basement: image_count:22 - Closing event 225819, shutting down]
01/23/21 19:17:34.366088 zma_m1[17591].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:17:37.387286 zma_m1[17591].INF-zma.cpp/136 [In mode 5/1, warming up]
01/23/21 19:17:37.491085 zma_m1[17591].INF-zm_monitor.cpp/1588 [Basement: 001 - Opening new event 225821, section start]
01/23/21 19:17:44.404107 zma_m1[17591].INF-zm_monitor.cpp/1356 [Basement: 100 - Analysing at 14.29 fps]
01/23/21 19:18:35.506053 zma_m1[17591].INF-zm_monitor.cpp/784 [Basement: image_count:138 - Closing event 225821, shutting down]
01/23/21 19:18:35.893804 zma_m1[17701].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:18:36.898608 zma_m1[17701].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:18:37.903539 zma_m1[17701].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:18:38.910469 zma_m1[17701].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:18:39.918364 zma_m1[17701].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:18:40.925576 zma_m1[17701].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]

ZMS Log:

Code: Select all

01/23/21 19:30:14.077817 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:15.096189 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:15.123235 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:16.143426 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:16.146743 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:17.163537 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:17.191916 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:18.208283 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:18.210548 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:19.225077 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:19.232318 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:20.251895 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:20.257889 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:21.272551 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:21.277233 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:30:22.290723 zms_m1[19027].ERR-zm_monitor.cpp/578 [Can't open memory map file /dev/shm/zm.mmap.1, probably not enough space free: No such file or directory]
01/23/21 19:30:22.294621 zms_m1[19027].ERR-zm_stream.cpp/62 [Unable to connect to monitor id 1 for streaming]
01/23/21 19:34:39.699733 zms_m1[19524].WAR-zm_monitorstream.cpp/800 [no last_frame_sent.  Shouldn't happen. frame_mod was (1) frame_count (0)]

ZMWatch Log:

Code: Select all

01/23/2021 19:12:04.659193 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 54 seconds (1611447124-1611447070)]
01/23/2021 19:12:05.184287 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Driveway, time since last capture 53 seconds (1611447125-1611447072)]
01/23/2021 19:12:55.840948 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Basement, time since last capture 46 seconds (1611447175-1611447129)]
01/23/2021 19:12:56.299625 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 47 seconds (1611447176-1611447129)]
01/23/2021 19:14:06.824338 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Basement, time since last capture 55 seconds (1611447246-1611447191)]
01/23/2021 19:14:07.464577 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 55 seconds (1611447247-1611447192)]
01/23/2021 19:14:07.951823 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Driveway, time since last capture 54 seconds (1611447247-1611447193)]
01/23/2021 19:15:18.456872 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Basement, time since last capture 54 seconds (1611447318-1611447264)]
01/23/2021 19:15:18.959979 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 54 seconds (1611447318-1611447264)]
01/23/2021 19:15:19.440739 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Driveway, time since last capture 54 seconds (1611447319-1611447265)]
01/23/2021 19:15:30.150813 zmwatch[16907].ERR [ZoneMinder::Memory::Mapped:90] [Memory map file '/dev/shm/zm.mmap.2' does not exist in zmMemAttach.  zmc might not be running.]
01/23/2021 19:15:30.233195 zmwatch[16907].INF [main:136] [Restarting capture daemon for Kitchen, shared data not valid]
01/23/2021 19:16:30.775835 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Basement, time since last capture 53 seconds (1611447390-1611447337)]
01/23/2021 19:16:31.296900 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 54 seconds (1611447391-1611447337)]
01/23/2021 19:16:31.780098 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Driveway, time since last capture 53 seconds (1611447391-1611447338)]
01/23/2021 19:16:42.303966 zmwatch[16907].ERR [ZoneMinder::Memory::Mapped:90] [Memory map file '/dev/shm/zm.mmap.1' does not exist in zmMemAttach.  zmc might not be running.]
01/23/2021 19:16:42.703516 zmwatch[16907].INF [main:136] [Restarting capture daemon for Basement, shared data not valid]
01/23/2021 19:16:43.208843 zmwatch[16907].ERR [ZoneMinder::Memory::Mapped:90] [Memory map file '/dev/shm/zm.mmap.3' does not exist in zmMemAttach.  zmc might not be running.]
01/23/2021 19:16:43.212967 zmwatch[16907].INF [main:136] [Restarting capture daemon for Driveway, shared data not valid]
01/23/2021 19:17:33.768125 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Basement, time since last capture 46 seconds (1611447453-1611447407)]
01/23/2021 19:17:34.299683 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 48 seconds (1611447454-1611447406)]
01/23/2021 19:17:34.799848 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Driveway, time since last capture 47 seconds (1611447454-1611447407)]
01/23/2021 19:18:35.318970 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Basement, time since last capture 47 seconds (1611447515-1611447468)]
01/23/2021 19:18:35.832727 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Kitchen, time since last capture 47 seconds (1611447515-1611447468)]
01/23/2021 19:18:36.377002 zmwatch[16907].WAR [main:130] [Restarting capture daemon for Driveway, time since last capture 47 seconds (1611447516-1611447469)]
01/23/2021 19:18:46.912613 zmwatch[16907].ERR [ZoneMinder::Memory::Mapped:90] [Memory map file '/dev/shm/zm.mmap.2' does not exist in zmMemAttach.  zmc might not be running.]
01/23/2021 19:18:46.916372 zmwatch[16907].INF [main:136] [Restarting capture daemon for Kitchen, shared data not valid]
01/23/2021 19:18:57.458130 zmwatch[16907].ERR [ZoneMinder::Memory::Mapped:90] [Memory map file '/dev/shm/zm.mmap.2' does not exist in zmMemAttach.  zmc might not be running.]
01/23/2021 19:18:57.465419 zmwatch[16907].INF [main:136] [Restarting capture daemon for Kitchen, shared data not valid]

[noogs]

I ended up downgrading back to 1.34. Had to play a bit with the database to get everything working again without having to build from scratch but everything is up and running now with no issues and basically the exact same configuration on 1.34. I'm not sure what the issue was but I suppose I'll hold off on upgrading to 1.35 since I don't NEED any of those new features.