ZMC exhausts memory and crashes

[thisabstractmind]

Describe Your Environment
ZM version : 1.36.33
Installed by isaac ppa
Ubuntu 22.04.3 LTS (GNU/Linux 5.15.0-84-generic x86_64)

zmc process has a possible memory leak, start the zoneminder service and will eventually run out of memory, killing the process. The process will start over again and this will repeat.

Expected behavior
To run without exploding.

Debug Logs

"
Dmesg output:

[203814.098768] Out of memory: Killed process 24122 (zmc) total-vm:20431444kB, anon-rss:14641864kB, file-rss:2744kB, shmem-rss:40508kB, UID:33 pgtables:38256kB oom_score_adj:0
[203817.419600] oom_reaper: reaped process 24122 (zmc), now anon-rss:16kB, file-rss:0kB, shmem-rss:40508kB
[204585.299535] systemd invoked oom-killer: gfp_mask=0x1100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
[204585.299541] CPU: 1 PID: 1 Comm: systemd Not tainted 5.15.0-84-generic #93-Ubuntu
[204585.299544] Hardware name: LENOVO 10FH005NUS/30BC, BIOS FWKT63A   12/08/2016
[204585.299545] Call Trace:
[204585.299547]  <TASK>
[204585.299549]  show_stack+0x52/0x5c
[204585.299555]  dump_stack_lvl+0x4a/0x63
[204585.299559]  dump_stack+0x10/0x16
[204585.299561]  dump_header+0x53/0x228
[204585.299563]  oom_kill_process.cold+0xb/0x10
[204585.299566]  out_of_memory+0x106/0x2e0
[204585.299569]  __alloc_pages_slowpath.constprop.0+0x9b7/0xa80
[204585.299574]  __alloc_pages+0x311/0x330
[204585.299577]  alloc_pages+0x9e/0x1e0
[204585.299580]  __page_cache_alloc+0x7e/0x90
[204585.299584]  pagecache_get_page+0x152/0x590
[204585.299586]  ? page_cache_ra_unbounded+0x166/0x210
[204585.299590]  filemap_fault+0x488/0xab0
[204585.299592]  ? filemap_map_pages+0x309/0x400
[204585.299596]  __do_fault+0x39/0x120
[204585.299599]  do_read_fault+0xeb/0x160
[204585.299601]  do_fault+0xa0/0x2e0
[204585.299603]  handle_pte_fault+0x1cd/0x240
[204585.299605]  __handle_mm_fault+0x405/0x6f0
[204585.299608]  handle_mm_fault+0xd8/0x2c0
[204585.299610]  do_user_addr_fault+0x1c9/0x670
[204585.299613]  exc_page_fault+0x77/0x170
[204585.299617]  asm_exc_page_fault+0x27/0x30
[204585.299619] RIP: 0033:0x55834e437b30
[204585.299625] Code: Unable to access opcode bytes at RIP 0x55834e437b06.
[204585.299626] RSP: 002b:00007ffd7176aef8 EFLAGS: 00010246
[204585.299629] RAX: 0000000000000000 RBX: 000055834edbee70 RCX: 00007ffd7176af38
[204585.299630] RDX: 00007ffd7176af30 RSI: 0000000000000001 RDI: 000055834efdfc20
[204585.299631] RBP: 000055834e451740 R08: 0000000000000000 R09: 000055834eeb1708
[204585.299633] R10: 00007ffd7176af50 R11: 0000000000000010 R12: 000055834e456180
[204585.299634] R13: 000055834efdfc20 R14: 00007ffd7176af50 R15: 0000000000000000
[204585.299637]  </TASK>
[204585.299638] Mem-Info:
[204585.299640] active_anon:4463401 inactive_anon:2118543 isolated_anon:0
                 active_file:536223 inactive_file:871638 isolated_file:960
                 unevictable:27208 dirty:1408033 writeback:0
                 slab_reclaimable:69719 slab_unreclaimable:24336
                 mapped:22525 shmem:20261 pagetables:17927 bounce:0
                 kernel_misc_reclaimable:0
                 free:50292 free_pcp:0 free_cma:0
