search

ZoneMinder / zmeventnotification

Machine Learning powered Secure Websocket & MQTT based ZoneMinder event notification server
408 stars 128 forks source link

match_past_detections = yes make an error in debug log #385

Closed connectnet closed 3 years ago

connectnet commented 3 years ago

Event Server version app:6.1.20, pyzm:0.3.45

Hooks version (if you are using Object Detection) app:6.1.20, pyzm:0.3.45

Are you using MLAPI? (Y/N) n

The version of ZoneMinder you are using: v1.34.23

What is the nature of your issue

Details

match_past_detections = yes make an error in debug log

Debug Logs (if applicable)

Important: Please post DEBUG logs NOT INF logs. Instructions on how to enable debug logs are posted HERE


04/10/21 12:17:53 zmesdetect_m2[74819] INF ZMLog.py:225 [Setting up signal handler for logs]
04/10/21 12:17:53 zmesdetect_m2[74819] INF ZMLog.py:234 [Switching global logger to ZMLog]
04/10/21 12:17:53 zmesdetect_m2[74819] INF zm_detect.py:271 [---------| app:6.1.20, pyzm:0.3.45, ES:6.1.20 , OpenCV:4.5.2-dev|------------]
04/10/21 12:17:54 zmesdetect_m2[74819] INF zm_detect.py:296 [Importing local classes for Object/Face]
04/10/21 12:17:54 zmesdetect_m2[74819] INF zm_detect.py:319 [Connecting with ZM APIs]
04/10/21 12:18:09 zmesdetect_m2[74819] INF detect_sequence.py:795 [Removing matches to past detections for monitor:2]
04/10/21 12:18:09 zmesdetect_m2[74819] FAT zm_detect.py:552 [Unrecoverable error:list index out of range Traceback:Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 547, in <module>
    main_handler()
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 411, in main_handler
    matched_data,all_data = m.detect_stream(stream=stream, options=stream_options)
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py", line 798, in detect_stream
    matched_b,matched_l,matched_c, matched_detection_types, matched_model_names = self._process_past_detections(matched_b, matched_l, matched_c, matched_det
ection_types, matched_model_names)
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py", line 368, in _process_past_detections
    new_detection_types.append(matched_detection_types[idx])
IndexError: list index out of range
]
pliablepixels commented 3 years ago

  1. I am not able to replicate this. Please make sure you have updated your ES+pyzm correctly. Your versions show correct, but the error seems to indicate it is an old library (pyzm)

  2. Please follow the instructions in the issue template - you haven't posted DEBUG logs

connectnet commented 3 years ago
  1. Sorry for the incomplete log.
  2. Here are the debug logfiles

zmesdetect_m2.log

