[SOLVED] Help with zmN+ZM+ES+ML Detection:

[linuxnutt]

TL;DR version:
Specifically I need assistance;
1. zm_detect.py machine learning to stop returning results of no object found, "hook start returned with text: json:[] exit:1]".
2. Look at my ES + hooks/detect logs, zmeventnotification.ini, objectconfig.ini, and tell me what I'm doing wrong.

Longer Version;
I would like to get some help with setting up zmN+ZM+ES+ML to get it working properly. I am interested in person|car|motorbike|bus|truck|boat| detection. I have read the docs but I'm still having trouble getting events to trigger as a result of ML detection, and having event notifications sent to zmNinga. I'm using docker "dlandon's GitHub zoneminder.machine.learning" docker container running Zoneminder v1.36.12, ES and Hook version: 6.1.23 on Linux Mint 20.1 Ulyssa with CPU object based detection (for now GPU or TPU later) and znNinja on an android device. I get events from ES (a lot of them) when I turn off Hooks (use_hooks = no), but when I turn hooks back on (use_hooks = yes) I do not get any notifications but still get events. No alert notifications via FCM as zm_detect.py keeps coming up with "0" no object found. To me in the logs it looks like the detection is seeing a person during zmesdetect YOLO because of "model iteration inside object found: labels: ['person'],conf:[0.5948755145072937]]", yet during zm_detect.py I'm only geting notifications of nothing found, "eid:694 hook start returned with text: json:[] exit:0]". I have been working on this for weeks now, but no cigar. I came late to the party! I know zmNinga, ES + ML from Asker has reached end of life as of Dec 2021, and dlandon's docker is not being maintained any more but Asker's documentation is so good (the excellent Zoneminder documentation) it was always been on my To Do list to learn ES and ML. Now better than never.

ES + hooks/detect logs, eid:827

Code: Select all

root@30656f8d7a9e:/# tail -F  /var/log/zm/zmesdetect*.log /var/log/zm/zmeventnotification.log
==> /var/log/zm/zmesdetect_m1.log <==
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:448 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (640, 0), (640, 480), (0, 480)], 'pattern': None}]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG3 detect_sequence.py:228 [resized polygons x=1.25/y=1.25: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 600), (0, 600)], 'pattern': None}]]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((228 5, 696 5, 696 591, 228 591, 228 5)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(228, 5), (696, 5), (696, 591), (228, 591)]]]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]
03/04/22 00:48:55 zmesdetect_m1[2420] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

==> /var/log/zm/zmeventnotification.log <==
03/04/22 00:52:50.146302 zmeventnotification[2297].DB1 [main:1006] [PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data]
03/04/22 00:52:50.146649 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:52:50.146796 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:52:50.146952 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:1, active hooks: 0)<--------------]
03/04/22 00:52:55.136487 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:0, total forks:1, active hooks: 0 running for:11 min)<--------------]
03/04/22 00:52:55.136725 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:52:55.136898 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:52:55.137306 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:52:55.137470 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:52:55.137645 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:1, active hooks: 0)<--------------]
03/04/22 00:53:00.135238 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:0, total forks:1, active hooks: 0 running for:11 min)<--------------]
03/04/22 00:53:00.135475 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:00.135649 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:00.136057 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:00.136223 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:00.136397 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:1, active hooks: 0)<--------------]
03/04/22 00:53:05.136498 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:0, total forks:1, active hooks: 0 running for:11 min)<--------------]
03/04/22 00:53:05.136742 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:05.136944 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:05.137358 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:05.137505 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:05.137663 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:1, active hooks: 0)<--------------]
03/04/22 00:53:10.135246 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:0, total forks:1, active hooks: 0 running for:11 min)<--------------]
03/04/22 00:53:10.135483 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:10.135655 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:10.136069 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:10.136217 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:10.136373 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:1, active hooks: 0)<--------------]
03/04/22 00:53:15.135336 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:0, total forks:1, active hooks: 0 running for:11 min)<--------------]
03/04/22 00:53:15.135545 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:15.135700 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:15.136330 zmeventnotification[2297].INF [main:1018] [PARENT: New event 827 reported for Monitor:1 (Name:Camera1-BesderA6-PTZ-1) Motion New[last processed eid:825]]
03/04/22 00:53:15.138634 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=1]
03/04/22 00:53:15.138798 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 new Events to process]
03/04/22 00:53:15.144450 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 0)<--------------]
03/04/22 00:53:15.145371 zmeventnotification[2516].DB1 [ZoneMinder::Logger:321] [LogOpts: level=DB4/DB1, screen=OFF, database=INF, logfile=DB1->/var/log/zm/zmeventnotification.log, syslog=INF]
03/04/22 00:53:15.145679 zmeventnotification[2516].DB1 [main:1006] [PARENT: Forked process:2516 to handle alarm eid:827]
03/04/22 00:53:15.146120 zmeventnotification[2516].DB1 [ZoneMinder::Object:125] [Loading ZoneMinder::Event from Events WHERE Id = 827]
03/04/22 00:53:15.148653 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Adding event path:/var/cache/zoneminder/events/1/2022-03-04/827 to hook for image storage]
03/04/22 00:53:15.148817 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 827 1 "Camera1-BesderA6-PTZ-1" "Motion New" "/var/cache/zoneminder/events/1/2022-03-04/827"]

==> /var/log/zm/zmesdetect_m1.log <==
03/04/22 00:53:16 zmesdetect_m1[2520] INF ZMLog.py:292 [Setting up signal handler for logs]
03/04/22 00:53:16 zmesdetect_m1[2520] INF ZMLog.py:301 [Switching global logger to ZMLog]
03/04/22 00:53:16 zmesdetect_m1[2520] INF zm_detect.py:271 [---------| app:6.1.23, pyzm:0.3.55, ES:6.1.23 , OpenCV:4.5.3|------------]
03/04/22 00:53:16 zmesdetect_m1[2520] INF utils.py:406 [Reading config from: /etc/zm/objectconfig.ini]
03/04/22 00:53:16 zmesdetect_m1[2520] INF utils.py:411 [Reading secrets from: /etc/zm/secrets.ini]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !ML_USER]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG1 utils.py:446 [allowing self-signed certs to work...]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG4 utils.py:456 [Now checking for monitor overrides]
03/04/22 00:53:16 zmesdetect_m1[2520] DBG4 utils.py:524 [Finally, doing parameter substitution]
03/04/22 00:53:16 zmesdetect_m1[2520] INF zm_detect.py:296 [Importing local classes for Object/Face]
03/04/22 00:53:16 zmesdetect_m1[2520] INF zm_detect.py:321 [Connecting with ZM APIs]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 api.py:72 [API SSL certificate check has been disbled]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 api.py:181 [using username/password for login]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 api.py:210 [Using new token API]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 api.py:217 [Access token expires on:2022-03-04 02:53:17.122812 [7200s]]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 api.py:221 [Refresh token expires on:2022-03-05 00:53:17.124684 [86400s]]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 zm_detect.py:329 [using ml_sequence]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 zm_detect.py:341 [using stream_sequence]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 detect_sequence.py:160 [Resetting models, will be loaded on next run]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG3 detect_sequence.py:634 [Using automatic locking as we are switching between models]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 Media.py:99 [Using URL 827 for stream]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 Media.py:137 [No need to start streams, we are picking images from https://192.168.1.50:8443/zm/index.php?view=image&eid=827]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG3 Media.py:271 [Reading https://192.168.1.50:8443/zm/index.php?view=image&eid=827&fid=snapshot]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG3 api.py:144 [No need to relogin as access token still has 119.9996812 minutes remaining]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG3 api.py:272 [make_request called with url=https://192.168.1.50:8443/zm/index.php?view=image&eid=827&fid=snapshot payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjQ2MzgzOTk3LCJleHAiOjE2NDYzOTExOTcsInVzZXIiOiJzdGV2ZSIsInR5cGUiOiJhY2Nlc3MifQ.AxiFW_UB8W8bNuS_HiqthYxmrLlVMFzMoPBz1IJ4UJw'}]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 detect_sequence.py:654 [perf: Starting for frame:snapshot]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object', 'face', 'alpr']]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running object detection type in sequence ==================]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 detect_sequence.py:174 [Skipping TPU object detection as it is disabled]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 detect_sequence.py:178 [Loading sequence: YoloV4 GPU/CPU]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 detect_sequence.py:179 [Initializing model  type:object with options:{'name': 'YoloV4 GPU/CPU', 'enabled': 'yes', 'object_config': '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg', 'object_weights': '/var/lib/zmeventnotification/models/yolov4/yolov4.weights', 'object_labels': '/var/lib/zmeventnotification/models/yolov4/coco.names', 'object_min_confidence': 0.3, 'object_framework': 'opencv', 'object_processor': 'gpu', 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_processes': 3, 'cpu_max_lock_wait': 100, 'max_detection_size': '90%', 'disable_locks': 'no'}]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 yolo.py:37 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 detect_sequence.py:701 [--------- Frame:snapshot Running variation: #1 -------------]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx600h]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 yolo.py:49 [Waiting for pyzm_uid33_gpu_lock portalock...]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG2 yolo.py:51 [Got pyzm_uid33_gpu_lock portalock]
03/04/22 00:53:17 zmesdetect_m1[2520] DBG1 yolo.py:84 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]
03/04/22 00:53:18 zmesdetect_m1[2520] DBG1 yolo.py:91 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 1606.47 ms]
03/04/22 00:53:18 zmesdetect_m1[2520] DBG2 yolo.py:107 [Setting CUDA backend for OpenCV]
03/04/22 00:53:18 zmesdetect_m1[2520] DBG3 yolo.py:108 [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]
03/04/22 00:53:18 zmesdetect_m1[2520] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*600h, model resize dimensions: 416w*416h) ----------|]

