"Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA

Forum for questions and support relating to the 1.34.x releases only.
Post Reply
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

"Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA

Post by fulvioth »

Hi,
As for the topic i encountered unexpected out of memory problems with cuda enabled in ZM and ES.
I solved it by stopping using the link monitor function but, as you will (hopefully!) read in the next "chapters" this is not necessary the only source of the problem.
For this reason i don't wanna waste anyone's time reading the whole post, considering that when it comes to cuda there are simply too many factors playing and my gpu (GT730) is old. I can live with my actual perfectly working setup.
But if you have time to spend like for an easy reading before sleep, then i'd appreciate any comment

Please consider:
This is gonna be a long post, sorry
i'm not an expert (don't laugh :D )
i'm not (by anymean) sure this is a real problem, nor it's really a ZM/ES issue
I have a stable installation of ZM 1.34.16, ES 5.15, CUDA 10.2.89, cuDNN7.6.5, openCV 4.3.0, dlib 19.19.99, ffmpeg 4.1.6 (everything compiled for nvidia-cuda accelleration) and zmNinja of course
ZM hw accelleration is set to cuvid (decoding), ES with hooks to use cuda

Problem:
One day i noticed i was starting to miss notifications in zmninja, i suddenly had nice thoughts about my old vpn provider as usual (because i really forgot about zm for some time beside a "small" change to one monitor, btw really... great job guys!) but this time the problem was different.
In zmdc.log was logged this traceback:

Code: Select all

07/14/2020 05:58:10.090830 zmdc[13267].INF [ZMServer:410] ['zma -m 3' starting at 20/07/14 05:58:10, pid = 13342]
07/14/2020 05:58:10.091317 zmdc[13342].INF [ZMServer:410] ['zma -m 3' started at 20/07/14 05:58:10]
07/14/2020 05:58:10.233992 zmdc[13345].INF [ZMServer:410] ['zmfilter.pl --filter_id=2 --daemon' started at 20/07/14 05:58:10]
07/14/2020 05:58:10.234837 zmdc[13267].INF [ZMServer:410] ['zmfilter.pl --filter_id=2 --daemon' starting at 20/07/14 05:58:10, pid = 13345]
07/14/2020 05:58:10.542657 zmdc[13267].INF [ZMServer:410] ['zmaudit.pl -c' starting at 20/07/14 05:58:10, pid = 13352]
07/14/2020 05:58:10.544307 zmdc[13352].INF [ZMServer:410] ['zmaudit.pl -c' started at 20/07/14 05:58:10]
07/14/2020 05:58:10.863288 zmdc[13360].INF [ZMServer:410] ['zmwatch.pl' started at 20/07/14 05:58:10]
07/14/2020 05:58:10.863802 zmdc[13267].INF [ZMServer:410] ['zmwatch.pl' starting at 20/07/14 05:58:10, pid = 13360]
07/14/2020 05:58:11.087396 zmdc[13267].INF [ZMServer:410] ['zmupdate.pl -c' starting at 20/07/14 05:58:11, pid = 13366]
07/14/2020 05:58:11.087523 zmdc[13366].INF [ZMServer:410] ['zmupdate.pl -c' started at 20/07/14 05:58:11]
07/14/2020 05:58:11.328751 zmdc[13371].INF [ZMServer:410] ['zmeventnotification.pl' started at 20/07/14 05:58:11]
07/14/2020 05:58:11.329410 zmdc[13267].INF [ZMServer:410] ['zmeventnotification.pl' starting at 20/07/14 05:58:11, pid = 13371]
Update agent starting at 20/07/14 05:58:11
07/14/2020 05:58:11.575475 zmdc[13267].INF [ZMServer:410] ['zmstats.pl' starting at 20/07/14 05:58:11, pid = 13377]
07/14/2020 05:58:11.575485 zmdc[13377].INF [ZMServer:410] ['zmstats.pl' started at 20/07/14 05:58:11]
Can't ignore signal CHLD, forcing to default.
Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/memory.hpp:54: error: (-217:Gpu API call) out of memory in function 'ManagedPtr'

bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/face.py", line 102, in detect
    number_of_times_to_upsample=self.upsample_times)
  File "/usr/local/lib/python3.6/dist-packages/face_recognition/api.py", line 116, in face_locations
    return [_trim_css_to_bounds(_rect_to_css(face.rect), img.shape) for face in _raw_face_locations(img, number_of_times_to_upsample, "cnn")]
  File "/usr/local/lib/python3.6/dist-packages/face_recognition/api.py", line 100, in _raw_face_locations
    return cnn_face_detector(img, number_of_times_to_upsample)
RuntimeError: Error while calling cudaMalloc(&data, new_size*sizeof(float)) in file /home/fulvio/dlib/dlib/cuda/gpu_data.cpp:218. code: 2, reason: out of memory
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
bad bcrypt settings at /usr/bin/zmeventnotification.pl line 1492.
Can't ignore signal CHLD, forcing to default.
Short story:
I have 3 ip cams in modect and 3 zm monitors. No relevant errors
The problem was related to the following change as far as i can tell:

First camera was modified enabling a second stream so to have 2 different streams from the same camera mapped to 2 ZM monitors (4 zm monitors in total now):
First monitor: 1920x1080x32 10fps NODECT
Second monitor: 640x480x32 10fps MODECT
First monitor was linked to second one to trigger recording.
Other two cameras running as usual in modect
No other link
yolo/face detection is active on all cameras

Basic idea: i run detection on the second stream (perhaps lowering to greyscale and 5fps who knows!) but record/archive/watch the one recorded from the first stream. This way i may reduce overall cpu usage or at least better distribute load between processes, better separation i don't know, i just tought it could be worth a try.
But this led to the above problem based on my tests (sorry, for this you have to read the long story :)).
When an alarm was caught on the second stream both cameras recorded the event correctly but ES proccesses could not complete safely.
zmdc logged the above exception
esnotificationserver: Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed
esdetect stuck on: zm_detect.py:373 [Using model: yolo with /var/lib/zmeventnotification/images/11756-alarm.jpg]

Alarms were correctly caught, processed and notified from the other two cameras.
Removing the link solved the problem for me. After that, i forced a concurrent alarm on all monitors and received 4 notifications.
At this point i should think of some bug... but honestly there's much more to say/confess considering that little things could make big differences in such a complex OS. And mine wasn't that tiny :D
So my zm server is able to manage 4 concurrent events and properly queue cuda detection operations, why not just 2 from the linked monitors?
Honestly i can't say it wouldn't have work before the...

Long story:

Code: Select all

