Ubuntu 18.04 service fails to "start" even though it's running

timw_suqld · Post by **timw_suqld** » Tue Mar 10, 2020 1:35 am

Had a 16.04 machine that I recently updated to 18.04. Zoneminder 1.32 from the PPA was having issues "starting" where systemd thought it wasn't started (exit code 1) but it was actually running. I uninstalled zoneminder 1.32, add the 1.34 PPA and installed 1.34. The issue remained. I uninstalled and purged zoneminder (other than the DB), ensured no config files in /etc/zm remained, install 1.34 from the PPA and still the same issue.

Basically, it appears the zmpkg.pl gives a failure exit status, even though it has managed to start zoneminder in the background. Systemd then continues trying to restart zoneminder ever 10 seconds or so (I think the retry backs off with bigger sleeps), but ultimately systemd thinks things arent' running, but according to zmdc.pl it is running.

I can't work out why zmpkg.pl is giving an exit of 1.

Code: Select all

$ sudo systemctl status zoneminder
● zoneminder.service - ZoneMinder CCTV recording and surveillance system
   Loaded: loaded (/lib/systemd/system/zoneminder.service; disabled; vendor preset: enabled)
   Active: activating (auto-restart) (Result: exit-code) since Tue 2020-03-10 11:28:21 AEST; 3s ago
  Process: 28510 ExecStart=/usr/bin/zmpkg.pl start (code=exited, status=1/FAILURE)
  
$ sudo /usr/bin/zmdc.pl status
'zmc -m 21' running since 20/03/10 11:18:39, pid = 16017, valid
'zmc -m 14' running since 20/03/10 11:18:37, pid = 15877, valid
'zmwatch.pl' running since 20/03/10 11:18:43, pid = 16244, valid
'zmaudit.pl -c' running since 20/03/10 11:18:43, pid = 16234, valid
'zma -m 23' running since 20/03/10 11:18:45, pid = 16314, valid
'zmc -m 27' running since 20/03/10 11:18:41, pid = 16138, valid
'zma -m 21' running since 20/03/10 11:18:44, pid = 16291, valid
'zmc -m 20' running since 20/03/10 11:18:39, pid = 16003, valid
'zma -m 17' running since 20/03/10 11:18:43, pid = 16228, valid
'zmfilter.pl --filter_id=1 --daemon' running since 20/03/10 11:18:42, pid = 16198, valid
'zma -m 22' running since 20/03/10 11:18:39, pid = 16038, valid
'zma -m 14' running since 20/03/10 11:18:42, pid = 16171, valid
'zmc -m 19' running since 20/03/10 11:18:38, pid = 15963, valid
'zma -m 27' running since 20/03/10 11:18:41, pid = 16145, valid
'zmc -m 17' running since 20/03/10 11:18:38, pid = 15935, valid
'zmc -m 16' running since 20/03/10 11:18:37, pid = 15911, valid
'zmc -m 22' running since 20/03/10 11:18:39, pid = 16031, valid
'zma -m 19' running since 20/03/10 11:18:39, pid = 15990, valid
'zmfilter.pl --filter_id=2 --daemon' running since 20/03/10 11:18:43, pid = 16224, valid
'zmc -m 23' running since 20/03/10 11:18:40, pid = 16055, valid
'zma -m 24' running since 20/03/10 11:22:16, pid = 21118, valid
'zma -m 29' running since 20/03/10 11:18:42, pid = 16201, valid
'zma -m 15' running since 20/03/10 11:18:42, pid = 16172, valid
'zmstats.pl' running since 20/03/10 11:18:43, pid = 16252, valid
'zma -m 18' running since 20/03/10 11:18:38, pid = 15956, valid
'zmc -m 29' running since 20/03/10 11:18:42, pid = 16183, valid
'zmc -m 28' running since 20/03/10 11:18:42, pid = 16165, valid
'zma -m 20' running since 20/03/10 11:18:39, pid = 16010, valid
'zma -m 16' running since 20/03/10 11:18:38, pid = 15922, valid
'zmc -m 26' running since 20/03/10 11:22:36, pid = 21521, valid
'zmc -m 24' running since 20/03/10 11:22:03, pid = 20891, valid
'zmc -m 13' running since 20/03/10 11:18:36, pid = 15843, valid
'zma -m 26' running since 20/03/10 11:22:37, pid = 21568, valid
'zmc -m 25' running since 20/03/10 11:21:46, pid = 20522, valid
'zmc -m 10' running since 20/03/10 11:19:24, pid = 17716, valid
'zmc -m 18' running since 20/03/10 11:18:38, pid = 15949, valid
'zmc -m 15' running since 20/03/10 11:18:37, pid = 15897, valid
'zma -m 13' running since 20/03/10 11:18:37, pid = 15881, valid
'zma -m 25' running since 20/03/10 11:21:46, pid = 20527, valid
'zma -m 28' running since 20/03/10 11:18:42, pid = 16176, valid
'zma -m 3' pending at 20/03/10 11:29:39
'zmc -m 3' pending at 20/03/10 11:29:49
  
  
$ apt-cache policy zoneminder
zoneminder:
  Installed: 1.34.6-bionic1
  Candidate: 1.34.6-bionic1
  Version table:
 *** 1.34.6-bionic1 500
        500 http://ppa.launchpad.net/iconnor/zoneminder-1.34/ubuntu bionic/main amd64 Packages
        100 /var/lib/dpkg/status

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 18.04.4 LTS
Release:        18.04
Codename:       bionic

