zmupdate.pl continuously using close to 100% CPU

Forum for questions and support relating to the 1.29.x releases only.
Forum rules
Locked
ngauruhoe
Posts: 25
Joined: Sun Jan 03, 2016 5:26 pm

zmupdate.pl continuously using close to 100% CPU

Post by ngauruhoe »

Had top running for 15min or so. I see zmupdate.pl using close to a 100% CPU all the time. Since I read this is only used to check for updates it doesn't look right to me. Stopped ZM. All fine. Restarted and the same happens again.
  • PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
    1498 www-data 20 0 110152 34600 9560 R 99.3 4.6 14:48.72 zmupdate.pl
    1 root 20 0 37532 5644 4000 S 0.0 0.7 0:01.60 systemd
    2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
    3 root 20 0 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
    5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
    6 root 20 0 0 0 0 S 0.0 0.0 0:00.18 kworker/u2:0
    7 root 20 0 0 0 0 S 0.0 0.0 0:00.07 rcu_sched
    8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh
    9 root 20 0 0 0 0 R 0.0 0.0 0:00.06 rcuos/0
    10 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/0
    11 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
    12 root rt 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
    13 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 khelper
    14 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs
    15 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns
    16 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 perf
    17 root 20 0 0 0 0 S 0.0 0.0 0:00.00 khungtaskd
    18 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 writeback
    19 root 25 5 0 0 0 S 0.0 0.0 0:00.00 ksmd
    20 root 39 19 0 0 0 S 0.0 0.0 0:00.13 khugepaged
    21 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 crypto
    22 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kintegrityd
    23 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 bioset
    24 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kblockd
    25 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 ata_sff
    26 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 md
    27 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 devfreq_wq
    31 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kswapd0
    32 root 20 0 0 0 0 S 0.0 0.0 0:00.00 fsnotify_ma+
    33 root 20 0 0 0 0 S 0.0 0.0 0:00.00 ecryptfs-kt+
    44 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kthrotld
    45 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 acpi_therma+
    46 root 20 0 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0
Top
User avatar
knight-of-ni
Posts: 2404
Joined: Thu Oct 18, 2007 1:55 pm
Location: Shiloh, IL

Re: zmupdate.pl continuously using close to 100% CPU

Post by knight-of-ni »

Working fine here.
Make sure you've got access to this url -> https://update.zoneminder.com/version.txt

As always, you need to check your zoneminder log for any relevant messages.
You are looking for a message that says "Update agent starting at" and also the events that immediately follow it.

You can also call "zmupdate.pl --check" directly from the command line to see what it is up to.
Visit my blog for ZoneMinder related projects using the Raspberry Pi, Orange Pi, Odroid, and the ESP8266
All of these can be found at https://zoneminder.blogspot.com/
Top
bbunge
Posts: 2934
Joined: Mon Mar 26, 2012 11:40 am
Location: Pennsylvania

Re: zmupdate.pl continuously using close to 100% CPU

Post by bbunge »

As I recall there were some issues with the database that pushed the processor use up. But Top or Htop would show MySQL as using a lot of processor. Errors in the camera setup could cause issues like this as well..
You are using Ubuntu 15.x? Did you install from the PPA Master and what install procedure did you use? If you did an upgrade of ZM did you update the database and the database permissions?
Top
ngauruhoe
Posts: 25
Joined: Sun Jan 03, 2016 5:26 pm

Re: zmupdate.pl continuously using close to 100% CPU

Post by ngauruhoe »

Sorry for the late response. Busy week at the officce.

I used w3m from a terminal session to verify that I can access https://update.zoneminder.com/version.txt. Which opens up just fine.

Looking at the ZM log I see normal zmupdate startup message, see below. Killing it only gives a momentarily relief since it gets restarted automatically within a few seconds and starts using 100% cpu again. I also tried to start zmupdate.pl --check manually resulting in two processes using each 100% CPU. I guess that's because I've got multiple processors assigned to this vm. See below.

