ZMEVENTNOTIFICATION: Error running model: invalid index to scalar variable

[bpohvoodoo]

Hello,

i've got a problem with the Event Notification Server.
I get an error
2021-09-13 11:43:42 zmesdetect_m1 1025 ERR Error running model: invalid index to scalar variable. detect_sequence.py 713
using zoneminder 1.36.5

Here are my logs.
Any sugestions?
Kind Regards

root@ProxNAS:~# pkg-config --modversion opencv4
4.5.3
root@ProxNAS:~# python3 -c "import cv2; print(cv2.__version__)"
4.5.3-dev
root@ProxNAS:~# tail -F /var/log/zm/zmesdetect*.log /var/log/zm/zmeventnotification.log
==> /var/log/zm/zmesdetect_m1.log <==
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/yolo.py", line 156, in detect
ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/yolo.py", line 156, in <listcomp>
ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
IndexError: invalid index to scalar variable.
]
09/13/21 11:41:12 zmesdetect_m1[924] DBG2 detect_sequence.py:770 [We did not find any object matches in frame: alarm]
09/13/21 11:41:12 zmesdetect_m1[924] DBG2 yolo.py:63 [pyzm_uid33_gpu_lock portalock already released]
09/13/21 11:41:12 zmesdetect_m1[924] DBG1 detect_sequence.py:827 [perf: TOTAL detection sequence (with image loads) took: 162.95 ms to process 89650]
09/13/21 11:41:12 zmesdetect_m1[924] DBG1 zm_detect.py:557 [Closing logs]

==> /var/log/zm/zmeventnotification.log <==
09/13/21 11:43:11.411610 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:11.411705 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:11.411728 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:11.411757 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:0, total forks:3, active hooks: 0)<--------------]
09/13/21 11:43:16.411504 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:0, total forks:3, active hooks: 0 running for:12 min)<--------------]
09/13/21 11:43:16.411569 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:16.411595 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:16.411688 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:16.411711 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:16.411740 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:0, total forks:3, active hooks: 0)<--------------]
09/13/21 11:43:21.411487 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:0, total forks:3, active hooks: 0 running for:12 min)<--------------]
09/13/21 11:43:21.411563 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:21.411592 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:21.411690 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:21.411743 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:21.411805 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:0, total forks:3, active hooks: 0)<--------------]
09/13/21 11:43:26.413804 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:0, total forks:3, active hooks: 0 running for:12 min)<--------------]
09/13/21 11:43:26.413879 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:26.413922 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:26.414025 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:26.414051 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:26.414085 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:0, total forks:3, active hooks: 0)<--------------]
09/13/21 11:43:31.411472 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:0, total forks:3, active hooks: 0 running for:13 min)<--------------]
09/13/21 11:43:31.411550 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:31.411592 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:31.411738 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:31.411767 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:31.411805 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:0, total forks:3, active hooks: 0)<--------------]
09/13/21 11:43:36.411474 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:0, total forks:3, active hooks: 0 running for:13 min)<--------------]
09/13/21 11:43:36.411545 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:36.411575 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:36.411686 zmeventnotification[656].INF [main:1048] [PARENT: New event 89651 reported for Monitor:1 (Name:IPD-L26Y02-BS) Motion Zone_1[last processed eid:89650]]
09/13/21 11:43:36.411713 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=1]
09/13/21 11:43:36.411736 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 1 new Events to process]
09/13/21 11:43:36.413804 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:4, active hooks: 0)<--------------]
09/13/21 11:43:36.414027 zmeventnotification[1021].DB1 [ZoneMinder::Logger:321] [LogOpts: level=DB1/DB1, screen=OFF, database=ERR, logfile=DB1->/var/log/zm/zmeventnotification.log, syslog=ERR]
09/13/21 11:43:36.414097 zmeventnotification[1021].DB1 [main:1036] [PARENT: Forked process:1021 to handle alarm eid:89651]
09/13/21 11:43:36.414260 zmeventnotification[1021].DB1 [ZoneMinder::Object:125] [Loading ZoneMinder::Event from Events WHERE Id = 89651]
09/13/21 11:43:36.414671 zmeventnotification[1021].DB1 [ZoneMinder::Object:125] [Loading ZoneMinder::Storage from Storage WHERE Id = 2]
09/13/21 11:43:36.415205 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Adding event path:/Shares/Recordings/1/2021-09-13/89651 to hook for image storage]
09/13/21 11:43:36.415238 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 89651 1 "IPD-L26Y02-BS" "Motion Zone_1" "/Shares/Recordings/1/2021-09-13/89651"]