ffmpeg -hwaccels
Hardware acceleration methods:
cuvid
One day (another one) i decided to understand why, if i have cuda everywhere, ffmpeg shows only cuvid (i don't even know if it is really hw acceleration since i'm not seeing usage of gpu memory when i run ffmpeg or zm with that option on)... anyway i checked which ffmpeg version was required to enable cuda on my gpu. After a "quick" check i realized i just need to recompile my current version with cuda-sdk, moreover (and many hours later), if i upgrade my nvidia drivers (not major update) i can use ffmpeg last version and maintain compatibility with cuda 10.2 backend & C.
Great! A newer ffmpeg is surely better, of course drivers are always drivers...
Stopped ZM
Installed the new drivers (didn't reboot, i know, i know... i wasn't asked to :)) and verified they were up
Quick check to cuda and opencv with python and all was good.
compiled ffmpeg with 0 probs and ran the above command again... and cuda was there!
Started zm, and quickly my 3 monitors came up again (still cuvid), great first step.
Checked alarms, cuda detection, face recognition and notifications.
Perfect!
I can't believe i did it right at first!
And obviously i decided, since this was one of my lucky days, to try to optimize zmc cpu usage splitting one camera (and then all cameras! top!) in two streams as already said.
So i generated a real alarm on the low-res monitor and quickly the linked monitor recorded the same video at high-res.
Perfect! twice, in the same day...
Let's go with the other two cameras too!!!
Perfect! ...
i can't say if zm console was showing "person" in the event info, nor i can say if i did receive a notification for that alarm.
I checked everything was functioning properly one second before splitting the streams, and that made me more confident that eveything was at the right place.

But a couple of days later i noticed missing notifications and saw that error. Then a real mess began... and apparently it was all a waste of time!

Epilogue:
Really, no thoughts in my mind were of the kind: "remove the monitor link and check", i just said, i didn't reboot and drivers are now showing their real power!
Now i'm gonna discard all the tries i made recompiling all the sources in various steps hoping to "quickly" sort this out... after lots of tries, readings, and still no clear evidence of a possible driver compatibility problem with any of the involved components, i still decided to revert back to my original drivers. Even some run test on cuda (see later) was performing right, i mean no errors.
Disabled zm and uninstalled opencv, cudnn and cuda. uninstalled nvidia drivers to nouveau, rebooted.
Deleted any directory or file left related to any of these packages, rebooted again.
No relevant messages in kernel logs.
Installed nvidia drivers and verified with nvidia-smi: drivers 440.33.01 and no cuda
installed cuda, cudnn and verified they were ok (see later)
recompiled opencv, ffmpeg and dlib
tested opencv via python
rebooted! and verified again
I was sure i was done, so i started zm and discovered the error was still there!
At that time i had all the 3 cameras splitted to 2 monitors each. No notification were actually sent so i was totally sure that i was still having problem with cuda and that my clean up ain't been that good after all.
I tried configuring the event server to globally ignore the 3 monitors in high-res but nothing changed.
I think i was going to delete the 3 monitor clones just to "free up" some resources for zm when i got a notification thanks to my dog!!!
So, after figuring this out(the monitor link!), i made a final test creating a single link (not a circular one) between 2 monitors (short story), verifying the problem was still there and only for that camera.

Tests:
Here the tests i ran when zoneminder was showing this problem:
These tests never failed for me even before clean up

Cuda:

Code: Select all

./deviceQuery Starting...

 CUDA Device Query (Runtime API) version (CUDART static linking)

Detected 1 CUDA Capable device(s)

Device 0: "GeForce GT 730"
  CUDA Driver Version / Runtime Version          10.2 / 10.2
  CUDA Capability Major/Minor version number:    3.5
  Total amount of global memory:                 2002 MBytes (2098921472 bytes)
  ( 2) Multiprocessors, (192) CUDA Cores/MP:     384 CUDA Cores
  GPU Max Clock rate:                            902 MHz (0.90 GHz)
  Memory Clock rate:                             2505 Mhz
  Memory Bus Width:                              64-bit
  L2 Cache Size:                                 524288 bytes
  Maximum Texture Dimension Size (x,y,z)         1D=(65536), 2D=(65536, 65536), 3D=(4096, 4096, 4096)
  Maximum Layered 1D Texture Size, (num) layers  1D=(16384), 2048 layers
  Maximum Layered 2D Texture Size, (num) layers  2D=(16384, 16384), 2048 layers
  Total amount of constant memory:               65536 bytes
  Total amount of shared memory per block:       49152 bytes
  Total number of registers available per block: 65536
  Warp size:                                     32
  Maximum number of threads per multiprocessor:  2048
  Maximum number of threads per block:           1024
  Max dimension size of a thread block (x,y,z): (1024, 1024, 64)
  Max dimension size of a grid size    (x,y,z): (2147483647, 65535, 65535)
  Maximum memory pitch:                          2147483647 bytes
  Texture alignment:                             512 bytes
  Concurrent copy and kernel execution:          Yes with 1 copy engine(s)
  Run time limit on kernels:                     No
  Integrated GPU sharing Host Memory:            No
  Support host page-locked memory mapping:       Yes
  Alignment requirement for Surfaces:            Yes
  Device has ECC support:                        Disabled
  Device supports Unified Addressing (UVA):      Yes
  Device supports Compute Preemption:            No
  Supports Cooperative Kernel Launch:            No
  Supports MultiDevice Co-op Kernel Launch:      No
  Device PCI Domain ID / Bus ID / location ID:   0 / 1 / 0
  Compute Mode:
     < Default (multiple host threads can use ::cudaSetDevice() with device simultaneously) >

deviceQuery, CUDA Driver = CUDART, CUDA Driver Version = 10.2, CUDA Runtime Version = 10.2, NumDevs = 1
Result = PASS

Code: Select all

[CUDA Bandwidth Test] - Starting...
Running on...

 Device 0: GeForce GT 730
 Quick Mode

 Host to Device Bandwidth, 1 Device(s)
 PINNED Memory Transfers
   Transfer Size (Bytes)        Bandwidth(GB/s)
   32000000                     2.8

 Device to Host Bandwidth, 1 Device(s)
 PINNED Memory Transfers
   Transfer Size (Bytes)        Bandwidth(GB/s)
   32000000                     3.4

 Device to Device Bandwidth, 1 Device(s)
 PINNED Memory Transfers
   Transfer Size (Bytes)        Bandwidth(GB/s)
   32000000                     32.9

Result = PASS

NOTE: The CUDA Samples are not meant for performance measurements. Results may vary when GPU Boost is enabled.
cuDNN:

Code: Select all

./mnistCUDNN
cudnnGetVersion() : 7605 , CUDNN_VERSION from cudnn.h : 7605 (7.6.5)
Host compiler version : GCC 7.4.0
There are 1 CUDA capable devices on your machine :
device 0 : sms  2  Capabilities 3.5, SmClock 901.5 Mhz, MemSize (Mb) 2001, MemClock 2505.0 Mhz, Ecc=0, boardGroupID=0
Using device 0

