The zmeventnotification.pl is not starting with docker start

[llibyddap]

Version: 1.34.16 (last pulled 7/2/2020)

To start - thanks so much for sharing your work... It is outstanding - I've actually got it up and running on an RKE cluster in its most basic form.

The only thing I can't figure out (and I've done a couple of pulls to restart from scratch to isolate my issue) is why zmeventnotification.pl doesn't start automatically with the the container.

At first I thought I was having issues regarding the actual object detection hooks and various configurations. I could run everything manually without issue. But what I found was that the hook scripts were not being triggered automatically and I couldn't find any zmeventnotification.logs. I went into the docker container (CLI) and ran

Code: Select all

sudo -u www-data /usr/bin/zmeventnotification.pl

and sure enough the zmeventnotifications.ini was loaded and the motion detection alerts now trigger the ml hooks automatically. I've gone through the unmodified configuration files on github vs my configuration files and don't see that there is anything in these files that would inadvertently turn off zmeventnotification.pl.

Is this something new or is it user error? If it's user error could you point me in the right direction. I'm not sure any of the logs are helpful - they show nothing for zmeventnotificaiton on boot. Then when I run it from the command line it loads everything and works as I would expect. I wasn't able to back trace the startup script to figure it out (although I didn't spend a lot of time parsing through the systemd stuff]. If there is a log missing that would be helpful I can pull it (I included startup logs and logs when manually deploying zmeventnotifications for reference).

Again, thanks for a much appreciated effort.

Container Startup Logs:

Code: Select all

Freshening configuration in database 
Migratings passwords, if any... 
Loading config from DB 230 entries 
Saving config to DB 230 entries 
 * Starting Apache httpd web server apache2         * 
Starting ZoneMinder: 
07/02/20 14:12:36.901413 zmpkg[3464].INF [main:310] [Sanity checking States table...] 
Jul  2 14:12:36 zoneminder-6b567f46d-kqjr4 zmpkg[3464]: INF [Sanity checking States table...] 
07/02/20 14:12:36.927152 zmpkg[3464].INF [main:95] [Command: start] 
Jul  2 14:12:36 zoneminder-6b567f46d-kqjr4 zmpkg[3464]: INF [Command: start] 
Jul  2 14:12:37 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Server starting at 20/07/02 14:12:37] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Socket should be open at /var/run/zm/zmdc.sock] 
07/02/20 14:12:38.630223 zmpkg[3464].INF [main:203] [Single server configuration detected. Starting up services.] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmpkg[3464]: INF [Single server configuration detected. Starting up services.] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmc -m 1' starting at 20/07/02 14:12:38, pid = 3505] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3505]: INF ['zmc -m 1' started at 20/07/02 14:12:38] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 1' starting at 20/07/02 14:12:38, pid = 3510] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3510]: INF ['zma -m 1' started at 20/07/02 14:12:38] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmc -m 2' starting at 20/07/02 14:12:38, pid = 3514] 
Jul  2 14:12:38 zoneminder-6b567f46d-kqjr4 zmdc[3514]: INF ['zmc -m 2' started at 20/07/02 14:12:38] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3518]: INF ['zma -m 2' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 2' starting at 20/07/02 14:12:39, pid = 3518] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmfilter.pl --filter_id=1 --daemon' starting at 20/07/02 14:12:39, pid = 3522] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3522]: INF ['zmfilter.pl --filter_id=1 --daemon' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [Not enabling ffmpeg logs, as LOG_FFMPEG and/or LOG_DEBUG is disabled in options, or this monitor is not part of your debug targets] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmfilter.pl --filter_id=2 --daemon' starting at 20/07/02 14:12:39, pid = 3526] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3526]: INF ['zmfilter.pl --filter_id=2 --daemon' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmwatch.pl' starting at 20/07/02 14:12:39, pid = 3531] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3531]: INF ['zmwatch.pl' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zma_m1[3510]: ERR [zma_m1] [Shared data not initialised by capture daemon for monitor AVCam01] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [Not enabling ffmpeg logs, as LOG_FFMPEG and/or LOG_DEBUG is disabled in options, or this monitor is not part of your debug targets] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: ERR ['zma -m 1' exited abnormally, exit status 255] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3536]: INF ['zmupdate.pl -c' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmupdate.pl -c' starting at 20/07/02 14:12:39, pid = 3536] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Starting pending process, zma -m 1] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 1' starting at 20/07/02 14:12:39, pid = 3539] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3539]: INF ['zma -m 1' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmtelemetry.pl' starting at 20/07/02 14:12:39, pid = 3542] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3542]: INF ['zmtelemetry.pl' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zma_m2[3518]: ERR [zma_m2] [Shared data not initialised by capture daemon for monitor AVCam02] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmfilter_1[3522]: INF [Scanning for events using filter id '1'] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zmstats.pl' starting at 20/07/02 14:12:39, pid = 3549] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3549]: INF ['zmstats.pl' started at 20/07/02 14:12:39] 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmdc[3476]: ERR ['zma -m 2' exited abnormally, exit status 255] 
ZoneMinder started successfully 
 