==> /var/log/zm/zmesdetect_m1.log <==
09/13/21 11:43:36 zmesdetect_m1[1025] INF ZMLog.py:292 [Setting up signal handler for logs]
09/13/21 11:43:36 zmesdetect_m1[1025] INF ZMLog.py:301 [Switching global logger to ZMLog]
09/13/21 11:43:36 zmesdetect_m1[1025] INF zm_detect.py:284 [---------| app:6.1.27, pyzm:0.3.54, ES:6.1.27
, OpenCV:4.5.3-dev|------------]
09/13/21 11:43:36 zmesdetect_m1[1025] INF utils.py:405 [Reading config from: /etc/zm/objectconfig.ini]
09/13/21 11:43:36 zmesdetect_m1[1025] INF utils.py:410 [Reading secrets from: /etc/zm/secrets.ini]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !ZM_PORTAL]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !ZM_USER]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !ZM_PASSWORD]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !ZM_API_PORTAL]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !ML_USER]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !ML_PASSWORD]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:382 [Secret token found in config: !PLATEREC_ALPR_KEY]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG1 utils.py:445 [allowing self-signed certs to work...]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:455 [Now checking for monitor overrides]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:491 [my_model_sequence is not a polygon, adding it as unknown string key]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:resize with value:no]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:match_past_detections with value:no]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:wait with value:5]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:frame_id with value:bestmatch]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:object_detection_pattern with value:(person|cat|dog|bird)]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:delete_after_analyze with value:yes]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:473 [[monitor-1] overrides key:import_zm_zones with value:no]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG2 utils.py:487 [adding polygon: perimeter [0,0 1919,0 1919,1079 0,1079]]
09/13/21 11:43:36 zmesdetect_m1[1025] DBG3 utils.py:522 [Finally, doing parameter substitution]
09/13/21 11:43:36 zmesdetect_m1[1025] INF zm_detect.py:309 [Importing local classes for Object/Face]
09/13/21 11:43:37 zmesdetect_m1[1025] INF zm_detect.py:334 [Connecting with ZM APIs]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG2 api.py:72 [API SSL certificate check has been disbled]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG1 api.py:181 [using username/password for login]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG2 api.py:210 [Using new token API]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG1 api.py:217 [Access token expires on:2021-09-13 13:43:37.170258 [7200s]]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG1 api.py:221 [Refresh token expires on:2021-09-14 11:43:37.170595 [86400s]]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG2 zm_detect.py:342 [using ml_sequence]
09/13/21 11:43:37 zmesdetect_m1[1025] DBG2 zm_detect.py:354 [using stream_sequence]
09/13/21 11:43:37 zmesdetect_m1[1025] INF zm_detect.py:418 [Sleeping for 5 seconds before inferencing]

==> /var/log/zm/zmeventnotification.log <==
09/13/21 11:43:41.411493 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:4, active hooks: 0 running for:13 min)<--------------]
09/13/21 11:43:41.411587 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:41.411725 zmeventnotification[656].DB1 [main:1036] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add]
09/13/21 11:43:41.411766 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 1 active child forks & 1 zm_detect processes running...]
09/13/21 11:43:41.411905 zmeventnotification[656].DB1 [main:1036] [PARENT: We've already worked on Monitor:1, Event:89651, not doing anything more]
09/13/21 11:43:41.411930 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:41.411954 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:41.411992 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:4, active hooks: 1)<--------------]