Testing single precision
Loading image data/one_28x28.pgm
Performing forward propagation ...
Testing cudnnGetConvolutionForwardAlgorithm ...
Fastest algorithm is Algo 2
Testing cudnnFindConvolutionForwardAlgorithm ...
^^^^ CUDNN_STATUS_SUCCESS for Algo 1: 0.032800 time requiring 100 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 0: 0.033344 time requiring 0 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 2: 0.081440 time requiring 57600 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 5: 0.283552 time requiring 203008 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 4: 0.332032 time requiring 207360 memory
Resulting weights from Softmax:
0.0000000 0.9999399 0.0000000 0.0000000 0.0000561 0.0000000 0.0000012 0.0000017 0.0000010 0.0000000
Loading image data/three_28x28.pgm
Performing forward propagation ...
Resulting weights from Softmax:
0.0000000 0.0000000 0.0000000 0.9999288 0.0000000 0.0000711 0.0000000 0.0000000 0.0000000 0.0000000
Loading image data/five_28x28.pgm
Performing forward propagation ...
Resulting weights from Softmax:
0.0000000 0.0000008 0.0000000 0.0000002 0.0000000 0.9999820 0.0000154 0.0000000 0.0000012 0.0000006

Result of classification: 1 3 5

Test passed!

Testing half precision (math in single precision)
Loading image data/one_28x28.pgm
Performing forward propagation ...
Testing cudnnGetConvolutionForwardAlgorithm ...
Fastest algorithm is Algo 2
Testing cudnnFindConvolutionForwardAlgorithm ...
^^^^ CUDNN_STATUS_SUCCESS for Algo 1: 0.032128 time requiring 100 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 0: 0.032704 time requiring 0 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 2: 0.096000 time requiring 28800 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 5: 0.296512 time requiring 203008 memory
^^^^ CUDNN_STATUS_SUCCESS for Algo 4: 0.328288 time requiring 207360 memory
Resulting weights from Softmax:
0.0000001 1.0000000 0.0000001 0.0000000 0.0000563 0.0000001 0.0000012 0.0000017 0.0000010 0.0000001
Loading image data/three_28x28.pgm
Performing forward propagation ...
Resulting weights from Softmax:
0.0000000 0.0000000 0.0000000 1.0000000 0.0000000 0.0000714 0.0000000 0.0000000 0.0000000 0.0000000
Loading image data/five_28x28.pgm
Performing forward propagation ...
Resulting weights from Softmax:
0.0000000 0.0000008 0.0000000 0.0000002 0.0000000 1.0000000 0.0000154 0.0000000 0.0000012 0.0000006

Result of classification: 1 3 5

Test passed!
openCV (this one gives me 3fps and i find it weird but gives no errors):

Code: Select all

import numpy as np
import cv2 as cv
import time

confidence_threshold = 0.5
nms_threshold = 0.4
num_classes = 80

net = cv.dnn.readNet(model="/var/lib/zmeventnotification/models/yolov3/yolov3.weights", config="/var/lib/zmeventnotification/models/yolov3/yolov3.cfg")
net.setPreferableBackend(cv.dnn.DNN_BACKEND_CUDA)
net.setPreferableTarget(cv.dnn.DNN_TARGET_CUDA)

image = cv.imread("gm.jpg")
blob = cv.dnn.blobFromImage(image, 0.00392, (416, 416), [0, 0, 0], True, False)

# warmup
for i in range(3):
    net.setInput(blob)
    detections = net.forward(net.getUnconnectedOutLayersNames())

# benchmark
start = time.time()
for i in range(100):
    net.setInput(blob)
    detections = net.forward(net.getUnconnectedOutLayersNames())
end = time.time()

ms_per_image = (end - start) * 1000 / 100

print("Time per inference: %f ms" % (ms_per_image))
print("FPS: ", 1000.0 / ms_per_image)


Time per inference: 332.912259 ms
FPS:  3.0037944613328595
As a final test i made a really rough benchmark (but consistent for me) on gpu memory usage using nvidia-smi.
i observed in about 10 positive tests a gradual increase of memory usage (at 1s interval) until about 1,4Gb (2Gb total) and then a relative gradual decrease to 0.
With linked monitor in about the same number of tests, memory was gradually increasing to 1.4 and then straight to 0 (the exception i guess).
I'd expect to reach the 2Gb limit before that exception is raised but i don't really know.
So my guess is that something is different with linked monitors in ES but i'd like to know other opinions...
...perhaps one like: "did you enable 'that' option in zm config via the gui?", really i'd love this! :D
Last edited by fulvioth on Thu Jul 16, 2020 7:04 am, edited 2 times in total.
User avatar
asker
Posts: 1553
Joined: Sun Mar 01, 2015 12:12 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by asker »

(Did not read the full post in detail)

You might be running out of GPU memory if the ES gets stuck at loading model. Keep a window with

Code: Select all

watch -n 0.1 nvidia-smi
running and watch gpu memory. 2gb is very less to run both models and monitors on CUDA. I have 4gb and I run out of memory.
I no longer work on zmNinja, zmeventnotification, pyzm or mlapi. I may respond on occasion based on my available time/interest.

Please read before posting:
How to set up logging properly
How to troubleshoot and report - ES
How to troubleshoot and report - zmNinja
ES docs
zmNinja docs
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by fulvioth »

Hi asker,
i will check but i already did a similar test i don't know if it can be considered valid.
As a final test i made a really rough benchmark (but consistent for me) on gpu memory usage using nvidia-smi.
i observed in about 10 positive tests a gradual increase of memory usage (at 1s interval) until about 1,4Gb/2Gb and then a relative gradual decrease to 0.
With linked monitor in about the same number of tests, memory was gradually increasing to 1.4 and then straight to 0 (the exception i guess).
I'd expect to reach the 2Gb limit before that exception is raised but i don't really know
Monitors in zm are set to use cuvid during decoding (not cuda) and this way i can confirm that zm does not use gpu memory for monitors, it will probably use gpu memory if i switch it to cuda (but i can't due to codec availability reason for my gt730).
Having that said, i think i should face the same problem with my 3 monitors, but they'are working really good and no errors in log since i disabled the link.
i forced a concurrent alarm on all monitors and received 4 notifications.
So this test was made to force zm to queue cuda detection processes and memory never exceeded 1.4, 1.5Gb.
Why memory problem happens (if it really does) when triggering only two monitors (linked together)?

When zm is working properly i concurrently ran some opencv test to take gpu memory usage at limit (i read 1,99Gb), still everything completed successfully

Can i ask you some more info on cuvid? is it really hw acceleration? and if yes why i don't see zm/ffmpeg use gpu memory for it?
User avatar
asker
Posts: 1553
Joined: Sun Mar 01, 2015 12:12 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by asker »

I'd propose doing a simpler test.

1. Don't run ES in daemon mode, but run it in manual mode from command line
2. I suspect ES is not getting stuck. It is actually crashing while trying to load the model, which you will see if you run it from command line

I am not sure if your controlled tests mimic a real life situation. If you have multiple events that occur at the same time, each zm_detect process will load its own model, that will very quickly exhaust your 2GB, unless you are running mlapi.
I no longer work on zmNinja, zmeventnotification, pyzm or mlapi. I may respond on occasion based on my available time/interest.

Please read before posting:
How to set up logging properly
How to troubleshoot and report - ES
How to troubleshoot and report - zmNinja
ES docs
zmNinja docs
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by fulvioth »

I should have thought that before...
it's much more immediate. It shows the same exception but doesn't crash and this is good! :)
I am not sure if your controlled tests mimic a real life situation.
i'm not sure how the hell i tested the 3 concurrent alarms since it's not working anymore now... i thought this problem was closed but in fact it was really not, because it surely happened since i reverted back with no links (and even before at this point).
Anyway sorry for my mistake and thanks for your time opening my eyes. now i'm taking a look to your mlapi this way i should really close this matter
User avatar
asker
Posts: 1553
Joined: Sun Mar 01, 2015 12:12 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by asker »