==> /var/log/zm/zmeventnotification.log <==
03/04/22 00:53:20.135111 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 0 running for:11 min)<--------------]
03/04/22 00:53:20.135326 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:20.135844 zmeventnotification[2297].DB1 [main:1006] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add]
03/04/22 00:53:20.135974 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/04/22 00:53:20.136474 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:20.136579 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:20.136685 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 1)<--------------]

==> /var/log/zm/zmesdetect_m1.log <==
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 yolo.py:67 [Released pyzm_uid33_gpu_lock portalock]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG1 yolo.py:173 [perf: processor:gpu Yolo detection took: 1789.47 ms]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 yolo.py:208 [perf: processor:gpu Yolo NMS filtering took: 1.10 ms]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 object.py:66 [core model detection over, got 1 objects. Now filtering]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 object.py:70 [Max object size found to be: 90%]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 object.py:78 [Converted 90% to 432000.0]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 object.py:103 [Returning filtered list of 1 objects.]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:711 [This model iteration inside object found: labels: ['person'],conf:[0.869956910610199]]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:448 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (640, 0), (640, 480), (0, 480)], 'pattern': None}]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG3 detect_sequence.py:228 [resized polygons x=1.25/y=1.25: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 600), (0, 600)], 'pattern': None}]]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((510 18, 708 18, 708 604, 510 604, 510 18)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(510, 18), (708, 18), (708, 604), (510, 604)]]]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

==> /var/log/zm/zmeventnotification.log <==
03/04/22 00:53:25.135325 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 1 running for:11 min)<--------------]
03/04/22 00:53:25.135525 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:25.135667 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/04/22 00:53:25.136034 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:25.136169 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:25.136313 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 1)<--------------]
03/04/22 00:53:30.136759 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 1 running for:11 min)<--------------]
03/04/22 00:53:30.136860 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:30.136923 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/04/22 00:53:30.137102 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:30.137159 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:30.137223 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 1)<--------------]
03/04/22 00:53:35.135216 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 1 running for:11 min)<--------------]
03/04/22 00:53:35.135428 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:35.135570 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/04/22 00:53:35.135962 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:35.136110 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:35.136269 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 1)<--------------]
03/04/22 00:53:38.578423 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 parse of hook: and []]
03/04/22 00:53:38.578569 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 hook start returned with text: json:[] exit:1]
03/04/22 00:53:38.578835 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 For 1 (Camera1-BesderA6-PTZ-1), SHM says: state=0, eid=828]
03/04/22 00:53:38.579212 zmeventnotification[2516].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Event 827 for Monitor 1 has finished]
03/04/22 00:53:40.135297 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 1 running for:12 min)<--------------]
03/04/22 00:53:40.135521 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:40.136071 zmeventnotification[2297].DB1 [main:1006] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del]
03/04/22 00:53:40.136278 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:40.136702 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:40.136850 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:40.137007 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 0)<--------------]
03/04/22 00:53:40.750216 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Event end object is: state=>pending with cause=>Motion: All, New]
03/04/22 00:53:42.800583 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 rules: Checking rules for alarm caused by eid:827, monitor:1, at: Fri Mar  4 00:53:42 2022 with cause:Motion New]
03/04/22 00:53:42.800681 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 rules: No rules found for Monitor, allowing:1]
03/04/22 00:53:42.800772 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Matching alarm to connection rules...]
03/04/22 00:53:42.800887 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Checking alarm conditions for token ending in:...BqYagXnjLX]
03/04/22 00:53:42.801026 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Monitor 1 event: should send out as  265.542560100555 is >= interval of 0]
03/04/22 00:53:42.801090 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 token is unique, shouldSendEventToConn returned true, so calling sendEvent]
03/04/22 00:53:42.801208 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 isAllowedChannel: got type:event_start resCode:1]
03/04/22 00:53:42.801370 zmeventnotification[2516].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Not sending over FCM as notify filters are on_success:all and on_fail:none]
03/04/22 00:53:44.233787 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 child finished writing to parent]
03/04/22 00:53:45.135296 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 0 running for:12 min)<--------------]
03/04/22 00:53:45.174653 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:45.175130 zmeventnotification[2297].DB1 [main:1006] [PARENT: RAW TEXT-->timestamp--TYPE--1646383360.1187--SPLIT--1--SPLIT--1646384022.80113]
03/04/22 00:53:45.175241 zmeventnotification[2297].DB1 [main:1006] [PARENT: Job: Update last sent timestamp of monitor:1 to 1646384022.80113 for id:1646383360.1187]
03/04/22 00:53:45.175343 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:45.175545 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:45.175611 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:45.175684 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 0)<--------------]
03/04/22 00:53:46.235003 zmeventnotification[2516].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 end hooks/use hooks not being used, going to directly send out a notification if checks pass]
03/04/22 00:53:50.095730 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 rules: Checking rules for alarm caused by eid:827, monitor:1, at: Fri Mar  4 00:53:50 2022 with cause:Motion New]
03/04/22 00:53:50.095861 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 rules: No rules found for Monitor, allowing:1]
03/04/22 00:53:50.096103 zmeventnotification[2516].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
03/04/22 00:53:50.135284 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 0 running for:12 min)<--------------]
03/04/22 00:53:50.135466 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:50.135596 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:50.135958 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:50.136081 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:50.136203 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:2, active hooks: 0)<--------------]
03/04/22 00:53:54.101713 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 exiting]
03/04/22 00:53:54.101916 zmeventnotification[2516].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:827 Ending process:2516 to handle alarms]
03/04/22 00:53:55.135085 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:2, active hooks: 0 running for:12 min)<--------------]
03/04/22 00:53:55.135223 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:53:55.135550 zmeventnotification[2297].DB1 [main:1006] [PARENT: RAW TEXT-->active_event_delete--TYPE--1--SPLIT--827]
03/04/22 00:53:55.135661 zmeventnotification[2297].DB1 [main:1006] [PARENT: Job: Deleting active_event eid:827, mid:1]
03/04/22 00:53:55.135773 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:53:55.135987 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:53:55.136054 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:53:55.136128 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:2, active hooks: 0)<--------------]
03/04/22 00:54:00.135267 zmeventnotification[2297].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:0, total forks:2, active hooks: 0 running for:12 min)<--------------]
03/04/22 00:54:00.135439 zmeventnotification[2297].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/04/22 00:54:00.135581 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
03/04/22 00:54:00.135940 zmeventnotification[2297].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/04/22 00:54:00.136074 zmeventnotification[2297].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/04/22 00:54:00.136217 zmeventnotification[2297].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:0, total forks:2, active hooks: 0)<--------------]