/10/21 14:41:25 zmesdetect_m2[99989] INF ZMLog.py:225 [Setting up signal handler for logs]
04/10/21 14:41:25 zmesdetect_m2[99989] INF ZMLog.py:234 [Switching global logger to ZMLog]
04/10/21 14:41:25 zmesdetect_m2[99989] INF zm_detect.py:271 [---------| app:6.1.20, pyzm:0.3.45, ES:6.1.20 , OpenCV:4.5.2-dev|------------]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 utils.py:410 [secret filename: /etc/zm/secrets.ini]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !ML_USER]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 utils.py:445 [allowing self-signed certs to work...]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG4 utils.py:455 [Now checking for monitor overrides]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG4 utils.py:523 [Finally, doing parameter substitution]
04/10/21 14:41:25 zmesdetect_m2[99989] INF zm_detect.py:296 [Importing local classes for Object/Face]
04/10/21 14:41:25 zmesdetect_m2[99989] INF zm_detect.py:319 [Connecting with ZM APIs]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 api.py:67 [API SSL certificate check has been disbled]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 api.py:176 [using username/password for login]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 api.py:205 [Using new token API]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 zm_detect.py:327 [using ml_sequence]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 zm_detect.py:339 [using stream_sequence]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 detect_sequence.py:145 [Resetting models, will be loaded on next run]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG3 detect_sequence.py:609 [Using manual locking as we are only using one model]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 Media.py:53 [Media get SSL certificate check has been disbled]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 Media.py:101 [Using URL 168 for stream]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 Media.py:137 [No need to start streams, we are picking images from http://127.0.0.1/zm/index.php?view=image&eid=168]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG3 Media.py:271 [Reading http://127.0.0.1/zm/index.php?view=image&eid=168&fid=snapshot]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG4 api.py:267 [make_request called with url=http://127.0.0.1/zm/index.php?view=image&eid=168&fid=snapshot payload={} type=get query={'token': None}]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 detect_sequence.py:628 [perf: Starting for frame:snapshot]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 detect_sequence.py:642 [============ Frame: snapshot Running object model in sequence ==================]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG4 detect_sequence.py:160 [Skipping TPU object detection as it is disabled]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG4 detect_sequence.py:164 [Loading sequence: YoloV4 GPU/CPU]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 detect_sequence.py:165 [Initializing model  type:object with options:{'name': 'YoloV4 GPU/CPU', 'enabled': 'yes', 'object_config': '/var/lib/zmevent
notification/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'}]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 yolo.py:39 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 yolo.py:51 [Waiting for pyzm_uid33_gpu_lock portalock...]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 yolo.py:53 [Got pyzm_uid33_gpu_lock portalock]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG3 detect_sequence.py:662 [object has a same_model_sequence strategy of first]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG3 detect_sequence.py:674 [--------- Frame:snapshot Running variation: #1 -------------]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 yolo.py:48 [pyzm_uid33_gpu_lock portalock already acquired]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 yolo.py:86 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 yolo.py:93 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 105.58
 ms]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG2 yolo.py:109 [Setting CUDA backend for OpenCV]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG3 yolo.py:110 [If you did not set your CUDA_ARCH_BIN correctly during OpenCV compilation, you will get errors during detection related to invalid devi
ce/make_policy]
04/10/21 14:41:25 zmesdetect_m2[99989] DBG1 yolo.py:148 [|---------- YOLO (input image: 800w*450h, model resize dimensions: 416w*416h) ----------|]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 yolo.py:69 [Released pyzm_uid33_gpu_lock portalock]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG1 yolo.py:174 [perf: processor:gpu Yolo detection took: 892.88 ms]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 yolo.py:209 [perf: processor:gpu Yolo NMS filtering took: 0.96 ms]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 object.py:59 [core model detection over, got 2 objects. Now filtering]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 object.py:63 [Max object size found to be: 90%]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 object.py:71 [Converted 90% to 324000.0]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 object.py:96 [Returning filtered list of 2 objects.]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG4 detect_sequence.py:684 [This model iteration inside object found: labels: ['car', 'person'],conf:[0.964298665523529, 0.4617263674736023]]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:398 [Max object size found to be: 90%]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 detect_sequence.py:406 [Converted 90% to 324000.0]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 detect_sequence.py:422 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (1920, 0), (1920, 1080), (0, 1080)], 'patte
rn': None}]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:214 [resized polygons x=0.4166666666666667/y=0.4166666666666667: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 450), 
(0, 450)], 'pattern': None}]]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:473 [intersection: comparing object:car,POLYGON ((92 44, 414 44, 414 424, 92 424, 92 44)) to polygon:full_image,POLYGON ((0 0, 80
0 0, 800 450, 0 450, 0 0))]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 detect_sequence.py:491 [Using global match pattern: .*]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:499 [full_image intersects object:car[[(92, 44), (414, 44), (414, 424), (92, 424)]]]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:473 [intersection: comparing object:person,POLYGON ((188 106, 274 106, 274 188, 188 188, 188 106)) to polygon:full_image,POLYGON 
((0 0, 800 0, 800 450, 0 450, 0 0))]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 detect_sequence.py:491 [Using global match pattern: .*]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:499 [full_image intersects object:person[[(188, 106), (274, 106), (274, 188), (188, 188)]]]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:726 [breaking out of same model loop, as matches found and strategy is "first"]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 Media.py:271 [Reading http://127.0.0.1/zm/index.php?view=image&eid=168&fid=alarm]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG4 api.py:267 [make_request called with url=http://127.0.0.1/zm/index.php?view=image&eid=168&fid=alarm payload={} type=get query={'token': None}]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG1 detect_sequence.py:628 [perf: Starting for frame:alarm]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG1 detect_sequence.py:642 [============ Frame: alarm Running object model in sequence ==================]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:662 [object has a same_model_sequence strategy of first]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG3 detect_sequence.py:674 [--------- Frame:alarm Running variation: #1 -------------]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 yolo.py:51 [Waiting for pyzm_uid33_gpu_lock portalock...]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG2 yolo.py:53 [Got pyzm_uid33_gpu_lock portalock]
04/10/21 14:41:26 zmesdetect_m2[99989] DBG1 yolo.py:148 [|---------- YOLO (input image: 800w*450h, model resize dimensions: 416w*416h) ----------|]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 yolo.py:69 [Released pyzm_uid33_gpu_lock portalock]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG1 yolo.py:174 [perf: processor:gpu Yolo detection took: 603.95 ms]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 yolo.py:209 [perf: processor:gpu Yolo NMS filtering took: 0.89 ms]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG3 object.py:59 [core model detection over, got 2 objects. Now filtering]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG3 object.py:63 [Max object size found to be: 90%]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 object.py:71 [Converted 90% to 324000.0]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 object.py:94 [Ignoring person [210, 27, 242, 53] as conf. level 0.24049755930900574 is lower than 0.3]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 object.py:96 [Returning filtered list of 1 objects.]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG4 detect_sequence.py:684 [This model iteration inside object found: labels: ['car'],conf:[0.9985272884368896]]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG3 detect_sequence.py:398 [Max object size found to be: 90%]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 detect_sequence.py:406 [Converted 90% to 324000.0]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG3 detect_sequence.py:473 [intersection: comparing object:car,POLYGON ((146 3, 406 3, 406 141, 146 141, 146 3)) to polygon:full_image,POLYGON ((0 0, 80
0 0, 800 450, 0 450, 0 0))]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 detect_sequence.py:491 [Using global match pattern: .*]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG3 detect_sequence.py:499 [full_image intersects object:car[[(146, 3), (406, 3), (406, 141), (146, 141)]]]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG3 detect_sequence.py:726 [breaking out of same model loop, as matches found and strategy is "first"]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 yolo.py:65 [pyzm_uid33_gpu_lock portalock already released]
04/10/21 14:41:27 zmesdetect_m2[99989] INF detect_sequence.py:795 [Removing matches to past detections for monitor:2]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG2 detect_sequence.py:237 [trying to load /var/lib/zmeventnotification/images/monitor-2-data.pkl]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG1 detect_sequence.py:248 [No history data file found for monitor 2]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG4 detect_sequence.py:284 [Globals:past detection:use_percent:True, max_diff_area:5]
04/10/21 14:41:27 zmesdetect_m2[99989] DBG4 detect_sequence.py:308 [Found car_past_det_max_diff_area=10%]
04/10/21 14:41:27 zmesdetect_m2[99989] FAT zm_detect.py:552 [Unrecoverable error:list index out of range Traceback:Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 547, in <module>
    main_handler()
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 411, in main_handler
    matched_data,all_data = m.detect_stream(stream=stream, options=stream_options)
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py", line 798, in detect_stream
    matched_b,matched_l,matched_c, matched_detection_types, matched_model_names = self._process_past_detections(matched_b, matched_l, matched_c, matched_detection_types, matched_model_names)
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py", line 368, in _process_past_detections
    new_detection_types.append(matched_detection_types[idx])
IndexError: list index out of range

sudo -u www-data /usr/bin/zmeventnotification.pl --debug

10.04.2021 14:44:31.364333 zmeventnotification[102242].INF [main:326] [Running on WebSocket library version:0.004]
INF:2021-04-10,14:44:31 PARENT: using config file: /etc/zm/zmeventnotification.ini
10.04.2021 14:44:31.405092 zmeventnotification[102242].INF [main:1010] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
INF:2021-04-10,14:44:31 PARENT: using secrets file: /etc/zm/secrets.ini
10.04.2021 14:44:31.423387 zmeventnotification[102242].INF [main:1010] [PARENT: using secrets file: /etc/zm/secrets.ini]
DBG-2:2021-04-10,14:44:31 PARENT: Got secret token !ZMES_PICTURE_URL
DBG-2:2021-04-10,14:44:31 PARENT: Got secret token !ZM_USER
DBG-2:2021-04-10,14:44:31 PARENT: Got secret token !ZM_PASSWORD
DBG-3:2021-04-10,14:44:31 PARENT: config string substitution: {{base_data_path}} is '/var/lib/zmeventnotification'

Configuration (read /etc/zm/zmeventnotification.ini):

Secrets file.......................... /etc/zm/secrets.ini
Base data path........................ /var/lib/zmeventnotification
Restart interval (secs)............... 0

Use admin interface .................. no
Admin interface password.............. (undefined)
Admin interface persistence file ..... /var/lib/zmeventnotification/misc/escontrol_interface.dat

Port ................................. 9000
Address .............................. [::]
Event check interval ................. 5
Monitor reload interval .............. 300
Skipped monitors...................... (undefined)

Auth enabled ......................... no
Auth timeout ......................... 20

Use API Push.......................... no
API Push Script....................... (undefined)

Use FCM .............................. yes
Use FCM V1 APIs....................... yes
FCM Date Format....................... %I:%M %p, %d-%b
Only show latest FCMv1 message........ no
Android FCM push priority............. high
Android FCM push ttl.................. (undefined)

Token file ........................... /var/lib/zmeventnotification/push/tokens.txt

Use MQTT ............................. no
MQTT Server .......................... 127.0.0.1
MQTT Topic ........................... zoneminder
MQTT Username ........................ (undefined)
MQTT Password ........................ (undefined)
MQTT Retain .......................... no
MQTT Tick Interval ................... 15
MQTT TLS CA ........................ (undefined)
MQTT TLS Cert ........................ (undefined)
MQTT TLS Key ........................ (undefined)
MQTT TLS Insecure ........................ no

SSL enabled .......................... no
SSL cert file ........................ /path/to/cert/file.pem
SSL key file ......................... /path/to/key/file.pem

Verbose .............................. yes
ES Debug level.........................4
Read alarm cause ..................... yes
Tag alarm event id ................... yes
Use custom notification sound ........ no
Send event start notification..........yes
Send event end notification............yes
Monitor rules JSON file................(undefined)

Use Hooks............................. yes
Hook Script on Event Start ........... '/var/lib/zmeventnotification/bin/zm_event_start.sh'
User Script on Event Start.............(undefined)
Hook Script on Event End.............. (undefined)
User Script on Event End.............(undefined)
Hook Skipped monitors................. (undefined)

Notify on Event Start (hook success).. all
Notify on Event Start (hook fail)..... none
Notify on Event End (hook success).... fcm,web,api
Notify on Event End (hook fail)....... none
Notify End only if Start success...... yes

Use Hook Description.................. yes
Keep frame match type................. yes
Store Frame in ZM......................yes

Picture URL .......................... http://127.0.0.1/zm/index.php?view=image&eid=EVENTID&fid=objdetect&width=600
Include picture....................... yes
Picture username ..................... admin
Picture password ..................... (defined)

INF:2021-04-10,14:44:31 PARENT: Push enabled via FCM
10.04.2021 14:44:31.528539 zmeventnotification[102242].INF [main:1010] [PARENT: Push enabled via FCM]
DBG-4:2021-04-10,14:44:31 PARENT: fcmv1: --> FCM V1 APIs: 1
INF:2021-04-10,14:44:31 PARENT: MQTT Disabled
10.04.2021 14:44:31.540911 zmeventnotification[102242].INF [main:1010] [PARENT: MQTT Disabled]
INF:2021-04-10,14:44:31 PARENT: |------- Starting ES version: 6.1.20 ---------|
10.04.2021 14:44:31.555121 zmeventnotification[102242].INF [main:1010] [PARENT: |------- Starting ES version: 6.1.20 ---------|]
DBG-1:2021-04-10,14:44:31 PARENT: Started with: perl:/usr/bin/perl and command:/usr/bin/zmeventnotification.pl
Can't ignore signal CHLD, forcing to default.
DBG-1:2021-04-10,14:44:31 PARENT: ES invoked manually. Will handle restarts ourselves
WAR:2021-04-10,14:44:31 PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted
10.04.2021 14:44:31.659566 zmeventnotification[102242].WAR [main:1018] [PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted]
DBG-2:2021-04-10,14:44:31 PARENT: Parent<--Child pipe ready
INF:2021-04-10,14:44:31 PARENT: Event Notification daemon v 6.1.20 starting

10.04.2021 14:44:31.672088 zmeventnotification[102242].INF [main:1010] [PARENT: Event Notification daemon v 6.1.20 starting]
DBG-1:2021-04-10,14:44:31 PARENT: Initializing FCM tokens...
DBG-1:2021-04-10,14:44:31 PARENT: Total event client connections: 0

ERR:2021-04-10,14:44:31 PARENT: Error writing tokens file during count update: Permission denied
10.04.2021 14:44:31.686968 zmeventnotification[102242].ERR [main:1026] [PARENT: Error writing tokens file during count update: Permission denied]
INF:2021-04-10,14:44:31 PARENT: Re-loading monitors
10.04.2021 14:44:31.702171 zmeventnotification[102242].INF [main:1010] [PARENT: Re-loading monitors]
DBG-1:2021-04-10,14:44:31 PARENT: Loading Monitor-1
DBG-1:2021-04-10,14:44:31 PARENT: Loading Monitor-2
DBG-1:2021-04-10,14:44:31 PARENT: Loading Monitor-3
DBG-1:2021-04-10,14:44:31 PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data
DBG-2:2021-04-10,14:44:31 PARENT: checkEvents() new events found=0
INF:2021-04-10,14:44:31 PARENT: Secure WS is disabled...
10.04.2021 14:44:31.717148 zmeventnotification[102242].INF [main:1010] [PARENT: Secure WS is disabled...]
INF:2021-04-10,14:44:31 PARENT: Web Socket Event Server listening on port 9000
10.04.2021 14:44:31.732102 zmeventnotification[102242].INF [main:1010] [PARENT: Web Socket Event Server listening on port 9000]
DBG-2:2021-04-10,14:44:36 PARENT: ----------> Tick START (active forks:0, total forks:0, running for:1 min)<--------------
DBG-2:2021-04-10,14:44:36 PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-04-10,14:44:36 PARENT: There are 0 active child forks...
DBG-2:2021-04-10,14:44:36 PARENT: checkEvents() new events found=0
DBG-2:2021-04-10,14:44:36 PARENT: There are 0 new Events to process
DBG-2:2021-04-10,14:44:36 PARENT: ---------->Tick END (active forks:0, total forks:0)<--------------
pliablepixels commented 3 years ago

Looks like old pyzm code.

Please update ES to 6.1.21, make sure it installs pyzm 0.3.46

After you update, please check the output of 

pp@homeserver:~$ head -738 /usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py | tail -1

In my case it prints 

   _detection_types_in_frame.extend([seq]*len(_l_best_in_same_model))
connectnet commented 3 years ago

output of head -738 /usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py | tail -1 prints (now after update) _detection_types_in_frame.extend([seq]*len(_l_best_in_same_model))

pliablepixels commented 3 years ago

ok good, let me know if the error continues

connectnet commented 3 years ago

thank you for the fix, works and is error free but after a car is detected the alpr recognition doesn't works

[ml]
ml_sequence= {
    'general': {
        'model_sequence': '{{my_sequence}}',
            'disable_locks': '{{disable_locks}}',
        'match_past_detections': '{{match_past_detections}}',
        'past_det_max_diff_area': '5%',
        'car_past_det_max_diff_area': '10%',
        #'ignore_past_detection_labels': ['dog', 'cat']

    },
    'object': {
        'general':{
        'pattern':'{{object_detection_pattern}}',
        'same_model_sequence_strategy': 'first' # also 'most', 'most_unique's
        },
        'sequence': [{
        #First run on TPU with higher confidence
        'name': 'TPU object detection',
        'enabled': 'no',
        'object_weights':'{{tpu_object_weights_mobiledet}}',
        'object_labels': '{{tpu_object_labels}}',
        'object_min_confidence': {{tpu_min_confidence}},
        'object_framework':'{{tpu_object_framework}}',
        'tpu_max_processes': {{tpu_max_processes}},
        'tpu_max_lock_wait': {{tpu_max_lock_wait}},
                'max_detection_size':'{{max_detection_size}}'

        },
        {
        # YoloV4 on GPU if TPU fails (because sequence strategy is 'first')
        'name': 'YoloV4 GPU/CPU',
        'enabled': 'yes', # don't really need to say this explictly
        'object_config':'{{yolo4_object_config}}',
        'object_weights':'{{yolo4_object_weights}}',
        'object_labels': '{{yolo4_object_labels}}',
        'object_min_confidence': {{object_min_confidence}},
        'object_framework':'{{yolo4_object_framework}}',
        'object_processor': '{{yolo4_object_processor}}',
        'gpu_max_processes': {{gpu_max_processes}},
        'gpu_max_lock_wait': {{gpu_max_lock_wait}},
        'cpu_max_processes': {{cpu_max_processes}},
        'cpu_max_lock_wait': {{cpu_max_lock_wait}},
                'max_detection_size':'{{max_detection_size}}'

        }]
    },
    'face': {
        'general':{
        'pattern': '{{face_detection_pattern}}',
        'same_model_sequence_strategy': 'union' # combines all outputs of this sequence
        },
        'sequence': [
        {
            'name': 'TPU face detection',
            'enabled': 'no',
            'face_detection_framework': 'tpu',
            'face_weights':'/var/lib/zmeventnotification/models/coral_edgetpu/ssd_mobilenet_v2_face_quant_postprocess_edgetpu.tflite',
            'face_min_confidence': 0.3,

        },
        {
        'name': 'DLIB based face recognition',
        'enabled': 'yes',
        #'pre_existing_labels': ['face'], # use in combination with TPU face det above
        'save_unknown_faces':'{{save_unknown_faces}}',
        'save_unknown_faces_leeway_pixels':{{save_unknown_faces_leeway_pixels}},
        'face_detection_framework': '{{face_detection_framework}}',
        'known_images_path': '{{known_images_path}}',
        'unknown_images_path': '{{unknown_images_path}}',
        'face_model': '{{face_model}}',
        'face_train_model': '{{face_train_model}}',
        'face_recog_dist_threshold': '{{face_recog_dist_threshold}}',
        'face_num_jitters': '{{face_num_jitters}}',
        'face_upsample_times':'{{face_upsample_times}}',
        'gpu_max_processes': {{gpu_max_processes}},
        'gpu_max_lock_wait': {{gpu_max_lock_wait}},
        'cpu_max_processes': {{cpu_max_processes}},
        'cpu_max_lock_wait': {{cpu_max_lock_wait}},
        'max_size':800
        }]
    },

    'alpr': {
        'general':{
        'same_model_sequence_strategy': 'first',
        'pre_existing_labels':'car', 'motorbike', 'bus', 'truck', 'boat',
        'pattern': '{{alpr_detection_pattern}}'

        },
        'sequence': {
        'name': 'Platerecognizer cloud',
        'enabled': 'yes',
        'alpr_api_type': '{{alpr_api_type}}',
        'alpr_service': '{{alpr_service}}',
        'alpr_key': '{{alpr_key}}',
        'platrec_stats': '{{platerec_stats}}',
        'platerec_min_dscore': {{platerec_min_dscore}},
        'platerec_min_score': {{platerec_min_score}},
        'max_size':1600
        }
    }
    }
pliablepixels commented 3 years ago

Need to see debug logs (and make sure my_sequence has alpr in it)

connectnet commented 3 years ago

objectconfig.ini

[Monitor-2]
wait=5
my_sequence=object,face,alpr

zmesdetect_m2.log

04/10/21 17:29:16 zmesdetect_m2[118957] INF ZMLog.py:225 [Setting up signal handler for logs]
04/10/21 17:29:16 zmesdetect_m2[118957] INF ZMLog.py:234 [Switching global logger to ZMLog]
04/10/21 17:29:16 zmesdetect_m2[118957] INF zm_detect.py:271 [---------| app:6.1.21, pyzm:0.3.46, ES:6.1.21 , OpenCV:4.5.2-dev|------------]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG1 utils.py:410 [secret filename: /etc/zm/secrets.ini]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !ML_USER]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG1 utils.py:445 [allowing self-signed certs to work...]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG4 utils.py:455 [Now checking for monitor overrides]
04/10/21 17:29:16 zmesdetect_m2[118957] DBG4 utils.py:523 [Finally, doing parameter substitution]
04/10/21 17:29:16 zmesdetect_m2[118957] INF zm_detect.py:296 [Importing local classes for Object/Face]
04/10/21 17:29:17 zmesdetect_m2[118957] INF zm_detect.py:319 [Connecting with ZM APIs]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 api.py:67 [API SSL certificate check has been disbled]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 api.py:176 [using username/password for login]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 api.py:205 [Using new token API]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 zm_detect.py:334 [mapping legacy ml data from config]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG3 utils.py:125 [Changing detection_mode from all to most_models to adapt to new features]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 zm_detect.py:343 [mapping legacy stream data from config]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 detect_sequence.py:145 [Resetting models, will be loaded on next run]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG3 detect_sequence.py:608 [Using automatic locking as we are switching between models]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 Media.py:99 [Using URL 259 for stream]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 Media.py:114 [We will only process frames: ['alarm', 'snapshot']]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 Media.py:137 [No need to start streams, we are picking images from http://127.0.0.1/zm/index.php?view=image&eid=259]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG3 Media.py:271 [Reading http://127.0.0.1/zm/index.php?view=image&eid=259&fid=alarm]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG4 api.py:267 [make_request called with url=http://127.0.0.1/zm/index.php?view=image&eid=259&fid=alarm payload={} type=get query={'token': None}]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 detect_sequence.py:629 [perf: Starting for frame:alarm]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 detect_sequence.py:643 [============ Frame: alarm Running object model in sequence ==================]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG4 detect_sequence.py:164 [Loading sequence: index:0]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 detect_sequence.py:165 [Initializing model  type:object with options:{'tpu_max_processes': 1, 'tpu_max_lock_wait': 100, 'gpu_max_processes': 1, 'gp
u_max_lock_wait': 100, 'cpu_max_processes': 3, 'cpu_max_lock_wait': 100, 'max_detection_size': '90%', 'object_config': '/var/lib/zmeventnotification/models/yolov3/yolov3.cfg', 'object_weights'
: '/var/lib/zmeventnotification/models/yolov3/yolov3.weights', 'object_labels': '/var/lib/zmeventnotification/models/yolov3/coco.names', 'object_min_confidence': 0.3, 'object_framework': 'open
cv', 'object_processor': 'gpu', 'disable_locks': 'no'}]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 yolo.py:39 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG3 detect_sequence.py:663 [object has a same_model_sequence strategy of first]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG3 detect_sequence.py:675 [--------- Frame:alarm Running variation: #1 -------------]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 yolo.py:51 [Waiting for pyzm_uid33_gpu_lock portalock...]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 yolo.py:53 [Got pyzm_uid33_gpu_lock portalock]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 yolo.py:86 [|--------- Loading "Yolo" model from disk -------------|]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 yolo.py:93 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov3/yolov3.weights model from disk) took: 161.1
2 ms]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 yolo.py:109 [Setting CUDA backend for OpenCV]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG3 yolo.py:110 [If you did not set your CUDA_ARCH_BIN correctly during OpenCV compilation, you will get errors during detection related to invalid dev
ice/make_policy]
04/10/21 17:29:17 zmesdetect_m2[118957] DBG1 yolo.py:148 [|---------- YOLO (input image: 800w*450h, model resize dimensions: 416w*416h) ----------|]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 yolo.py:69 [Released pyzm_uid33_gpu_lock portalock]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG1 yolo.py:174 [perf: processor:gpu Yolo detection took: 753.08 ms]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 yolo.py:209 [perf: processor:gpu Yolo NMS filtering took: 0.95 ms]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 object.py:59 [core model detection over, got 1 objects. Now filtering]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 object.py:63 [Max object size found to be: 90%]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 object.py:71 [Converted 90% to 324000.0]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 object.py:96 [Returning filtered list of 1 objects.]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG4 detect_sequence.py:685 [This model iteration inside object found: labels: ['car'],conf:[0.9959191679954529]]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 detect_sequence.py:399 [Max object size found to be: 90%]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 detect_sequence.py:407 [Converted 90% to 324000.0]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 detect_sequence.py:423 [No polygons, adding full image polygon: {'name': 'full_image', 'value': [(0, 0), (1920, 0), (1920, 1080), (0, 1080)], 'patt
ern': None}]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 detect_sequence.py:214 [resized polygons x=0.4166666666666667/y=0.4166666666666667: [{'name': 'full_image', 'value': [(0, 0), (800, 0), (800, 450),
 (0, 450)], 'pattern': None}]]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 detect_sequence.py:475 [intersection: comparing object:car,POLYGON ((558 -6, 802 -6, 802 130, 558 130, 558 -6)) to polygon:full_image,POLYGON ((0 0
, 800 0, 800 450, 0 450, 0 0))]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG2 detect_sequence.py:493 [Using global match pattern: .*]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 detect_sequence.py:501 [full_image intersects object:car[[(558, -6), (802, -6), (802, 130), (558, 130)]]]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG3 detect_sequence.py:727 [breaking out of same model loop, as matches found and strategy is "first"]
04/10/21 17:29:18 zmesdetect_m2[118957] DBG1 detect_sequence.py:643 [============ Frame: alarm Running face model in sequence ==================]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG1 face_dlib.py:43 [perf: processor:cpu Face Recognition library load time took: 0.00 ms ]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG1 face_dlib.py:51 [Initializing face recognition with model:hog upsample:1, jitters:0]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG2 face_dlib.py:74 [portalock: max:3, name:pyzm_uid33_cpu_lock, timeout:100]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG1 face_dlib.py:90 [pre-trained faces found, using that. If you want to add new images, remove: /var/lib/zmeventnotification/known_faces/faces.dat]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG3 detect_sequence.py:663 [face has a same_model_sequence strategy of first]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG3 detect_sequence.py:675 [--------- Frame:alarm Running variation: #1 -------------]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG1 face_dlib.py:165 [|---------- Dlib Face recognition (input image: 800w*450h) ----------|]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG5 face_dlib.py:175 [Face options={'tpu_max_processes': 1, 'tpu_max_lock_wait': 100, 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_proces
ses': 3, 'cpu_max_lock_wait': 100, 'face_detection_framework': 'dlib', 'face_recognition_framework': 'dlib', 'face_processor': 'cpu', 'known_images_path': '/var/lib/zmeventnotification/known_f
aces', 'face_model': 'cnn', 'face_train_model': 'cnn', 'unknown_images_path': '/var/lib/zmeventnotification/unknown_faces', 'unknown_face_name': 'unknown face', 'save_unknown_faces': 'yes', 's
ave_unknown_faces_leeway_pixels': 100, 'face_recog_dist_threshold': 0.6, 'face_num_jitters': 1, 'face_upsample_times': 1, 'disable_locks': 'no'}]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG2 face_dlib.py:124 [Waiting for pyzm_uid33_cpu_lock portalock...]
04/10/21 17:29:20 zmesdetect_m2[118957] DBG2 face_dlib.py:126 [Got pyzm_uid33_cpu_lock lock...]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG1 face_dlib.py:207 [perf: processor:cpu Finding faces took 6217.87 ms]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG1 face_dlib.py:142 [Released pyzm_uid33_cpu_lock portalock]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG1 face_dlib.py:219 [perf: processor:cpu Computing face recognition distances took 0.75 ms]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG4 detect_sequence.py:685 [This model iteration inside face found: labels: [],conf:[]]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG3 detect_sequence.py:399 [Max object size found to be: 90%]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG2 detect_sequence.py:407 [Converted 90% to 324000.0]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG2 detect_sequence.py:744 [We did not find any face matches in frame: alarm]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG3 Media.py:271 [Reading http://127.0.0.1/zm/index.php?view=image&eid=259&fid=snapshot]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG4 api.py:267 [make_request called with url=http://127.0.0.1/zm/index.php?view=image&eid=259&fid=snapshot payload={} type=get query={'token': None}]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG1 detect_sequence.py:629 [perf: Starting for frame:snapshot]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG1 detect_sequence.py:643 [============ Frame: snapshot Running object model in sequence ==================]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG3 detect_sequence.py:663 [object has a same_model_sequence strategy of first]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG3 detect_sequence.py:675 [--------- Frame:snapshot Running variation: #1 -------------]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG2 yolo.py:51 [Waiting for pyzm_uid33_gpu_lock portalock...]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG2 yolo.py:53 [Got pyzm_uid33_gpu_lock portalock]
04/10/21 17:29:26 zmesdetect_m2[118957] DBG1 yolo.py:148 [|---------- YOLO (input image: 800w*450h, model resize dimensions: 416w*416h) ----------|]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 yolo.py:69 [Released pyzm_uid33_gpu_lock portalock]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG1 yolo.py:174 [perf: processor:gpu Yolo detection took: 562.43 ms]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 yolo.py:209 [perf: processor:gpu Yolo NMS filtering took: 1.32 ms]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 object.py:59 [core model detection over, got 1 objects. Now filtering]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 object.py:63 [Max object size found to be: 90%]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 object.py:71 [Converted 90% to 324000.0]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 object.py:96 [Returning filtered list of 1 objects.]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG4 detect_sequence.py:685 [This model iteration inside object found: labels: ['car'],conf:[0.9492009878158569]]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 detect_sequence.py:399 [Max object size found to be: 90%]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 detect_sequence.py:407 [Converted 90% to 324000.0]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 detect_sequence.py:475 [intersection: comparing object:car,POLYGON ((-20 34, 574 34, 574 434, -20 434, -20 34)) to polygon:full_image,POLYGON ((0 0
, 800 0, 800 450, 0 450, 0 0))]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 detect_sequence.py:493 [Using global match pattern: .*]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 detect_sequence.py:501 [full_image intersects object:car[[(-20, 34), (574, 34), (574, 434), (-20, 434)]]]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 detect_sequence.py:727 [breaking out of same model loop, as matches found and strategy is "first"]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG1 detect_sequence.py:643 [============ Frame: snapshot Running face model in sequence ==================]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 detect_sequence.py:663 [face has a same_model_sequence strategy of first]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG3 detect_sequence.py:675 [--------- Frame:snapshot Running variation: #1 -------------]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG1 face_dlib.py:165 [|---------- Dlib Face recognition (input image: 800w*450h) ----------|]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG5 face_dlib.py:175 [Face options={'tpu_max_processes': 1, 'tpu_max_lock_wait': 100, 'gpu_max_processes': 1, 'gpu_max_lock_wait': 100, 'cpu_max_proces
ses': 3, 'cpu_max_lock_wait': 100, 'face_detection_framework': 'dlib', 'face_recognition_framework': 'dlib', 'face_processor': 'cpu', 'known_images_path': '/var/lib/zmeventnotification/known_f
aces', 'face_model': 'cnn', 'face_train_model': 'cnn', 'unknown_images_path': '/var/lib/zmeventnotification/unknown_faces', 'unknown_face_name': 'unknown face', 'save_unknown_faces': 'yes', 's
ave_unknown_faces_leeway_pixels': 100, 'face_recog_dist_threshold': 0.6, 'face_num_jitters': 1, 'face_upsample_times': 1, 'disable_locks': 'no'}]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 face_dlib.py:124 [Waiting for pyzm_uid33_cpu_lock portalock...]
04/10/21 17:29:27 zmesdetect_m2[118957] DBG2 face_dlib.py:126 [Got pyzm_uid33_cpu_lock lock...]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 face_dlib.py:207 [perf: processor:cpu Finding faces took 4738.70 ms]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 face_dlib.py:142 [Released pyzm_uid33_cpu_lock portalock]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 face_dlib.py:219 [perf: processor:cpu Computing face recognition distances took 0.54 ms]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG4 detect_sequence.py:685 [This model iteration inside face found: labels: [],conf:[]]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG3 detect_sequence.py:399 [Max object size found to be: 90%]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG2 detect_sequence.py:407 [Converted 90% to 324000.0]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG2 detect_sequence.py:744 [We did not find any face matches in frame: snapshot]
04/10/21 17:29:32 zmesdetect_m2[118957] INF detect_sequence.py:796 [Removing matches to past detections for monitor:2]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG2 detect_sequence.py:237 [trying to load /var/lib/zmeventnotification/images/monitor-2-data.pkl]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG4 detect_sequence.py:284 [Globals:past detection:use_percent:True, max_diff_area:5]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG4 detect_sequence.py:345 [match_past_detections: Comparing  saved car@[(558, -6), (802, -6), (802, 130), (558, 130)] to car@[(558, -6), (802, -6), (8
02, 130), (558, 130)]]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 detect_sequence.py:357 [past detection car@[(558, -6), (802, -6), (802, 130), (558, 130)] approximately matches car@[(558, -6), (802, -6), (802, 13
0), (558, 130)] removing]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 detect_sequence.py:373 [Saving detections for monitor 2 for future match]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG4 detect_sequence.py:381 [saving boxes:[[558, -6, 802, 130]], labels:['car'] confs:[0.9959191679954529] to /var/lib/zmeventnotification/images/monito
r-2-data.pkl]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 detect_sequence.py:804 [perf: TOTAL detection sequence (with image loads) took: 15364.55 ms  to process 259]
04/10/21 17:29:32 zmesdetect_m2[118957] DBG1 zm_detect.py:548 [Closing logs]

zmeventnotification.log

10.04.2021 17:29:03.876046 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:0, total forks:46, running for:159 min)<--------------]
10.04.2021 17:29:03.876114 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:03.876147 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:03.876179 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:03.876251 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:03.876319 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:03.876357 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:03.876405 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:03.876440 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:03.876492 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:03.876518 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:03.876549 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:0, total forks:46)<--------------]
10.04.2021 17:29:08.876629 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:0, total forks:46, running for:159 min)<--------------]
10.04.2021 17:29:08.876712 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:08.876751 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:08.876788 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:08.876870 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:08.876952 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:08.876997 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:08.877056 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:08.877098 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:08.877289 zmeventnotification[103065].INF [main:1010] [PARENT: New event 293 reported for Monitor:3 (Name:Monitor-2) Motion All[last processed eid:291]]
10.04.2021 17:29:08.889526 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=1]
10.04.2021 17:29:08.889618 zmeventnotification[103065].DBG [main:998] [PARENT: There are 1 new Events to process]
10.04.2021 17:29:08.893965 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:1, total forks:47)<--------------]
10.04.2021 17:29:08.894369 zmeventnotification[118910].DBG [ZoneMinder::Logger:294] [LogOpts: level=DBG/DBG, screen=OFF, database=INF, logfile=DBG->/var/log/zm/zmeventnotification.log, syslog=INF]
10.04.2021 17:29:08.894485 zmeventnotification[118910].DBG [main:998] [PARENT: Forked process:118910 to handle alarm eid:293]
10.04.2021 17:29:08.894724 zmeventnotification[118910].DBG [ZoneMinder::Object:119] [Loading ZoneMinder::Event from Events WHERE Id = 293]
10.04.2021 17:29:08.895703 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 Adding event path:/var/cache/zoneminder/events/3/2021-04-10/293 to hook for image storage]
10.04.2021 17:29:08.895732 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 293 3 "Monitor-2" "Motion All" "/var/cache/zoneminder/events/3/2021-04-10/293"]
10.04.2021 17:29:13.874682 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:1, total forks:47, running for:159 min)<--------------]
10.04.2021 17:29:13.874817 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:13.874881 zmeventnotification[103065].DBG [main:998] [PARENT: There are 1 active child forks...]
10.04.2021 17:29:13.874990 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:13.875146 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:13.875297 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:13.875357 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:13.875447 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:13.875508 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:13.875615 zmeventnotification[103065].DBG [main:998] [PARENT: We've already worked on Monitor:3, Event:293, not doing anything more]
10.04.2021 17:29:13.875669 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:13.875717 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:13.875771 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:1, total forks:47)<--------------]
10.04.2021 17:29:18.874645 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:1, total forks:47, running for:159 min)<--------------]
10.04.2021 17:29:18.874731 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:18.874775 zmeventnotification[103065].DBG [main:998] [PARENT: There are 1 active child forks...]
10.04.2021 17:29:18.874817 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:18.874906 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:18.874997 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:18.875062 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:18.875132 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:18.875182 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:18.875258 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:18.875294 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:18.875334 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:1, total forks:47)<--------------]
10.04.2021 17:29:23.875957 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:1, total forks:47, running for:159 min)<--------------]
10.04.2021 17:29:23.876051 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:23.876099 zmeventnotification[103065].DBG [main:998] [PARENT: There are 1 active child forks...]
10.04.2021 17:29:23.876144 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:23.876240 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:23.876339 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:23.876394 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:23.876468 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:23.876521 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:23.876602 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:23.876641 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:23.876687 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:1, total forks:47)<--------------]
10.04.2021 17:29:25.974432 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 parse of hook:[a] detected:bicycle:98% person:84%  and {"labels": ["bicycle", "person"], "boxes": [[8, 297, 208, 447], [1, 110, 109, 460]], "frame_id": "alarm", "confidences": [0.9767767190933228, 0.8386163711547852], "image_dimensions": {"original": [1080, 1920], "resized": [450, 800]}}]
10.04.2021 17:29:25.974621 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 hook start returned with text:[a] detected:bicycle:98% person:84%  json:{"labels": ["bicycle", "person"], "boxes": [[8, 297, 208, 447], [1, 110, 109, 460]], "frame_id": "alarm", "confidences": [0.9767767190933228, 0.8386163711547852], "image_dimensions": {"original": [1080, 1920], "resized": [450, 800]}} exit:0]
10.04.2021 17:29:25.974935 zmeventnotification[118910].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:25.975161 zmeventnotification[118910].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:25.975287 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 For 3 (Monitor-2), SHM says: state=0, eid=293]
10.04.2021 17:29:25.975816 zmeventnotification[118910].INF [main:1010] [|----> FORK:Monitor-2 (3), eid:293 Event 293 for Monitor 3 has finished]
10.04.2021 17:29:25.991149 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 Event end object is: state=>pending with cause=>Motion: All]
10.04.2021 17:29:27.991661 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 rules: Checking rules for alarm caused by eid:293, monitor:3, at: Sat Apr 10 17:29:27 2021 with cause:[a] detected:bicycle:98% person:84%  Motion All]
10.04.2021 17:29:27.991759 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 rules: No rules found for Monitor, allowing:3]
10.04.2021 17:29:27.991826 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 Matching alarm to connection rules...]
10.04.2021 17:29:27.991875 zmeventnotification[118910].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:27.991955 zmeventnotification[118910].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:28.874702 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:1, total forks:47, running for:159 min)<--------------]
10.04.2021 17:29:28.874823 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:28.875945 zmeventnotification[103065].DBG [main:998] [PARENT: RAW TEXT-->active_event_update--TYPE--3--SPLIT--293--SPLIT--Start--SPLIT--Cause--SPLIT--[a] detected:bicycle:98% person:84%  Motion All--JSON--{"labels": ["bicycle", "person"], "boxes": [[8, 297, 208, 447], [1, 110, 109, 460]], "frame_id": "alarm", "confidences": [0.9767767190933228, 0.8386163711547852], "image_dimensions": {"original": [1080, 1920], "resized": [450, 800]}}]
10.04.2021 17:29:28.876076 zmeventnotification[103065].DBG [main:998] [PARENT: Job: Update active_event eid:293, mid:3, type:Start, field:Cause to: [a] detected:bicycle:98% person:84%  Motion All--JSON--{"labels": ["bicycle", "person"], "boxes": [[8, 297, 208, 447], [1, 110, 109, 460]], "frame_id": "alarm", "confidences": [0.9767767190933228, 0.8386163711547852], "image_dimensions": {"original": [1080, 1920], "resized": [450, 800]}}]
10.04.2021 17:29:28.876460 zmeventnotification[103065].DBG [main:998] [PARENT: RAW TEXT-->event_description--TYPE--3--SPLIT--293--SPLIT--[a] detected:bicycle:98% person:84% ]
10.04.2021 17:29:28.876539 zmeventnotification[103065].DBG [main:998] [PARENT: Job: Update monitor 3 description:[a] detected:bicycle:98% person:84% ]
10.04.2021 17:29:28.876604 zmeventnotification[103065].DBG [main:998] [PARENT: updating Notes clause for Event:293 with:[a] detected:bicycle:98% person:84%  ]
10.04.2021 17:29:28.889793 zmeventnotification[103065].DBG [main:998] [PARENT: There are 1 active child forks...]
10.04.2021 17:29:28.889894 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:28.890054 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:28.890194 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:28.890272 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:28.890370 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:28.890444 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:28.890558 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:28.890606 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:28.890657 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:1, total forks:47)<--------------]
10.04.2021 17:29:29.992787 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 DB Event notes contain detection text, all good]
10.04.2021 17:29:29.993062 zmeventnotification[118910].INF [main:1010] [|----> FORK:Monitor-2 (3), eid:293 end hooks/use hooks not being used, going to directly send out a notification if checks pass]
10.04.2021 17:29:30.006198 zmeventnotification[118910].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:30.006409 zmeventnotification[118910].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:32.006736 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 rules: Checking rules for alarm caused by eid:293, monitor:3, at: Sat Apr 10 17:29:32 2021 with cause:[a] detected:bicycle:98% person:84%  Motion All]
10.04.2021 17:29:32.006816 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 rules: No rules found for Monitor, allowing:3]
10.04.2021 17:29:32.006865 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 Matching alarm to connection rules...]
10.04.2021 17:29:32.006907 zmeventnotification[118910].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:32.006983 zmeventnotification[118910].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:33.876047 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:1, total forks:47, running for:160 min)<--------------]
10.04.2021 17:29:33.876123 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:33.876158 zmeventnotification[103065].DBG [main:998] [PARENT: There are 1 active child forks...]
10.04.2021 17:29:33.876196 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:33.876257 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:33.876333 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:33.876358 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:33.876390 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:33.876414 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:33.876473 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:33.876492 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:33.876515 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:1, total forks:47)<--------------]
10.04.2021 17:29:34.007151 zmeventnotification[118910].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:34.007283 zmeventnotification[118910].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:36.007539 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 exiting]
10.04.2021 17:29:36.007668 zmeventnotification[118910].DBG [main:998] [|----> FORK:Monitor-2 (3), eid:293 Ending process:118910 to handle alarms]
10.04.2021 17:29:38.876623 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:1, total forks:47, running for:160 min)<--------------]
10.04.2021 17:29:38.876697 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:38.876914 zmeventnotification[103065].DBG [main:998] [PARENT: RAW TEXT-->active_event_delete--TYPE--3--SPLIT--293]
10.04.2021 17:29:38.876979 zmeventnotification[103065].DBG [main:998] [PARENT: Job: Deleting active_event eid:293, mid:3]
10.04.2021 17:29:38.877067 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:38.877122 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:38.877197 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:38.877271 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:38.877313 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:38.877367 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:38.877407 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:38.877467 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:38.877496 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:38.877530 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:0, total forks:47)<--------------]
10.04.2021 17:29:43.874830 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:0, total forks:47, running for:160 min)<--------------]
10.04.2021 17:29:43.875082 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:43.875212 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:43.875324 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:43.875566 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:43.875813 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:43.875951 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:43.876118 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:43.876234 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:43.876416 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:43.876483 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:43.876538 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:0, total forks:47)<--------------]
10.04.2021 17:29:48.876633 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:0, total forks:47, running for:160 min)<--------------]
10.04.2021 17:29:48.876711 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:48.876751 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:48.876789 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:48.876871 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:48.876953 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:48.876998 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:48.877057 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:48.877098 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:48.877181 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:48.877212 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:48.877248 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:0, total forks:47)<--------------]
10.04.2021 17:29:53.876038 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:0, total forks:47, running for:160 min)<--------------]
10.04.2021 17:29:53.876100 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:53.876125 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:53.876152 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:53.876213 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:53.876271 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:53.876305 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:53.876343 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:53.876369 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:53.876408 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:53.876427 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:53.876451 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:0, total forks:47)<--------------]
10.04.2021 17:29:58.876661 zmeventnotification[103065].DBG [main:998] [PARENT: ----------> Tick START (active forks:0, total forks:47, running for:160 min)<--------------]
10.04.2021 17:29:58.876732 zmeventnotification[103065].DBG [main:998] [PARENT: After tick: TOTAL: 0,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
10.04.2021 17:29:58.876775 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 active child forks...]
10.04.2021 17:29:58.876808 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961583112192 for 1]
10.04.2021 17:29:58.876882 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
10.04.2021 17:29:58.876951 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961571504128 for 4]
10.04.2021 17:29:58.876989 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 4: 1]
10.04.2021 17:29:58.877037 zmeventnotification[103065].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 139961582743552 for 3]
10.04.2021 17:29:58.877072 zmeventnotification[103065].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1]
10.04.2021 17:29:58.877124 zmeventnotification[103065].DBG [main:998] [PARENT: checkEvents() new events found=0]
10.04.2021 17:29:58.877150 zmeventnotification[103065].DBG [main:998] [PARENT: There are 0 new Events to process]
10.04.2021 17:29:58.877181 zmeventnotification[103065].DBG [main:998] [PARENT: ---------->Tick END (active forks:0, total forks:47)<--------------]
pliablepixels commented 3 years ago 
04/10/21 17:29:17 zmesdetect_m2[118957] DBG2 zm_detect.py:334 [mapping legacy ml data from config]