Also, look at switching to TinyYoloV4 (not v3, needs master branch of OpenCV). It consumes a lot less memory and may work instead of using mlapi (mlapi has its own issues of concurrent execution)
I no longer work on zmNinja, zmeventnotification, pyzm or mlapi. I may respond on occasion based on my available time/interest.

Please read before posting:
How to set up logging properly
How to troubleshoot and report - ES
How to troubleshoot and report - zmNinja
ES docs
zmNinja docs
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by fulvioth »

i will thanks, as you may have already guessed mlapi keeps both models cached and i don't have enough gpu ram for them.
perhaps tinyyolo and face will.
i'd prefer a way to enqueue detections, some lag is better than a chance to miss them... i think

is there an easy way to keep an "eye" on the process so to restart it if hangs or crashes? the fallback could serve in the meanwhile
User avatar
asker
Posts: 1553
Joined: Sun Mar 01, 2015 12:12 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by asker »

I've never had zm_detect hang. Can you enable debug logs and post the output of debug logs when it hangs? I've always had it crash with an explicit out of memory error. Specifically, I am looking for the output of the zmesdetect_mX.log file where the model load hangs.
I no longer work on zmNinja, zmeventnotification, pyzm or mlapi. I may respond on occasion based on my available time/interest.

Please read before posting:
How to set up logging properly
How to troubleshoot and report - ES
How to troubleshoot and report - zmNinja
ES docs
zmNinja docs
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA and linked monitors

Post by fulvioth »

is there an easy way to keep an "eye" on the process so to restart it if hangs or crashes? the fallback could serve in the meanwhile
i was talking about mlapi process.

zm_detect didn't hang, tried to load model (initializing yolo) and nothing else gets logged until another event triggers (spawning a new process i guess).
Since gpu ram usage returns instantly back to 0, i guess the old detect process already terminated.
I'm at office now but when i get back home i'll post it anyway.
Isn't it strange anyway that if two detect processes runs, both crashes? i mean the first one should have time to allocate all the memory it needs and thus complete while the second one will crash for out of memory error.
In my situations all detect processes crash and all alarms fails to be notified.

mlapi is running with tiny yoloV3 (wasn't able to even download tiny yolo v4 (or better i only found the weights but no cfg, and the names from v3) and both models fills about 1.3Gb of gpu memory, this way i should be safe enough.
I've found a couple of possible small bugs in mlapi. i don't know if you're interested in them (for example if i make it point to zm yolo models, it still searches for cfg file in its local models directory, and the first time you run it (to create the first user), it requires it's own internal cfg (common_params.py) correctly configured to point to db (and the dict 'config' it's actually empty)
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA

Post by fulvioth »

Here's what i did
1) triggered two alarms at 19.07.16 (monitor 1 and 2)
Monitor 1 last line logged at 19:07:20 zmesdetect_m1[22451] DBG1 yolo.py:88 [YOLO initialization (loading model from disk) took: 111.058 milliseconds]
2) got exception
3) triggered one alarm at 19.08.21 (not notified but got no errors)

Monitor 1 detect:

Code: Select all