zmeventnotification.in
https://pastebin.com/w3CgneFe

objectconfig.ini
https://pastebin.com/0xscCQxs

Thanks in advance for your assistance.
Cheers

[Magic919]

I wouldn't say I've spent loads of time on it, but looking through I'd agree - it finds a person and stops there as is was told to.

I can't see what it thinks it's doing about notifying. Can you try a method other than FCM as a test? I use Pushover and I think I have MQTT.

[asker]

Code: Select all

03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]
03/04/22 00:53:20 zmesdetect_m1[2520] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

I find it odd that is the last debug line in your detect logs.
I wonder if its crashing somewhere. I have no idea which version dlandon packages in his docker image, but make sure its using the latest versions of pyzm/detect and ES.

Then I'd recommend you follow the steps for manual operation for detect first.
https://zmeventnotification.readthedocs ... rking-well

Code: Select all

sudo -u www-data /var/lib/zmeventnotification/bin/zm_detect.py --config /etc/zm/objectconfig.ini  --eventid <eid> --monitorid <mid> --debug

Bottom line, zm_detect.py needs to return back a "detected:" string following what it detected back to the wrapper shell script, zm_event_start.sh. It doesn't seem to even though it looks to have detected a person, and I don't see any filtering logic removing it in your logs. Hence the suspicion its crashing somewhere (or the software version is old and there is a bug, or its latest and there is still a bug )

[linuxnutt]

Detection still not working, I'm really struggling to figure out what is going on. I have gone back through the steps and yet I still can not figure out what is going wrong. Perhaps posting these debug logs will shed some light on what is going wrong.

Asker thanks for your reply.

As far as detection crashing somewhere because the software being out of date, it looks like dlandon docker container seems to be up to date zoneminder is v1.36.12, and I believe these are the latest pyzm/detect and ES
3/13/22 21:45:13 zmesdetect_m1[28426] INF zm_detect.py:271 [---------| app:6.1.23, pyzm:0.3.55, ES:6.1.23 , OpenCV:4.5.3|------------]

I need help troubleshooting these outputs for manual zm_detect.py and zm_event_start.sh.

When I run zm_detect.py manually I get a very ominous "Illegal instruction" and everything stops.(See manual zm_detect.py below).

While running zm_event_start.sh manually I get the following output. I believe there should be more? Should there be a different output here if things are working correctly?

sudo -u www-data '/var/lib/zmeventnotification/bin/zm_event_start.sh' 1517 1

[ WARN:0] global /root/opencv/modules/dnn/src/dnn.cpp (1451) setUpNet DNN module was not built with CUDA backend; switching to CPU

Please let me know what you think and let me know if you need me to try different things.

******

Below I'm using event 1517 first with manual debug detection and next the same event with tail -F for /zmesdetect*.log and zmeventnotification.log for a compare and contrast between the two. Hopefully this will allow someone to see something from someone who understands the log out better than me.

Event 1517 manually invoke the detection module:
sudo -u www-data /var/lib/zmeventnotification/bin/zm_detect.py --config /etc/zm/objectconfig.ini --eventid 1517 --monitorid 1 --debug

---AND----

tail -F /var/log/zm/zmesdetect*.log /var/log/zm/zmeventnotification.log for the 1517

******

Code: Select all

********************************
Event 1517
********************************
root@30656f8d7a9e:/# sudo -u www-data /var/lib/zmeventnotification/bin/zm_detect.py --config /etc/zm/objectconfig.ini  --eventid 1517 --monitorid 1 --debug
03/13/22 19:36:11 zmesdetect_m1[27301] INF ZMLog.py:292 [Setting up signal handler for logs]

03/13/22 19:36:11 zmesdetect_m1[27301] INF ZMLog.py:301 [Switching global logger to ZMLog]

03/13/22 19:36:11 zmesdetect_m1[27301] INF zm_detect.py:271 [---------| app:6.1.23, pyzm:0.3.55, ES:6.1.23 , OpenCV:4.5.3|------------]

03/13/22 19:36:11 zmesdetect_m1[27301] INF utils.py:406 [Reading config from: /etc/zm/objectconfig.ini]

03/13/22 19:36:11 zmesdetect_m1[27301] INF utils.py:411 [Reading secrets from: /etc/zm/secrets.ini]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !ML_USER]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG1 utils.py:446 [allowing self-signed certs to work...]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG4 utils.py:456 [Now checking for monitor overrides]

03/13/22 19:36:11 zmesdetect_m1[27301] DBG4 utils.py:524 [Finally, doing parameter substitution]

03/13/22 19:36:11 zmesdetect_m1[27301] INF zm_detect.py:296 [Importing local classes for Object/Face]

03/13/22 19:36:12 zmesdetect_m1[27301] INF zm_detect.py:321 [Connecting with ZM APIs]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 api.py:72 [API SSL certificate check has been disbled]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 api.py:181 [using username/password for login]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 api.py:210 [Using new token API]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 api.py:217 [Access token expires on:2022-03-13 21:36:12.287294 [7200s]]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 api.py:221 [Refresh token expires on:2022-03-14 19:36:12.289341 [86400s]]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 zm_detect.py:329 [using ml_sequence]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 zm_detect.py:341 [using stream_sequence]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 detect_sequence.py:160 [Resetting models, will be loaded on next run]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG3 detect_sequence.py:634 [Using automatic locking as we are switching between models]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 Media.py:99 [Using URL 1517 for stream]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 Media.py:137 [No need to start streams, we are picking images from https://192.168.1.50:8443/zm/index.php?view=image&eid=1517]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG3 Media.py:271 [Reading https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=snapshot]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG3 api.py:144 [No need to relogin as access token still has 119.99967271666667 minutes remaining]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG3 api.py:272 [make_request called with url=https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=snapshot payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjQ3MjI1MzcyLCJleHAiOjE2NDcyMzI1NzIsInVzZXIiOiJzdGV2ZSIsInR5cGUiOiJhY2Nlc3MifQ.6VV8WU6S56ID-bsK4k1ru64uVTf1P13fMsLQVQzbwqg'}]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 detect_sequence.py:654 [perf: Starting for frame:snapshot]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object', 'face', 'alpr']]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running object detection type in sequence ==================]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 detect_sequence.py:174 [Skipping TPU object detection as it is disabled]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 detect_sequence.py:178 [Loading sequence: YoloV4 GPU/CPU]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 detect_sequence.py:179 [Initializing model  type:object with options:{'name': 'YoloV4 GPU/CPU', 'enabled': 'yes', 'object_config': '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg', 'object_wBelow I'm using event 1517 first with manual debug detection and next the same event with tail -F for /zmesdetect*.log and zmeventnotification.log for a compare and contrast between the two. Hopefully this will allow eights': '/var/lib/zmeventnotification/models/yolov4/yolov4.weights', 'object_labels': '/var/lib/zmeventnotification/models/yolov4/coco.names', 'object_min_confidence': 0.3, 'object_framework': 'opencv', 'object_processor': 'gpu', 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_processes': 3, 'cpu_max_lock_wait': 100, 'max_detection_size': '90%', 'disable_locks': 'no'}]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 yolo.py:37 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 detect_sequence.py:701 [--------- Frame:snapshot Running variation: #1 -------------]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx600h]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 yolo.py:49 [Waiting for pyzm_uid33_gpu_lock portalock...]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG2 yolo.py:51 [Got pyzm_uid33_gpu_lock portalock]

03/13/22 19:36:12 zmesdetect_m1[27301] DBG1 yolo.py:84 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]