==> /var/log/zm/zmesdetect_m1.log <==
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:160 [Resetting models, will be loaded on next run]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 detect_sequence.py:637 [Using manual locking as we are only using one model]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 Media.py:51 [Media get SSL certificate check has been disbled]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 Media.py:99 [Using URL 89651 for stream]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 Media.py:114 [We will only process frames: ['snapshot', 'alarm']]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 Media.py:137 [No need to start streams, we are picking images from https://127.0.0.1/zm/index.php?view=image&eid=89651]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 Media.py:271 [Reading https://127.0.0.1/zm/index.php?view=ima ... d=snapshot]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 api.py:144 [No need to relogin as access token still has 119.91649486666667 minutes remaining]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 api.py:272 [make_request called with url=https://127.0.0.1/zm/index.php?view=ima ... d=snapshot payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjMxNTI2MjE3LCJleHAiOjE2MzE1MzM0MTcsInVzZXIiOiJhZG1pbiIsInR5cGUiOiJhY2Nlc3MifQ.5Dm92e5hiWYCN8PjA8Cb5fT7Mr_P8fL6I-vhLIn5oFc'}]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:654 [perf: Starting for frame:snapshot]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object']]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:669 [============ Frame: snapshot Running object detection type in sequence ==================]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 detect_sequence.py:174 [Skipping TPU object detection as it is disabled]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 detect_sequence.py:178 [Loading sequence: YoloV4 GPU/CPU]
09/13/21 11:43:42 zmesdetect_m1[1025] 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'}]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:37 [portalock: max:1, name:pyzm_uid33_gpu_lock, timeout:100]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:49 [Waiting for pyzm_uid33_gpu_lock portalock...]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:51 [Got pyzm_uid33_gpu_lock portalock]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:701 [--------- Frame:snapshot Running variation: #1 -------------]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx450h]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:46 [pyzm_uid33_gpu_lock portalock already acquired]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 yolo.py:84 [|--------- Loading "YoloV4 GPU/CPU" model from disk -------------|]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 yolo.py:91 [perf: processor:gpu Yolo initialization (loading /var/lib/zmeventnotification/models/yolov4/yolov4.weights model from disk) took: 82.48 ms]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:107 [Setting CUDA backend for OpenCV]
09/13/21 11:43:42 zmesdetect_m1[1025] 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]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*450h, model resize dimensions: 416w*416h) ----------|]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:67 [Released pyzm_uid33_gpu_lock portalock]
09/13/21 11:43:42 zmesdetect_m1[1025] ERR detect_sequence.py:713 [Error running model: invalid index to scalar variable.]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 detect_sequence.py:714 [Traceback (most recent call last):
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/detect_sequence.py", line 710, in detect_stream
_b,_l,_c,_m = m.detect(image=frame)
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/object.py", line 65, in detect
b,l,c,_model_names = self.model.detect(image)
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/yolo.py", line 156, in detect
ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/yolo.py", line 156, in <listcomp>
ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
IndexError: invalid index to scalar variable.
]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 detect_sequence.py:770 [We did not find any object matches in frame: snapshot]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 Media.py:271 [Reading https://127.0.0.1/zm/index.php?view=ima ... &fid=alarm]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 api.py:144 [No need to relogin as access token still has 119.91440821666667 minutes remaining]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 api.py:272 [make_request called with url=https://127.0.0.1/zm/index.php?view=ima ... &fid=alarm payload={} type=get query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJab25lTWluZGVyIiwiaWF0IjoxNjMxNTI2MjE3LCJleHAiOjE2MzE1MzM0MTcsInVzZXIiOiJhZG1pbiIsInR5cGUiOiJhY2Nlc3MifQ.5Dm92e5hiWYCN8PjA8Cb5fT7Mr_P8fL6I-vhLIn5oFc'}]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:654 [perf: Starting for frame:alarm]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:664 [Sequence of detection types to execute: ['object']]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:669 [============ Frame: alarm Running object detection type in sequence ==================]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG3 detect_sequence.py:689 [object has a same_model_sequence strategy of first]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:701 [--------- Frame:alarm Running variation: #1 -------------]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:123 [detect extracted image dimensions as: 800wx450h]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:49 [Waiting for pyzm_uid33_gpu_lock portalock...]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:51 [Got pyzm_uid33_gpu_lock portalock]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 yolo.py:147 [|---------- YOLO (input image: 800w*450h, model resize dimensions: 416w*416h) ----------|]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:67 [Released pyzm_uid33_gpu_lock portalock]
09/13/21 11:43:42 zmesdetect_m1[1025] ERR detect_sequence.py:713 [Error running model: invalid index to scalar variable.]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 detect_sequence.py:714 [Traceback (most recent call last):
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/detect_sequence.py", line 710, in detect_stream
_b,_l,_c,_m = m.detect(image=frame)
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/object.py", line 65, in detect
b,l,c,_model_names = self.model.detect(image)
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/yolo.py", line 156, in detect
ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
File "/usr/local/lib/python3.9/dist-packages/pyzm/ml/yolo.py", line 156, in <listcomp>
ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
IndexError: invalid index to scalar variable.
]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 detect_sequence.py:770 [We did not find any object matches in frame: alarm]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG2 yolo.py:63 [pyzm_uid33_gpu_lock portalock already released]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 detect_sequence.py:827 [perf: TOTAL detection sequence (with image loads) took: 156.72 ms to process 89651]
09/13/21 11:43:42 zmesdetect_m1[1025] DBG1 zm_detect.py:557 [Closing logs]

==> /var/log/zm/zmeventnotification.log <==
09/13/21 11:43:42.433004 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 parse of hook: and []]
09/13/21 11:43:42.433065 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 hook start returned with text: json:[] exit:1]
09/13/21 11:43:44.433564 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 rules: Checking rules for alarm caused by eid:89651, monitor:1, at: Mon Sep 13 11:43:44 2021 with cause:Motion Zone_1]
09/13/21 11:43:44.433622 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 rules: No rules found for Monitor, allowing:1]
09/13/21 11:43:44.433668 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Matching alarm to connection rules...]
09/13/21 11:43:44.433742 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Checking alarm conditions for token ending in:...EF3j5E6thf]
09/13/21 11:43:44.433799 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Monitor 1 event: should send out as 149.542259931564 is >= interval of ]
09/13/21 11:43:44.433826 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 token is unique, shouldSendEventToConn returned true, so calling sendEvent]
09/13/21 11:43:44.433884 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 child finished writing to parent]
09/13/21 11:43:44.433919 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Checking alarm conditions for token ending in:...j4YV-wy1CZ]
09/13/21 11:43:44.433953 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Monitor 1 event: should send out as 149.542000055313 is >= interval of 10]
09/13/21 11:43:44.433978 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 token is unique, shouldSendEventToConn returned true, so calling sendEvent]
09/13/21 11:43:44.434010 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 child finished writing to parent]
09/13/21 11:43:44.434066 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Checking alarm conditions for token ending in:...wE10R-TTLt]
09/13/21 11:43:44.434117 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Monitor 1 event: should send out as 149.542000055313 is >= interval of 0]
09/13/21 11:43:44.434167 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 token is unique, shouldSendEventToConn returned true, so calling sendEvent]
09/13/21 11:43:44.434230 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 isAllowedChannel: got type:event_start resCode:1]
09/13/21 11:43:44.434279 zmeventnotification[1021].INF [main:1048] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Not sending over FCM as notify filters are on_success:all and on_fail:none]
09/13/21 11:43:44.434324 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 child finished writing to parent]
09/13/21 11:43:46.414869 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:4, active hooks: 1 running for:13 min)<--------------]
09/13/21 11:43:46.414944 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:46.415061 zmeventnotification[656].DB1 [main:1036] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del]
09/13/21 11:43:46.415152 zmeventnotification[656].DB1 [main:1036] [PARENT: RAW TEXT-->timestamp--TYPE--1631525486.40715--SPLIT--1--SPLIT--1631526224.43384]
09/13/21 11:43:46.415194 zmeventnotification[656].DB1 [main:1036] [PARENT: Job: Update last sent timestamp of monitor:1 to 1631526224.43384 for id:1631525486.40715]
09/13/21 11:43:46.415293 zmeventnotification[656].DB1 [main:1036] [PARENT: RAW TEXT-->timestamp--TYPE--1631525486.40717--SPLIT--1--SPLIT--1631526224.43399]
09/13/21 11:43:46.415325 zmeventnotification[656].DB1 [main:1036] [PARENT: Job: Update last sent timestamp of monitor:1 to 1631526224.43399 for id:1631525486.40717]
09/13/21 11:43:46.415454 zmeventnotification[656].DB1 [main:1036] [PARENT: RAW TEXT-->timestamp--TYPE--1631525486.40717--SPLIT--1--SPLIT--1631526224.4342]
09/13/21 11:43:46.415485 zmeventnotification[656].DB1 [main:1036] [PARENT: Job: Update last sent timestamp of monitor:1 to 1631526224.4342 for id:1631525486.40717]
09/13/21 11:43:46.415515 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:46.415605 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:46.415658 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:46.415691 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:4, active hooks: 0)<--------------]
09/13/21 11:43:46.434668 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 For 1 (IPD-L26Y02-BS), SHM says: state=0, eid=89651]
09/13/21 11:43:46.434716 zmeventnotification[1021].INF [main:1048] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Event 89651 for Monitor 1 has finished]
09/13/21 11:43:46.435026 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Event end object is: state=>pending with cause=>Motion: Zone_1]
09/13/21 11:43:48.435519 zmeventnotification[1021].INF [main:1048] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 end hooks/use hooks not being used, going to directly send out a notification if checks pass]
09/13/21 11:43:50.435823 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 rules: Checking rules for alarm caused by eid:89651, monitor:1, at: Mon Sep 13 11:43:50 2021 with cause:Motion Zone_1]
09/13/21 11:43:50.435879 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 rules: No rules found for Monitor, allowing:1]
09/13/21 11:43:50.435908 zmeventnotification[1021].INF [main:1048] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
09/13/21 11:43:51.411500 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:4, active hooks: 0 running for:13 min)<--------------]
09/13/21 11:43:51.411572 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:51.411599 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:51.411695 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:51.411721 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:51.411751 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:4, active hooks: 0)<--------------]
09/13/21 11:43:54.436275 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 exiting]
09/13/21 11:43:54.436358 zmeventnotification[1021].DB1 [main:1036] [|----> FORK:IPD-L26Y02-BS (1), eid:89651 Ending process:1021 to handle alarms]
09/13/21 11:43:56.411480 zmeventnotification[656].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:4, active hooks: 0 running for:13 min)<--------------]
09/13/21 11:43:56.411549 zmeventnotification[656].DB1 [main:1036] [PARENT: After tick: TOTAL: 3, ES_CONTROL: 0, FCM+WEB: 0, FCM: 3, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
09/13/21 11:43:56.411718 zmeventnotification[656].DB1 [main:1036] [PARENT: RAW TEXT-->active_event_delete--TYPE--1--SPLIT--89651]
09/13/21 11:43:56.411797 zmeventnotification[656].DB1 [main:1036] [PARENT: Job: Deleting active_event eid:89651, mid:1]
09/13/21 11:43:56.411868 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 active child forks & 0 zm_detect processes running...]
09/13/21 11:43:56.412039 zmeventnotification[656].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
09/13/21 11:43:56.412066 zmeventnotification[656].DB1 [main:1036] [PARENT: There are 0 new Events to process]
09/13/21 11:43:56.412135 zmeventnotification[656].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:0, total forks:4, active hooks: 0)<--------------]