[204585.299645] Node 0 active_anon:17853604kB inactive_anon:8474172kB active_file:2144892kB inactive_file:3486076kB unevictable:108832kB isolated(anon):0kB isolated(file):3840kB mapped:90100kB dirty:5632132kB writeback:0kB shmem:81044kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB kernel_stack:4752kB pagetables:71708kB all_unreclaimable? no
[204585.299651] Node 0 DMA free:11264kB min:28kB low:40kB high:52kB reserved_highatomic:0KB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15984kB managed:15360kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[204585.299656] lowmem_reserve[]: 0 3105 31894 31894 31894
[204585.299659] Node 0 DMA32 free:121688kB min:6576kB low:9752kB high:12928kB reserved_highatomic:0KB active_anon:3145084kB inactive_anon:7672kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:3352956kB managed:3286924kB mlocked:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[204585.299665] lowmem_reserve[]: 0 0 28789 28789 28789
[204585.299668] Node 0 Normal free:68216kB min:60972kB low:90448kB high:119924kB reserved_highatomic:8192KB active_anon:14708520kB inactive_anon:8466500kB active_file:2145768kB inactive_file:3486076kB unevictable:108832kB writepending:5632132kB present:30113792kB managed:29488820kB mlocked:108832kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[204585.299673] lowmem_reserve[]: 0 0 0 0 0
[204585.299676] Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 2*4096kB (M) = 11264kB
[204585.299689] Node 0 DMA32: 78*4kB (UME) 76*8kB (UME) 126*16kB (UME) 123*32kB (UME) 80*64kB (UME) 69*128kB (UME) 58*256kB (UE) 44*512kB (UME) 24*1024kB (UE) 11*2048kB (UME) 4*4096kB (E) = 121688kB
[204585.299704] Node 0 Normal: 2398*4kB (ME) 746*8kB (UME) 181*16kB (UME) 125*32kB (UME) 29*64kB (UME) 9*128kB (ME) 7*256kB (M) 36*512kB (UM) 22*1024kB (M) 0*2048kB 0*4096kB = 68216kB
[204585.299719] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[204585.299721] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[204585.299722] 1667912 total pagecache pages
[204585.299723] 236728 pages in swap cache
[204585.299724] Swap cache stats: add 112060036, delete 112035739, find 2478894/3566145
[204585.299726] Free swap  = 0kB
[204585.299726] Total swap = 8388604kB
[204585.299727] 8370683 pages RAM
[204585.299728] 0 pages HighMem/MovableOnly
[204585.299729] 172907 pages reserved
[204585.299729] 0 pages hwpoisoned
[204585.299730] Tasks state (memory values in pages):
[204585.299731] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[204585.299737] [    536]     0   536    72370     6775   110592        0         -1000 multipathd
[204585.299741] [    852]   103   852     2246      769    53248      151          -900 dbus-daemon
[204585.299744] [    856]     0   856    20692      616    61440       90             0 irqbalance
[204585.299746] [    858]     0   858     8184      747    98304     2218             0 networkd-dispat
[204585.299749] [    859]     0   859    58623      551    81920      216             0 polkitd
[204585.299752] [    860]   107   860    55600      616    77824      554             0 rsyslogd
[204585.299754] [    865]     0   865    31497      207    94208      232             0 thermald
[204585.299757] [    867]     0   867    98198      669   126976      849             0 udisksd
[204585.299759] [    868]     0   868     4123      647    77824      218             0 wpa_supplicant
[204585.299761] [    882]     0   882    79489      797   114688      517             0 ModemManager
[204585.299763] [    899]     0   899     1723      518    57344       67             0 cron
[204585.299766] [    922]     0   922     1543      185    49152       33             0 agetty
[204585.299768] [    942]     0   942    27434      870   110592     2078             0 unattended-upgr
[204585.299770] [    960]     0   960     3856      763    65536      411         -1000 sshd
[204585.299772] [    972]   114   972  1047528     1367  1769472   148721             0 mysqld
[204585.299775] [   1046]     0  1046     2988        0    49152      156             0 pure-ftpd
[204585.299777] [   2787]     0  2787    59906      575    98304      372             0 upowerd
[204585.299780] [   4810]     0  4810    73890      446   159744      754             0 packagekitd
[204585.299782] [  16782]     0 16782    61714      426   167936     1543             0 apache2
[204585.299785] [  18009]   104 18009    22338      611    77824      259             0 systemd-timesyn
[204585.299787] [  20091]     0 20091     6418      555    81920      479         -1000 systemd-udevd
[204585.299790] [  20097]   102 20097     6382      616    94208     1088             0 systemd-resolve
[204585.299792] [  20098]   101 20098     4062      258    73728      231             0 systemd-network
[204585.299794] [  20624]     0 20624     7831      442    86016      191          -250 systemd-journal
[204585.299797] [  20632]     0 20632    11953      467    90112      247             0 systemd-logind
[204585.299799] [  21394]    33 21394    61837      216   139264     1557             0 apache2
[204585.299802] [  21395]    33 21395    61837      216   139264     1557             0 apache2
[204585.299804] [  21396]    33 21396    61837      216   139264     1557             0 apache2
[204585.299806] [  21397]    33 21397    61837      216   139264     1557             0 apache2
[204585.299808] [  21398]    33 21398    61837      216   139264     1557             0 apache2
[204585.299811] [  23869]     0 23869   440757        0   290816     2635          -900 snapd
[204585.299814] [  24178]    33 24178     9737      524   118784     3161             0 zmdc.pl
[204585.299816] [  24206]    33 24206  4287867  3031816 32333824   898227             0 zmc
[204585.299819] [  24210]    33 24210  4670331  3329382 35565568  1001821             0 zmc
[204585.299822] [  24216]    33 24216    13315     1232   143360     6159             0 zmfilter.pl
[204585.299824] [  24221]    33 24221    13319     1507   147456     5823             0 zmfilter.pl
[204585.299826] [  24226]    33 24226     9607      822   114688     2654             0 zmwatch.pl
[204585.299828] [  24232]    33 24232    10832      622   131072     4344             0 zmupdate.pl
[204585.299831] [  24236]    33 24236    13644      644   151552     6870             0 zmtelemetry.pl
[204585.299833] [  24242]    33 24242     9532      729   122880     2869             0 zmstats.pl
[204585.299836] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=init.scope,mems_allowed=0,global_oom,task_memcg=/system.slice/zoneminder.service,task=zmc,pid=24210,uid=33
[204585.299862] Out of memory: Killed process 24210 (zmc) total-vm:18681324kB, anon-rss:13275348kB, file-rss:1672kB, shmem-rss:40508kB, UID:33 pgtables:34732kB oom_score_adj:0
[204588.656345] oom_reaper: reaped process 24210 (zmc), now anon-rss:16kB, file-rss:0kB, shmem-rss:40508kB
[205895.510926] loop5: detected capacity change from 0 to 8
[214047.519867] loop5: detected capacity change from 0 to 8
[221413.010668] loop5: detected capacity change from 0 to 8