03/13/22 19:36:13 zmesdetect_m1[27301] DBG1 yolo.py:91 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 926.24 ms]

03/13/22 19:36:13 zmesdetect_m1[27301] DBG2 yolo.py:107 [Setting CUDA backend for OpenCV]

03/13/22 19:36:13 zmesdetect_m1[27301] DBG3 yolo.py:108 [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]

03/13/22 19:36:13 zmesdetect_m1[27301] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*600h, model resize dimensions: 416w*416h) ----------|]

[ WARN:0] global /root/opencv/modules/dnn/src/dnn.cpp (1451) setUpNet DNN module was not built with CUDA backend; switching to CPU
03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 yolo.py:67 [Released pyzm_uid33_gpu_lock portalock]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG1 yolo.py:173 [perf: processor:gpu Yolo detection took: 1739.18 ms]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 yolo.py:208 [perf: processor:gpu Yolo NMS filtering took: 1.04 ms]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 object.py:66 [core model detection over, got 1 objects. Now filtering]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 object.py:70 [Max object size found to be: 90%]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 object.py:78 [Converted 90% to 432000.0]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 object.py:103 [Returning filtered list of 1 objects.]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:711 [This model iteration inside object found: labels: ['person'],conf:[0.6926378607749939]]  ##### Person detected #######

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:448 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (640, 0), (640, 480), (0, 480)], 'pattern': None}]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG3 detect_sequence.py:228 [resized polygons x=1.25/y=1.25: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 600), (0, 600)], 'pattern': None}]]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((-2 11, 332 11, 332 597, -2 597, -2 11)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(-2, 11), (332, 11), (332, 597), (-2, 597)]]]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

Illegal instruction ########### WHAT IS THIS ?? ###############

root@30656f8d7a9e:# 


End of Debug

********************************
********************************

tail -F /var/log/zm/zmesdetect*.log /var/log/zm/zmeventnotification.log for the 1517

Code: Select all

root@30656f8d7a9e:/# tail -F  /var/log/zm/zmesdetect*.log /var/log/zm/zmeventnotification.log

