ZoneMinder Forums

ZoneMinder Forums
https://forums.zoneminder.com/

Zoneminder stops and won't restart

https://forums.zoneminder.com/viewtopic.php?t=27441

Page 1 of 1

Zoneminder stops and won't restart

Posted: Fri Aug 10, 2018 3:41 am
by desertcroc
Hi all,

I've been having with ZM 1.30.4 stopping after a couple of days, and then refusing to start again. I've turned on all the debugging logs, and the best I can gather is that the zmc processes don't want to restart, or maybe it's an issue with MySQL. I see a lot of MySQL errors, but it's not clear to me if they are due to zmc crashing while trying to start, or MySQL issues internally. Restarting the machine sometimes works to get it running again, but sometimes not.

I'm running within an Ubuntu 16.04 VM in VMWare Fusion on Mac with 4 cores and 4GB of RAM (out of 8GB total) dedicated to the VM. I was going to move to bare metal (4 cores, 4 GB RAM) that just arrived today, but want to solve the current stability issues first. In terms of cameras, I have 4 Foscams on FFMPEG, each with a low-res monitor running Modect (2 zones - normal and exclusive) and linked to a high-res monitor running Nodect.

As far as I can tell from looking at top output, the machine doesn't seem to be running out of RAM, and for the most part runs at under .5 load. Sometimes I see it spike as it seems to be doing some sort of Ubuntu upgrades, but it's generally very low.

Any help would be much appreciated, as I would love to have this be a more stable platform. Everything about it is fantastic other than these stability issues.

MySQL error.log:

Code: Select all

2018-08-09T05:33:12.498625Z 1019 [Note] Aborted connection 1019 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:20.988497Z 1023 [Note] Aborted connection 1023 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:20.992000Z 1022 [Note] Aborted connection 1022 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.002385Z 1028 [Note] Aborted connection 1028 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.002394Z 1029 [Note] Aborted connection 1029 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.004409Z 966 [Note] Aborted connection 966 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.004531Z 965 [Note] Aborted connection 965 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.029613Z 986 [Note] Aborted connection 986 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.029767Z 987 [Note] Aborted connection 987 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.040964Z 963 [Note] Aborted connection 963 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.042234Z 997 [Note] Aborted connection 997 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
2018-08-09T05:33:38.045216Z 998 [Note] Aborted connection 998 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)

syslog

Code: Select all