df -h

Filesystem                         Size  Used Avail Use% Mounted on
tmpfs                              3.2G  1.6M  3.2G   1% /run
/dev/mapper/ubuntu--vg-ubuntu--lv   98G   32G   61G  35% /
tmpfs                               16G   80M   16G   1% /dev/shm
tmpfs                              5.0M     0  5.0M   0% /run/lock
/dev/sda2                          2.0G  252M  1.6G  14% /boot
/dev/sdc1                          1.8T  716G  1.0T  42% /mnt/driveB
/dev/sda1                          1.1G  6.1M  1.1G   1% /boot/efi
/dev/sdb1                          1.8T  169G  1.6T  10% /mnt/driveA
tmpfs                              3.2G  4.0K  3.2G   1% /run/user/1000

"

[jrtaylor71]

I have the same problem. When a rtsp camera is not reachable zmc consumes all the memory on the server. This seems to happen during the restart process of zmc. This has been reported many times in the forum. Setting max buffer does nothing because the stream is never started.

https://forums.zoneminder.com/viewtopic.php?t=32739
https://forums.zoneminder.com/viewtopic.php?t=32756
https://forums.zoneminder.com/viewtopic.php?t=32633

This is also reproducible in 1.37.x

[Middim]

I am running into the same issue, I believe. After the server went down a few times due to OOM, I set up cgroups to limit memory consumption.