03/13/22 19:06:40.768892 zmeventnotification[1440].INF [main:1018] [PARENT: New event 1517 reported for Monitor:1 (Name:Camera1-BesderA6-PTZ-1) Motion All[last processed eid:1516]]  #############Start 1517 ##########
03/13/22 19:06:40.770690 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=1]
03/13/22 19:06:40.770787 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 new Events to process]
03/13/22 19:06:40.774706 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:162, active hooks: 0)<--------------]
03/13/22 19:06:40.774966 zmeventnotification[26917].DB1 [ZoneMinder::Logger:321] [LogOpts: level=DB4/DB1, screen=OFF, database=INF, logfile=DB1->/var/log/zm/zmeventnotification.log, syslog=INF]
03/13/22 19:06:40.775177 zmeventnotification[26917].DB1 [main:1006] [PARENT: Forked process:26917 to handle alarm eid:1517]
03/13/22 19:06:40.775534 zmeventnotification[26917].DB1 [ZoneMinder::Object:125] [Loading ZoneMinder::Event from Events WHERE Id = 1517]
03/13/22 19:06:40.777658 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Adding event path:/var/cache/zoneminder/events/1/2022-03-13/1517 to hook for image storage]
03/13/22 19:06:40.777758 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 1517 1 "Camera1-BesderA6-PTZ-1" "Motion All" "/var/cache/zoneminder/events/1/2022-03-13/1517"]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:06:42 zmesdetect_m1[26921] INF ZMLog.py:292 [Setting up signal handler for logs]
03/13/22 19:06:42 zmesdetect_m1[26921] INF ZMLog.py:301 [Switching global logger to ZMLog]
03/13/22 19:06:42 zmesdetect_m1[26921] INF zm_detect.py:271 [---------| app:6.1.23, pyzm:0.3.55, ES:6.1.23 , OpenCV:4.5.3|------------]
03/13/22 19:06:42 zmesdetect_m1[26921] INF utils.py:406 [Reading config from: /etc/zm/objectconfig.ini]
03/13/22 19:06:42 zmesdetect_m1[26921] INF utils.py:411 [Reading secrets from: /etc/zm/secrets.ini]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !ML_USER]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG1 utils.py:446 [allowing self-signed certs to work...]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG4 utils.py:456 [Now checking for monitor overrides]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG4 utils.py:524 [Finally, doing parameter substitution]
03/13/22 19:06:42 zmesdetect_m1[26921] INF zm_detect.py:296 [Importing local classes for Object/Face]
03/13/22 19:06:42 zmesdetect_m1[26921] INF zm_detect.py:321 [Connecting with ZM APIs]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 api.py:72 [API SSL certificate check has been disbled]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG1 api.py:181 [using username/password for login]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 api.py:210 [Using new token API]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG1 api.py:217 [Access token expires on:2022-03-13 21:06:42.966877 [7200s]]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG1 api.py:221 [Refresh token expires on:2022-03-14 19:06:42.968109 [86400s]]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 zm_detect.py:329 [using ml_sequence]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 zm_detect.py:341 [using stream_sequence]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG1 detect_sequence.py:160 [Resetting models, will be loaded on next run]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG3 detect_sequence.py:634 [Using automatic locking as we are switching between models]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 Media.py:99 [Using URL 1517 for stream]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG2 Media.py:137 [No need to start streams, we are picking images from https://192.168.1.50:8443/zm/index.php?view=image&eid=1517]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG3 Media.py:271 [Reading https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=snapshot]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG3 api.py:144 [No need to relogin as access token still has 119.9996919 minutes remaining]
03/13/22 19:06:42 zmesdetect_m1[26921] DBG3 api.py:272 [make_request called with url=https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=snapshot payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjQ3MjIzNjAyLCJleHAiOjE2NDcyMzA4MDIsInVzZXIiOiJzdGV2ZSIsInR5cGUiOiJhY2Nlc3MifQ.Pm4Ux_6wM1mva3exX3lvBKkqJB76iG2y8WU3i6usbKk'}]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 detect_sequence.py:654 [perf: Starting for frame:snapshot]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object', 'face', 'alpr']]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running object detection type in sequence ==================]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 detect_sequence.py:174 [Skipping TPU object detection as it is disabled]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 detect_sequence.py:178 [Loading sequence: YoloV4 GPU/CPU]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 detect_sequence.py:179 [Initializing model  type:object with options:{'name': 'YoloV4 GPU/CPU', 'enabled': 'yes', 'object_config': '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg', 'object_weights': '/var/lib/zmeventnotification/models/yolov4/yolov4.weights', 'object_labels': '/var/lib/zmeventnotification/models/yolov4/coco.names', 'object_min_confidence': 0.3, 'object_framework': 'opencv', 'object_processor': 'gpu', 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_processes': 3, 'cpu_max_lock_wait': 100, 'max_detection_size': '90%', 'disable_locks': 'no'}]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 yolo.py:37 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 detect_sequence.py:701 [--------- Frame:snapshot Running variation: #1 -------------]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx600h]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 yolo.py:49 [Waiting for pyzm_uid33_gpu_lock portalock...]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 yolo.py:51 [Got pyzm_uid33_gpu_lock portalock]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 yolo.py:84 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 yolo.py:91 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 385.32 ms]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG2 yolo.py:107 [Setting CUDA backend for OpenCV]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG3 yolo.py:108 [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]
03/13/22 19:06:43 zmesdetect_m1[26921] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*600h, model resize dimensions: 416w*416h) ----------|]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 yolo.py:67 [Released pyzm_uid33_gpu_lock portalock]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG1 yolo.py:173 [perf: processor:gpu Yolo detection took: 2104.76 ms]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:06:45.764244 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:162, active hooks: 0 running for:4276 min)<--------------]
03/13/22 19:06:45.764388 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:06:45.764706 zmeventnotification[1440].DB1 [main:1006] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add]
03/13/22 19:06:45.764790 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/13/22 19:06:45.783566 zmeventnotification[1440].DB1 [main:1006] [PARENT: Total event client connections: 1]
03/13/22 19:06:45.783698 zmeventnotification[1440].DB1 [main:1006] [PARENT: -->checkNewEvents: Connection 1: ID->1647223391.40582 IP->192.168.1.110 Token->:...BqYagXnjLX Plat:android Push:enabled]
03/13/22 19:06:45.784333 zmeventnotification[1440].INF [main:1018] [PARENT: Re-loading monitors]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 yolo.py:208 [perf: processor:gpu Yolo NMS filtering took: 1.15 ms]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 object.py:66 [core model detection over, got 1 objects. Now filtering]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 object.py:70 [Max object size found to be: 90%]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 object.py:78 [Converted 90% to 432000.0]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 object.py:103 [Returning filtered list of 1 objects.]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:711 [This model iteration inside object found: labels: ['person'],conf:[0.6926378607749939]]    ############ Person Detected ############
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:448 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (640, 0), (640, 480), (0, 480)], 'pattern': None}]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG3 detect_sequence.py:228 [resized polygons x=1.25/y=1.25: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 600), (0, 600)], 'pattern': None}]]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((-2 11, 332 11, 332 597, -2 597, -2 11)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(-2, 11), (332, 11), (332, 597), (-2, 597)]]]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]
03/13/22 19:06:45 zmesdetect_m1[26921] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:06:45.907016 zmeventnotification[1440].DB1 [main:1006] [PARENT: Loading Camera1-BesderA6-PTZ-1]
03/13/22 19:06:45.907131 zmeventnotification[1440].DB1 [main:1006] [PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data]
03/13/22 19:06:45.907347 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/13/22 19:06:45.907455 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/13/22 19:06:45.907609 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:162, active hooks: 1)<--------------]
03/13/22 19:06:50.768169 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:162, active hooks: 1 running for:4276 min)<--------------]
03/13/22 19:06:50.768336 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:06:50.768442 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/13/22 19:06:50.768764 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/13/22 19:06:50.768863 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/13/22 19:06:50.768974 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:162, active hooks: 1)<--------------]
03/13/22 19:06:55.767753 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:162, active hooks: 1 running for:4276 min)<--------------]
03/13/22 19:06:55.767871 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:06:55.767934 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/13/22 19:06:55.768157 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/13/22 19:06:55.768218 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/13/22 19:06:55.768281 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:1, total forks:162, active hooks: 1)<--------------]
03/13/22 19:07:00.768226 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:1, total forks:162, active hooks: 1 running for:4276 min)<--------------]
03/13/22 19:07:00.768348 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:07:00.768418 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/13/22 19:07:00.768655 zmeventnotification[1440].DB1 [main:1006] [PARENT: Closing unclosed event:1517 of Monitor:1 as we are in a new event]
03/13/22 19:07:00.769302 zmeventnotification[1440].INF [main:1018] [PARENT: New event 1518 reported for Monitor:1 (Name:Camera1-BesderA6-PTZ-1) Motion New[last processed eid:1517]]
03/13/22 19:07:01.383549 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=1]
03/13/22 19:07:01.383699 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 new Events to process]
03/13/22 19:07:01.388689 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:2, total forks:163, active hooks: 1)<--------------]
03/13/22 19:07:01.389204 zmeventnotification[26976].DB1 [ZoneMinder::Logger:321] [LogOpts: level=DB4/DB1, screen=OFF, database=INF, logfile=DB1->/var/log/zm/zmeventnotification.log, syslog=INF]
03/13/22 19:07:01.389381 zmeventnotification[26976].DB1 [main:1006] [PARENT: Forked process:26976 to handle alarm eid:1518]
03/13/22 19:07:01.389939 zmeventnotification[26976].DB1 [ZoneMinder::Object:125] [Loading ZoneMinder::Event from Events WHERE Id = 1518]
03/13/22 19:07:01.392257 zmeventnotification[26976].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1518 Adding event path:/var/cache/zoneminder/events/1/2022-03-13/1518 to hook for image storage]
03/13/22 19:07:01.392353 zmeventnotification[26976].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1518 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 1518 1 "Camera1-BesderA6-PTZ-1" "Motion New" "/var/cache/zoneminder/events/1/2022-03-13/1518"]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:05 zmesdetect_m1[26980] INF ZMLog.py:292 [Setting up signal handler for logs]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:05.764161 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:2, total forks:163, active hooks: 1 running for:4276 min)<--------------]
03/13/22 19:07:05.764320 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:07:05.764665 zmeventnotification[1440].DB1 [main:1006] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add]
03/13/22 19:07:05.764748 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 2 active child forks & 2 zm_detect processes running...]
03/13/22 19:07:05.765056 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/13/22 19:07:05.765116 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/13/22 19:07:05.765189 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:2, total forks:163, active hooks: 2)<--------------]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:05 zmesdetect_m1[26980] INF ZMLog.py:301 [Switching global logger to ZMLog]
03/13/22 19:07:06 zmesdetect_m1[26980] INF zm_detect.py:271 [---------| app:6.1.23, pyzm:0.3.55, ES:6.1.23 , OpenCV:4.5.3|------------]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:06.564078 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 parse of hook: and []]
03/13/22 19:07:06.564249 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 hook start returned with text: json:[] exit:1]  ########## Exiting without finding anything ###########
03/13/22 19:07:06.564655 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 For 1 (Camera1-BesderA6-PTZ-1), SHM says: state=0, eid=1518]
03/13/22 19:07:06.565092 zmeventnotification[26917].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Event 1517 for Monitor 1 has finished]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:07 zmesdetect_m1[26980] INF utils.py:406 [Reading config from: /etc/zm/objectconfig.ini]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:06.963669 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Event end object is: state=>pending with cause=>Motion: All, New]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:08 zmesdetect_m1[26980] INF utils.py:411 [Reading secrets from: /etc/zm/secrets.ini]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !ML_USER]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG1 utils.py:446 [allowing self-signed certs to work...]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG4 utils.py:456 [Now checking for monitor overrides]
03/13/22 19:07:08 zmesdetect_m1[26980] DBG4 utils.py:524 [Finally, doing parameter substitution]
03/13/22 19:07:09 zmesdetect_m1[26980] INF zm_detect.py:296 [Importing local classes for Object/Face]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:08.964746 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 rules: Checking rules for alarm caused by eid:1517, monitor:1, at: Sun Mar 13 19:07:08 2022 with cause:Motion All]
03/13/22 19:07:08.964936 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 rules: No rules found for Monitor, allowing:1]
03/13/22 19:07:08.965164 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Matching alarm to connection rules...]
03/13/22 19:07:08.965427 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Checking alarm conditions for 192.168.1.110:53176, token ending in:...BqYagXnjLX]
03/13/22 19:07:08.965716 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Monitor 1 event: should send out as  154.074079990387 is >= interval of 0]
03/13/22 19:07:08.965864 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 token is unique, shouldSendEventToConn returned true, so calling sendEvent]
03/13/22 19:07:08.966133 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 isAllowedChannel: got type:event_start resCode:1]
03/13/22 19:07:08.966452 zmeventnotification[26917].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Not sending over FCM as notify filters are on_success:all and on_fail:none]conf
03/13/22 19:07:09.586780 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 child finished writing to parent]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:09 zmesdetect_m1[26980] INF zm_detect.py:321 [Connecting with ZM APIs]
03/13/22 19:07:09 zmesdetect_m1[26980] DBG2 api.py:72 [API SSL certificate check has been disbled]
03/13/22 19:07:09 zmesdetect_m1[26980] DBG1 api.py:181 [using username/password for login]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:10.768329 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:2, total forks:163, active hooks: 2 running for:4276 min)<--------------]
03/13/22 19:07:10.815431 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:07:10.815761 zmeventnotification[1440].DB1 [main:1006] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del]
03/13/22 19:07:10.816085 zmeventnotification[1440].DB1 [main:1006] [PARENT: RAW TEXT-->timestamp--TYPE--1647223391.40582--SPLIT--1--SPLIT--1647223628.96597]
03/13/22 19:07:10.816190 zmeventnotification[1440].DB1 [main:1006] [PARENT: Job: Update last sent timestamp of monitor:1 to 1647223628.96597 for id:1647223391.40582]
03/13/22 19:07:10.816283 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 2 active child forks & 1 zm_detect processes running...]
03/13/22 19:07:10.816476 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/13/22 19:07:10.816541 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/13/22 19:07:10.816613 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:2, total forks:163, active hooks: 1)<--------------]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 api.py:210 [Using new token API]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 api.py:217 [Access token expires on:2022-03-13 21:07:11.034541 [7200s]]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 api.py:221 [Refresh token expires on:2022-03-14 19:07:11.036061 [86400s]]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 zm_detect.py:329 [using ml_sequence]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 zm_detect.py:341 [using stream_sequence]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 detect_sequence.py:160 [Resetting models, will be loaded on next run]conf
03/13/22 19:07:11 zmesdetect_m1[26980] DBG3 detect_sequence.py:634 [Using automatic locking as we are switching between models]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 Media.py:99 [Using URL 1518 for stream]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 Media.py:137 [No need to start streams, we are picking images from https://192.168.1.50:8443/zm/index.php?view=image&eid=1518]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG3 Media.py:271 [Reading https://192.168.1.50:8443/zm/index.php?view=image&eid=1518&fid=snapshot]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG3 api.py:144 [No need to relogin as access token still has 119.99970088333333 minutes remaining]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG3 api.py:272 [make_request called with url=https://192.168.1.50:8443/zm/index.php?view=image&eid=1518&fid=snapshot payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjQ3MjIzNjMxLCJleHAiOjE2NDcyMzA4MzEsInVzZXIiOiJzdGV2ZSIsInR5cGUiOiJhY2Nlc3MifQ.GCscnrfsLmWzJROOzAnLqyP3Bm3uH6QexFRNwGAl3ao'}]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 detect_sequence.py:654 [perf: Starting for frame:snapshot]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object', 'face', 'alpr']]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running object detection type in sequence ==================]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 detect_sequence.py:174 [Skipping TPU object detection as it is disabled]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 detect_sequence.py:178 [Loading sequence: YoloV4 GPU/CPU]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 detect_sequence.py:179 [Initializing model  type:object with options:{'name': 'YoloV4 GPU/CPU', 'enabled': 'yes', 'object_config': '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg', 'object_weights': '/var/lib/zmeventnotification/models/yolov4/yolov4.weights', 'object_labels': '/var/lib/zmeventnotification/models/yolov4/coco.names', 'object_min_confidence': 0.3, 'object_framework': 'opencv', 'object_processor': 'gpu', 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_processes': 3, 'cpu_max_lock_wait': 100, 'max_detection_size': '90%', 'disable_locks': 'no'}]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 yolo.py:37 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 detect_sequence.py:701 [--------- Frame:snapshot Running variation: #1 -------------]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx600h]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 yolo.py:49 [Waiting for pyzm_uid33_gpu_lock portalock...]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 yolo.py:51 [Got pyzm_uid33_gpu_lock portalock]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 yolo.py:84 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 yolo.py:91 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 147.62 ms]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG2 yolo.py:107 [Setting CUDA backend for OpenCV]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG3 yolo.py:108 [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]
03/13/22 19:07:11 zmesdetect_m1[26980] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*600h, model resize dimensions: 416w*416h) ----------|]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:11.587776 zmeventnotification[26917].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 end hooks/use hooks not being used, going to directly send out a notification if checks pass]

