zoneminder service stopped itself

Forum for questions and support relating to the 1.30.x releases only.
Locked
evolotion
Posts: 46
Joined: Mon Aug 01, 2016 9:03 pm

zoneminder service stopped itself

Post by evolotion »

There is a very similar thread on the 1.29.x subforum tho there logs do not match mine, this is a relevant snippet from my log

Code: Select all

Sep 23 20:27:03 garagehost zma_m8[4666]: INF [workshop small 50: 502001 - Opening new event 33689, section start]
Sep 23 20:27:03 garagehost zma_m8[4666]: INF [In overload mode, 3 frames of 3 remaining]
Sep 23 20:27:03 garagehost zma_m8[4666]: INF [In overload mode, 2 frames of 3 remaining]
Sep 23 20:27:03 garagehost zma_m8[4666]: INF [In overload mode, 1 frames of 3 remaining]
Sep 23 20:27:04 garagehost zma_m8[4666]: INF [In overload mode, 3 frames of 3 remaining]
Sep 23 20:27:05 garagehost zma_m8[4666]: INF [In overload mode, 2 frames of 3 remaining]
Sep 23 20:27:05 garagehost zma_m8[4666]: INF [In overload mode, 1 frames of 3 remaining]
Sep 23 20:27:05 garagehost zma_m8[4666]: INF [In overload mode, 3 frames of 3 remaining]
Sep 23 20:27:06 garagehost zma_m8[4666]: INF [In overload mode, 2 frames of 3 remaining]
Sep 23 20:27:06 garagehost zma_m8[4666]: INF [In overload mode, 1 frames of 3 remaining]
Sep 23 20:27:06 garagehost zma_m8[4666]: INF [In overload mode, 3 frames of 3 remaining]
Sep 23 20:27:06 garagehost zma_m8[4666]: INF [In overload mode, 2 frames of 3 remaining]
Sep 23 20:27:07 garagehost zma_m8[4666]: INF [In overload mode, 1 frames of 3 remaining]
Sep 23 20:27:07 garagehost zma_m8[4666]: INF [workshop small 50: 502017 - Gone into prealarm state]
Sep 23 20:27:21 garagehost zmwatch[3357]: INF [Restarting capture daemon for Ally, time since last capture 12 seconds (1474658841-1474658829)]
Sep 23 20:27:22 garagehost zmdc[2820]: INF ['zmc -m 10' sending stop to pid 16126 at 16/09/23 20:27:22]
Sep 23 20:27:22 garagehost zmc_m10[16126]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:28 garagehost zmdc[2820]: WAR ['zmc -m 10' has not stopped at 16/09/23 20:27:28. Sending KILL to pid 16126]
Sep 23 20:27:28 garagehost zmdc[2820]: INF ['zmc -m 10' exited normally]
Sep 23 20:27:29 garagehost systemd[1]: zoneminder.service: Main process exited, code=exited, status=4/NOPERMISSION
Sep 23 20:27:29 garagehost zmpkg[16130]: INF [Sanity checking States table...]
Sep 23 20:27:29 garagehost zmpkg[16130]: INF [Command: stop]
Sep 23 20:27:29 garagehost sudo[16136]:     root : TTY=unknown ; PWD=/usr/share/zoneminder/www ; USER=www-data ; COMMAND=/bin/true
Sep 23 20:27:29 garagehost sudo[16136]: pam_unix(sudo:session): session opened for user www-data by (uid=0)
Sep 23 20:27:29 garagehost sudo[16136]: pam_unix(sudo:session): session closed for user www-data
Sep 23 20:27:29 garagehost sudo[16138]:     root : TTY=unknown ; PWD=/usr/share/zoneminder/www ; USER=www-data ; COMMAND=/usr/bin/zmdc.pl check
Sep 23 20:27:29 garagehost sudo[16138]: pam_unix(sudo:session): session opened for user www-data by (uid=0)
Sep 23 20:27:29 garagehost sudo[16138]: pam_unix(sudo:session): session closed for user www-data
Sep 23 20:27:30 garagehost systemd[1]: zoneminder.service: Control process exited, code=exited status=1
Sep 23 20:27:30 garagehost zmc_m8[16105]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zmc_m5[4616]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zmc_m7[4471]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zmc_m6[16102]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m5[4620]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m6[15771]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m8[4666]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m10[11836]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zmc_m9[16127]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m9[14444]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m7[4475]: INF [Got signal 15 (Terminated), exiting]
Sep 23 20:27:30 garagehost zma_m8[4666]: INF [workshop small 50: 502184 - Closing event 33689, section end]
Sep 23 20:27:30 garagehost zma_m9[14444]: INF [Ally small 52: 64300 - Closing event 33688, shutting down]
Sep 23 20:27:30 garagehost zma_m7[4475]: INF [office small 51: 514932 - Closing event 33686, shutting down]
Sep 23 20:27:31 garagehost zma_m8[4666]: WAR [Event 33690 has zero time, setting to current]
Sep 23 20:27:31 garagehost zma_m8[4666]: INF [workshop small 50: 502184 - Opening new event 33690, section start]
Sep 23 20:27:31 garagehost zma_m8[4666]: INF [workshop small 50: 502184 - Gone into prealarm state]
Sep 23 20:27:32 garagehost zma_m8[4666]: INF [workshop small 50: 502185 - Closing event 33690, shutting down]
Sep 23 20:27:32 garagehost systemd[1]: zoneminder.service: Unit entered failed state.
Sep 23 20:27:32 garagehost systemd[1]: zoneminder.service: Failed with result 'exit-code'.
as can be seen the service stops right after the block of "overload mode" these do not occur anywhere else in the logfile apart from one other occurence where the zoneminder service stopped by itself. system has plenty resource overhead, unless some other process is loading and grinding the system down at that time ?

