1.32.3 - Revotech cameras rebooting every few minutes.

Forum for questions and support relating to the 1.32.x releases only.
Post Reply
darmach
Posts: 19
Joined: Thu Aug 13, 2015 8:26 am

1.32.3 - Revotech cameras rebooting every few minutes.

Post by darmach » Sat Apr 20, 2019 3:48 pm

Hi everyone, I decided to post new topic, as my previous post about this was under some old solved topic under older zm version forum.

I have 8 Revotec cameras, 1080p 25fps, 802.3af POE, running on zoneminder 1.32.3 in docker container:

Streaming address is ../live0.264 so similarly as in this topic, the issue is also similar.

The cameras reboot often, nothing useful in the logs. None of them managed to run more than 30-50 minutes. They work fine, nice picture, even high frame count (tried up to 25 fps) and the BAM, from time to time I just hear visible light filter clicking and I see camera rebooted. Managed to log on via telnet (ipc71a default password for root) and load is ~17 but I guess this might be normal for embedded linux.

And after reading the thread I mentioned before I decided to try out different software. First cams ran for 24 hours with chinese CMS software (terrible btw), then I tried out you-know-what which also managed to run the cameras for few hours without any issues.

Can some of you guys help me sort this out?

I already tried the fixes from this thread:
- I'm running dockerized ZM, ffmpeg is already 3.4.4.
- All alarm definitions in the cameras are off.
- tried setting zm to remote and settings from this thread, but this fails with:

Code: Select all

Date/Time
Component	Server	PID	Level	Message	File	Line
2019-04-17 16:52:35	zmc_m1		487	INF	Starting Capture version 1.32.3	zmc.cpp	223
2019-04-17 16:52:35	zmc_m1		488	INF	Received new Content-Base in DESCRIBE response header. Updated device Url to: 'rtsp://192.168.1.101:554/live0.264/'	zm_rtsp.cpp	355
2019-04-17 16:52:35	zmc_m1		488	WAR	The device is using a codec that may not be supported. Do not be surprised if things don't work.	zm_rtp_source.cpp	69
2019-04-17 16:52:35	zmc_m1		487	FAT	Unable to locate video stream	zm_remote_camera_rtsp.cpp	188
2019-04-17 16:52:24	zmc_m1		480	WAR	The device is using a codec that may not be supported. Do not be surprised if things don't work.	zm_rtp_source.cpp	69
2019-04-17 16:52:24	zmc_m1		480	INF	Received new Content-Base in DESCRIBE response header. Updated device Url to: 'rtsp://192.168.1.101:554/live0.264/'	zm_rtsp.cpp	355
2019-04-17 16:52:24	zmc_m1		478	INF	Starting Capture version 1.32.3	zmc.cpp	223
2019-04-17 16:52:24	zmc_m1		478	FAT	Unable to locate video stream	zm_remote_camera_rtsp.cpp	188
2019-04-17 16:52:24	zmc_m1		478	INF	Got signal 15 (Terminated), exiting	zm_signal.cpp	40
2019-04-17 16:52:17	zmc_m1		476	FAT	Unable to locate video stream	zm_remote_camera_rtsp.cpp	188
2019-04-17 16:52:17	zmc_m1		477	WAR	The device is using a codec that may not be supported. Do not be surprised if things don't work.	zm_rtp_source.cpp	69
2019-04-17 16:52:17	zmc_m1		477	INF	Received new Content-Base in DESCRIBE response header. Updated device Url to: 'rtsp://192.168.1.101:554/live0.264/'	zm_rtsp.cpp	355
2019-04-17 16:52:17	zmc_m1		476	INF	Starting Capture version 1.32.3	zmc.cpp	223
2019-04-17 16:52:14	zmc_m1		468	FAT	Unable to locate video stream	zm_remote_camera_rtsp.cpp	188
2019-04-17 16:52:14	zmc_m1		470	WAR	The device is using a codec that may not be supported. Do not be surprised if things don't work.	zm_rtp_source.cpp	69

mikb
Posts: 404
Joined: Mon Mar 25, 2013 12:34 pm

Re: 1.32.3 - Revotech cameras rebooting every few minutes.

Post by mikb » Sat Apr 20, 2019 8:05 pm