==> /var/log/zm/zmesdetect_m1.log <==
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 yolo.py:67 [Released pyzm_uid33_gpu_lock portalock]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG1 yolo.py:173 [perf: processor:gpu Yolo detection took: 1915.62 ms]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 yolo.py:208 [perf: processor:gpu Yolo NMS filtering took: 1.35 ms]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 object.py:66 [core model detection over, got 1 objects. Now filtering]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 object.py:70 [Max object size found to be: 90%]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 object.py:78 [Converted 90% to 432000.0]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 object.py:103 [Returning filtered list of 1 objects.]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:711 [This model iteration inside object found: labels: ['person'],conf:[0.6926378607749939]]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:448 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (640, 0), (640, 480), (0, 480)], 'pattern': None}]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG3 detect_sequence.py:228 [resized polygons x=1.25/y=1.25: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 600), (0, 600)], 'pattern': None}]]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((-2 11, 332 11, 332 597, -2 597, -2 11)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(-2, 11), (332, 11), (332, 597), (-2, 597)]]]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]
03/13/22 19:07:13 zmesdetect_m1[26980] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

==> /var/log/zm/zmeventnotification.log <==
03/13/22 19:07:14.656957 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 rules: Checking rules for alarm caused by eid:1517, monitor:1, at: Sun Mar 13 19:07:14 2022 with cause:Motion All]
03/13/22 19:07:14.657153 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 rules: No rules found for Monitor, allowing:1]
03/13/22 19:07:14.657476 zmeventnotification[26917].INF [main:1018] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
03/13/22 19:07:15.764229 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:2, total forks:163, active hooks: 1 running for:4276 min)<--------------]
03/13/22 19:07:15.764377 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:07:15.764481 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 2 active child forks & 1 zm_detect processes running...]
03/13/22 19:07:15.764776 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=0]
03/13/22 19:07:15.764863 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 0 new Events to process]
03/13/22 19:07:15.764976 zmeventnotification[1440].DB1 [main:1006] [PARENT: ---------->Tick END (active forks:2, total forks:163, active hooks: 1)<--------------]
03/13/22 19:07:19.068215 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 exiting]
03/13/22 19:07:19.068339 zmeventnotification[26917].DB1 [main:1006] [|----> FORK:Camera1-BesderA6-PTZ-1 (1), eid:1517 Ending process:26917 to handle alarms]
03/13/22 19:07:20.768219 zmeventnotification[1440].DB1 [main:1006] [PARENT: ----------> Tick START (active forks:2, total forks:163, active hooks: 1 running for:4276 min)<--------------]
03/13/22 19:07:20.768346 zmeventnotification[1440].DB1 [main:1006] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 1, FCM+WEB: 1, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
03/13/22 19:07:20.768690 zmeventnotification[1440].DB1 [main:1006] [PARENT: RAW TEXT-->active_event_delete--TYPE--1--SPLIT--1517]
03/13/22 19:07:20.768810 zmeventnotification[1440].DB1 [main:1006] [PARENT: Job: Deleting active_event eid:1517, mid:1]           ############# 1517 Deletion #############
03/13/22 19:07:20.768958 zmeventnotification[1440].DB1 [main:1006] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
03/13/22 19:07:20.769224 zmeventnotification[1440].DB1 [main:1006] [PARENT: Closing unclosed event:1518 of Monitor:1 as we are in a new event]
03/13/22 19:07:20.770025 zmeventnotification[1440].INF [main:1018] [PARENT: New event 1519 reported for Monitor:1 (Name:Camera1-BesderA6-PTZ-1) Motion All[last processed eid:1518]]
03/13/22 19:07:21.221274 zmeventnotification[1440].DB1 [main:1006] [PARENT: checkEvents() new events found=1]