Aug  8 22:32:00 zoneminder zmpkg[88918]: INF [Sanity checking States table...]
Aug  8 22:32:00 zoneminder zmpkg[88918]: INF [Command: start]
Aug  8 22:32:04 zoneminder systemd[1]: Created slice User Slice of root.
Aug  8 22:32:05 zoneminder systemd[1]: Starting User Manager for UID 0...
Aug  8 22:32:05 zoneminder systemd[1]: Started Session c1 of user root.
Aug  8 22:32:07 zoneminder systemd[88927]: Reached target Sockets.
Aug  8 22:32:07 zoneminder systemd[88927]: Reached target Timers.
Aug  8 22:32:07 zoneminder systemd[88927]: Reached target Paths.
Aug  8 22:32:07 zoneminder systemd[88927]: Reached target Basic System.
Aug  8 22:32:07 zoneminder systemd[88927]: Reached target Default.
Aug  8 22:32:07 zoneminder systemd[88927]: Startup finished in 832ms.
Aug  8 22:32:07 zoneminder systemd[1]: Started User Manager for UID 0.
Aug  8 22:32:07 zoneminder zmsystemctl[88924]: INF [Redirecting command through systemctl]
Aug  8 22:32:07 zoneminder systemd[1]: Starting ZoneMinder CCTV recording and surveillance system...
Aug  8 22:32:08 zoneminder zmpkg[88940]: INF [Sanity checking States table...]
Aug  8 22:32:08 zoneminder zmpkg[88940]: INF [Command: start]
Aug  8 22:32:12 zoneminder zmdc[88955]: INF [Server starting at 18/08/08 22:32:12]
Aug  8 22:32:14 zoneminder web_php[67895]: FAT [SQL-ERR 'SQLSTATE[HY000]: General error: 2006 MySQL server has gone away', statement was 'delete from Filters where Name like '_TempFilter%'']
Aug  8 22:32:14 zoneminder web_php[67895]: FAT [Can't write log entry 'INSERT INTO Logs ( TimeKey, Component, Pid, Level, Code, Message, File, Line ) values ( ?, ?, ?, ?, ?, ?, ?, ? )': SQLSTATE[HY000]: General error: 2006 MySQL server has gone away]
Aug  8 22:32:17 zoneminder zmpkg[88940]: INF [Single server configuration detected. Starting up services.]
Aug  8 22:32:28 zoneminder zmdc[88986]: INF ['zmc -m 2' started at 18/08/08 22:32:28]
Aug  8 22:32:28 zoneminder zmdc[88955]: INF ['zmc -m 2' starting at 18/08/08 22:32:28, pid = 88986]
Aug  8 22:32:31 zoneminder zmdc[88955]: INF ['zma -m 2' starting at 18/08/08 22:32:30, pid = 88990]
Aug  8 22:32:31 zoneminder zmdc[88990]: INF ['zma -m 2' started at 18/08/08 22:32:30]
Aug  8 22:32:32 zoneminder zmdc[88955]: ERR ['zmc -m 2' exited abnormally, exit status 255]
Aug  8 22:32:33 zoneminder zmdc[88955]: INF [Starting pending process, zmc -m 2]
Aug  8 22:32:33 zoneminder zmdc[88997]: INF ['zmc -m 2' started at 18/08/08 22:32:33]
Aug  8 22:32:33 zoneminder zmdc[88955]: INF ['zmc -m 2' starting at 18/08/08 22:32:33, pid = 88997]
Aug  8 22:32:33 zoneminder zma_m2[88990]: ERR [Shared data not initialised by capture daemon for monitor Driveway]
Aug  8 22:32:33 zoneminder zmdc[88955]: ERR ['zma -m 2' exited abnormally, exit status 255]
Aug  8 22:32:33 zoneminder zmdc[88955]: INF ['zmc -m 3' starting at 18/08/08 22:32:33, pid = 88998]
Aug  8 22:32:33 zoneminder zmdc[88998]: INF ['zmc -m 3' started at 18/08/08 22:32:33]
Aug  8 22:32:33 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 2]
Aug  8 22:32:33 zoneminder zmdc[89002]: INF ['zma -m 2' started at 18/08/08 22:32:33]
Aug  8 22:32:33 zoneminder zmdc[88955]: INF ['zma -m 2' starting at 18/08/08 22:32:33, pid = 89002]
Aug  8 22:32:33 zoneminder zmdc[88955]: ERR ['zmc -m 3' exited abnormally, exit status 255]
Aug  8 22:32:34 zoneminder zmdc[88955]: INF [Starting pending process, zmc -m 3]
Aug  8 22:32:37 zoneminder zmdc[89004]: INF ['zmc -m 3' started at 18/08/08 22:32:37]
Aug  8 22:32:37 zoneminder zmdc[88955]: INF ['zmc -m 3' starting at 18/08/08 22:32:37, pid = 89004]
Aug  8 22:32:38 zoneminder zma_m2[89002]: ERR [Shared data not initialised by capture daemon for monitor Driveway]
Aug  8 22:32:38 zoneminder zmdc[88955]: ERR ['zma -m 2' exited abnormally, exit status 255]
Aug  8 22:32:43 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 2]
Aug  8 22:32:44 zoneminder zmdc[88955]: INF ['zma -m 2' starting at 18/08/08 22:32:44, pid = 89008]
Aug  8 22:32:44 zoneminder zmdc[89008]: INF ['zma -m 2' started at 18/08/08 22:32:44]
Aug  8 22:32:46 zoneminder zmdc[88955]: INF ['zma -m 3' starting at 18/08/08 22:32:46, pid = 89009]
Aug  8 22:32:46 zoneminder zmdc[89009]: INF ['zma -m 3' started at 18/08/08 22:32:46]
Aug  8 22:32:47 zoneminder zma_m2[89008]: ERR [Shared data not initialised by capture daemon for monitor Driveway]
Aug  8 22:32:47 zoneminder zmdc[88955]: ERR ['zma -m 2' exited abnormally, exit status 255]
Aug  8 22:32:49 zoneminder zma_m3[89009]: ERR [Shared data not initialised by capture daemon for monitor Front Door]
Aug  8 22:32:49 zoneminder zmdc[88955]: ERR ['zma -m 3' exited abnormally, exit status 255]
Aug  8 22:32:49 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 3]
Aug  8 22:32:50 zoneminder zmdc[89016]: INF ['zma -m 3' started at 18/08/08 22:32:50]
Aug  8 22:32:50 zoneminder zmdc[88955]: INF ['zma -m 3' starting at 18/08/08 22:32:50, pid = 89016]
Aug  8 22:32:57 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 2]
Aug  8 22:32:58 zoneminder zma_m3[89016]: ERR [Shared data not initialised by capture daemon for monitor Front Door]
Aug  8 22:32:58 zoneminder zmdc[89019]: INF ['zma -m 2' started at 18/08/08 22:32:58]
Aug  8 22:32:58 zoneminder zmdc[88955]: INF ['zma -m 2' starting at 18/08/08 22:32:58, pid = 89019]
Aug  8 22:32:58 zoneminder zmdc[88955]: ERR ['zma -m 3' exited abnormally, exit status 255]
Aug  8 22:33:03 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 3]
Aug  8 22:33:05 zoneminder zmdc[89020]: INF ['zma -m 3' started at 18/08/08 22:33:05]
Aug  8 22:33:06 zoneminder zmdc[88955]: INF ['zma -m 3' starting at 18/08/08 22:33:05, pid = 89020]
Aug  8 22:33:06 zoneminder zma_m2[89019]: ERR [Shared data not initialised by capture daemon for monitor Driveway]
Aug  8 22:33:06 zoneminder zmdc[88955]: ERR ['zma -m 2' exited abnormally, exit status 255]
Aug  8 22:33:12 zoneminder zma_m3[89020]: ERR [Shared data not initialised by capture daemon for monitor Front Door]
Aug  8 22:33:12 zoneminder zmdc[88955]: ERR ['zma -m 3' exited abnormally, exit status 255]
Aug  8 22:33:18 zoneminder zmdc[88955]: INF ['zmc -m 4' starting at 18/08/08 22:33:18, pid = 89026]
Aug  8 22:33:18 zoneminder zmdc[89026]: INF ['zmc -m 4' started at 18/08/08 22:33:18]
Aug  8 22:33:20 zoneminder zmdc[88955]: ERR ['zmc -m 4' exited abnormally, exit status 255]
Aug  8 22:33:21 zoneminder zmdc[88955]: INF [Starting pending process, zmc -m 4]
Aug  8 22:33:23 zoneminder zmdc[89029]: INF ['zmc -m 4' started at 18/08/08 22:33:23]
Aug  8 22:33:23 zoneminder zmdc[88955]: INF ['zmc -m 4' starting at 18/08/08 22:33:23, pid = 89029]
Aug  8 22:33:24 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 3]
Aug  8 22:33:27 zoneminder zmdc[89032]: INF ['zma -m 3' started at 18/08/08 22:33:27]
Aug  8 22:33:27 zoneminder zmdc[88955]: INF ['zma -m 3' starting at 18/08/08 22:33:27, pid = 89032]
Aug  8 22:33:28 zoneminder zmdc[88955]: INF [Starting pending process, zma -m 2]
Aug  8 22:33:34 zoneminder zmdc[89033]: INF ['zma -m 2' started at 18/08/08 22:33:33]
Aug  8 22:33:34 zoneminder zmdc[88955]: INF ['zma -m 2' starting at 18/08/08 22:33:33, pid = 89033]
Aug  8 22:33:38 zoneminder systemd[1]: zoneminder.service: Start operation timed out. Terminating.
Aug  8 22:33:38 zoneminder zmdc[88955]: INF ['zmc -m 2' sending stop to pid 88997 at 18/08/08 22:33:37]
Aug  8 22:33:38 zoneminder systemd[1]: Failed to start ZoneMinder CCTV recording and surveillance system.
Aug  8 22:33:38 zoneminder systemd[1]: zoneminder.service: Unit entered failed state.
Aug  8 22:33:38 zoneminder systemd[1]: zoneminder.service: Failed with result 'timeout'.
Aug  8 22:33:38 zoneminder zmdc[88955]: INF ['zmc -m 2' exited, signal 14]
Aug  8 22:33:38 zoneminder zmdc[88955]: INF ['zmc -m 3' exited, signal 14]
Aug  8 22:33:38 zoneminder zmdc[88955]: INF ['zmc -m 4' exited, signal 14]
Aug  8 22:33:38 zoneminder zmdc[88955]: INF ['zma -m 3' exited, signal 14]
Aug  8 22:33:38 zoneminder zmdc[88955]: INF ['zma -m 2' exited, signal 14]
Aug  8 22:33:38 zoneminder systemd[1]: zoneminder.service: Service hold-off time over, scheduling restart.
Aug  8 22:33:38 zoneminder systemd[1]: Stopped ZoneMinder CCTV recording and surveillance system.
Aug  8 22:33:38 zoneminder systemd[1]: Starting ZoneMinder CCTV recording and surveillance system...
Aug  8 22:33:38 zoneminder systemd[1]: Stopping User Manager for UID 0...
Aug  8 22:33:38 zoneminder systemd[88927]: Reached target Shutdown.
Aug  8 22:33:38 zoneminder systemd[88927]: Starting Exit the Session...
Aug  8 22:33:38 zoneminder systemd[88927]: Stopped target Default.
Aug  8 22:33:38 zoneminder systemd[88927]: Stopped target Basic System.
Aug  8 22:33:38 zoneminder systemd[88927]: Stopped target Timers.
Aug  8 22:33:38 zoneminder systemd[88927]: Stopped target Sockets.
Aug  8 22:33:38 zoneminder systemd[88927]: Stopped target Paths.
Aug  8 22:33:38 zoneminder zmpkg[89039]: INF [Sanity checking States table...]
Aug  8 22:33:38 zoneminder systemd[88927]: Received SIGRTMIN+24 from PID 89040 (kill).
Aug  8 22:33:38 zoneminder zmpkg[89039]: INF [Command: start]
Aug  8 22:33:38 zoneminder systemd[1]: Stopped User Manager for UID 0.
Aug  8 22:33:39 zoneminder systemd[1]: Removed slice User Slice of root.
Aug  8 22:33:43 zoneminder systemd[1]: zoneminder.service: Control process exited, code=exited status=1
Aug  8 22:33:48 zoneminder zmdc[88955]: INF [Server shutdown at 18/08/08 22:33:48]
Aug  8 22:33:58 zoneminder zmdc[88955]: INF [Server shutdown at 18/08/08 22:33:58]
Aug  8 22:33:58 zoneminder systemd[1]: Failed to start ZoneMinder CCTV recording and surveillance system.
Aug  8 22:33:58 zoneminder systemd[1]: zoneminder.service: Unit entered failed state.
Aug  8 22:33:58 zoneminder systemd[1]: zoneminder.service: Failed with result 'exit-code'.
top output:

Code: Select all

top - 22:36:06 up 2 days, 41 min,  2 users,  load average: 0.53, 0.93, 0.44
Tasks: 208 total,   1 running, 207 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.1 us,  0.2 sy,  0.0 ni, 99.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  3825340 total,  2077180 free,   466516 used,  1281644 buff/cache
KiB Swap:  1003516 total,  1001168 free,     2348 used.  2880848 avail Mem

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
   786 root      20   0  116248   7232   6044 S   0.3  0.2   3:05.60 vmtoolsd
  1266 blueche+  20   0  143072   7008   5168 S   0.3  0.2   9:33.70 bc-server
 70720 mysql     20   0 2622092 335584  17564 S   0.3  8.8   3:32.97 mysqld
 89322 user  20   0   41936   3960   3236 R   0.3  0.1   0:00.08 top
     1 root      20   0   38108   5636   3524 S   0.0  0.1   0:27.21 systemd
     2 root      20   0       0      0      0 S   0.0  0.0   0:00.20 kthreadd
     3 root      20   0       0      0      0 S   0.0  0.0   0:02.81 ksoftirqd/0
     5 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/0:0H
     7 root      20   0       0      0      0 S   0.0  0.0   0:21.84 rcu_sched
     8 root      20   0       0      0      0 S   0.0  0.0   0:00.00 rcu_bh
     9 root      rt   0       0      0      0 S   0.0  0.0   0:00.75 migration/0
    10 root      rt   0       0      0      0 S   0.0  0.0   0:00.78 watchdog/0
    11 root      rt   0       0      0      0 S   0.0  0.0   0:00.70 watchdog/1
    12 root      rt   0       0      0      0 S   0.0  0.0   0:00.52 migration/1
    13 root      20   0       0      0      0 S   0.0  0.0   0:01.14 ksoftirqd/1
    15 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/1:0H
    16 root      rt   0       0      0      0 S   0.0  0.0   0:00.70 watchdog/2
    17 root      rt   0       0      0      0 S   0.0  0.0   0:00.53 migration/2