The wiki documented procedure I used to install 1.29 are here: http://zoneminder.readthedocs.org/en/st ... rom-source. This worked fine, no errors. Only the permission issue described in this viewtopic.php?f=34&t=23841 topic.

Anyway, to summarize, I can access the version url, I don't see any strange zmupdate log messages and I followed the wiki documented process to install. Any other suggestions? How can I simply stop zmupdate from getting (re) started?

BTW, opening the log view identifies another problem. As soon as the log view window opens warning message "http://192.168.1.250:30080 is not found in servers list" starts being written every second which fills up the log view pretty fast. I tried to use the export log function to offload. However all tries in different formats all end up with empty files. Export function does not seem to work. Finally tried ctrl-A, crtl-C and pasted the result into text file. See below.
  • skywalker@uServer-Watchdog:~$ top
    top - 22:14:22 up 1:13, 2 users, load average: 1.80, 1.26, 1.06
    Tasks: 128 total, 3 running, 125 sleeping, 0 stopped, 0 zombie
    %Cpu(s): 40.0 us, 0.1 sy, 0.0 ni, 59.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
    KiB Mem: 758128 total, 510348 used, 247780 free, 18076 buffers
    KiB Swap: 784380 total, 0 used, 784380 free. 166320 cached Mem

    PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
    1445 www-data 20 0 110120 34732 9628 R 99.9 4.6 36:06.79 zmupdate.pl
    1632 skywalk+ 20 0 110124 34572 9636 R 99.9 4.6 1:33.33 zmupdate.pl
    12 root rt 0 0 0 0 S 0.3 0.0 0:00.06 watchdog/0
    232 root 20 0 0 0 0 S 0.3 0.0 0:00.50 kworker/0:2
    1 root 20 0 37484 5580 3988 S 0.0 0.7 0:01.98 systemd
    2 root 20 0 0 0 0 S 0.0 0.0 0:00.03 kthreadd
    3 root 20 0 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
    5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:+
    7 root 20 0 0 0 0 S 0.0 0.0 0:01.22 rcu_sched
    8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh
    9 root 20 0 0 0 0 S 0.0 0.0 0:00.80 rcuos/0
    10 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/0
    11 root rt 0 0 0 0 S 0.0 0.0 0:00.11 migration/0
    13 root rt 0 0 0 0 S 0.0 0.0 0:00.05 watchdog/1
    14 root rt 0 0 0 0 S 0.0 0.0 0:00.12 migration/1
    15 root 20 0 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/1
    17 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/1:+
  • DATE/TIME COMPONENT SERVER PID LEVEL MESSAGE FILE LINE
    2016-01-08 21:39:19.757448 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:18.650084 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:17.593447 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:16.538943 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:15.488985 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:14.427332 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:13.372113 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:12.312947 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:11.251874 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:10.072801 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:08.991683 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:07.858646 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:06.772171 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:05.690028 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:04.594993 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:03.313421 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:39:03.042401 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers list. /usr/local/share/zoneminder/www/includes/functions.php 111
    2016-01-08 21:38:15.245540 zmupdate 1445 INF Checking for updates zmupdate.pl
    2016-01-08 21:38:15.063600 zmdc 1075 INF 'zmupdate.pl -c' starting at 16/01/08 21:38:15, pid = 1445 zmdc.pl
    2016-01-08 21:38:15.063370 zmdc 1445 INF 'zmupdate.pl -c' started at 16/01/08 21:38:15 zmdc.pl
    2016-01-08 21:38:15.032750 zmdc 1075 INF Starting pending process, zmupdate.pl -c zmdc.pl
    2016-01-08 21:37:35.538130 zmdc 1075 INF 'zmupdate.pl -c' exited, signal 14 zmdc.pl
    2016-01-08 21:36:13.240270 zmupdate 1378 INF Checking for updates zmupdate.pl
    2016-01-08 21:36:13.046160 zmdc 1075 INF 'zmupdate.pl -c' starting at 16/01/08 21:36:13, pid = 1378 zmdc.pl
    2016-01-08 21:36:13.044840 zmdc 1378 INF 'zmupdate.pl -c' started at 16/01/08 21:36:13 zmdc.pl
    2016-01-08 21:36:13.027500 zmdc 1075 INF Starting pending process, zmupdate.pl -c zmdc.pl
    2016-01-08 21:35:53.040820 zmdc 1075 INF 'zmupdate.pl -c' exited, signal 14 zmdc.pl
    2016-01-08 21:33:31.603850 zmupdate 1368 INF Checking for updates zmupdate.pl
    2016-01-08 21:32:25.280090 zmupdate 1365 INF Checking for updates zmupdate.pl
    2016-01-08 21:32:25.100310 zmdc 1365 INF 'zmupdate.pl -c' started at 16/01/08 21:32:25 zmdc.pl
    2016-01-08 21:32:25.100190 zmdc 1075 INF 'zmupdate.pl -c' starting at 16/01/08 21:32:25, pid = 1365 zmdc.pl
    2016-01-08 21:32:25.073160 zmdc 1075 INF Starting pending process, zmupdate.pl -c zmdc.pl
    2016-01-08 21:32:15.517400 zmdc 1075 INF 'zmupdate.pl -c' exited, signal 14 zmdc.pl
    2016-01-08 21:28:46.558560 zmupdate 1291 INF Checking for updates zmupdate.pl
    2016-01-08 21:28:46.124100 zmdc 1291 INF 'zmupdate.pl -c' started at 16/01/08 21:28:46 zmdc.pl
    2016-01-08 21:28:46.123830 zmdc 1075 INF 'zmupdate.pl -c' starting at 16/01/08 21:28:46, pid = 1291 zmdc.pl
    2016-01-08 21:28:46.099890 zmdc 1075 INF Starting pending process, zmupdate.pl -c zmdc.pl
    2016-01-08 21:28:41.065900 zmdc 1075 INF 'zmupdate.pl -c' exited, signal 14 zmdc.pl
    2016-01-08 21:23:27.972650 zmupdate 1277 INF Checking for updates zmupdate.pl
    2016-01-08 21:23:27.446100 zmdc 1277 INF 'zmupdate.pl -c' started at 16/01/08 21:23:27 zmdc.pl
    2016-01-08 21:23:27.445340 zmdc 1075 INF 'zmupdate.pl -c' starting at 16/01/08 21:23:27, pid = 1277 zmdc.pl
    2016-01-08 21:23:27.427830 zmdc 1075 INF Starting pending process, zmupdate.pl -c zmdc.pl
    2016-01-08 21:23:27.397930 zmdc 1075 INF 'zmupdate.pl -c' exited, signal 14 zmdc.pl
    2016-01-08 21:01:07.231760 zmupdate 1118 INF Checking for updates zmupdate.pl
    2016-01-08 21:01:06.995360 zmfilter 1101 INF Scanning for events zmfilter.pl
    2016-01-08 21:01:06.942750 zmwatch 1112 INF Watchdog pausing for 30 seconds zmwatch.pl
    2016-01-08 21:01:06.935120 zmdc 1118 INF 'zmupdate.pl -c' started at 16/01/08 21:01:06 zmdc.pl
    2016-01-08 21:01:06.935110 zmdc 1075 INF 'zmupdate.pl -c' starting at 16/01/08 21:01:06, pid = 1118 zmdc.pl
    2016-01-08 21:01:06.919100 zmwatch 1112 INF Watchdog starting zmwatch.pl
    2016-01-08 21:01:06.724270 zmdc 1112 INF 'zmwatch.pl' started at 16/01/08 21:01:06 zmdc.pl
    2016-01-08 21:01:06.724230 zmdc 1075 INF 'zmwatch.pl' starting at 16/01/08 21:01:06, pid = 1112 zmdc.pl
    2016-01-08 21:01:06.539280 zmdc 1106 INF 'zmaudit.pl -c' started at 16/01/08 21:01:06 zmdc.pl
    2016-01-08 21:01:06.539170 zmdc 1075 INF 'zmaudit.pl -c' starting at 16/01/08 21:01:06, pid = 1106 zmdc.pl
    2016-01-08 21:01:06.385240 zmdc 1075 INF 'zmfilter.pl' starting at 16/01/08 21:01:06, pid = 1101 zmdc.pl
    2016-01-08 21:01:06.385160 zmdc 1101 INF 'zmfilter.pl' started at 16/01/08 21:01:06 zmdc.pl
    2016-01-08 21:01:06.225980 zmpkg 1058 INF Starting up services zmpkg.pl
    2016-01-08 21:01:03.221810 zmdc 1075 INF Server starting at 16/01/08 21:01:03 zmdc.pl
    2016-01-08 21:01:02.628570 zmpkg 1058 INF Command: start zmpkg.pl
    2016-01-08 21:01:02.534910 zmpkg 1058 INF Sanity checking States table... zmpkg.pl
    2016-01-08 19:10:01.717960 zmdc 1087 INF 'zmwatch.pl' exited, signal 14 zmdc.pl
    2016-01-08 19:10:01.711170 zmdc 1087 INF 'zmfilter.pl' exited, signal 14 zmdc.pl
    2016-01-08 19:10:01.707110 zmdc 1087 INF 'zmaudit.pl -c' sending stop to pid 1118 at 16/01/08 19:10:01 zmdc.pl
    2016-01-08 19:10:01.702190 zmdc 1087 INF 'zmwatch.pl' sending stop to pid 1124 at 16/01/08 19:10:01 zmdc.pl
    2016-01-08 19:10:01.637070 zmdc 1087 INF 'zmfilter.pl' sending stop to pid 1113 at 16/01/08 19:10:01 zmdc.pl
    2016-01-08 19:10:00.703750 zmpkg 1276 INF Command: stop zmpkg.pl
    2016-01-08 19:10:00.673980 zmpkg 1276 INF Sanity checking States table... zmpkg.pl
    2016-01-08 19:08:00.751900 zmupdate 1131 INF Checking for updates zmupdate.pl
    2016-01-08 19:08:00.508090 zmfilter 1113 INF Scanning for events zmfilter.pl
    2016-01-08 19:08:00.478290 zmdc 1087 INF 'zmupdate.pl -c' starting at 16/01/08 19:08:00, pid = 1131 zmdc.pl
    2016-01-08 19:08:00.478290 zmdc 1131 INF 'zmupdate.pl -c' started at 16/01/08 19:08:00 zmdc.pl
    2016-01-08 19:08:00.469410 zmwatch 1124 INF Watchdog pausing for 30 seconds zmwatch.pl
    2016-01-08 19:08:00.465630 zmwatch 1124 INF Watchdog starting zmwatch.pl
    2016-01-08 19:08:00.267690 zmdc 1124 INF 'zmwatch.pl' started at 16/01/08 19:08:00 zmdc.pl
    2016-01-08 19:08:00.267690 zmdc 1087 INF 'zmwatch.pl' starting at 16/01/08 19:08:00, pid = 1124 zmdc.pl
    2016-01-08 19:08:00.076240 zmdc 1118 INF 'zmaudit.pl -c' started at 16/01/08 19:08:00 zmdc.pl
    2016-01-08 19:08:00.076240 zmdc 1087 INF 'zmaudit.pl -c' starting at 16/01/08 19:08:00, pid = 1118 zmdc.pl
    2016-01-08 19:07:59.919640 zmdc 1087 INF 'zmfilter.pl' starting at 16/01/08 19:07:59, pid = 1113 zmdc.pl
    2016-01-08 19:07:59.919130 zmdc 1113 INF 'zmfilter.pl' started at 16/01/08 19:07:59 zmdc.pl
    2016-01-08 19:07:59.701220 zmpkg 1070 INF Starting up services zmpkg.pl
    2016-01-08 19:07:56.689800 zmdc 1087 INF Server starting at 16/01/08 19:07:56 zmdc.pl
    2016-01-08 19:07:56.116500 zmpkg 1070 INF Command: start zmpkg.pl
    2016-01-08 19:07:55.921720 zmpkg 1070 INF Sanity checking States table... zmpkg.pl
    2016-01-06 21:30:00.898250 zmdc 1038 INF Server shutdown at 16/01/06 21:30:00 zmdc.pl
    2016-01-06 21:29:50.731430 zmdc 1038 INF 'zmaudit.pl -c' exited, signal 14 zmdc.pl
    2016-01-06 21:29:50.725510 zmdc 1038 INF 'zmaudit.pl -c' sending stop to pid 1069 at 16/01/06 21:29:50 zmdc.pl
    2016-01-06 21:29:50.721120 zmdc 1038 INF 'zmwatch.pl' exited, signal 14 zmdc.pl
    2016-01-06 21:29:50.714800 zmdc 1038 INF 'zmupdate.pl -c' exited, signal 14 zmdc.pl
    2016-01-06 21:29:50.711670 zmdc 1038 INF 'zmfilter.pl' exited, signal 14 zmdc.pl
    2016-01-06 21:29:50.705380 zmdc 1038 INF 'zmwatch.pl' sending stop to pid 1075 at 16/01/06 21:29:50 zmdc.pl
    2016-01-06 21:29:50.700390 zmdc 1038 INF 'zmfilter.pl' sending stop to pid 1064 at 16/01/06 21:29:50 zmdc.pl
    2016-01-06 21:29:50.677900 zmdc 1038 INF 'zmupdate.pl -c' sending stop to pid 1084 at 16/01/06 21:29:50 zmdc.pl
    2016-01-06 21:29:48.846180 zmpkg 1255 INF Command: stop zmpkg.pl
    2016-01-06 21:29:48.823950 zmpkg 1255 INF Sanity checking States table... zmpkg.pl