07/16/20 19:07:18 zmesdetect_m1[22451] INF zm_detect.py:181 [---------| hook version: 5.15.6, ES version: 5.15 , OpenCV version: 4.3.0|------------]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 utils.py:290 [secret filename: /etc/zm/secrets.ini]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !ZM_PORTAL]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !ZM_API_PORTAL]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !ZM_USER]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !ZM_PASSWORD]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !ML_USER]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !ML_PASSWORD]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:263 [Secret token found in config: !PLATEREC_ALPR_KEY]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 utils.py:315 [strict SSL cert checking is on...]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:332 [[monitor-1] overrides key:resize with value:no]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:332 [[monitor-1] overrides key:detect_pattern with value:(person|cell phone|dog|cat|backpack|handbag|suitcase|bottle|wine glass|knife|chair|sofa|tvmonitor|laptop|mouse|remote|keyboard)]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:332 [[monitor-1] overrides key:delete_after_analyze with value:no]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:332 [[monitor-1] overrides key:models with value:yolo,face]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:332 [[monitor-1] overrides key:face_model with value:cnn]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:332 [[monitor-1] overrides key:face_train_model with value:cnn]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [config] is '/var/lib/zmeventnotification/models/yolov3/yolov3.cfg' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [weights] is '/var/lib/zmeventnotification/models/yolov3/yolov3.weights' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [labels] is '/var/lib/zmeventnotification/models/yolov3/coco.names' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [tiny_config] is '/var/lib/zmeventnotification/models/tinyyolo/yolov3-tiny.cfg' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [tiny_weights] is '/var/lib/zmeventnotification/models/tinyyolo/yolov3-tiny.weights' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [tiny_labels] is '/var/lib/zmeventnotification/models/tinyyolo/yolov3-tiny.txt' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [known_images_path] is '/var/lib/zmeventnotification/known_faces' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 utils.py:373 [key [unknown_images_path] is '/var/lib/zmeventnotification/unknown_faces' after substitution]
07/16/20 19:07:18 zmesdetect_m1[22451] INF zm_detect.py:210 [Importing local classes for Yolo/Face]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 utils.py:166 [Trying to download https://....
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 utils.py:185 [Trying to download https://....
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 zm_detect.py:267 [No polygon area specfied, so adding a full image polygon:[{'name': 'full_image', 'value': [(0, 0), (1280, 0), (1280, 960), (0, 960)]}]]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 zm_detect.py:291 [User ALPR if vehicle found: False]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 zm_detect.py:373 [Using model: yolo with /var/lib/zmeventnotification/images/12387-alarm.jpg]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 yolo.py:48 [|---------- YOLO (input image: 1280w*960h, resized to: 416w*416h) ----------|]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG1 yolo.py:59 [Initializing Yolo]
07/16/20 19:07:18 zmesdetect_m1[22451] DBG2 yolo.py:61 [config:/var/lib/zmeventnotification/models/yolov3/yolov3.cfg, weights:/var/lib/zmeventnotification/models/yolov3/yolov3.weights]
07/16/20 19:07:20 zmesdetect_m1[22451] DBG1 yolo.py:78 [Setting CUDA backend for OpenCV. If you did not set your CUDA_ARCH_BIN correctly during OpenCV compilation, you will get errors during detection related to invalid device/make_policy]
07/16/20 19:07:20 zmesdetect_m1[22451] DBG1 yolo.py:88 [YOLO initialization (loading model from disk) took: 111.058 milliseconds]
07/16/20 19:08:23 zmesdetect_m1[24176] INF zm_detect.py:181 [---------| hook version: 5.15.6, ES version: 5.15 , OpenCV version: 4.3.0|------------]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 utils.py:290 [secret filename: /etc/zm/secrets.ini]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !ZM_PORTAL]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !ZM_API_PORTAL]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !ZM_USER]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !ZM_PASSWORD]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !ML_USER]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !ML_PASSWORD]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:263 [Secret token found in config: !PLATEREC_ALPR_KEY]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 utils.py:315 [strict SSL cert checking is on...]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:332 [[monitor-1] overrides key:resize with value:no]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:332 [[monitor-1] overrides key:detect_pattern with value:(person|cell phone|dog|cat|backpack|handbag|suitcase|bottle|wine glass|knife|chair|sofa|tvmonitor|laptop|mouse|remote|keyboard)]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:332 [[monitor-1] overrides key:delete_after_analyze with value:no]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:332 [[monitor-1] overrides key:models with value:yolo,face]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:332 [[monitor-1] overrides key:face_model with value:cnn]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:332 [[monitor-1] overrides key:face_train_model with value:cnn]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [config] is '/var/lib/zmeventnotification/models/yolov3/yolov3.cfg' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [weights] is '/var/lib/zmeventnotification/models/yolov3/yolov3.weights' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [labels] is '/var/lib/zmeventnotification/models/yolov3/coco.names' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [tiny_config] is '/var/lib/zmeventnotification/models/tinyyolo/yolov3-tiny.cfg' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [tiny_weights] is '/var/lib/zmeventnotification/models/tinyyolo/yolov3-tiny.weights' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [tiny_labels] is '/var/lib/zmeventnotification/models/tinyyolo/yolov3-tiny.txt' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [known_images_path] is '/var/lib/zmeventnotification/known_faces' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 utils.py:373 [key [unknown_images_path] is '/var/lib/zmeventnotification/unknown_faces' after substitution]
07/16/20 19:08:23 zmesdetect_m1[24176] INF zm_detect.py:210 [Importing local classes for Yolo/Face]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 utils.py:166 [Trying to download https://....
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 utils.py:185 [Trying to download https://....
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 zm_detect.py:267 [No polygon area specfied, so adding a full image polygon:[{'name': 'full_image', 'value': [(0, 0), (1280, 0), (1280, 960), (0, 960)]}]]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 zm_detect.py:291 [User ALPR if vehicle found: False]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 zm_detect.py:373 [Using model: yolo with /var/lib/zmeventnotification/images/12389-alarm.jpg]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 yolo.py:48 [|---------- YOLO (input image: 1280w*960h, resized to: 416w*416h) ----------|]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG1 yolo.py:59 [Initializing Yolo]
07/16/20 19:08:23 zmesdetect_m1[24176] DBG2 yolo.py:61 [config:/var/lib/zmeventnotification/models/yolov3/yolov3.cfg, weights:/var/lib/zmeventnotification/models/yolov3/yolov3.weights]
07/16/20 19:08:25 zmesdetect_m1[24176] DBG1 yolo.py:78 [Setting CUDA backend for OpenCV. If you did not set your CUDA_ARCH_BIN correctly during OpenCV compilation, you will get errors during detection related to invalid device/make_policy]
07/16/20 19:08:25 zmesdetect_m1[24176] DBG1 yolo.py:88 [YOLO initialization (loading model from disk) took: 699.755 milliseconds]
07/16/20 19:08:28 zmesdetect_m1[24176] DBG1 yolo.py:103 [YOLO detection took: 380.576 milliseconds]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 yolo.py:136 [YOLO NMS filtering took: 1.838 milliseconds]
07/16/20 19:08:29 zmesdetect_m1[24176] INF yolo.py:162 [object:bed at [358, 562, 712, 800] has a acceptable confidence:0.9445521831512451 compared to min confidence of: 0.3, adding]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG2 image_manip.py:282 [intersection: polygon in process=[(358, 562), (712, 562), (712, 800), (358, 800)]]
07/16/20 19:08:29 zmesdetect_m1[24176] INF image_manip.py:296 [discarding "bed" as it does not match your filters]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 image_manip.py:300 [full_image intersects object:bed[[(358, 562), (712, 562), (712, 800), (358, 800)]] but does NOT match your detect_pattern filter of (person|cell phone|dog|cat|backpack|handbag|suitcase|bottle|wine glass|knife|chair|sofa|tvmonitor|laptop|mouse|remote|keyboard)]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG2 zm_detect.py:602 [ALPR not in use, no need for look aheads in processing]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 zm_detect.py:631 [No match found in /var/lib/zmeventnotification/images/12389-alarm.jpg using model:yolo]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 zm_detect.py:373 [Using model: yolo with /var/lib/zmeventnotification/images/12389-snapshot.jpg]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 yolo.py:48 [|---------- YOLO (input image: 1280w*960h, resized to: 416w*416h) ----------|]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 yolo.py:103 [YOLO detection took: 339.623 milliseconds]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG1 yolo.py:136 [YOLO NMS filtering took: 1.69 milliseconds]
07/16/20 19:08:29 zmesdetect_m1[24176] INF yolo.py:162 [object:bed at [358, 562, 712, 800] has a acceptable confidence:0.9445521831512451 compared to min confidence of: 0.3, adding]
07/16/20 19:08:29 zmesdetect_m1[24176] DBG2 image_manip.py:282 [intersection: polygon in process=[(358, 562), (712, 562), (712, 800), (358, 800)]]
07/16/20 19:08:30 zmesdetect_m1[24176] INF image_manip.py:296 [discarding "bed" as it does not match your filters]
07/16/20 19:08:30 zmesdetect_m1[24176] DBG1 image_manip.py:300 [full_image intersects object:bed[[(358, 562), (712, 562), (712, 800), (358, 800)]] but does NOT match your detect_pattern filter of (person|cell phone|dog|cat|backpack|handbag|suitcase|bottle|wine glass|knife|chair|sofa|tvmonitor|laptop|mouse|remote|keyboard)]
07/16/20 19:08:30 zmesdetect_m1[24176] DBG2 zm_detect.py:602 [ALPR not in use, no need for look aheads in processing]
07/16/20 19:08:30 zmesdetect_m1[24176] DBG1 zm_detect.py:631 [No match found in /var/lib/zmeventnotification/images/12389-snapshot.jpg using model:yolo]
07/16/20 19:08:32 zmesdetect_m1[24176] DBG1 face_train.py:20 [Face Recognition library load time took: 0.009 milliseconds]
07/16/20 19:08:32 zmesdetect_m1[24176] DBG1 face.py:24 [Initializing face recognition with model:cnn upsample:1, jitters:1]
07/16/20 19:08:32 zmesdetect_m1[24176] DBG1 face.py:46 [pre-trained faces found, using that. If you want to add new images, remove: /var/lib/zmeventnotification/known_faces/faces.dat]
07/16/20 19:08:33 zmesdetect_m1[24176] DBG1 zm_detect.py:373 [Using model: face with /var/lib/zmeventnotification/images/12389-alarm.jpg]
07/16/20 19:08:33 zmesdetect_m1[24176] DBG1 face.py:87 [|---------- Face recognition (input image: 1280w*960h) ----------|]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG1 face.py:105 [Finding faces took 15.097 milliseconds]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG1 face.py:115 [Computing face recognition distances took 0.021 milliseconds]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG1 zm_detect.py:412 [Appending known faces to filter list]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG2 zm_detect.py:602 [ALPR not in use, no need for look aheads in processing]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG1 zm_detect.py:631 [No match found in /var/lib/zmeventnotification/images/12389-alarm.jpg using model:face]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG1 zm_detect.py:373 [Using model: face with /var/lib/zmeventnotification/images/12389-snapshot.jpg]
07/16/20 19:08:35 zmesdetect_m1[24176] DBG1 face.py:87 [|---------- Face recognition (input image: 1280w*960h) ----------|]
07/16/20 19:08:36 zmesdetect_m1[24176] DBG1 face.py:105 [Finding faces took 639.321 milliseconds]
07/16/20 19:08:36 zmesdetect_m1[24176] DBG1 face.py:115 [Computing face recognition distances took 0.024 milliseconds]
07/16/20 19:08:36 zmesdetect_m1[24176] DBG1 zm_detect.py:412 [Appending known faces to filter list]
07/16/20 19:08:36 zmesdetect_m1[24176] DBG2 zm_detect.py:602 [ALPR not in use, no need for look aheads in processing]
07/16/20 19:08:36 zmesdetect_m1[24176] DBG1 zm_detect.py:631 [No match found in /var/lib/zmeventnotification/images/12389-snapshot.jpg using model:face]
07/16/20 19:08:36 zmesdetect_m1[24176] INF zm_detect.py:644 [No patterns found using any models in all files]
Eventserver:

Code: Select all

07/16/2020 19:07:16.593777 zmeventnotification[13269].INF [main:892] [PARENT: New event 12388 reported for Monitor:2 (Name:IPC-02 ) Forced Web[last processed eid:12386]]
07/16/2020 19:07:16.636824 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:16.636966 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:16.637223 zmeventnotification[13269].INF [main:892] [PARENT: New event 12387 reported for Monitor:1 (Name:IPC-06 ) Forced Web[last processed eid:12385]]
07/16/2020 19:07:16.662086 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=2]
07/16/2020 19:07:16.662196 zmeventnotification[13269].DBG [main:883] [PARENT: There are 2 new Events to process]
07/16/2020 19:07:16.665664 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:16.669890 zmeventnotification[22441].DBG [main:883] [PARENT: Forked process:22441 to handle alarm eid:12388]
07/16/2020 19:07:16.670331 zmeventnotification[22441].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Event from Events WHERE Id = 12388]
07/16/2020 19:07:16.671356 zmeventnotification[22441].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Storage from Storage WHERE Id = 2]
07/16/2020 19:07:16.671398 zmeventnotification[22442].DBG [main:883] [PARENT: Forked process:22442 to handle alarm eid:12387]
07/16/2020 19:07:16.671781 zmeventnotification[22442].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Event from Events WHERE Id = 12387]
07/16/2020 19:07:16.672422 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Adding event path:/home/zm/events/2/2020-07-16/12388 to hook for image storage]
07/16/2020 19:07:16.672500 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 12388 2 "IPC-02 " "Forced Web" "/home/zm/events/2/2020-07-16/12388"]
07/16/2020 19:07:16.672760 zmeventnotification[22442].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Storage from Storage WHERE Id = 2]
07/16/2020 19:07:16.673776 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Adding event path:/home/zm/events/1/2020-07-16/12387 to hook for image storage]
07/16/2020 19:07:16.673847 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 12387 1 "IPC-06 " "Forced Web" "/home/zm/events/1/2020-07-16/12387"]
07/16/2020 19:07:21.593204 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:21.593384 zmeventnotification[13269].DBG [main:883] [PARENT: There are 2 active child forks...]
07/16/2020 19:07:21.593496 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:21.593675 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:21.593825 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:21.593887 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:21.593986 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:21.594046 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:21.594142 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:21.594195 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:21.594244 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:21.594291 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:24.887858 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 parse of hook: and []]
07/16/2020 19:07:24.887997 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 hook start returned with text: json:[] exit:1]
07/16/2020 19:07:24.888139 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:24.888379 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:24.959826 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 parse of hook: and []]
07/16/2020 19:07:24.959939 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 hook start returned with text: json:[] exit:1]
07/16/2020 19:07:24.960038 zmeventnotification[22441].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:24.960215 zmeventnotification[22441].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:24.960759 zmeventnotification[22441].INF [main:892] [|----> FORK:IPC-02  (2), eid:12388 Event 12388 for Monitor 2 has finished]
07/16/2020 19:07:26.592767 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:26.592933 zmeventnotification[13269].DBG [main:883] [PARENT: There are 2 active child forks...]
07/16/2020 19:07:26.593003 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:26.593116 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:26.593220 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:26.593310 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:26.593402 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:26.593465 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:26.593568 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:26.593617 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:26.593666 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:26.593715 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:26.888717 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Matching alarm to connection rules...]
07/16/2020 19:07:26.888897 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Checking alarm rules for token ending in:..._WCY2IBAnS]
07/16/2020 19:07:26.889030 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Monitor 1 event: should send out as  55.6836099624634 is >= interval of 0]
07/16/2020 19:07:26.889088 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 shouldSendEventToConn returned true, so calling sendEvent]
07/16/2020 19:07:26.889241 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 isAllowedChannel: got type:event_start resCode:1]
07/16/2020 19:07:26.889677 zmeventnotification[22442].INF [main:892] [|----> FORK:IPC-06  (1), eid:12387 Not sending over FCM as notify filters are on_success:fcm,web,api and on_fail:none]
07/16/2020 19:07:26.913222 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:26.913367 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:26.996242 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Matching alarm to connection rules...]
07/16/2020 19:07:26.996459 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Checking alarm rules for token ending in:..._WCY2IBAnS]
07/16/2020 19:07:26.996654 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Monitor 2 event: should send out as  63.8822500705719 is >= interval of 0]
07/16/2020 19:07:26.996724 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 shouldSendEventToConn returned true, so calling sendEvent]
07/16/2020 19:07:26.996903 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 isAllowedChannel: got type:event_start resCode:1]
07/16/2020 19:07:26.997131 zmeventnotification[22441].INF [main:892] [|----> FORK:IPC-02  (2), eid:12388 Not sending over FCM as notify filters are on_success:fcm,web,api and on_fail:none]
07/16/2020 19:07:27.021707 zmeventnotification[22441].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:27.021838 zmeventnotification[22441].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:28.913604 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:28.913796 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:29.022601 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Adding event path:/home/zm/events/2/2020-07-16/12388 to hook for image storage]
07/16/2020 19:07:29.022692 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 12388 2 "IPC-02 " "Forced Web: " "/home/zm/events/2/2020-07-16/12388"]
07/16/2020 19:07:29.030549 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 parse of hook:Forced Web:  and []]
07/16/2020 19:07:29.030694 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 hook end returned with text:Forced Web:   json:[] exit:0]
07/16/2020 19:07:29.030807 zmeventnotification[22441].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:29.030999 zmeventnotification[22441].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:30.914056 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:30.914316 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:31.031487 zmeventnotification[22441].INF [main:892] [|----> FORK:IPC-02  (2), eid:12388 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
07/16/2020 19:07:31.057673 zmeventnotification[22441].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:31.057981 zmeventnotification[22441].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:31.588663 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:31.589187 zmeventnotification[13269].DBG [main:883] [PARENT: RAW TEXT-->timestamp--TYPE--1594918891.44467--SPLIT--1--SPLIT--1594919246.88914]
07/16/2020 19:07:31.589271 zmeventnotification[13269].DBG [main:883] [PARENT: Job: Update last sent timestamp of monitor:1 to 1594919246.88914 for id:1594918891.44467]
07/16/2020 19:07:31.589556 zmeventnotification[13269].DBG [main:883] [PARENT: RAW TEXT-->timestamp--TYPE--1594918891.44467--SPLIT--2--SPLIT--1594919246.99678]
07/16/2020 19:07:31.589621 zmeventnotification[13269].DBG [main:883] [PARENT: Job: Update last sent timestamp of monitor:2 to 1594919246.99678 for id:1594918891.44467]
07/16/2020 19:07:31.589687 zmeventnotification[13269].DBG [main:883] [PARENT: There are 2 active child forks...]
07/16/2020 19:07:31.589743 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:31.589841 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:31.589934 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:31.590004 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:31.590100 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:31.590169 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:31.590279 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:31.590333 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:31.590387 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:31.590440 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:32.914536 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:32.914726 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:33.059165 zmeventnotification[22441].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:33.059392 zmeventnotification[22441].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:34.914958 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:34.915158 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:35.059672 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 exiting]
07/16/2020 19:07:35.059832 zmeventnotification[22441].DBG [main:883] [|----> FORK:IPC-02  (2), eid:12388 Ending process:22441 to handle alarms]
07/16/2020 19:07:36.590181 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:36.590578 zmeventnotification[13269].DBG [main:883] [PARENT: RAW TEXT-->active_event_delete--TYPE--2--SPLIT--12388]
07/16/2020 19:07:36.590670 zmeventnotification[13269].DBG [main:883] [PARENT: Job: Deleting active_event eid:12388, mid:2]
07/16/2020 19:07:36.590781 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:07:36.590845 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:36.590947 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:36.591044 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:36.591115 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:36.591213 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:36.591283 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:36.591395 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:36.591453 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:36.591513 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:36.591570 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:36.915390 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:36.915633 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:38.915847 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:38.916050 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:40.916280 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:40.916492 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:41.593150 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:41.593293 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:07:41.593353 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:41.593450 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:41.593538 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:41.593601 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:41.593707 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:41.593768 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:41.593865 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:41.593913 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:41.593961 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:41.594009 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:42.916782 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:42.916994 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:44.917217 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:44.917442 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:46.592700 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:46.592867 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:07:46.592943 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:46.593106 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:46.593224 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:46.593324 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:46.593439 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:46.593520 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:46.593656 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:46.593751 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:46.593814 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:46.593878 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:46.917673 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:46.917877 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:48.918145 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:48.918365 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:50.918609 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:50.918816 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:51.592683 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:51.592817 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:07:51.592881 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:51.593006 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:51.593104 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:51.593175 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:51.593271 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:51.593340 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:51.593449 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:51.593504 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:51.593558 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:51.593612 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:52.919754 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:52.920049 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:54.920295 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:54.920508 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:56.592911 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:07:56.593083 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:07:56.593163 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:07:56.593285 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:07:56.593390 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:07:56.593460 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:07:56.593558 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:56.593627 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:56.593737 zmeventnotification[13269].DBG [main:883] [PARENT: We've already worked on Monitor:1, Event:12387, not doing anything more]
07/16/2020 19:07:56.593801 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:07:56.593857 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:07:56.593911 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:07:56.920777 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:56.920986 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:58.921256 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:07:58.921488 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:07:58.921715 zmeventnotification[22442].INF [main:892] [|----> FORK:IPC-06  (1), eid:12387 Event 12387 for Monitor 1 has finished]
07/16/2020 19:08:00.949163 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Adding event path:/home/zm/events/1/2020-07-16/12387 to hook for image storage]
07/16/2020 19:08:00.949300 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 12387 1 "IPC-06 " "Forced Web: " "/home/zm/events/1/2020-07-16/12387"]
07/16/2020 19:08:00.955822 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 parse of hook:Forced Web:  and []]
07/16/2020 19:08:00.955958 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 hook end returned with text:Forced Web:   json:[] exit:0]
07/16/2020 19:08:00.956071 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:00.956227 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:01.592707 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:01.592860 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:08:01.592926 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:01.593033 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:01.593125 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:01.593188 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:01.593276 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:01.593337 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:01.593431 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:01.593479 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:01.593527 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:02.956713 zmeventnotification[22442].INF [main:892] [|----> FORK:IPC-06  (1), eid:12387 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
07/16/2020 19:08:02.982517 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:02.982688 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:04.982906 zmeventnotification[22442].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:04.983086 zmeventnotification[22442].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:06.592838 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:06.593025 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:08:06.593105 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:06.593274 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:06.593386 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:06.593457 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:06.593556 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:06.593657 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:06.593765 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:06.593821 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:06.593874 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:06.983326 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 exiting]
07/16/2020 19:08:06.983502 zmeventnotification[22442].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12387 Ending process:22442 to handle alarms]
07/16/2020 19:08:11.592673 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:11.593063 zmeventnotification[13269].DBG [main:883] [PARENT: RAW TEXT-->active_event_delete--TYPE--1--SPLIT--12387]
07/16/2020 19:08:11.593169 zmeventnotification[13269].DBG [main:883] [PARENT: Job: Deleting active_event eid:12387, mid:1]
07/16/2020 19:08:11.593252 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 active child forks...]
07/16/2020 19:08:11.593314 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:11.593419 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:11.593509 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:11.593573 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:11.593661 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:11.593737 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:11.593870 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:11.593940 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:11.594007 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:16.592726 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:16.592887 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 active child forks...]
07/16/2020 19:08:16.592965 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:16.593089 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:16.593214 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:16.593297 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:16.593411 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:16.593492 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:16.593618 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:16.593683 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:16.593746 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:21.592660 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:21.592815 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 active child forks...]
07/16/2020 19:08:21.592890 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:21.593027 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:21.593140 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:21.593222 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:21.593333 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:21.593414 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:21.593754 zmeventnotification[13269].INF [main:892] [PARENT: New event 12389 reported for Monitor:1 (Name:IPC-06 ) Forced Web[last processed eid:12387]]
07/16/2020 19:08:21.616663 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=1]
07/16/2020 19:08:21.616762 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 new Events to process]
07/16/2020 19:08:21.618672 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:21.622542 zmeventnotification[24172].DBG [main:883] [PARENT: Forked process:24172 to handle alarm eid:12389]
07/16/2020 19:08:21.622900 zmeventnotification[24172].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Event from Events WHERE Id = 12389]
07/16/2020 19:08:21.623774 zmeventnotification[24172].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Storage from Storage WHERE Id = 2]
07/16/2020 19:08:21.624779 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 Adding event path:/home/zm/events/1/2020-07-16/12389 to hook for image storage]
07/16/2020 19:08:21.624857 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 12389 1 "IPC-06 " "Forced Web" "/home/zm/events/1/2020-07-16/12389"]
07/16/2020 19:08:26.592830 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:26.593068 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:08:26.593195 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:26.593403 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:26.593575 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:26.593639 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:26.593747 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:26.593810 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:26.593914 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:26.593966 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:26.594014 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:31.592660 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:31.592792 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:08:31.592854 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:31.592949 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:31.593054 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:31.593117 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:31.593202 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:31.593263 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:31.593356 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:31.593405 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:31.593451 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:36.592717 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:36.592896 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:08:36.592966 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:36.593082 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:36.593181 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:36.593245 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:36.593336 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:36.593399 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:36.593504 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:36.593556 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:36.593605 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
07/16/2020 19:08:37.661609 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 parse of hook: and []]
07/16/2020 19:08:37.661933 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 hook start returned with text: json:[] exit:1]
07/16/2020 19:08:37.662038 zmeventnotification[24172].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:37.662201 zmeventnotification[24172].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:37.662686 zmeventnotification[24172].INF [main:892] [|----> FORK:IPC-06  (1), eid:12389 Event 12389 for Monitor 1 has finished]
07/16/2020 19:08:39.694174 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 Matching alarm to connection rules...]
07/16/2020 19:08:39.694343 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 Checking alarm rules for token ending in:..._WCY2IBAnS]
07/16/2020 19:08:39.694477 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 Monitor 1 event: should send out as  72.1108601093292 is >= interval of 0]
07/16/2020 19:08:39.694528 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 shouldSendEventToConn returned true, so calling sendEvent]
07/16/2020 19:08:39.694658 zmeventnotification[24172].DBG [main:883] [|----> FORK:IPC-06  (1), eid:12389 isAllowedChannel: got type:event_start resCode:1]
07/16/2020 19:08:39.694822 zmeventnotification[24172].INF [main:892] [|----> FORK:IPC-06  (1), eid:12389 Not sending over FCM as notify filters are on_success:fcm,web,api and on_fail:none]
07/16/2020 19:08:39.728044 zmeventnotification[24172].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:39.728235 zmeventnotification[24172].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:41.593169 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick START<--------------]
07/16/2020 19:08:41.593773 zmeventnotification[13269].DBG [main:883] [PARENT: RAW TEXT-->timestamp--TYPE--1594918891.44467--SPLIT--1--SPLIT--1594919319.69457]
07/16/2020 19:08:41.593870 zmeventnotification[13269].DBG [main:883] [PARENT: Job: Update last sent timestamp of monitor:1 to 1594919319.69457 for id:1594918891.44467]
07/16/2020 19:08:41.593957 zmeventnotification[13269].DBG [main:883] [PARENT: There are 1 active child forks...]
07/16/2020 19:08:41.594021 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676782080 for 3]
07/16/2020 19:08:41.594130 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
07/16/2020 19:08:41.594238 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676786176 for 2]
07/16/2020 19:08:41.594321 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/16/2020 19:08:41.594441 zmeventnotification[13269].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140064676790272 for 1]
07/16/2020 19:08:41.594522 zmeventnotification[13269].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/16/2020 19:08:41.594646 zmeventnotification[13269].DBG [main:883] [PARENT: checkEvents() new events found=0]
07/16/2020 19:08:41.594711 zmeventnotification[13269].DBG [main:883] [PARENT: There are 0 new Events to process]
07/16/2020 19:08:41.594773 zmeventnotification[13269].DBG [main:883] [PARENT: ---------->Tick END<--------------]
fulvioth
Posts: 21
Joined: Wed Dec 18, 2019 5:27 pm

