Performance Issues / Comparision 1.32 to 1.30

Forum for questions and support relating to the 1.32.x releases only.
Post Reply
AnotherBrian
Posts: 112
Joined: Tue Jul 27, 2010 6:36 am

Performance Issues / Comparision 1.32 to 1.30

Post by AnotherBrian »

I'm finding zma (analyzer) consumes about 4 times the processor time in 1.32 compared to 1.30. zmc takes less.

My experimental setup: Hardware is i7-5600u with hard drive and 16gb ram and a single hikvision 2032 camera running 4 frames / second at 1920x1080. I flip between hard drives to do experiments where one system is v1.30.4 /16.04.06 (zoneminder/ubuntu) and other is v1.32.3 / 18.04. I run just one camera. I have the zoneminder camera set to record. zmaudit, reported in other threads as a performance hog, is turned off on both systems!

Okee doke: Nice architectural diagram over at zoneminder.readthedocs.io/en/stable/userguide/components.html which shows each camera video feed goes to a zmc (camera) process that then feeds a zma (analyzer) process. So we focus on zma and zmc.

Process performance data is available via /proc/$pid/stat where $pid is the process id. Starting at field 14 of the file we have utime, stime, cutime, cstime measured in 100ths of seconds. when a process runs it picks up clock ticks in utime versus stime depending whether the context of the process is user or system. Read this file twice over a time period and you now have the amount of cpu (system and user) time consumed by the process. Now we compare to output of top command which reports time+. It does appear that top's time+ is utime+stime (and perhaps dead children cpu times but that doesn't apply here). Reading proc data is a the better way to go because we get to see if something funky is going on during system time of the process. It turns out system time is negligible - so this is all application code hogging the cpu.

Okee Doke here is my script on v1.32:

Code: Select all

#manually determine the process ids of zma and zmc
zmaPID=1493;
zmcPID=1332;
waitTime=10  #we will wait 10 seconds between measurements
# first read proc data for zma and zmc
cat /proc/$zmaPID/stat;
cat /proc/$zmcPID/stat;
# now use top to report on user www-data.  top reports out twice with 10 second gap.   
top -u www-data -b -n2 -d $waitTime;
# now (AGAIN) read proc data for zma and zmc so we can compute the cputime
cat /proc/$zmaPID/stat  
cat /proc/$zmcPID/stat 
I run the script twice just to see if the measurements are consistent when taken over different times. They are!

Here is what I got:

v1.30: zma utime 73 stime 2
v1.32: zma utime 282 stime 0 <- 4 times more

v1:30 zmc utime 139 stime 1
v1:32 zmc utime 108 stime 1

Conclusion: in the new release, zma is hogging the cpu by a factor of about 4 compared to the old release. zmc, on the other hand, is improved somewhat.

Now lets consider the assertion that 18.04 security updates are accounting for the performance degradation. If, indeed, this was the case, wouldn't the expectation be that the performance hit occurs across both zmc and zma. But here we see just zma taking the performance hit and zmc is actually reduced. Maybe functionality was moved between the two processes?!

Another assurtion was that zma was taking performance hits because sound data was considered in the new zma. A suggestion had been made that allowed_media_types=video should be added to rstp command in the video description. I haven't measured it but I can say, without taking the measurements, that v1.32 will not run my 8 cameras even if I do the video suggestion.

Here is an example of the output of my scripts:

1493 (zma) S 1274 1274 1255 0 -1 1077936128 14527 0 17 0 9581 52 0 0 20 0 10 0 11308 1682817024 207489 18446744073709551615 1 1 0 0 0 0 65536 4096 20207 0 0 0 17 3 0 0 32 0 0 0 0 0 0 0 0 0 0
1332 (zmc) S 1274 1274 1255 0 -1 4194304 52124 0 133 0 3470 59 0 0 20 0 1 0 10285 635621376 52867 18446744073709551615 1 1 0 0 0 0 68097 4096 20207 0 0 0 17 1 0 0 556 0 0 0 0 0 0 0 0 0 0
top - 12:05:36 up 7 min, 1 user, load average: 0.70, 1.10, 0.64
Tasks: 276 total, 1 running, 223 sleeping, 0 stopped, 0 zombie
%Cpu(s): 6.8 us, 0.8 sy, 2.8 ni, 77.8 id, 11.3 wa, 0.0 hi, 0.5 si, 0.0 st
KiB Mem : 16294984 total, 13089760 free, 1941652 used, 1263572 buff/cache
KiB Swap: 999420 total, 999420 free, 0 used. 13625468 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1332 www-data 20 0 620724 211468 185652 S 18.8 1.3 0:35.32 zmc
1493 www-data 20 0 1643376 829956 184848 S 18.8 5.1 1:36.36 zma

1125 www-data 20 0 415772 20516 13328 S 0.0 0.1 0:00.05 apache2
1126 www-data 20 0 416104 18556 11976 S 0.0 0.1 0:00.00 apache2
1127 www-data 20 0 415672 18012 11848 S 0.0 0.1 0:00.05 apache2
1128 www-data 20 0 415664 18468 11976 S 0.0 0.1 0:00.02 apache2
1129 www-data 20 0 415872 18580 11976 S 0.0 0.1 0:00.05 apache2
1274 www-data 20 0 88528 16140 4184 S 0.0 0.1 0:00.04 zmdc.pl
1341 www-data 20 0 111120 33656 7420 S 0.0 0.2 0:00.21 zmfilter.pl
1346 www-data 20 0 111176 33396 7148 S 0.0 0.2 0:00.19 zmfilter.pl
1354 www-data 20 0 85924 18396 7032 S 0.0 0.1 0:00.14 zmwatch.pl
1397 www-data 20 0 91368 22160 7108 S 0.0 0.1 0:00.10 zmupdate.pl
1446 www-data 20 0 95544 22396 7120 S 0.0 0.1 0:00.12 zmtelemetr+
1513 www-data 20 0 85776 18512 7268 S 0.0 0.1 0:00.08 zmstats.pl
1531 www-data 20 0 415660 19928 13348 S 0.0 0.1 0:00.02 apache2
1533 www-data 20 0 415656 17988 11852 S 0.0 0.1 0:00.02 apache2
1534 www-data 20 0 415656 17996 11860 S 0.0 0.1 0:00.01 apache2
1535 www-data 20 0 415848 18564 11988 S 0.0 0.1 0:00.04 apache2
1536 www-data 20 0 415656 17996 11860 S 0.0 0.1 0:00.02 apache2

top - 12:05:46 up 7 min, 1 user, load average: 0.59, 1.07, 0.63
Tasks: 276 total, 1 running, 223 sleeping, 0 stopped, 0 zombie
%Cpu(s): 6.0 us, 0.2 sy, 3.6 ni, 89.6 id, 0.3 wa, 0.0 hi, 0.3 si, 0.0 st
KiB Mem : 16294984 total, 13091592 free, 1942168 used, 1261224 buff/cache
KiB Swap: 999420 total, 999420 free, 0 used. 13630244 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1493 www-data 20 0 1643376 829956 184848 S 27.7 5.1 1:39.14 zma
1332 www-data 20 0 620724 211468 185652 S 10.6 1.3 0:36.38 zmc