www-data  483061  0.0  0.0  40064  2816 ?        S    Sep26   0:16 /usr/bin/perl -wT /usr/bin/zmdc.pl startup
www-data  483093 37.3 36.0 17501112 2934360 ?    SLl  Sep26 1541:12 /usr/bin/zmc -m 7
www-data  483100  0.0  0.1  52400 10052 ?        S    Sep26   0:00 /usr/bin/zmcontrol.pl --id 7

It hit the mem caps, however it was still running.

Here's what it looks like normally:

www-data  705258  0.0  0.2  40064 18400 ?        S    12:01   0:00 /usr/bin/perl -wT /usr/bin/zmdc.pl startup
www-data  705288 33.7  7.2 923832 593144 ?       SLl  12:01   5:57 /usr/bin/zmc -m 7
www-data  705293  0.0  0.3  46836 31684 ?        S    12:01   0:00 /usr/bin/zmcontrol.pl --id 7

This was on 1.37.45~20230926121048-focal from the ppa.

[j-marz]

Experiencing the same thing - currently running v1.37.43
Swap fills after a few days, mostly related to zmc processes.

[thisabstractmind]

@jrtaylor71 is correct. There is a direct correlation to the camera not being able to be accessed and the memory consumption.

[connortechnology]

I have not been able to recreate this here. Are the FFmpeg type or Remote type or something else? I need a debug level 3 log from one of the zmc processes.

[j-marz]

@connortechnology ffmpeg in my case. I agree with @thisabstractmind that this might be related to camera not being accessible - i have 5 monitors accessed through vpn tunnel over internet, so their streams aren't as stable as local network and memory seems to climb after short network outages. I'm away atm, so can't get you the debug logs.

[niziak]

The same issue. I'm using 4 cheap WiFi Yi camera with YiHack to add RTSP server. Cameras are cheap and with constrained resources so RTSP stream is not stable (parallel background stream is still running to manufacturer server). All cameras are added as Ffmpeg source and method is TCP due to some random artefacts when UDP was used.

I'm using unprivileged LXC container in Proxmox. System is Debian. Zone Minder was working correctly for months (with high CPU usage due to video analysis but stability was OK).

I think problem begins after one of system update.

Now I'm using latest Debian Bookworm but today I've added deb multimedia repo, so ffmpeg + libraries were updated.
Lets see what happens.

[jrtaylor71]

Debug from 3 cameras. Camera 5 is dead right now, camera's 7 and 12 I simulated a switch failure by rebooting it. All 3 camera's are are powered from an Avaya ERS5520 and run on vlan 555.

Before test
root@nvr:~# free -h total used free shared buff/cache available Mem: 31Gi 9.8Gi 19Gi 309Mi 1.7Gi 20Gi Swap: 8.0Gi 0B 8.0Gi

After test
root@nvr:~# free -h total used free shared buff/cache available Mem: 31Gi 10Gi 1.4Gi 310Mi 19Gi 19Gi Swap: 8.0Gi 2.0Mi 8.0Gi

After a larger failure like this I have had to reboot the vm to release the memory. Restarting the zoneminder service does not help.

zoneminder 1.36.33-jammy1
HPE DL360p G8 running vmware 6.5
ubuntu 22 vm has 16 cpu, 32gb ram, 100gb os, 10tb video, 15 camera's total