This means your use_sequence is set to no and old legacy settings are applied. Please change to use_sequence=yes and then debug through.

connectnet commented 3 years ago

ups... zmesdetect_m2.log

04/10/21 18:22:58 zmesdetect_m2[122819] INF ZMLog.py:225 [Setting up signal handler for logs]
04/10/21 18:22:58 zmesdetect_m2[122819] INF ZMLog.py:234 [Switching global logger to ZMLog]
04/10/21 18:22:58 zmesdetect_m2[122819] INF zm_detect.py:271 [---------| app:6.1.21, pyzm:0.3.46, ES:6.1.21 , OpenCV:4.5.2-dev|------------]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG1 utils.py:410 [secret filename: /etc/zm/secrets.ini]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !ZM_PORTAL]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !ZM_USER]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !ZM_PASSWORD]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !ZM_API_PORTAL]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !ML_USER]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !ML_PASSWORD]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 utils.py:383 [Secret token found in config: !PLATEREC_ALPR_KEY]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG1 utils.py:445 [allowing self-signed certs to work...]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG4 utils.py:455 [Now checking for monitor overrides]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG4 utils.py:523 [Finally, doing parameter substitution]
04/10/21 18:22:58 zmesdetect_m2[122819] INF zm_detect.py:296 [Importing local classes for Object/Face]
04/10/21 18:22:58 zmesdetect_m2[122819] INF zm_detect.py:319 [Connecting with ZM APIs]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 api.py:67 [API SSL certificate check has been disbled]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG1 api.py:176 [using username/password for login]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 api.py:205 [Using new token API]
04/10/21 18:22:58 zmesdetect_m2[122819] DBG2 zm_detect.py:327 [using ml_sequence]
04/10/21 18:22:58 zmesdetect_m2[122819] FAT zm_detect.py:552 [Unrecoverable error:invalid syntax (<unknown>, line 83) Traceback:Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 547, in <module>
    main_handler()
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 331, in main_handler
    ml_options = ast.literal_eval(ml_options)
  File "/usr/lib/python3.8/ast.py", line 59, in literal_eval
    node_or_string = parse(node_or_string, mode='eval')
  File "/usr/lib/python3.8/ast.py", line 47, in parse
    return compile(source, filename, mode, flags,
  File "<unknown>", line 83
    'pre_existing_labels':'car', 'motorbike', 'bus', 'truck', 'boat',
                                            ^
SyntaxError: invalid syntax
]
pliablepixels commented 3 years ago

You have to read the docs, look at examples and fix your structure. pre_existing_labels is an array.

connectnet commented 3 years ago

After reading the docs it works now. Thank you for your patience.