DF output

Code: Select all

Filesystem     1M-blocks    Used Available Use% Mounted on
udev               7870M      0M     7870M   0% /dev
tmpfs              1576M     58M     1519M   4% /run
/dev/sda1         51915M  10003M    39253M  21% /
tmpfs              7880M   1550M     6331M  20% /dev/shm
tmpfs                 5M      1M        5M   1% /run/lock
tmpfs              7880M      0M     7880M   0% /sys/fs/cgroup
/dev/sdc1       2816556M 638327M  2035134M  24% /media/denis/storage1
tmpfs              1576M      1M     1576M   1% /run/user/112
tmpfs              1576M      0M     1576M   0% /run/user/1000
Free -mega output

Code: Select all

              total        used        free      shared  buff/cache   available
Mem:          16136         802         161        1687       15171       13307
Swap:          8376           0        8376
load average usually hovers around 1.8, low as 1.5 with no activity max of 3.4 ish with activty on all cameras. both events where zoneminder shut down all cameras were idle. On a 4 core processor.

Any help or pointers to troubleshoot this would be appreciated, only started 2 days ago after manually purging the logfile (coincidence?) system has been faultless for about a month now on 1.30.

EDIT: Debian testing on 4.6.0-1-amd64 kernel
evolotion
Posts: 46
Joined: Mon Aug 01, 2016 9:03 pm

Re: zoneminder service stopped itself

Post by evolotion »

I didnt not realize overload frame count meant what it meant. I have now reduced the overload frame count from 3 to 0 on camera m8 (the rest were at 0 already) shall see how that effects the logs.
evolotion
Posts: 46
Joined: Mon Aug 01, 2016 9:03 pm

Re: zoneminder service stopped itself

Post by evolotion »

happened again around midnight, nothing to do with overload warnings.

Log this time (as above pulled from journalctl)

Code: Select all