Thanks in advance for the help!!!!

[asker]

So your output for

Code: Select all

sudo -u www-data /var/lib/zmeventnotification/bin/zm_detect.py --config /etc/zm/objectconfig.ini --eventid 1517 --monitorid 1 --debug

is really what we need to focus on. It's crashing (Illegal instruction) right after object detection is performed which explains why the ES is not receiving detected data.

Looking at your logs, it is crashing when it is trying to do face detection right after object detection.

03/13/22 19:36:15 zmesdetect_m1[27301] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]

03/13/22 19:36:15 zmesdetect_m1[27301] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

Chances are very high you haven't set up face detection properly. In your "ml_sequence" area of objectconfig.ini, set the 'enabled' key to 'no' for the DLIB face detection part. I'd highly recommend you set all ml_sequence sub sections to 'enabled': 'no' except for your object detection part to make sure you are only using what you need. Then turn them on one by one (for the ones you configure correctly for your environment)
As an aside, you may also want to set yolo4_object_processor=cpu in your config (line 214) as it looks like you don't have a GPU (or openCV is not compiled for GPU support)

Re-run the manual command above again.

[linuxnutt]

Oh My, Hurrah, Hallelujah, THANKS ASKER, IT IS WORKING !!!
I've been working on getting this to work for LONG LONG TIME now, so its really a relief to see it actually working.
Thanks Again for your help!!!!!!

So, here is what I did and yes of course you were spot on 100% right it was just two easy changes in the objectconfig.ini file.

Asker wrote,
"In your "ml_sequence" area of objectconfig.ini, set the 'enabled' key to 'no' for the DLIB face detection part."

Should be "no" as I haven't setup face detection. Only object detectin at this time.
***
root@30656f8d7a9e:/config/hook# cat objectconfig.ini | grep -i 'sln\|DLIB\|enabled'
...
'name': 'DLIB based face recognition',
### Changed sln 3-25-22 enabled was yes ###
'enabled': 'no',

AND,

Asker wrote,
"As an aside, you may also want to set yolo4_object_processor=cpu in your config (line 214) as it looks like you don't have a GPU (or openCV is not compiled for GPU support)"

Interesting I thought it would use CPU if there was no GPU, "Yolo v4 on GPU (falls back to CPU if no GPU)", but perhaps telling yolo4_object_processor to use cpu spread up the detection process? I didn't have a GPU or a TPU setup on this machine, so just using CPU (for now). Even so the CPU detection rate on eid 2480 was only 5.04103 seconds not bad.

***
cat objectconfig.ini | grep -i 'sln\|enabled\|cpu\|DLIB'
...
# Yolo v4 on GPU (falls back to CPU if no GPU)
### Added sln 3/25/2022 was gpu
yolo4_object_processor=cpu

And after these changes ran debug and it looked like it was working so I walked in front of the camera and started getting alert notifications on zmNinja on my tablet... I'm a happy camper!

Now I know what the actual debug looks like for a successful detection, and now the log file should look as well .. here are those exhibits in case anyone want to reference or needs a reference.

Debug Event 1517

Code: Select all

# sudo -u www-data /var/lib/zmeventnotification/bin/zm_detect.py --config /etc/zm/objectconfig.ini --eventid 1517 --monitorid 1 --debug
03/25/22 15:00:30 zmesdetect_m1[9273] INF ZMLog.py:292 [Setting up signal handler for logs]

03/25/22 15:00:30 zmesdetect_m1[9273] INF ZMLog.py:301 [Switching global logger to ZMLog]

03/25/22 15:00:30 zmesdetect_m1[9273] INF zm_detect.py:271 [---------| app:6.1.23, pyzm:0.3.55, ES:6.1.23 , OpenCV:4.5.3|------------]

03/25/22 15:00:30 zmesdetect_m1[9273] INF utils.py:406 [Reading config from: /etc/zm/objectconfig.ini]

03/25/22 15:00:30 zmesdetect_m1[9273] INF utils.py:411 [Reading secrets from: /etc/zm/secrets.ini]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !ML_USER]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG1 utils.py:446 [allowing self-signed certs to work...]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG4 utils.py:456 [Now checking for monitor overrides]

03/25/22 15:00:30 zmesdetect_m1[9273] DBG4 utils.py:524 [Finally, doing parameter substitution]

03/25/22 15:00:30 zmesdetect_m1[9273] INF zm_detect.py:296 [Importing local classes for Object/Face]

03/25/22 15:00:31 zmesdetect_m1[9273] INF zm_detect.py:321 [Connecting with ZM APIs]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 api.py:72 [API SSL certificate check has been disbled]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 api.py:181 [using username/password for login]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 api.py:210 [Using new token API]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 api.py:217 [Access token expires on:2022-03-25 17:00:31.369479 [7200s]]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 api.py:221 [Refresh token expires on:2022-03-26 15:00:31.371098 [86400s]]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 zm_detect.py:329 [using ml_sequence]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 zm_detect.py:341 [using stream_sequence]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 detect_sequence.py:160 [Resetting models, will be loaded on next run]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG3 detect_sequence.py:634 [Using automatic locking as we are switching between models]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 Media.py:99 [Using URL 1517 for stream]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 Media.py:137 [No need to start streams, we are picking images from https://192.168.1.50:8443/zm/index.php?view=image&eid=1517]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG3 Media.py:271 [Reading https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=snapshot]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG3 api.py:144 [No need to relogin as access token still has 119.99970873333334 minutes remaining]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG3 api.py:272 [make_request called with url=https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=snapshot payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjQ4MjQ1NjMxLCJleHAiOjE2NDgyNTI4MzEsInVzZXIiOiJzdGV2ZSIsInR5cGUiOiJhY2Nlc3MifQ.y-sAeuqFTJVaTSjbHDUC4i6jXXjnXssN1aXgtc6N_YM'}]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 detect_sequence.py:654 [perf: Starting for frame:snapshot]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object', 'face', 'alpr']]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running object detection type in sequence ==================]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 detect_sequence.py:174 [Skipping TPU object detection as it is disabled]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 detect_sequence.py:178 [Loading sequence: YoloV4 GPU/CPU]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 detect_sequence.py:179 [Initializing model  type:object with options:{'name': 'YoloV4 GPU/CPU', 'enabled': 'yes', 'object_config': '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg', 'object_weights': '/var/lib/zmeventnotification/models/yolov4/yolov4.weights', 'object_labels': '/var/lib/zmeventnotification/models/yolov4/coco.names', 'object_min_confidence': 0.3, 'object_framework': 'opencv', 'object_processor': 'cpu', 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_processes': 3, 'cpu_max_lock_wait': 100, 'max_detection_size': '90%', 'disable_locks': 'no'}]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 yolo.py:37 [portalock: max:3, name:pyzm_uid33_cpu_lock, timeout:100]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 detect_sequence.py:701 [--------- Frame:snapshot Running variation: #1 -------------]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx600h]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 yolo.py:49 [Waiting for pyzm_uid33_cpu_lock portalock...]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG2 yolo.py:51 [Got pyzm_uid33_cpu_lock portalock]

03/25/22 15:00:31 zmesdetect_m1[9273] DBG1 yolo.py:84 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]