[zedamota]

Hi,

Were you able to fix the issue, I'm facing the exact same thing.

[sdamasoc]

I'm also having the same issue:

Code: Select all

10/10/21 21:58:27 zmesdetect_m11[102221] DBG2 detect_sequence.py:714 [Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/detect_sequence.py", line 710, in detect_stream
    _b,_l,_c,_m = m.detect(image=frame)
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/object.py", line 65, in detect
    b,l,c,_model_names = self.model.detect(image)
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/yolo.py", line 156, in detect
    ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
  File "/usr/local/lib/python3.8/dist-packages/pyzm/ml/yolo.py", line 156, in <listcomp>
    ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]
IndexError: invalid index to scalar variable.
]

zoneminder: V1.36.8
zmeventnotification: v6.1.27

[Magic919]

Post in the Mobile Apps and Event Server section for better response.

[sdamasoc]

I found the problem and I think there is a bug on lines 156 and 217of /usr/local/lib/python3.8/dist-packages/pyzm/ml/yolo.py file:

Code: Select all

ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]

here the variable i seems to be an index and not an array.
I fixed this line by removing the [0]:

Code: Select all

ln = [ln[i - 1] for i in self.net.getUnconnectedOutLayers()]

Then on line 217 the same problem:

Code: Select all

i = i[0] 