Sep 24 23:02:33 garagehost zma_m6[29064]: INF [Workshop1: 93302 - Gone into prealarm state]
Sep 24 23:02:33 garagehost zma_m8[32587]: INF [workshop small 50: 7962 - Opening new event 34380, section start]
Sep 24 23:02:36 garagehost zma_m10[29110]: INF [Ally: 81000 - Analysing at 5.81 fps]
Sep 24 23:02:38 garagehost zma_m8[32587]: INF [workshop small 50: 8000 - Analysing at 6.80 fps]
Sep 24 23:02:49 garagehost zmc_m9[32566]: FAT [Unable to decode frame at frame 6936]
Sep 24 23:02:49 garagehost zmc_m10[32569]: FAT [Unable to decode frame at frame 6845]
Sep 24 23:02:49 garagehost zmdc[29015]: ERR ['zmc -m 9' exited abnormally, exit status 255]
Sep 24 23:02:49 garagehost zmdc[29015]: ERR ['zmc -m 10' exited abnormally, exit status 255]
Sep 24 23:02:49 garagehost zmdc[29015]: INF [Starting pending process, zmc -m 10]
Sep 24 23:02:49 garagehost zmc_m8[32680]: FAT [Unable to decode frame at frame 651]
Sep 24 23:02:49 garagehost zmc_m6[32679]: FAT [Unable to decode frame at frame 553]
Sep 24 23:02:49 garagehost zmdc[29015]: ERR ['zmc -m 6' exited abnormally, exit status 255]
Sep 24 23:02:49 garagehost zmdc[29015]: ERR ['zmc -m 8' exited abnormally, exit status 255]
Sep 24 23:02:49 garagehost zmdc[29015]: FAT [Can't execute log entry 'insert into Logs ( TimeKey, Component, Pid, Level, Code, Message, File, Line ) values ( ?, ?, ?, ?
Sep 24 23:02:49 garagehost systemd[1]: zoneminder.service: Main process exited, code=exited, status=255/n/a
Sep 24 23:02:50 garagehost zmpkg[32687]: INF [Sanity checking States table...]
Sep 24 23:02:50 garagehost zmpkg[32687]: INF [Command: stop]
Sep 24 23:02:50 garagehost sudo[32693]:     root : TTY=unknown ; PWD=/usr/share/zoneminder/www ; USER=www-data ; COMMAND=/bin/true
Sep 24 23:02:50 garagehost sudo[32693]: pam_unix(sudo:session): session opened for user www-data by (uid=0)
Sep 24 23:02:50 garagehost sudo[32693]: pam_unix(sudo:session): session closed for user www-data
Sep 24 23:02:50 garagehost sudo[32695]:     root : TTY=unknown ; PWD=/usr/share/zoneminder/www ; USER=www-data ; COMMAND=/usr/bin/zmdc.pl check
Sep 24 23:02:50 garagehost sudo[32695]: pam_unix(sudo:session): session opened for user www-data by (uid=0)
Sep 24 23:02:50 garagehost sudo[32695]: pam_unix(sudo:session): session closed for user www-data
Sep 24 23:02:50 garagehost systemd[1]: zoneminder.service: Control process exited, code=exited status=1
Sep 24 23:02:50 garagehost zma_m8[32587]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zma_m10[29110]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zmc_m5[29045]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zmc_m7[30656]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zma_m9[30605]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zma_m5[29050]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zma_m6[29064]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zma_m7[30660]: INF [Got signal 15 (Terminated), exiting]
Sep 24 23:02:51 garagehost zma_m8[32587]: INF [workshop small 50: 8086 - Closing event 34380, shutting down]
Sep 24 23:02:51 garagehost zma_m9[30605]: INF [Ally small 52: 79624 - Closing event 34377, shutting down]
Sep 24 23:02:51 garagehost zma_m7[30660]: INF [office small 51: 91545 - Closing event 34378, shutting down]
Sep 24 23:02:51 garagehost systemd[1]: zoneminder.service: Unit entered failed state.
Sep 24 23:02:51 garagehost systemd[1]: zoneminder.service: Failed with result 'exit-code'.
Im not exactly a linux expert, if I could just find out if systemd is shutting zoneminder down, or zoneminder is shutting itself down and find a relavent log or enable a debugging log to track it down., last resort will be a reinstall but would prefer to sort it for the learning experience and has taken quite a while to get everything just how I want it.
cheers
evolotion
Posts: 46
Joined: Mon Aug 01, 2016 9:03 pm

Re: zoneminder service stopped itself

Post by evolotion »

Code: Select all

sudo service zoneminder status
● zoneminder.service - ZoneMinder CCTV recording and surveillance system
   Loaded: loaded (/lib/systemd/system/zoneminder.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2016-09-25 09:53:06 BST; 52min ago
  Process: 32687 ExecStop=/usr/bin/zmpkg.pl stop (code=exited, status=1/FAILURE)
  Process: 4431 ExecStart=/usr/bin/zmpkg.pl start (code=exited, status=0/SUCCESS)
 Main PID: 4445 (zmdc.pl)
    Tasks: 17 (limit: 4915)
   CGroup: /system.slice/zoneminder.service
           ├─4445 /usr/bin/perl -wT /usr/bin/zmdc.pl startup
           ├─4475 /usr/bin/zmc -m 5
           ├─4483 /usr/bin/zma -m 5
           ├─4498 /usr/bin/zma -m 6
           ├─4504 /usr/bin/zmc -m 7
           ├─4505 /usr/bin/zma -m 7
           ├─4518 /usr/bin/zma -m 8
           ├─4531 /usr/bin/zma -m 9
           ├─4551 /usr/bin/zma -m 10
           ├─4552 /usr/bin/perl -wT /usr/bin/zmfilter.pl
           ├─4557 /usr/bin/perl -wT /usr/bin/zmaudit.pl -c
           ├─4565 /usr/bin/perl -wT /usr/bin/zmwatch.pl
           ├─4571 /usr/bin/perl -w /usr/bin/zmtelemetry.pl
           ├─5310 /usr/bin/zmc -m 9
           ├─5313 /usr/bin/zmc -m 10
           ├─5366 /usr/bin/zmc -m 8
           └─5367 /usr/bin/zmc -m 6
have obviously restarted teh service but may help, think I need to investigate zmpkg.pl
tiripon
Posts: 34
Joined: Fri Aug 12, 2016 4:06 pm

Re: zoneminder service stopped itself

Post by tiripon »

Mine is also doing that. It shuts down after several hours by itself. The web page is still accessible and I start it from there.
I can't find an "overload frame count" I have an "Alarm Frame Count" which is set to 1. I don't think this is the same.

How do I export the log? And which log?
j-voyles
Posts: 1
Joined: Wed Oct 04, 2017 6:18 pm

Re: zoneminder service stopped itself

Post by j-voyles »

I am also having this problem on v1.30.4. I only have 2 cameras. System resources are also mostly idol. Disk IOPS are within reasonable limits for the data stream I am capturing. (I am on a RAID 5 on a HP ML110 Gen9 server). I did lower frame-rate on the cameras to see if it would stabilize and it appears to have done nothing.
bbunge
Posts: 2934
Joined: Mon Mar 26, 2012 11:40 am
Location: Pennsylvania

Re: zoneminder service stopped itself

Post by bbunge »

There have been several reports of Zoneminder having issues on Debian 9 and Debian Testing is likely no better. Submit your problem on a Debian bug site so the package maintainer has a record.

If you want t working system that does not beat you to death use Ubuntu 16.04 or CentOS. Both have install instructions (Ubuntu on the ZM WIKI) that work.
flowwolf
Posts: 1
Joined: Thu Mar 15, 2018 7:41 pm

Re: zoneminder service stopped itself

Post by flowwolf »

Similar issue on Debian 4.9.0-5-rt-amd64 #1 SMP PREEMPT RT Debian 4.9.65-3+deb9u2 (2018-01-04)
zm v1.30.4.

Code: Select all

Mar 13 07:26:40 x3k30c-Azalia zma_m3[23065]: INF [In mode 3/1, warming up]
Mar 13 07:29:00 x3k30c-Azalia zmwatch[1473]: INF [Restarting capture daemon for Monitor-3, time since last capture 9 seconds (1520922540-1520922531)]
Mar 13 07:29:00 x3k30c-Azalia zmdc[1361]: INF ['zmc -d /dev/video0' sending stop to pid 22925 at 18/03/13 07:29:00]
Mar 13 07:29:00 x3k30c-Azalia zmc_dvideo0[22925]: INF [Got signal 15 (Terminated), exiting]
Mar 13 07:29:06 x3k30c-Azalia zmdc[1361]: WAR ['zmc -d /dev/video0' has not stopped at 18/03/13 07:29:06. Sending KILL to pid 22925]
Mar 13 07:29:06 x3k30c-Azalia zmdc[1361]: INF ['zmc -d /dev/video0' exited normally]
Mar 13 07:29:07 x3k30c-Azalia systemd[1]: zoneminder.service: Main process exited, code=exited, status=4/NOPERMISSION
Mar 13 07:29:07 x3k30c-Azalia zmpkg[24043]: INF [Sanity checking States table...]
Mar 13 07:29:07 x3k30c-Azalia zmpkg[24043]: INF [Command: stop]
Mar 13 07:29:07 x3k30c-Azalia systemd[1]: zoneminder.service: Control process exited, code=exited status=1
Mar 13 07:29:07 x3k30c-Azalia zma_m3[23065]: INF [Got signal 15 (Terminated), exiting]
Mar 13 07:29:08 x3k30c-Azalia systemd[1]: zoneminder.service: Unit entered failed state.
Mar 13 07:29:08 x3k30c-Azalia systemd[1]: zoneminder.service: Failed with result 'exit-code'.
I have never experienced anything like this before, zm had been running correctly for months. Maybe it's related to the -5-rt-amd64 kernel update.

I wouldn't exclude the possibility of a virus, hackers timed those viruses on my pc to exact times e.g. 9:00 and 9:30 etc. (or a minute earlier), but they have only attacked my usb system so far.

I'll try to post it to the Debian development forums somewhere.
gert
Posts: 14
Joined: Fri Jul 01, 2016 12:43 am

Re: zoneminder service stopped itself

Post by gert »

I'm seeing this behavior on Ubuntu 16.04; zoneminder 1.30.4-xenial1. The tail-end of the output of `sudo journalctl -u zoneminder`:

Code: Select all

Sep 09 22:07:58 skynet-alpha systemd[1]: zoneminder.service: Control process exited, code=exited status=1
Sep 09 22:07:58 skynet-alpha zma_m22[19070]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m25[17935]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m22[17970]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zma_m4[16575]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m57[16276]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zma_m56[16436]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m2[18976]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zma_m3[16506]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m58[16607]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m26[18266]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m4[18956]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zma_m56[16436]: INF [HIK1: 2476 - Closing event 104482, shutting down]
Sep 09 22:07:58 skynet-alpha zmc_m27[18979]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m30[19231]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m1[16266]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m24[16268]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m21[17826]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m29[17681]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zma_m2[19122]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m23[18263]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m3[18260]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:58 skynet-alpha zmc_m28[18521]: INF [Got signal 15 (Terminated), exiting]
Sep 09 22:07:59 skynet-alpha zma_m2[19122]: INF [hik23: 058 - Gone into alert state]
Sep 09 22:07:59 skynet-alpha zma_m2[19122]: INF [hik23: 059 - Closing event 104498, shutting down]
Sep 09 22:08:09 skynet-alpha systemd[1]: zoneminder.service: Unit entered failed state.
Sep 09 22:08:09 skynet-alpha systemd[1]: zoneminder.service: Failed with result 'exit-code'.
And systemctl status zoneminder.service

Code: Select all

:~$ systemctl status zoneminder.service 
● zoneminder.service - ZoneMinder CCTV recording and surveillance system
   Loaded: loaded (/etc/systemd/system/zoneminder.service; disabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Sun 2018-09-09 22:08:09 PDT; 10h ago
  Process: 19376 ExecStop=/usr/bin/zmpkg.pl stop (code=exited, status=1/FAILURE)
  Process: 12434 ExecStart=/usr/bin/zmpkg.pl start (code=exited, status=0/SUCCESS)
 Main PID: 12449 (code=exited, status=4)
I fear I may just go back to 14.04. Though I'd probably be satisfied with a "respawn" option. I guess I know enough systemd unit syntax I should go look into doing that.
gert
Posts: 14
Joined: Fri Jul 01, 2016 12:43 am

Re: zoneminder service stopped itself

Post by gert »

So looking at the systemd unit file, it is set to Restart=on-abnormal. Looking at the reference documentation for systemd, I decided to change it to =on-failure. Docs: https://manpages.debian.org/jessie/syst ... .5.en.html

I did the following:

Code: Select all

cd /etc/systemd/system/
sudo vim zoneminder.service 
# Change on-abnormal to on-failure
sudo systemd-analyze verify zoneminder.service # Check for a subset of syntax errors
sudo systemctl daemon-reload
sudo systemctl show zoneminder.service  | grep Restart  # To verify it took effect
sudo sytemctl start zoneminder.service 
Optional: I also added a oneline bash script and invoke it under the [System] block in the ExecStartPre=, in order to know how often zoneminder is restarting... (the separate script is useful since systemd is *very* limited in what you can put in the Exec lines; >> doesn't work for example)

Code: Select all

# In the .service file:
ExecStartPre=/bin/bash /home/gert/zoneminder_prestart.bash

# In /home/gert/zoneminder_prestart.bash
/bin/date >> /home/gert/zoneminder_restart_history
I'll leave trying a fresh install for another day/month... Guess I ought to also look for increased verbosity or debug output for more troubleshooting info (the previously shared logs obviously don't help much...)
Locked