darmach wrote:
Sat Apr 20, 2019 3:48 pm
Managed to log on via telnet (ipc71a default password for root) and load is ~17 but I guess this might be normal for embedded linux.
I don't know the specifics of your camera, but -- I assume it has a single processor core, which mean a load of 1.0 is "fully busy" and 17 is therefore "working its bits off". It could be that it runs out of CPU time/memory and a watchdog kicks it to reboot in an attempt to clear whatever has gone wrong.

Can you reboot the camera, with it not connected/used by ZM or anything else, so it is started and idle, and THEN check the load over time (e.g 2-3 mins) to verify that it's staying lower than 17? Then connect it to ZM and watch what happens to the load.

It's possible that ZM is doing something it doesn't like (e.g. dropping and remaking connections, leaving the camera dangling on multiple failed connections that ZM has abandoned, but the camera is still trying to keep track of, like an accidental Denial Of Service attack).

darmach
Posts: 19
Joined: Thu Aug 13, 2015 8:26 am

Re: 1.32.3 - Revotech cameras rebooting every few minutes.

Post by darmach » Mon Apr 22, 2019 6:16 pm

The load after powering the camera on (with zm container down) quickly rose:

Code: Select all

Mem: 30132K used, 22352K free, 0K shrd, 1220K buff, 5088K cached
CPU:  5.4% usr  3.2% sys  0.0% nic 88.8% idle  0.0% io  0.0% irq  2.5% sirq
Load average: 13.10 4.37 1.55 1/102 806
  PID  PPID USER     STAT   VSZ %MEM CPU %CPU COMMAND
  705   700 root     S     274m535.5   0 10.0 ./bin/sctrl
    6     2 root     SW       0  0.0   0  0.4 [rcu_kthread]
  805   801 root     R     1548  2.9   0  0.3 top
  702     1 root     S     1540  2.9   0  0.1 telnetd
    4     2 root     SW       0  0.0   0  0.1 [kworker/0:0]
    1     0 root     S     1548  2.9   0  0.0 init
  801   702 root     S     1548  2.9   0  0.0 -sh
  806     1 root     S     1544  2.9   0  0.0 /bin/login
  700     1 root     S     1536  2.9   0  0.0 /bin/sh ./startup.sh
  742     1 root     S     1476  2.8   0  0.0 /progs/bin/thttpd -d /progs/html/ -c /cgi-bin/*|/onvif/* -u root -T utf-8
  715     1 root     S     1016  1.9   0  0.0 /progs/bin/mySystem
  400     1 root     S <    872  1.6   0  0.0 udevd --daemon
    5     2 root     SW       0  0.0   0  0.0 [kworker/u:0]
  387     2 root     SW       0  0.0   0  0.0 [flush-1:0]
    7     2 root     SW<      0  0.0   0  0.0 [khelper]
  153     2 root     SW<      0  0.0   0  0.0 [rpciod]
  156     2 root     SW       0  0.0   0  0.0 [kswapd0]
  112     2 root     SW       0  0.0   0  0.0 [bdi-default]
    2     0 root     SW       0  0.0   0  0.0 [kthreadd]
  225     2 root     SW<      0  0.0   0  0.0 [crypto]
    8     2 root     SW       0  0.0   0  0.0 [kworker/u:1]
  110     2 root     SW       0  0.0   0  0.0 [sync_supers]
  308     2 root     SW       0  0.0   0  0.0 [mtdblock2]
  113     2 root     SW<      0  0.0   0  0.0 [kintegrityd]
  115     2 root     SW<      0  0.0   0  0.0 [kblockd]
  128     2 root     SW       0  0.0   0  0.0 [khubd]
  139     2 root     SW<      0  0.0   0  0.0 [cfg80211]
  140     2 root     SW       0  0.0   0  0.0 [kworker/0:1]
  332     2 root     SW       0  0.0   0  0.0 [romblock2]
  335     2 root     SW       0  0.0   0  0.0 [romblock3]
  210     2 root     SW       0  0.0   0  0.0 [fsnotify_mark]
  217     2 root     SW<      0  0.0   0  0.0 [nfsiod]
  375     2 root     SW       0  0.0   0  0.0 [kworker/u:2]
  298     2 root     SW       0  0.0   0  0.0 [mtdblock0]
  303     2 root     SW       0  0.0   0  0.0 [mtdblock1]
  418     2 root     SWN      0  0.0   0  0.0 [jffs2_gcd_mtd4]
  313     2 root     SW       0  0.0   0  0.0 [mtdblock3]
  318     2 root     SW       0  0.0   0  0.0 [mtdblock4]
  323     2 root     SW       0  0.0   0  0.0 [mtdblock5]
  326     2 root     SW       0  0.0   0  0.0 [romblock0]
  329     2 root     SW       0  0.0   0  0.0 [romblock1]
  790     2 root     SW       0  0.0   0  0.0 [flush-mtd-unmap]
    3     2 root     SW       0  0.0   0  0.0 [ksoftirqd/0]
I don't see any communication errors:

Code: Select all

# ifconfig -a
eth0      Link encap:Ethernet  HWaddr E0:62:90:B0:DE:F9
          inet addr:192.168.1.101  Bcast:192.168.1.255  Mask:255.255.255.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:1828 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1082 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:320643 (313.1 KiB)  TX bytes:137810 (134.5 KiB)
          Interrupt:12

eth0:0    Link encap:Ethernet  HWaddr E0:62:90:B0:DE:F9
          inet addr:169.254.0.1  Bcast:169.254.255.255  Mask:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          Interrupt:12

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:14 errors:0 dropped:0 overruns:0 frame:0
          TX packets:14 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:844 (844.0 B)  TX bytes:844 (844.0 B)

mikb
Posts: 404
Joined: Mon Mar 25, 2013 12:34 pm

Re: 1.32.3 - Revotech cameras rebooting every few minutes.

Post by mikb » Tue Apr 23, 2019 3:56 pm

Thanks for posting that, it may help someone else chip in.

A load of 13+ with next to nothing running looks very odd to me. If nothing is accessing the camera (as you say, ZM is shut down/stopped), why is it so busy? What is it doing to itself? It feels like there's something wrong with the camera, rather than ZM.

The communications errors I was talking about wouldn't show up on ifconfig etc. (hardware level). More the sort of thing where "netstat" shows you have thousands and thousands of connections all sitting there waiting for something, because a bug somewhere is leading to ZM/camera tearing down the connection, and the camera is keeping it open, hoping for something more! The sort of thing done deliberately in a denial-of-service attack, but which can happen accidentally when things go wrong.

darmach
Posts: 19
Joined: Thu Aug 13, 2015 8:26 am

Re: 1.32.3 - Revotech cameras rebooting every few minutes.

Post by darmach » Fri May 03, 2019 9:03 pm

I bought another one (a different case) from this manufacturer.

Load is as the others 12-17. Same thing with zoneminder - works fine with shi-no-bi, when zoneminder grabs it, reboot after few minutes.
Log below shows crash around 23:35:14

Can some of you guys help me debug this?

Code: Select all

2019-05-03 23:35:36.246847 web_php[187].ERR-/usr/share/zoneminder/www/includes/functions.php/2048 [Socket /var/run/zm/zms-192685s.sock does not exist.  This file is created by zms, and since it does not exist, either zms did not run, or zms exited early.  Please check your zms logs and ensure that CGI is enabled in apache and check that the PATH_ZMS is set correctly.  Make sure that ZM is actually recording.  If you are trying to view a live stream and the capture process (zmc) is not running then zms will exit. Please go to http://zoneminder.readthedocs.io/en/latest/faq.html#why-can-t-i-see-streamed-images-when-i-can-see-stills-in-the-zone-window-etc for more information.]
2019-05-03 23:35:35.668139 zms_m1[304].ERR-zms.cpp/254 [Unable to connect to zmc process for monitor 1]
2019-05-03 23:35:35.646159 zms_m1[304].ERR-zm_stream.cpp/48 [Unable to connect to monitor id 1 for streaming]
2019-05-03 23:35:35.463915 zms_m1[304].ERR-zm_monitor.cpp/538 [Got empty memory map file size 0, is the zmc process for this monitor running?]
2019-05-03 23:35:35.161272 web_php[191].ERR-/usr/share/zoneminder/www/includes/functions.php/2048 [Socket /var/run/zm/zms-192685s.sock does not exist.  This file is created by zms, and since it does not exist, either zms did not run, or zms exited early.  Please check your zms logs and ensure that CGI is enabled in apache and check that the PATH_ZMS is set correctly.  Make sure that ZM is actually recording.  If you are trying to view a live stream and the capture process (zmc) is not running then zms will exit. Please go to http://zoneminder.readthedocs.io/en/latest/faq.html#why-can-t-i-see-streamed-images-when-i-can-see-stills-in-the-zone-window-etc for more information.]
2019-05-03 23:35:35.151320 zmdc[221].INF-zmdc.pl [Command 'zmc -m 1' removed from pending list at 19/05/03 23:35:35]
2019-05-03 23:35:35.005010 zmdc[221].INF-zmdc.pl ['zmc -m 1' exited normally]
2019-05-03 23:35:34.635770 zmwatch[268].INF-zmwatch.pl [Restarting capture daemon for Front 1, time since last capture 20 seconds (1556919334-1556919314)]
2019-05-03 23:35:33.658770 zmfilter_2[256].INF-zmfilter.pl [Checking filter Update DiskSpace update disk space returned 0 events ]
2019-05-03 23:35:33.207590 zmfilter_1[251].INF-zmfilter.pl [Checking filter PurgeWhenFull delete returned 0 events ]
2019-05-03 23:35:24.671218 zmc_m1[247].ERR-zmc.cpp/253 [Failed to prime capture of initial monitor]
2019-05-03 23:35:24.649518 zmc_m1[247].ERR-zm_ffmpeg_camera.cpp/357 [Unable to open input rtsp://192.168.1.101:554/live0.264 due to: Interrupted system call]
2019-05-03 23:35:24.627276 zmc_m1[247].INF-zm_signal.cpp/40 [Got signal 15 (Terminated), exiting]
2019-05-03 23:35:24.602750 zmdc[221].INF-zmdc.pl ['zmc -m 1' sending stop to pid 247 at 19/05/03 23:35:24]
2019-05-03 23:35:24.544448 zmc_m1[247].INF-zm_ffmpeg_camera.cpp/163 [Priming capture from rtsp://192.168.1.101:554/live0.264]
2019-05-03 23:35:24.242200 zmwatch[268].INF-zmwatch.pl [Restarting capture daemon for Front 1, time since last capture 10 seconds (1556919324-1556919314)]
2019-05-03 23:35:14.521568 zmc_m1[247].ERR-zmc.cpp/253 [Failed to prime capture of initial monitor]
2019-05-03 23:35:14.500694 zmc_m1[247].ERR-zm_ffmpeg_camera.cpp/357 [Unable to open input rtsp://192.168.1.101:554/live0.264 due to: Operation now in progress]
2019-05-03 23:35:14.478297 zmc_m1[247].INF-zm_ffmpeg_camera.cpp/163 [Priming capture from rtsp://192.168.1.101:554/live0.264]
2019-05-03 23:35:14.458751 zmc_m1[247].INF-zmc.cpp/311 [Failed to capture image from monitor 1 Front 1 (1/1)]
2019-05-03 23:35:14.433625 zmc_m1[247].INF-zm_monitor.cpp/2391 [Return from Capture (-1), signal loss]
2019-05-03 23:35:14.417782 zmc_m1[247].INF-zm_ffmpeg_camera.cpp/710 [Unable to read packet from stream 0: error -541478725 "End of file".]
2019-05-03 23:35:14.104158 zmc_m1[247].WAR-zm_ffmpeg_camera.cpp/900 [Unable to receive frame 359: Resource temporarily unavailable, continuing]
2019-05-03 23:35:05.909735 zmc_m1[247].INF-zm_monitor.cpp/2477 [Front 1: images:300 - Capturing at 10.00 fps, capturing bandwidth 27158bytes/sec]
2019-05-03 23:34:55.864491 zmc_m1[247].INF-zm_monitor.cpp/2477 [Front 1: images:200 - Capturing at 10.00 fps, capturing bandwidth 27043bytes/sec]
2019-05-03 23:34:45.816393 zmc_m1[247].INF-zm_monitor.cpp/2477 [Front 1: images:100 - Capturing at 11.11 fps, capturing bandwidth 24759bytes/sec]
2019-05-03 23:34:36.033949 zmc_m1[247].INF-zm_monitor.cpp/2477 [Front 1: images:4 - Capturing at 100.00 fps, capturing bandwidth 10437bytes/sec]
2019-05-03 23:34:35.730742 zmc_m1[247].INF-zm_monitor.cpp/2477 [Front 1: images:1 - Capturing at 50.00 fps, capturing bandwidth 24728bytes/sec]
2019-05-03 23:34:35.494790 zmstats[282].INF-zmstats.pl [Stats Daemon starting in 30 seconds]
2019-05-03 23:34:35.136430 zmdc[282].INF-zmdc.pl ['zmstats.pl' started at 19/05/03 23:34:35]
2019-05-03 23:34:35.136310 zmdc[221].INF-zmdc.pl ['zmstats.pl' starting at 19/05/03 23:34:35, pid = 282]
2019-05-03 23:34:34.654300 zmdc[277].INF-zmdc.pl ['zmtelemetry.pl' started at 19/05/03 23:34:34]
2019-05-03 23:34:34.654300 zmdc[221].INF-zmdc.pl ['zmtelemetry.pl' starting at 19/05/03 23:34:34, pid = 277]
2019-05-03 23:34:34.226780 zmdc[273].INF-zmdc.pl ['zmupdate.pl -c' started at 19/05/03 23:34:34]
2019-05-03 23:34:34.226770 zmdc[221].INF-zmdc.pl ['zmupdate.pl -c' starting at 19/05/03 23:34:34, pid = 273]
2019-05-03 23:34:34.106860 zmwatch[268].INF-zmwatch.pl [Watchdog starting, pausing for 30 seconds]
2019-05-03 23:34:33.747000 zmdc[268].INF-zmdc.pl ['zmwatch.pl' started at 19/05/03 23:34:33]
2019-05-03 23:34:33.746990 zmdc[221].INF-zmdc.pl ['zmwatch.pl' starting at 19/05/03 23:34:33, pid = 268]
2019-05-03 23:34:33.627840 zmfilter_2[256].INF-zmfilter.pl [Checking filter Update DiskSpace update disk space returned 0 events ]
2019-05-03 23:34:33.587630 zmfilter_2[256].INF-zmfilter.pl [Scanning for events using filter id '2']
2019-05-03 23:34:33.365909 zmc_m1[247].INF-zm_ffmpeg_camera.cpp/378 [Stream open rtsp://192.168.1.101:554/live0.264, parsing streams...]
2019-05-03 23:34:33.300502 zmc_m1[247].INF-zm_ffmpeg_camera.cpp/163 [Priming capture from rtsp://192.168.1.101:554/live0.264]
2019-05-03 23:34:33.259793 zmc_m1[247].INF-zmc.cpp/223 [Starting Capture version 1.32.3]
2019-05-03 23:34:33.235280 zmdc[262].INF-zmdc.pl ['zmaudit.pl -c' started at 19/05/03 23:34:33]
2019-05-03 23:34:33.233180 zmdc[221].INF-zmdc.pl ['zmaudit.pl -c' starting at 19/05/03 23:34:33, pid = 262]
2019-05-03 23:34:33.180960 zmfilter_1[251].INF-zmfilter.pl [Checking filter PurgeWhenFull delete returned 0 events ]
2019-05-03 23:34:33.068880 zmfilter_1[251].INF-zmfilter.pl [Scanning for events using filter id '1']
2019-05-03 23:34:32.622210 zmdc[256].INF-zmdc.pl ['zmfilter.pl --filter_id=2 --daemon' started at 19/05/03 23:34:32]
2019-05-03 23:34:32.622200 zmdc[221].INF-zmdc.pl ['zmfilter.pl --filter_id=2 --daemon' starting at 19/05/03 23:34:32, pid = 256]
2019-05-03 23:34:32.002610 zmdc[251].INF-zmdc.pl ['zmfilter.pl --filter_id=1 --daemon' started at 19/05/03 23:34:31]
2019-05-03 23:34:32.002610 zmdc[221].INF-zmdc.pl ['zmfilter.pl --filter_id=1 --daemon' starting at 19/05/03 23:34:31, pid = 251]
2019-05-03 23:34:31.504670 zmdc[247].INF-zmdc.pl ['zmc -m 1' started at 19/05/03 23:34:31]
2019-05-03 23:34:31.504660 zmdc[221].INF-zmdc.pl ['zmc -m 1' starting at 19/05/03 23:34:31, pid = 247]
2019-05-03 23:34:31.173550 zmpkg[116].INF-zmpkg.pl [Single server configuration detected. Starting up services.]
2019-05-03 23:34:30.936280 zmdc[221].INF-zmdc.pl [Socket should be open at /var/run/zm/zmdc.sock]
2

Post Reply

Who is online

Users browsing this forum: Tomm and 2 guests