03/25/22 15:00:32 zmesdetect_m1[9273] DBG1 yolo.py:91 [perf: processor:cpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 949.23 ms]

03/25/22 15:00:32 zmesdetect_m1[9273] DBG1 yolo.py:104 [Using CPU for detection]

03/25/22 15:00:32 zmesdetect_m1[9273] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*600h, model resize dimensions: 416w*416h) ----------|]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 yolo.py:67 [Released pyzm_uid33_cpu_lock portalock]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 yolo.py:173 [perf: processor:cpu Yolo detection took: 1949.97 ms]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 yolo.py:208 [perf: processor:cpu Yolo NMS filtering took: 8.20 ms]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 object.py:66 [core model detection over, got 1 objects. Now filtering]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 object.py:70 [Max object size found to be: 90%]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 object.py:78 [Converted 90% to 432000.0]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 object.py:103 [Returning filtered list of 1 objects.]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:711 [This model iteration inside object found: labels: ['person'],conf:[0.6926378607749939]]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:448 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (640, 0), (640, 480), (0, 480)], 'pattern': None}]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG3 detect_sequence.py:228 [resized polygons x=1.25/y=1.25: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 600), (0, 600)], 'pattern': None}]]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((-2 11, 332 11, 332 597, -2 597, -2 11)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(-2, 11), (332, 11), (332, 597), (-2, 597)]]]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running face detection type in sequence ==================]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:190 [Skipping DLIB based face recognition as it is disabled]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG3 detect_sequence.py:689 [face has a same_model_sequence strategy of union]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:770 [We did not find any face matches in frame: snapshot]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running alpr detection type in sequence ==================]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 detect_sequence.py:672 [Making sure we have matched one of ['car', 'motorbike', 'bus', 'truck', 'boat'] in ['person'] before we proceed]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:674 [Did not find pre existing labels, not running detection type]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG3 Media.py:271 [Reading https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=alarm]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG3 api.py:144 [No need to relogin as access token still has 119.94399360000001 minutes remaining]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG3 api.py:272 [make_request called with url=https://192.168.1.50:8443/zm/index.php?view=image&eid=1517&fid=alarm payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjQ4MjQ1NjMxLCJleHAiOjE2NDgyNTI4MzEsInVzZXIiOiJzdGV2ZSIsInR5cGUiOiJhY2Nlc3MifQ.y-sAeuqFTJVaTSjbHDUC4i6jXXjnXssN1aXgtc6N_YM'}]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:654 [perf: Starting for frame:alarm]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object', 'face', 'alpr']]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:669 [============ Frame: alarm Running object detection type in sequence ==================]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 detect_sequence.py:701 [--------- Frame:alarm Running variation: #1 -------------]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx600h]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 yolo.py:49 [Waiting for pyzm_uid33_cpu_lock portalock...]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG2 yolo.py:51 [Got pyzm_uid33_cpu_lock portalock]

03/25/22 15:00:34 zmesdetect_m1[9273] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*600h, model resize dimensions: 416w*416h) ----------|]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 yolo.py:67 [Released pyzm_uid33_cpu_lock portalock]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 yolo.py:173 [perf: processor:cpu Yolo detection took: 1577.51 ms]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 yolo.py:208 [perf: processor:cpu Yolo NMS filtering took: 1.31 ms]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:66 [core model detection over, got 9 objects. Now filtering]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:70 [Max object size found to be: 90%]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:78 [Converted 90% to 432000.0]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:101 [Ignoring book [22, 420, 86, 444] as conf. level 0.2532336413860321 is lower than 0.3]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:101 [Ignoring book [730, 92, 800, 254] as conf. level 0.2509404420852661 is lower than 0.3]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:101 [Ignoring book [23, 436, 83, 454] as conf. level 0.24233776330947876 is lower than 0.3]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:101 [Ignoring book [16, 456, 84, 472] as conf. level 0.21052399277687073 is lower than 0.3]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 object.py:103 [Returning filtered list of 5 objects.]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:711 [This model iteration inside object found: labels: ['person', 'book', 'book', 'book', 'book'],conf:[0.9579234719276428, 0.4917953908443451, 0.3947797119617462, 0.3802471458911896, 0.33214399218559265]]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:424 [Max object size found to be: 90%]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:432 [Converted 90% to 432000.0]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:502 [intersection: object:person,POLYGON ((408 48, 594 48, 594 614, 408 614, 408 48)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:526 [full_image intersects object:person[[(408, 48), (594, 48), (594, 614), (408, 614)]]]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:502 [intersection: object:book,POLYGON ((721 43, 799 43, 799 175, 721 175, 721 43)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:535 [full_image intersects object:book[[(721, 43), (799, 43), (799, 175), (721, 175)]] but does NOT match your detect pattern filter]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:502 [intersection: object:book,POLYGON ((751 328, 797 328, 797 578, 751 578, 751 328)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:535 [full_image intersects object:book[[(751, 328), (797, 328), (797, 578), (751, 578)]] but does NOT match your detect pattern filter]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:502 [intersection: object:book,POLYGON ((710 433, 756 433, 756 559, 710 559, 710 433)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:535 [full_image intersects object:book[[(710, 433), (756, 433), (756, 559), (710, 559)]] but does NOT match your detect pattern filter]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:502 [intersection: object:book,POLYGON ((20 446, 84 446, 84 466, 20 466, 20 446)) intersects polygon:full_image,POLYGON ((0 0, 800 0, 800 600, 0 600, 0 0))]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:518 [Using global match pattern: (person|car|motorbike|bus|truck|boat)]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:535 [full_image intersects object:book[[(20, 446), (84, 446), (84, 466), (20, 466)]] but does NOT match your detect pattern filter]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:753 [breaking out of same model loop, as matches found and strategy is "first"]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 detect_sequence.py:669 [============ Frame: alarm Running face detection type in sequence ==================]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:190 [Skipping TPU face detection as it is disabled]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:190 [Skipping DLIB based face recognition as it is disabled]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG3 detect_sequence.py:689 [face has a same_model_sequence strategy of union]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:770 [We did not find any face matches in frame: alarm]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 detect_sequence.py:669 [============ Frame: alarm Running alpr detection type in sequence ==================]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG2 detect_sequence.py:672 [Making sure we have matched one of ['car', 'motorbike', 'bus', 'truck', 'boat'] in ['person'] before we proceed]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 detect_sequence.py:674 [Did not find pre existing labels, not running detection type]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 detect_sequence.py:827 [perf: TOTAL detection sequence (with image loads) took: 5330.17 ms  to process 1517]

03/25/22 15:00:36 zmesdetect_m1[9273] INF zm_detect.py:471 [Prediction string:[s] detected:person:69% ]

03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 zm_detect.py:473 [Prediction string JSON:{"labels": ["person"], "boxes": [[-2, 11, 332, 597]], "frame_id": "snapshot", "confidences": [0.6926378607749939], "image_dimensions": {"original": [480, 640], "resized": [600, 800]}}]

[s] detected:person:69% --SPLIT--{"labels": ["person"], "boxes": [[-2, 11, 332, 597]], "frame_id": "snapshot", "confidences": [0.6926378607749939], "image_dimensions": {"original": [480, 640], "resized": [600, 800]}}
03/25/22 15:00:36 zmesdetect_m1[9273] DBG1 zm_detect.py:550 [Closing logs]

Logging Event 2481
tail -F /var/log/zm/zmesdetect*.log /var/log/zm/zmeventnotification.log
[\b]

https://pastebin.com/qk7w2NJY