*** Running /etc/my_init.d/999_advanced_script.sh... 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmfilter_2[3526]: INF [Scanning for events using filter id '2'] 
*** Booting runit daemon... 
*** Runit started as PID 3554 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 cron[3557]: (CRON) INFO (pidfile fd = 3) 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 cron[3557]: (CRON) INFO (Running @reboot jobs) 
Jul  2 14:12:39 zoneminder-6b567f46d-kqjr4 zmwatch[3531]: INF [Watchdog starting, pausing for 30 seconds] 
Jul  2 14:12:40 zoneminder-6b567f46d-kqjr4 zmstats[3549]: INF [Stats Daemon starting in 30 seconds] 
Jul  2 14:12:40 zoneminder-6b567f46d-kqjr4 zma_m1[3539]: ERR [zma_m1] [Shared data not initialised by capture daemon for monitor AVCam01] 
Jul  2 14:12:40 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Starting pending process, zma -m 2] 
Jul  2 14:12:40 zoneminder-6b567f46d-kqjr4 zmdc[3563]: INF ['zma -m 2' started at 20/07/02 14:12:40] 
Jul  2 14:12:40 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 2' starting at 20/07/02 14:12:40, pid = 3563] 
Jul  2 14:12:40 zoneminder-6b567f46d-kqjr4 zmdc[3476]: ERR ['zma -m 1' exited abnormally, exit status 255] 
Jul  2 14:12:41 zoneminder-6b567f46d-kqjr4 zma_m2[3563]: ERR [zma_m2] [Shared data not initialised by capture daemon for monitor AVCam02] 
Jul  2 14:12:41 zoneminder-6b567f46d-kqjr4 zmdc[3476]: ERR ['zma -m 2' exited abnormally, exit status 255] 
Jul  2 14:12:45 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Starting pending process, zma -m 1] 
Jul  2 14:12:45 zoneminder-6b567f46d-kqjr4 zmdc[3564]: INF ['zma -m 1' started at 20/07/02 14:12:45] 
Jul  2 14:12:45 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 1' starting at 20/07/02 14:12:45, pid = 3564] 
Jul  2 14:12:46 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Starting pending process, zma -m 2] 
Jul  2 14:12:46 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 2' starting at 20/07/02 14:12:46, pid = 3565] 
Jul  2 14:12:46 zoneminder-6b567f46d-kqjr4 zmdc[3565]: INF ['zma -m 2' started at 20/07/02 14:12:46] 
Jul  2 14:12:49 zoneminder-6b567f46d-kqjr4 zma_m1[3564]: ERR [zma_m1] [Shared data not initialised by capture daemon for monitor AVCam01] 
Jul  2 14:12:50 zoneminder-6b567f46d-kqjr4 zmdc[3476]: ERR ['zma -m 1' exited abnormally, exit status 255] 
Jul  2 14:12:50 zoneminder-6b567f46d-kqjr4 zma_m2[3565]: ERR [zma_m2] [Shared data not initialised by capture daemon for monitor AVCam02] 
Jul  2 14:12:51 zoneminder-6b567f46d-kqjr4 zmdc[3476]: ERR ['zma -m 2' exited abnormally, exit status 255] 
Jul  2 14:12:55 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [Starting Capture version 1.34.16] 
Jul  2 14:12:55 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [Priming capture from rtsp://admin:wra44pea@192.168.2.60:554/cam/realmonitor?channel=1&subtype=0] 
Jul  2 14:12:55 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [Starting Capture version 1.34.16] 
Jul  2 14:12:55 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [Priming capture from rtsp://admin:wra44pea@192.168.2.122:554/cam/realmonitor?channel=1&subtype=0] 
Jul  2 14:12:57 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: WAR [zmc_m1] [Monitor dimensions are 1920x1080 but camera is sending 3840x2160] 
Jul  2 14:12:57 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:1 - Capturing at 0.50 fps, capturing bandwidth 166833bytes/sec] 
Jul  2 14:12:57 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: WAR [zmc_m2] [Monitor dimensions are 1920x1080 but camera is sending 3840x2160] 
Jul  2 14:12:57 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:1 - Capturing at 0.50 fps, capturing bandwidth 55457bytes/sec] 
Jul  2 14:13:00 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Starting pending process, zma -m 1] 
Jul  2 14:13:00 zoneminder-6b567f46d-kqjr4 zmdc[3567]: INF ['zma -m 1' started at 20/07/02 14:13:00] 
Jul  2 14:13:00 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 1' starting at 20/07/02 14:13:00, pid = 3567] 
Jul  2 14:13:01 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF [Starting pending process, zma -m 2] 
Jul  2 14:13:01 zoneminder-6b567f46d-kqjr4 zmdc[3568]: INF ['zma -m 2' started at 20/07/02 14:13:01] 
Jul  2 14:13:01 zoneminder-6b567f46d-kqjr4 zmdc[3476]: INF ['zma -m 2' starting at 20/07/02 14:13:01, pid = 3568] 
Jul  2 14:13:05 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:100 - Capturing at 12.50 fps, capturing bandwidth 421130bytes/sec] 
Jul  2 14:13:10 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [In mode 3/1, warming up] 
Jul  2 14:13:13 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [In mode 3/1, warming up] 
Jul  2 14:13:14 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:100 - Capturing at 5.88 fps, capturing bandwidth 202416bytes/sec] 
Jul  2 14:13:15 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 100 - Analysing at 16.67 fps] 
Jul  2 14:13:16 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:200 - Capturing at 50.00 fps, capturing bandwidth 2096306bytes/sec] 
Jul  2 14:13:16 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:200 - Capturing at 9.09 fps, capturing bandwidth 289315bytes/sec] 