I just removed the line.

I hope this can help.

[asker]

You should revert the changes, delete your models/labels and re-download the models again

[sdamasoc]

I had a fresh install, reinstalled twice and always the same error...
Which models/labels you advise to redownload?

[asker]

Remove everything under /var/lib/zmeventnotification/models
And then re-install

When this happens, most often I've seen its because the download was incorrect for the ml models

[sdamasoc]

I removed everything under /var/lib/zmeventnotification/models (coral_edgetpu, tinyyolov3, tinyyolov4, yolov3 and yolov4). I redownloaded all models (urls can be founded in install.sh script) and I have always the same error.

With my correction above everything works fine:

Screenshot 2021-10-14 205418.png (7.91 KiB) Viewed 10510 times

Till I don't have another solution I will use this workaround.

Thanks for all,

[bsc101]

I found the problem and I think there is a bug on lines 156 and 217of /usr/local/lib/python3.8/dist-packages/pyzm/ml/yolo.py file:

Code: Select all

ln = [ln[i[0] - 1] for i in self.net.getUnconnectedOutLayers()]

here the variable i seems to be an index and not an array.
I fixed this line by removing the [0]:

Code: Select all

ln = [ln[i - 1] for i in self.net.getUnconnectedOutLayers()]

Then on line 217 the same problem:

Code: Select all

i = i[0] 

I just removed the line.

I hope this can help.

Thanks for this workaround, I also had the same issue!

[asker]

As it turns out OpenCV 4.5.4 changed the API, so the above isn't a random hack that luckily happens to work in magical ways.
See https://github.com/ZoneMinder/mlapi/iss ... -958912650

However, this needs to be done correctly comparing openCV versions, which I'll commit soon. Please track updates here: https://github.com/ZoneMinder/mlapi/issues/44