zma_m3.log

Code: Select all

08/08/18 22:33:12.224710 zma_m3[89020].ERR-zm_monitor.cpp/442 [Shared data not initialised by capture daemon for monitor Front Door]
zmc logs contain nothing around this timestamp. the other zma log files show similar outputs to this one.

Re: Zoneminder stops and won't restart

Posted: Fri Aug 10, 2018 2:58 pm
by iconnor
Unfortunately the zmc logs are the ones that will have the answer. It may be crashing before logging anything. Crank up the debug level. Check mysql ogs.

Re: Zoneminder stops and won't restart

Posted: Sat Aug 11, 2018 3:29 am
by desertcroc
I cranked up debug level on both MySQL and ZM, but all I can figure is that it seems like ZM is having trouble keeping its connection to MySQL? I'm running a stock install of Ubuntu 16.04 with MySQL 5.7.

zmc_m3.log

Code: Select all

08/10/18 08:18:13.618305 zmc_m3[116941].INF-zmc.cpp/247 [Starting Capture version 1.30.4]
08/10/18 08:18:13.747670 zmc_m3[116941].INF-zm_ffmpeg_camera.cpp/104 [Priming capture from rtsp://jasonyau:EHNq6ycoF@foscam-frontdoor:88/videoMain]
08/10/18 08:18:32.322869 zmc_m3[117000].INF-zm_signal.cpp/40 [Got signal 15 (Terminated), exiting]
08/10/18 08:18:32.323089 zmc_m3[116941].INF-zm_signal.cpp/40 [Got signal 15 (Terminated), exiting]
08/10/18 08:18:32.371938 zmc_m3[116941].ERR-zm_logger.cpp/623 [Can't insert log entry: sql(insert into Logs ( TimeKey, Component, ServerId, Pid, Level, Code, Message, File, Line ) values ( 1533914312.323089, 'zmc_m3', 0, 116941, 0, 'INF', 'Got signal 15 (Terminated), exiting', 'zm_signal.cpp', 40 )) error(Lost connection to MySQL server during query)]
zma_m3.log

Code: Select all

08/10/18 17:20:28.458701 zma_m3[127191].INF-zma.cpp/142 [In mode 6/1, warming up]
08/10/18 17:21:36.311618 zma_m3[127191].INF-zm_signal.cpp/40 [Got signal 15 (Terminated), exiting]
zm_debug.log.127139

Code: Select all

08/10/18 17:20:10.003336 zmc_m2[127139].DB1-zm_logger.cpp/234 [LogOpts: level=DB9/DB9, screen=OFF, database=INF, logfile=DB9->/var/log/zm/zm_debug.log.127139, syslog=INF]
08/10/18 17:20:10.003392 zmc_m2[127139].DB1-zm_utils.cpp/266 [Detected a x86\x86-64 processor with SSSE3]
08/10/18 17:20:10.003938 zmc_m2[127139].DB4-zm_db.cpp/101 [Success running query: select Id, Name, ServerId, Type, Function+0, Enabled, LinkedMonitors, Device, Channel, Format, V4LMultiBuffer, V4LCapturesPerFrame, Protocol, Method, Host, Port, Path, Options, User, Pass, Width, Height, Colours, Palette, Orientation+0, Deinterlacing, RTSPDescribe, Brightness, Contrast, Hue, Colour, EventPrefix, LabelFormat, LabelX, LabelY, LabelSize, ImageBufferCount, WarmupCount, PreEventCount, PostEventCount, StreamReplayBuffer, AlarmFrameCount, SectionLength, FrameSkip, MotionFrameSkip, AnalysisFPS, AnalysisUpdateDelay, MaxFPS, AlarmMaxFPS, FPSReportInterval, RefBlendPerc, AlarmRefBlendPerc, TrackMotion, SignalCheckColour, Exif from Monitors where Id = 2]
08/10/18 17:20:10.003971 zmc_m2[127139].DB1-zm_monitor.cpp/2735 [Got 1 for v4l_captures_per_frame]
08/10/18 17:20:10.003997 zmc_m2[127139].DB2-zm_camera.cpp/39 [New camera id: 2 width: 1920 height: 1080 colours: 4 subpixelorder: 8 capture: 1]
08/10/18 17:20:10.004460 zmc_m2[127139].DB4-zm_image.cpp/198 [Blend: Using SSE2 fast blend function]
08/10/18 17:20:10.004475 zmc_m2[127139].DB4-zm_image.cpp/234 [Delta: Using SSSE3 delta functions]
08/10/18 17:20:10.004483 zmc_m2[127139].DB4-zm_image.cpp/278 [Deinterlace: Using SSSE3 delta functions]
08/10/18 17:20:10.004491 zmc_m2[127139].DB4-zm_image.cpp/291 [Image buffer copy: Using SSE2 aligned memcpy]
08/10/18 17:20:10.004498 zmc_m2[127139].DB3-zm_image.cpp/298 [Setting up static colour tables]
08/10/18 17:20:10.004526 zmc_m2[127139].DB1-zm_monitor.cpp/390 [monitor purpose=1]
08/10/18 17:20:10.004535 zmc_m2[127139].DB1-zm_monitor.cpp/398 [mem.size=414721760]
zm_debug.log.127143

Code: Select all

08/10/18 17:20:10.068814 zmc_m2[127143].DB1-zm_logger.cpp/234 [LogOpts: level=DB9/DB9, screen=OFF, database=INF, logfile=DB9->
/var/log/zm/zm_debug.log.127143, syslog=INF]
08/10/18 17:20:10.068868 zmc_m2[127143].DB1-zm_utils.cpp/266 [Detected a x86\x86-64 processor with SSSE3]
08/10/18 17:20:10.069423 zmc_m2[127143].DB4-zm_db.cpp/101 [Success running query: select Id, Name, ServerId, Type, Function+0,
 Enabled, LinkedMonitors, Device, Channel, Format, V4LMultiBuffer, V4LCapturesPerFrame, Protocol, Method, Host, Port, Path, Op
tions, User, Pass, Width, Height, Colours, Palette, Orientation+0, Deinterlacing, RTSPDescribe, Brightness, Contrast, Hue, Col
our, EventPrefix, LabelFormat, LabelX, LabelY, LabelSize, ImageBufferCount, WarmupCount, PreEventCount, PostEventCount, Stream
ReplayBuffer, AlarmFrameCount, SectionLength, FrameSkip, MotionFrameSkip, AnalysisFPS, AnalysisUpdateDelay, MaxFPS, AlarmMaxFP
S, FPSReportInterval, RefBlendPerc, AlarmRefBlendPerc, TrackMotion, SignalCheckColour, Exif from Monitors where Id = 2]
08/10/18 17:20:10.069490 zmc_m2[127143].DB1-zm_monitor.cpp/2735 [Got 1 for v4l_captures_per_frame]
08/10/18 17:20:10.069520 zmc_m2[127143].DB2-zm_camera.cpp/39 [New camera id: 2 width: 1920 height: 1080 colours: 4 subpixelord
er: 8 capture: 1]
08/10/18 17:20:10.069787 zmc_m2[127143].DB4-zm_image.cpp/198 [Blend: Using SSE2 fast blend function]
08/10/18 17:20:10.069805 zmc_m2[127143].DB4-zm_image.cpp/234 [Delta: Using SSSE3 delta functions]
08/10/18 17:20:10.069813 zmc_m2[127143].DB4-zm_image.cpp/278 [Deinterlace: Using SSSE3 delta functions]
08/10/18 17:20:10.069821 zmc_m2[127143].DB4-zm_image.cpp/291 [Image buffer copy: Using SSE2 aligned memcpy]
08/10/18 17:20:10.069829 zmc_m2[127143].DB3-zm_image.cpp/298 [Setting up static colour tables]
08/10/18 17:20:10.069863 zmc_m2[127143].DB1-zm_monitor.cpp/390 [monitor purpose=1]
08/10/18 17:20:10.069873 zmc_m2[127143].DB1-zm_monitor.cpp/398 [mem.size=414721760]
08/10/18 17:20:10.069896 zmc_m2[127143].DB1-zm_monitor.cpp/543 [Unable to map file /dev/shm/zm.mmap.2 (414721760 bytes) to loc
ked memory, trying unlocked]
08/10/18 17:20:10.069911 zmc_m2[127143].DB1-zm_monitor.cpp/546 [Mapped file /dev/shm/zm.mmap.2 (414721760 bytes) to locked mem
ory, unlocked]
08/10/18 17:20:14.758951 zmc_m2[127143].DB1-zm_monitor.cpp/449 [Monitor Driveway has no zones, adding one.]
08/10/18 17:20:14.759011 zmc_m2[127143].DB1-zm_zone.cpp/51 [Initialised zone 0/All - 1 - 1920x1080 - Rgb:0000ff, CM:3, MnAT:15
, MxAT:0, MnAP:50, MxAP:75000, FB:3x3, MnFP:50, MxFP:50000, MnBS:10, MxBS:0, MnB:0, MxB:0, OF: 0, AF: 0]
08/10/18 17:20:14.763680 zmc_m2[127143].DB9-zm_image.cpp/2386 [0: min_y: 0, max_y:1079, min_x:0.00, 1/m:-0.00]
08/10/18 17:20:14.763702 zmc_m2[127143].DB9-zm_image.cpp/2386 [1: min_y: 0, max_y:1079, min_x:1919.00, 1/m:0.00]
08/10/18 17:20:14.763713 zmc_m2[127143].DB9-zm_image.cpp/2400 [Moving global edge]
08/10/18 17:20:14.763722 zmc_m2[127143].DB9-zm_image.cpp/2400 [Moving global edge]
08/10/18 17:20:14.763730 zmc_m2[127143].DB9-zm_image.cpp/2421 [0 - 0: min_y: 0, max_y:1079, min_x:0.00, 1/m:-0.00]
08/10/18 17:20:14.763738 zmc_m2[127143].DB9-zm_image.cpp/2421 [0 - 1: min_y: 0, max_y:1079, min_x:1919.00, 1/m:0.00]
08/10/18 17:20:14.763756 zmc_m2[127143].DB9-zm_image.cpp/2421 [1 - 0: min_y: 0, max_y:1079, min_x:0.00, 1/m:-0.00]
08/10/18 17:20:14.763764 zmc_m2[127143].DB9-zm_image.cpp/2421 [1 - 1: min_y: 0, max_y:1079, min_x:1919.00, 1/m:0.00]
...
08/10/18 17:20:14.814533 zmc_m2[127143].DB9-zm_image.cpp/2421 [1078 - 0: min_y: 0, max_y:1079, min_x:0.00, 1/m:-0.00]
08/10/18 17:20:14.814541 zmc_m2[127143].DB9-zm_image.cpp/2421 [1078 - 1: min_y: 0, max_y:1079, min_x:1919.00, 1/m:0.00]
08/10/18 17:20:14.814557 zmc_m2[127143].DB9-zm_image.cpp/2471 [Deleting active_edge]
08/10/18 17:20:14.814565 zmc_m2[127143].DB9-zm_image.cpp/2471 [Deleting active_edge]
08/10/18 17:20:14.817585 zmc_m2[127143].DB1-zm_monitor.cpp/459 [Monitor Driveway has function 6]
08/10/18 17:20:14.817602 zmc_m2[127143].DB1-zm_monitor.cpp/460 [Monitor Driveway LBF = '%N - %d/%m/%y %H:%M:%S', LBX = 0, LBY
= 50, LBS = 1]
08/10/18 17:20:14.817611 zmc_m2[127143].DB1-zm_monitor.cpp/461 [Monitor Driveway IBC = 50, WUC = 25, pEC = 25, PEC = 25, EAF =
 1, FRI = 1000, RBP = 6, ARBP = 6, FM = 0]
08/10/18 17:20:14.818277 zmc_m2[127143].DB1-zm_zone.cpp/957 [Got 0 zones for monitor Driveway]
08/10/18 17:20:14.818402 zmc_m2[127143].DB1-zm_monitor.cpp/2998 [Loaded monitor 2(Driveway), 0 zones]
08/10/18 17:20:14.818414 zmc_m2[127143].INF-zmc.cpp/247 [Starting Capture version 1.30.4]
08/10/18 17:20:14.819497 zmc_m2[127143].INF-zm_ffmpeg_camera.cpp/104 [Priming capture from rtsp://jasonyau:cufQkYq7y@foscam-dr
iveway:88/videoMain]
08/10/18 17:20:14.833277 zmc_m2[127143].DB2-zm_ffmpeg_camera.cpp/227 [OpenFfmpeg called.]
08/10/18 17:20:14.833306 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/259 [Calling avformat_open_input]
08/10/18 17:20:17.118086 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/279 [Opened input]
08/10/18 17:20:17.118106 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/286 [Calling avformat_find_stream_info]
08/10/18 17:20:29.399998 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/291 [Got stream info]
08/10/18 17:20:29.400025 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/310 [Found video stream]
08/10/18 17:20:29.400042 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/318 [Found decoder]
08/10/18 17:20:29.400050 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/325 [Calling avcodec_open2]
08/10/18 17:20:29.418172 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/330 [Opened codec]
08/10/18 17:20:29.418189 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/349 [Allocated frames]
08/10/18 17:20:29.418199 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/361 [Validated imagesize]
08/10/18 17:20:29.418207 zmc_m2[127143].DB1-zm_ffmpeg_camera.cpp/364 [Calling sws_isSupportedInput]
08/10/18 17:20:29.418237 zmc_m2[127143].DB5-zm_ffmpeg_camera.cpp/170 [Got packet from stream 1]
08/10/18 17:20:29.418246 zmc_m2[127143].DB5-zm_ffmpeg_camera.cpp/170 [Got packet from stream 1]
08/10/18 17:20:29.418255 zmc_m2[127143].DB5-zm_ffmpeg_camera.cpp/170 [Got packet from stream 0]
08/10/18 17:20:29.418280 zmc_m2[127143].DB4-zm_ffmpeg_camera.cpp/180 [Decoded video packet at frame 0]
08/10/18 17:20:29.418290 zmc_m2[127143].DB5-zm_ffmpeg_camera.cpp/170 [Got packet from stream 1]
...
08/10/18 17:21:36.265465 zmc_m2[127143].DB3-zm_ffmpeg_camera.cpp/184 [Got frame 976]
08/10/18 17:21:36.317988 zmc_m2[127143].INF-zm_signal.cpp/40 [Got signal 15 (Terminated), exiting]
08/10/18 17:21:36.372212 zmc_m2[127143].DB5-zm_ffmpeg_camera.cpp/170 [Got packet from stream 1]
08/10/18 17:21:36.372288 zmc_m2[127143].DB5-zm_ffmpeg_camera.cpp/170 [Got packet from stream 0]
08/10/18 17:21:36.372507 zmc_m2[127143].DB4-zm_ffmpeg_camera.cpp/180 [Decoded video packet at frame 977]
08/10/18 17:21:36.372521 zmc_m2[127143].DB3-zm_ffmpeg_camera.cpp/184 [Got frame 977]
08/10/18 17:21:36.376117 zmc_m2[127143].DB2-zm_ffmpeg_camera.cpp/397 [CloseFfmpeg called.]
08/10/18 17:21:36.546612 zmc_m2[127143].INF-zm_signal.cpp/40 [Got signal 15 (Terminated), exiting]
08/10/18 17:21:36.608161 zmc_m2[127143].DB1-zm_logger.cpp/239 [Terminating Logger]
error.log (mysql)

Code: Select all


2018-08-10T23:39:10.830969Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
2018-08-10T23:39:10.831043Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
2018-08-10T23:39:22.844119Z 0 [Warning] The syntax '--log_warnings/-W' is deprecated and will be removed in a future release.
Please use '--log_error_verbosity' instead.
2018-08-10T23:39:22.853567Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_fo
r_timestamp server option (see documentation for more details).
2018-08-10T23:39:22.853584Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2018-08-10T23:39:23.609008Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.23-0ubuntu0.16.04.1) starting as process 126292 ...
2018-08-10T23:39:24.625301Z 0 [Note] InnoDB: PUNCH HOLE support available
2018-08-10T23:39:24.625356Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-08-10T23:39:24.625368Z 0 [Note] InnoDB: Uses event mutexes
2018-08-10T23:39:24.625382Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-08-10T23:39:24.625394Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2018-08-10T23:39:24.625405Z 0 [Note] InnoDB: Using Linux native AIO
2018-08-10T23:39:24.694842Z 0 [Note] InnoDB: Number of pools: 1
2018-08-10T23:39:24.727441Z 0 [Note] InnoDB: Using CPU crc32 instructions
2018-08-10T23:39:25.123050Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2018-08-10T23:39:27.275193Z 0 [Note] InnoDB: Completed initialization of buffer pool
2018-08-10T23:39:28.203116Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be c
hanged. See the man page of setpriority().
2018-08-10T23:39:28.638917Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2018-08-10T23:39:30.921037Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2018-08-10T23:39:30.921201Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please w
ait ...
2018-08-10T23:39:33.757239Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2018-08-10T23:39:33.837764Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2018-08-10T23:39:33.837802Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2018-08-10T23:39:33.849948Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 5646ms. The settings might not be optimal
. (flushed=0 and evicted=0, during the time.)
2018-08-10T23:39:33.859881Z 0 [Note] InnoDB: 5.7.23 started; log sequence number 907459160
2018-08-10T23:39:33.898777Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2018-08-10T23:39:33.940560Z 0 [Note] Plugin 'FEDERATED' is disabled.
2018-08-10T23:39:35.756736Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not us
able without certificate and private key
2018-08-10T23:39:35.756806Z 0 [Note] Server hostname (bind-address): '127.0.0.1'; port: 3306
2018-08-10T23:39:35.756829Z 0 [Note]   - '127.0.0.1' resolves to '127.0.0.1';
2018-08-10T23:39:35.756866Z 0 [Note] Server socket created on IP: '127.0.0.1'.
2018-08-10T23:39:35.756874Z 0 [Note] InnoDB: Buffer pool(s) load completed at 180810 16:39:35
2018-08-10T23:39:36.437186Z 0 [Note] Event Scheduler: Loaded 0 events
2018-08-10T23:39:36.445323Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.23-0ubuntu0.16.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)
2018-08-11T00:20:10.006474Z 39 [Note] Aborted connection 39 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading
 communication packets)