1126 www-data 20 0 416104 18556 11976 S 0.2 0.1 0:00.02 apache2
1125 www-data 20 0 415772 20516 13328 S 0.0 0.1 0:00.05 apache2
1127 www-data 20 0 415672 18012 11848 S 0.0 0.1 0:00.05 apache2
1128 www-data 20 0 415664 18468 11976 S 0.0 0.1 0:00.02 apache2
1129 www-data 20 0 415872 18580 11976 S 0.0 0.1 0:00.05 apache2
1274 www-data 20 0 88528 16140 4184 S 0.0 0.1 0:00.04 zmdc.pl
1341 www-data 20 0 111120 33656 7420 S 0.0 0.2 0:00.21 zmfilter.pl
1346 www-data 20 0 111176 33396 7148 S 0.0 0.2 0:00.19 zmfilter.pl
1354 www-data 20 0 85924 18396 7032 S 0.0 0.1 0:00.14 zmwatch.pl
1397 www-data 20 0 91368 22160 7108 S 0.0 0.1 0:00.10 zmupdate.pl
1446 www-data 20 0 95544 22396 7120 S 0.0 0.1 0:00.12 zmtelemetr+
1513 www-data 20 0 85776 18512 7268 S 0.0 0.1 0:00.08 zmstats.pl
1531 www-data 20 0 415660 19928 13348 S 0.0 0.1 0:00.02 apache2
1533 www-data 20 0 415656 17988 11852 S 0.0 0.1 0:00.02 apache2
1534 www-data 20 0 415656 17996 11860 S 0.0 0.1 0:00.01 apache2
1535 www-data 20 0 415848 18564 11988 S 0.0 0.1 0:00.04 apache2
1536 www-data 20 0 415656 17996 11860 S 0.0 0.1 0:00.02 apache2
1493 (zma) S 1274 1274 1255 0 -1 1077936128 14527 0 17 0 9863 52 0 0 20 0 10 0 11308 1682817024 207489 18446744073709551615 1 1 0 0 0 0 65536 4096 20207 0 0 0 17 3 0 0 32 0 0 0 0 0 0 0 0 0 0
1332 (zmc) S 1274 1274 1255 0 -1 4194304 52124 0 133 0 3578 60 0 0 20 0 1 0 10285 635621376 52867 18446744073709551615 1 1 0 0 0 0 68097 4096 20207 0 0 0 17 0 0 0 556 0 0 0 0 0 0 0 0 0 0

I use to work in application performance analysis area many years ago at which time I was proficient in c. I would think I could tear into zma in more detail but getting the source code / compiling up looks like an effort or maybe not so bad - not sure. Its been a long time.
jwarfin
Posts: 41
Joined: Mon Jul 23, 2018 4:36 am

Re: Performance Issues / Comparision 1.32 to 1.30

Post by jwarfin »

I use 1.30.4, but I've been watching user posts on 1.32 to see how the release is doing.

Looking at the metrics in your post, I think the memory utilization numbers for zma vs zmc provide an important clue too. Basically, zma is using over 4x the memory of zmc. Why?? I doubt it's audio because audio bandwidth typically isn't big enough to account for the magnitude of memory increase.

Assuming you configure 1.30 & 1.32 settings to be reasonably the same in your tests, it's clear 1.32 is using a lot more memory for analysis, which means the CPU is dealing with a bigger workload.

Concerning the side channel related security updates/mitigations for 18.04 (which actually apply to 14.04 and higher): memory ops (eg: device & memory I/O) takes the biggest performance hit (Intel processors are hit the hardest). Since zma has to do a lot of I/O, the side channel mitigations do exact a significant performance hit. The more memory zma uses, the more you'll feel the hit.

In any case - and if your data is a reasonable apples-to-apples comparison (settings-wise) of zma system utilization between 1.30 and 1.32 - then it does look like 1.32's zma memory consumption is much much higher. And, like you, I'd love to know why.
rockedge
Posts: 1173
Joined: Fri Apr 04, 2014 1:46 pm
Location: Connecticut,USA

Re: Performance Issues / Comparision 1.32 to 1.30

Post by rockedge »

Interesting... I think I am seeing better performance with version 1.33.9 than I did with the 1.32+ series
AnotherBrian
Posts: 112
Joined: Tue Jul 27, 2010 6:36 am

Re: Performance Issues / Comparision 1.32 to 1.30

Post by AnotherBrian »