System logs at zmeventnotification.pl (started at 14:19:47)

Code: Select all

Jul  2 14:19:30 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5100 - Analysing at 50.00 fps] 
Jul  2 14:19:32 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 5400 - Analysing at 14.29 fps] 
Jul  2 14:19:34 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:5500 - Capturing at 16.67 fps, capturing bandwidth 583705bytes/sec] 
Jul  2 14:19:34 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:5300 - Capturing at 20.00 fps, capturing bandwidth 743935bytes/sec] 
Jul  2 14:19:37 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5200 - Analysing at 14.29 fps] 
Jul  2 14:19:39 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 5500 - Analysing at 14.29 fps] 
Jul  2 14:19:40 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:5400 - Capturing at 16.67 fps, capturing bandwidth 538516bytes/sec] 
Jul  2 14:19:41 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:5600 - Capturing at 12.50 fps, capturing bandwidth 433683bytes/sec] 
Jul  2 14:19:44 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5300 - Analysing at 14.29 fps] 
Jul  2 14:19:47 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:5500 - Capturing at 14.29 fps, capturing bandwidth 458763bytes/sec] 
Jul  2 14:19:47 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: using config file: /etc/zm/zmeventnotification.ini] 
Jul  2 14:19:47 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: using secrets file: /etc/zm/secrets.ini] 
Jul  2 14:19:47 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: FCM disabled.] 
Jul  2 14:19:48 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: MQTT Enabled] 
Jul  2 14:19:48 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: |------- Starting ES version: 5.15-Docker ---------|] 
Jul  2 14:19:48 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: Event Notification daemon v 5.15-Docker starting] 
Jul  2 14:19:48 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: Initializing MQTT connection...] 
Jul  2 14:19:48 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: Re-loading monitors] 
Jul  2 14:19:50 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 5600 - Analysing at 9.09 fps] 
Jul  2 14:19:50 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:5700 - Capturing at 11.11 fps, capturing bandwidth 370856bytes/sec] 
Jul  2 14:20:02 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5400 - Analysing at 5.56 fps] 
Jul  2 14:20:03 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:5600 - Capturing at 6.67 fps, capturing bandwidth 241190bytes/sec] 
Jul  2 14:20:04 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 5700 - Analysing at 7.14 fps] 
Jul  2 14:20:04 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:5800 - Capturing at 7.14 fps, capturing bandwidth 241160bytes/sec] 
Jul  2 14:20:06 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 5800 - Analysing at 50.00 fps] 
Jul  2 14:20:06 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:5900 - Capturing at 50.00 fps, capturing bandwidth 1916780bytes/sec] 
Jul  2 14:20:09 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: Secure WS(WSS) is enabled...] 
Jul  2 14:20:09 zoneminder-6b567f46d-kqjr4 zmeventnotification[3606]: INF [PARENT: Web Socket Event Server listening on port 9000] 
Jul  2 14:20:09 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 5900 - Analysing at 33.33 fps] 
Jul  2 14:20:10 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5500 - Analysing at 12.50 fps] 
Jul  2 14:20:11 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:6000 - Capturing at 20.00 fps, capturing bandwidth 754927bytes/sec] 
Jul  2 14:20:11 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:5700 - Capturing at 11.11 fps, capturing bandwidth 399807bytes/sec] 
Jul  2 14:20:13 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5600 - Analysing at 33.33 fps] 
Jul  2 14:20:16 zoneminder-6b567f46d-kqjr4 zmc_m2[3514]: INF [zmc_m2] [AVCam02: images:5800 - Capturing at 20.00 fps, capturing bandwidth 653284bytes/sec] 
Jul  2 14:20:16 zoneminder-6b567f46d-kqjr4 zma_m1[3567]: INF [zma_m1] [AVCam01: 6000 - Analysing at 14.29 fps] 
Jul  2 14:20:17 zoneminder-6b567f46d-kqjr4 zmc_m1[3505]: INF [zmc_m1] [AVCam01: images:6100 - Capturing at 16.67 fps, capturing bandwidth 533422bytes/sec] 
Jul  2 14:20:19 zoneminder-6b567f46d-kqjr4 zma_m2[3568]: INF [zma_m2] [AVCam02: 5700 - Analysing at 16.67 fps] 

[llibyddap]

Short Answer.... I just need to read directions... enable OPT_USE_EVENTNOTIFICATION

TL;DR

In the docker image the default configuration is not to have the zmeventnotification server running. What I missed was that during my install and manual testing of the hooks and ML pieces, I was running zmeventnotification from the command line. Since it isn't enabled in the docker image it doesn't persist a restart, it needs to be set to run on startup. Of course, I figured out how to run a separate script to enable on each restart outside of ZM through docker.

Then I read the directions at ZoneMinder/zoneminder (not at dlandon/zoneminder which assumes you've started at ZoneMinder/zoneminder) and it is pretty clear that you have to enable OPT_USE_EVENTNOTIFICATION. This option is under the UI. It's under OPTIONS, SYSTEM and then about half way down. After putting a check in the box, restarting the container and checking - it works exactly the way it was meant to.