2018-08-11T00:20:10.006575Z 38 [Note] Aborted connection 38 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading
 communication packets)
2018-08-11T00:20:11.685560Z 48 [Note] Aborted connection 48 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading
 communication packets)
2018-08-11T00:20:11.685692Z 47 [Note] Aborted connection 47 to db: 'zm' user: 'zmuser' host: 'localhost' (Got an error reading communication packets)
<lots more of these>

Re: Zoneminder stops and won't restart

Posted: Sat Aug 11, 2018 11:44 am
by bbunge
What instructions did you use to set up Zoneminder?

Check free space in tmpfs.
Run mysqltuner. May need to add resources in connections and innodb buffer pool size.

Re: Zoneminder stops and won't restart

Posted: Sat Aug 11, 2018 9:13 pm
by jwarfin
In the past, when I had issues with some installs & I wasn't sure if it was due to a shortage of memory or other resources, I'd:

- Log into the ZM console as admin
- Stop ZM
- Then reconfigure all cams function to "none" and uncheck "enabled"
- Configure logging for debugging
- Open terminal windows to "tail -f" ZM & mysql logs
- Open another terminal/xterm window & run top in it
- then start ZM

If it started OK without cams enabled, then I'd:

- Stop ZM
- Set one of the disabled cams to function "monitor" and check "enabled"
- then start ZM again