sorry for poor presentation. this post is to make a complete record of the data. My first post of data shown above was running the script on v1.32 on ubuntu 18.04.02. What follows is v1.30.4 on ubuntu 16.04.06.

14884 (zma) S 14845 14845 14831 0 -1 1077936128 10875 0 0 0 1017 33 0 0 20 0 1 0 7265501 816590848 107614 18446744073709551615 1 1 0 0 0 0 65536 4096 20207 0 0 0 17 1 0 0 0 0 0 0 0 0 0 0 0 0 0
14876 (zmc) S 14845 14845 14831 0 -1 4194304 118286 0 0 0 2063 69 0 0 20 0 6 0 7265453 1207169024 119761 18446744073709551615 1 1 0 0 0 0 68096 4096 20206 0 0 0 17 2 0 0 0 0 0 0 0 0 0 0 0 0 0
top - 11:43:59 up 20:13, 1 user, load average: 0.78, 0.90, 0.88
Tasks: 241 total, 1 running, 184 sleeping, 0 stopped, 0 zombie
%Cpu(s): 9.2 us, 0.5 sy, 0.0 ni, 89.2 id, 1.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 16295716 total, 191596 free, 1456896 used, 14647224 buff/cache
KiB Swap: 999420 total, 999420 free, 0 used. 13631280 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
14876 www-data 20 0 1178876 479044 423340 S 20.0 2.9 0:21.35 zmc
14884 www-data 20 0 797452 430456 417444 S 13.3 2.6 0:10.52 zma

11224 www-data 20 0 337504 16424 9040 S 0.0 0.1 0:00.09 apache2
11225 www-data 20 0 337468 15676 8424 S 0.0 0.1 0:00.03 apache2
11227 www-data 20 0 337476 15912 8528 S 0.0 0.1 0:00.07 apache2
13538 www-data 20 0 337468 15716 8464 S 0.0 0.1 0:00.02 apache2
13539 www-data 20 0 337340 15716 8464 S 0.0 0.1 0:00.02 apache2
13540 www-data 20 0 337032 10144 3304 S 0.0 0.1 0:00.00 apache2
13543 www-data 20 0 337056 10344 3304 S 0.0 0.1 0:00.02 apache2
13547 www-data 20 0 337364 16528 9148 S 0.0 0.1 0:00.07 apache2
13911 www-data 20 0 337468 15732 8516 S 0.0 0.1 0:00.01 apache2
14642 www-data 20 0 337348 15564 8336 S 0.0 0.1 0:00.02 apache2
14845 www-data 20 0 85264 16344 4476 S 0.0 0.1 0:00.09 zmdc.pl
14885 www-data 20 0 103896 29292 7052 S 0.0 0.2 0:00.19 zmfilter.pl
14891 www-data 20 0 83480 16936 6828 S 0.0 0.1 0:00.11 zmwatch.pl
14896 www-data 20 0 89084 20760 6796 S 0.0 0.1 0:00.11 zmupdate.pl
14900 www-data 20 0 88292 20052 6768 S 0.0 0.1 0:00.12 zmtelemetr+

top - 11:44:09 up 20:13, 1 user, load average: 0.74, 0.88, 0.88
Tasks: 241 total, 1 running, 183 sleeping, 0 stopped, 0 zombie
%Cpu(s): 8.4 us, 0.8 sy, 0.0 ni, 88.7 id, 2.0 wa, 0.0 hi, 0.1 si, 0.0 st
KiB Mem : 16295716 total, 174064 free, 1456000 used, 14665652 buff/cache
KiB Swap: 999420 total, 999420 free, 0 used. 13632096 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
14876 www-data 20 0 1178876 479044 423340 S 13.7 2.9 0:22.72 zmc
14884 www-data 20 0 797452 430456 417444 S 7.3 2.6 0:11.25 zma