zmdc.log has the following when I try to start zoneminder

Code: Select all

03/10/2020 11:33:52.876103 zmdc[35004].ERR [ZMServer:705] ['zma -m 13' exited abnormally, exit status 255]
03/10/2020 11:33:53.189150 zmdc[35004].ERR [ZMServer:705] ['zma -m 14' exited abnormally, exit status 255]
03/10/2020 11:33:53.346476 zmdc[35004].ERR [ZMServer:705] ['zma -m 14' exited abnormally, exit status 255]
03/10/2020 11:33:53.496021 zmdc[35004].ERR [ZMServer:705] ['zma -m 15' exited abnormally, exit status 255]
03/10/2020 11:33:53.677374 zmdc[35004].ERR [ZMServer:705] ['zma -m 15' exited abnormally, exit status 255]
03/10/2020 11:33:54.122867 zmdc[35004].ERR [ZMServer:705] ['zma -m 17' exited abnormally, exit status 255]
03/10/2020 11:33:54.308538 zmdc[35004].ERR [ZMServer:705] ['zma -m 17' exited abnormally, exit status 255]
03/10/2020 11:33:55.393307 zmdc[35004].ERR [ZMServer:705] ['zma -m 21' exited abnormally, exit status 255]
03/10/2020 11:33:55.594323 zmdc[35004].ERR [ZMServer:705] ['zma -m 21' exited abnormally, exit status 255]
03/10/2020 11:33:56.039559 zmdc[35004].ERR [ZMServer:705] ['zma -m 23' exited abnormally, exit status 255]
03/10/2020 11:33:56.242298 zmdc[35004].ERR [ZMServer:705] ['zma -m 23' exited abnormally, exit status 255]
03/10/2020 11:33:56.391822 zmdc[35004].ERR [ZMServer:705] ['zma -m 24' exited abnormally, exit status 255]
03/10/2020 11:33:56.624068 zmdc[35004].ERR [ZMServer:705] ['zma -m 24' exited abnormally, exit status 255]
03/10/2020 11:33:57.148049 zmdc[35004].ERR [ZMServer:705] ['zma -m 26' exited abnormally, exit status 255]
03/10/2020 11:33:57.356131 zmdc[35004].ERR [ZMServer:705] ['zma -m 26' exited abnormally, exit status 255]
03/10/2020 11:33:58.300221 zmdc[35004].ERR [ZMServer:705] ['zma -m 29' exited abnormally, exit status 255]
03/10/2020 11:34:29.858723 zmdc[35004].ERR [ZMServer:705] ['zma -m 3' exited abnormally, exit status 255]

In the system logs I can see lots of the zma_ zmc_ log lines continuing, and every so often the systemd attempts to restart the job.

Code: Select all

Mar 10 11:30:16 hc-cameras systemd[1]: zoneminder.service: Service hold-off time over, scheduling restart.
Mar 10 11:30:16 hc-cameras systemd[1]: zoneminder.service: Scheduled restart job, restart counter is at 66.
Mar 10 11:30:16 hc-cameras systemd[1]: Stopped ZoneMinder CCTV recording and surveillance system.
Mar 10 11:30:16 hc-cameras systemd[1]: Starting ZoneMinder CCTV recording and surveillance system...
Mar 10 11:30:16 hc-cameras zma_m3[30476]: INF [zma_m3] [FrontFoyer: 134 - Left alarm state (5284544) - 145(74) images]
Mar 10 11:30:16 hc-cameras zma_m3[30476]: INF [zma_m3] [FrontFoyer: 134 - Closing event 5284544, alarm end]
Mar 10 11:30:16 hc-cameras zma_m15[16172]: INF [zma_m15] [LoadingDock-HD: 13900 - Analysing at 20.00 fps]
Mar 10 11:30:16 hc-cameras zmc_m23[16055]: WAR [zmc_m23] [ImageBufferCount 50 is too small. Needs to be at least 51. Either increase it or decrease time between keyframes]
Mar 10 11:30:16 hc-cameras zmpkg[30779]: INF [Sanity checking States table...]
Mar 10 11:30:16 hc-cameras zmc_m19[15963]: WAR [zmc_m19] [ImageBufferCount 50 is too small. Needs to be at least 51. Either increase it or decrease time between keyframes]
Mar 10 11:30:16 hc-cameras zmpkg[30779]: INF [Command: start]
Mar 10 11:30:16 hc-cameras systemd[1]: Started Session c176 of user www-data.
Mar 10 11:30:16 hc-cameras systemd[1]: Started Session c177 of user www-data.
Mar 10 11:30:16 hc-cameras zmc_m25[20522]: INF [zmc_m25] [FrontDoorNew-Low: images:10200 - Capturing at 20.00 fps, capturing bandwidth 16643bytes/sec]
Mar 10 11:30:16 hc-cameras systemd[1]: zoneminder.service: Control process exited, code=exited status=1
Mar 10 11:30:16 hc-cameras systemd[1]: zoneminder.service: Failed with result 'exit-code'.
Mar 10 11:30:16 hc-cameras systemd[1]: Failed to start ZoneMinder CCTV recording and surveillance system.

Any help to work out why it's failing to start correctly would be appreciated. Thanks