Top
User avatar
knight-of-ni
Posts: 2404
Joined: Thu Oct 18, 2007 1:55 pm
Location: Shiloh, IL

Re: zmupdate.pl continuously using close to 100% CPU

Post by knight-of-ni »

To turn it off, just go under Options and uncheck CHECK_FOR_UPDATES.
Visit my blog for ZoneMinder related projects using the Raspberry Pi, Orange Pi, Odroid, and the ESP8266
All of these can be found at https://zoneminder.blogspot.com/
Top
User avatar
knight-of-ni
Posts: 2404
Joined: Thu Oct 18, 2007 1:55 pm
Location: Shiloh, IL

Re: zmupdate.pl continuously using close to 100% CPU

Post by knight-of-ni »

ZoneMinder will put a "Got version" entry in the logs when it is successful as you can see here:
https://github.com/ZoneMinder/ZoneMinde ... pl.in#L182

Since you do see the "Checking for Updates" message at line 165, that implies your machine is getting hung up on the proxy settings or the http GET https://update.zoneminder.com/version.txt command.

This requires LWP::UserAgent, but one would expect a different error if you were missing that perl module.
Visit my blog for ZoneMinder related projects using the Raspberry Pi, Orange Pi, Odroid, and the ESP8266
All of these can be found at https://zoneminder.blogspot.com/
Top
ngauruhoe
Posts: 25
Joined: Sun Jan 03, 2016 5:26 pm

Re: zmupdate.pl continuously using close to 100% CPU

Post by ngauruhoe »

Ok, thx. I turned zmupdate off. Ok for the CPU consumption but not a permanent solution. I looked at the code but in the system settings THE UPDATE_CHECK_PROXY is blank. So how could it fail there?

Maybe it has something to do with the error I get that start being issued when I open the log window? Also seems network related. I changed the portnumber from 80 to 30080 in ports.conf and 000-default.conf as well as in the port forwarding in VirtualBox. So now ZM is listening on 30080. But that didn't make any difference to the error below.

What is meant by ''servers list' in the message below? Where do I find it?
  • 2016-01-08 21:39:19.757448 web_php 1453 WAR http://192.168.1.250:30080 is not found in servers
    list. /usr/local/share/zoneminder/www/includes/functions.php 111
Top
Locked

Return to “ZoneMinder 1.29.x”