If that worked I'd keep re-enabling cams adding one more at a time & keep watching the logs.

Looking at your original post, I saw the output from top. Even though your system has 4gb of ram, I see some swap usage. This could be because of your kernel's default "swapiness" setting (google it) or maybe you are using a custom swapiness setting that's not optimal. In any case, I generally get suspicious of resource/memory issues if I see any degree of swap usage. It's often a bad sign to see swap being used IF apps/services on the system rely heavily on shared mem or tmpfs (ZM consumes serious amount of both).

If your system has 4gb of ram because you're running a 32bit OS, consider switching to 64bit. This will allow you to easily add more memory to the system beyond 4gb if needed.

Oh, when setting up a new ZM system I typically disable ZM from starting at boot time and just start it manually via the console. When everything is working as it should and 100% stable I'll go ahead and re-enable ZM starting at boot. It just keeps things simpler to debug.

Re: Zoneminder stops and won't restart

Posted: Thu Aug 16, 2018 1:40 pm
by desertcroc
Thanks for the suggestions. I followed the quickstart instructions (easy way) here:
https://zoneminder.readthedocs.io/en/st ... untu-16-04

I ended up with a fresh install on the bare metal machine I purchased to be my monitoring box. Although it has the same specs as my VM, so far it hasn't shown any swap usage, and it has been stable for 72 hours.

For the record, when I was having issues, I had tried disabling all cams but one, and ZM still refused to start. I have a hunch that maybe the MySQL database got corrupted, and was dropping the connections without explanation. Just a guess. I can probably test on my VM by dropping the database and restoring it with mysqldump. Will give it a shot.
All times are UTC
Page 1 of 1

Powered by phpBB® Forum Software © phpBB Limited