14845 www-data 20 0 85264 16344 4476 S 0.1 0.1 0:00.10 zmdc.pl
11224 www-data 20 0 337504 16424 9040 S 0.0 0.1 0:00.09 apache2
11225 www-data 20 0 337468 15676 8424 S 0.0 0.1 0:00.03 apache2
11227 www-data 20 0 337476 15912 8528 S 0.0 0.1 0:00.07 apache2
13538 www-data 20 0 337468 15716 8464 S 0.0 0.1 0:00.02 apache2
13539 www-data 20 0 337340 15716 8464 S 0.0 0.1 0:00.02 apache2
13540 www-data 20 0 337032 10144 3304 S 0.0 0.1 0:00.00 apache2
13543 www-data 20 0 337056 10344 3304 S 0.0 0.1 0:00.02 apache2
13547 www-data 20 0 337364 16528 9148 S 0.0 0.1 0:00.07 apache2
13911 www-data 20 0 337468 15732 8516 S 0.0 0.1 0:00.01 apache2
14642 www-data 20 0 337348 15564 8336 S 0.0 0.1 0:00.02 apache2
14885 www-data 20 0 103896 29292 7052 S 0.0 0.2 0:00.19 zmfilter.pl
14891 www-data 20 0 83480 16936 6828 S 0.0 0.1 0:00.11 zmwatch.pl
14896 www-data 20 0 89084 20760 6796 S 0.0 0.1 0:00.11 zmupdate.pl
14900 www-data 20 0 88292 20052 6768 S 0.0 0.1 0:00.12 zmtelemetr+
14884 (zma) S 14845 14845 14831 0 -1 1077936128 10875 0 0 0 1090 35 0 0 20 0 1 0 7265501 816590848 107614 18446744073709551615 1 1 0 0 0 0 65536 4096 20207 0 0 0 17 1 0 0 0 0 0 0 0 0 0 0 0 0 0
14876 (zmc) S 14845 14845 14831 0 -1 4194304 118286 0 0 0 2202 70 0 0 20 0 6 0 7265453 1207169024 119761 18446744073709551615 1 1 0 0 0 0 68096 4096 20206 0 0 0 17 2 0 0 0 0 0 0 0 0 0 0 0 0 0

And now to show how one would calculate this we take the difference of the proc records to obtain cpu time:
zma utime=1070-1090=73 stime=35-33=2
zmc utime=2202-2063=139 stime=70-69=1
AnotherBrian
Posts: 112
Joined: Tue Jul 27, 2010 6:36 am

Re: Performance Issues / Comparision 1.32 to 1.30

Post by AnotherBrian »

okee doke - building on jwarfin's comment on memory utilization.

we have virtualMemory residentMemory and sharedMemory
1.30zma 1178876 479044 423340
1.32zma 1643376 829956 184848
-------------------------------------------
zma 1.32 has 39% more virtual memory, 73% more resident memory, and 56% less shared memory.

1.30zmc 1178876 479044 423340
1.32zmc 620724 211468 185652
---------------------------------------------
zmc 1.32 has 47% less virtual memory, 56% less resident memory, and 56% less shared memory.

Virtual memory is inconsequential - its just allocated air.

Shared memory is interesting. No surprise, both zma and zmc use same amount of shared memory. I assume the images are passed between the two processes using shared memory. v1.32 is using much less shared memory, 56% less.

Resident Memory is interesting. v1.32 zma using 73% more resident memory. v1.32 zmc using 56% less resident memory.


Ideal design where camera image copies are minimized: zmc writes the image into shared memory. zma analyzes and that requires analysis of multiple images all at once. zma or someone has to write the image to disk (RECORD). Further, overload conditions must be considered. All that is complex management.

Guess: v1.32 design reduced complexity of shared memory management. Perhaps the images now get copied into zma address space. That would be a performance hit.

Maybe I've made a mistake and my analysis is all wet. Maybe there is a configuration difference. Anyway I'd be curious to hear the difference in design of the two versions.
Post Reply