Re: "Possible" memory problem in Zoneminder 1.34.16 with Eventserver 5.15+CUDA

Post by fulvioth »

Exception (sorry inf level here):

Code: Select all

07/16/2020 19:01:30.818375 zmdc[13281].INF [ZMServer:410] ['zmstats.pl' started at 20/07/16 19:01:30]
Can't ignore signal CHLD, forcing to default.
Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/face.py", line 102, in detect
    number_of_times_to_upsample=self.upsample_times)
  File "/usr/local/lib/python3.6/dist-packages/face_recognition/api.py", line 116, in face_locations
    return [_trim_css_to_bounds(_rect_to_css(face.rect), img.shape) for face in _raw_face_locations(img, number_of_times_to_upsample, "cnn")]
  File "/usr/local/lib/python3.6/dist-packages/face_recognition/api.py", line 100, in _raw_face_locations
    return cnn_face_detector(img, number_of_times_to_upsample)
RuntimeError: Error while calling cudaMalloc(&data, new_size*sizeof(float)) in file /home/fulvio/dlib/dlib/cuda/gpu_data.cpp:218. code: 2, reason: out of memory
Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/memory.hpp:54: error: (-217:Gpu API call) out of memory in function 'ManagedPtr'

Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 402, in <module>
    b, l, c = m.detect(image)
  File "/usr/local/lib/python3.6/dist-packages/zmes_hook_helpers/yolo.py", line 99, in detect
    outs = self.net.forward(ln)
cv2.error: OpenCV(4.3.0) /home/fulvio/sources/opencv/modules/dnn/src/layers/../cuda4dnn/csl/cudnn/cudnn.hpp:65: error: (-217:Gpu API call) CUDNN_STATUS_NOT_INITIALIZED in function 'UniqueHandle'

07/16/2020 19:31:28.578515 zmdc[13046].INF [ZMServer:703] ['zmcontrol.pl --id 1' exited normally]
Post Reply