zmc_m7.log.tar.gz
zmc_m5.log.tar.gz
zmc_m12.log.tar.gz

[connortechnology]

If restarting ZM doesn't free up the memory... then it's not ZM that is consuming it.

ANyways, thos debug logs show zm connecting and disconnection to the offline camera.. unfortunately no information as to why memory would be used.

In my own testing, I setup top, hit M to sort by memory use... and then power cycled a camera and watched what happened. What happened is that ZM had a read failure, shut down everything, freed up all ram, and then retried the connection as it should WHen the connection came back it resumed and didn't use any excess ram.

What you logs do NOT show, that I expected to see, was a resource shortage. THey seem to be happy.

So I'm stumped.

[jrtaylor71]

I have always tested with more than one camera failure and when it has happened it has always been more than one. In fact the more cameras that go offline the faster the memory gets used up.

As for freeing the memory I should have pointed out that cache and swap are never free'd but I have seen zm crash like the above output without a reboot. Just a service restart free's the acvtive memory.

I have included some screen shots from munin that I have had running to track usage.

[connortechnology]

Latest build has a fix for a small memleak when trying to reconnect to a dead camera. So might fix this. Shouldn't leak too quickly though, so maybe not.

[jrtaylor71]

On what version? I think most of us that reported this are still on 1.36.

[Middim]

I updated last week and tried it again, but I still seem to be having an issue with the memory use growing significantly. I let it go for a while and generally it stays pretty consistent in memory usage, but sometimes it starts consuming more than the normal amount of memory. It gets oom-killed by the cgroup limit before it causes problems for the rest of the machine.

I do have multiple cameras in use, and the memory in one may increase significantly while the others are still fine. Due to backups, sometimes the CPU load on the machine is high, and other times it's nearly Zoneminder alone using the cpu cycles for mocap. They are all ffmpeg streams, and I have tried both tcp and udp rtsp streams with no significant difference.

I set up a script (taking 1 sample per min) to record the memory usage over time, along with the absolute time (to use in correlation with the logs) and the process time (in seconds) and the rss/vsz to show when it starts going up. Here's an excerpt of the memory usage log where it nears the end, right before it gets killed:

pid,systime,process_time,vsz,rss,camera
2355727, 1707058441, 0, 254232, 38952, 9
2355727, 1707058501, 20, 1036344, 637328, 9
2355727, 1707058561, 48, 1110076, 612356, 9
. . .
2355727, 1707095161, 13482, 1522260, 978784, 9
2355727, 1707095221, 13513, 1587796, 1052752, 9
2355727, 1707095281, 13556, 2177620, 1671004, 9
2355727, 1707095341, 13582, 3554388, 2681368, 9
2355727, 1707095401, 13601, 4799572, 2949904, 9
2355727, 1707095461, 13616, 6507888, 3383784, 9

The memory log and debug log are attached, along with the crash data. I trimmed the debug log to within the last ~11.5 minutes so it wouldn't be too large. I do have several full logs along with corresponding memory usage logs if I should send anything else.
zmc_memlog_2355727.txt
zm_debug.log.2355727.end.txt.gz
zmc_crash_2355727.txt

This is on 1.37.50~20240202093203-focal - I updated to current shortly before starting tests. I am not sure, but it's definitely possible there may be more than one issue at play as I haven't noticed significant increases in memory usage when I do try disconnecting/rebooting the cameras, and I am not on 1.36 like some of the others.

[connortechnology]

@Middim Thanks for the quality info. So at first glance, I see everything falling behind around 5:11. I see a ton of warnings from ffmpeg which could be bad network, but tend to more often be that your cpu is not keeping up. I also see that you are saving jpegs. Encoding jpegs is surprisingly cpu intensive. If you want the analysis images, then only save those. Saving jpegs is not feasible past 720p. Certainly not at 20fps.

[thisabstractmind]

@connortechnology I am the OP. I have not had an issue since changing video writer to pass through and disabling "save JPEGs". I think it was a bottleneck problem that led to delay and extra memory consumption. This was about 3 months ago.