Skip to content

Instantly share code, notes, and snippets.

@baudneo
Created October 20, 2021 11:04
Show Gist options
  • Save baudneo/d5a8b54843531fc2a5ae7c1826733d91 to your computer and use it in GitHub Desktop.
Save baudneo/d5a8b54843531fc2a5ae7c1826733d91 to your computer and use it in GitHub Desktop.
Log output of forked ZMES - This is on the MLAPI side, MLAPI is installed on a remote system without ZM or ZMES.
10/20/21 04:54:36.533656 zm_mlapi[25758] DBG1 mlapi:139 [mlapi:JWT: 'Neo' accessed this endpoint '/detect' with a v
alid JWT]
10/20/21 04:54:36.541542 zm_mlapi[25758] DBG1 mlapi_utils:418 [SENT TO LOGGER -> initilized STDOUT class]
10/20/21 04:54:36.543705 zm_mlapi[25758] DBG1 mlapi_utils:210 ['std.out' -> TESTING STDOUT FOR MLAPI]
10/20/21 04:54:36.545846 zm_mlapi[25758] INF mlapi_utils:212 [config:init: reading config file found at '/home/baudneo/
PycharmProjects/my_mlapi/mlapi/mlapiconfig.ini']
10/20/21 04:54:36.548096 zm_mlapi[25758] INF mlapi_utils:218 [config:init: reading secrets from: '/home/baudneo/Pycharm
Projects/my_mlapi/mlapi/secrets.ini']
10/20/21 04:54:36.553892 zm_mlapi[25758] DBG2 mlapi_utils:253 [config:init: found configuration overrides for monitor
'1', applying...]
10/20/21 04:54:36.556175 zm_mlapi[25758] DBG2 mlapi_utils:298 [config:init: monitor '1' CACHE adding Polygon 'front_y
ard' -> [(0, 877), (2170, 553), (3822, 1131), (3822, 2141), (0, 2159)]]
10/20/21 04:54:36.558285 zm_mlapi[25758] DBG2 mlapi_utils:280 [config:init: found zone 'front_yard' specific pattern:
(person|dog|cat)]
10/20/21 04:54:36.560406 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '1' CACHE key='object_detection_p
attern' is set to type=string value='(person|dog|cat)']
10/20/21 04:54:36.562538 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '1' CACHE key='frame_set' is set
to type=string value='snapshot,70,snapshot,140,210,alarm,280,350,430']
10/20/21 04:54:36.564646 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '1' CACHE key='model_sequence' is
set to type=string value='object']
10/20/21 04:54:36.566836 zm_mlapi[25758] DBG2 mlapi_utils:293 [config:init: monitor '1' CACHE adding unknown key 'per
son_min_confidence' type=<class 'str'> value='0.60']
10/20/21 04:54:36.568945 zm_mlapi[25758] DBG2 mlapi_utils:253 [config:init: found configuration overrides for monitor
'3', applying...]
10/20/21 04:54:36.57109 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '3' CACHE key='frame_set' is set t
o type=string value='snapshot,70,110,160,snapshot,alarm,210,280']
10/20/21 04:54:36.573194 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '3' CACHE key='max_detection_size
' is set to type=string value='65%']
10/20/21 04:54:36.575336 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '3' CACHE key='object_detection_p
attern' is set to type=string value='(person|dog|cat)']
10/20/21 04:54:36.577514 zm_mlapi[25758] DBG2 mlapi_utils:298 [config:init: monitor '3' CACHE adding Polygon 'parking
_pad' -> [(5, 408), (660, 175), (1695, 100), (1910, 275), (1910, 1070), (0, 1080)]]
10/20/21 04:54:36.579656 zm_mlapi[25758] DBG2 mlapi_utils:280 [config:init: found zone 'parking_pad' specific pattern
: (person|dog|cat)]
10/20/21 04:54:36.581828 zm_mlapi[25758] DBG2 mlapi_utils:293 [config:init: monitor '3' CACHE adding unknown key 'per
son_min_confidence' type=<class 'str'> value='0.60']
10/20/21 04:54:36.583862 zm_mlapi[25758] DBG2 mlapi_utils:253 [config:init: found configuration overrides for monitor
'4', applying...]
10/20/21 04:54:36.585884 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '4' CACHE key='object_detection_p
attern' is set to type=string value='(person)']
10/20/21 04:54:36.587902 zm_mlapi[25758] DBG2 mlapi_utils:280 [config:init: found zone 'back_yard' specific pattern:
(person)]
10/20/21 04:54:36.589969 zm_mlapi[25758] DBG2 mlapi_utils:298 [config:init: monitor '4' CACHE adding Polygon 'back_ya
rd' -> [(0, 547), (824, 246), (1511, 161), (1706, 1070), (0, 1080)]]
10/20/21 04:54:36.592044 zm_mlapi[25758] DBG2 mlapi_utils:293 [config:init: monitor '4' CACHE adding unknown key 'per
son_min_confidence' type=<class 'str'> value='0.60']
10/20/21 04:54:36.594036 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '4' CACHE key='frame_set' is set
to type=string value='snapshot,70,110,160,snapshot,alarm,210,280']
10/20/21 04:54:36.596045 zm_mlapi[25758] DBG2 mlapi_utils:253 [config:init: found configuration overrides for monitor
'5', applying...]
10/20/21 04:54:36.598066 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '5' CACHE key='object_detection_p
attern' is set to type=string value='(person|face)']
10/20/21 04:54:36.600064 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '5' CACHE key='model_sequence' is
set to type=string value='object,face']
10/20/21 04:54:36.602119 zm_mlapi[25758] DBG2 mlapi_utils:293 [config:init: monitor '5' CACHE adding unknown key 'fra
me_strategy' type=<class 'str'> value='most']
10/20/21 04:54:36.604185 zm_mlapi[25758] DBG2 mlapi_utils:293 [config:init: monitor '5' CACHE adding unknown key 'sam
e_model_seq_strategy' type=<class 'str'> value='most']
10/20/21 04:54:36.60618 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '5' CACHE key='frame_set' is set t
o type=string value='snapshot,110,snapshot,210,310']
10/20/21 04:54:36.608184 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '5' CACHE key='face_upsample_time
s' is set to type=int value='2']
10/20/21 04:54:36.610207 zm_mlapi[25758] DBG2 mlapi_utils:286 [config:init: monitor '5' CACHE key='face_num_jitters'
is set to type=int value='2']
10/20/21 04:54:36.612399 zm_mlapi[25758] DBG1 mlapi_utils:327 [config:init: secrets found -> {[ZM_API_PORTAL]}, {[MLA
PI_SECRET_KEY]}, {[PLATEREC_ALPR_KEY]}]
10/20/21 04:54:36.61446 zm_mlapi[25758] DBG2 mlapi_utils:328 [config:init: doing parameter substitution for global co
nfig]
10/20/21 04:54:36.617303 zm_mlapi[25758] DBG2 mlapi_utils:353 [config:init: doing parameter substitution for monitor
specific entities]
10/20/21 04:54:36.620216 zm_mlapi[25758] DBG1 mlapi:165 [mlapi: ZMES sent encrypted data! Checking the keystore for '
mlapi_one']
10/20/21 04:54:36.623208 zm_mlapi[25758] DBG1 mlapi:180 [decrypted={'auth_type': 'token', 'api_url': 'https://<redacted>/zm/api', 'portal_url': 'https://<redacted>/zm', 'user': '<redacted>', 'pass': '<redacted>'}]
10/20/21 04:54:36.625263 zm_mlapi[25758] DBG2 mlapi:219 [api: SSL certificate verification disabled (encryption enabl
ed but vulnerable to MITM attacks)]
10/20/21 04:54:36.627296 zm_mlapi[25758] DBG1 mlapi:219 [api: no token found, trying user/pass for login]
10/20/21 04:54:36.742212 zm_mlapi[25758] DBG2 mlapi:219 [api: detected API ver 2.0+, using token system]
10/20/21 04:54:36.742536 zm_mlapi[25758] DBG1 mlapi:219 [api: access token expires on: 2021-10-20 10:54:36.742490 (21
600s)]
10/20/21 04:54:36.742693 zm_mlapi[25758] DBG1 mlapi:219 [api: refresh token expires on: 2021-10-21 04:54:36.742665 (8
6400s)]
10/20/21 04:54:36.745316 zm_mlapi[25758] DBG2 Zones:47 [Retrieving zones via API]
10/20/21 04:54:36.763791 zm_mlapi[25758] DBG2 mlapi_utils:63 [mlapi:util: overriding 'match_pattern' for monitor 1 zo
ne 'front_yard' with: (person|dog|cat)]
10/20/21 04:54:36.765888 zm_mlapi[25758] DBG2 mlapi_utils:63 [mlapi:util: overriding 'match_pattern' for monitor 3 zo
ne 'parking_pad' with: (person|dog|cat)]
10/20/21 04:54:36.76795 zm_mlapi[25758] DBG2 mlapi_utils:63 [mlapi:util: overriding 'match_pattern' for monitor 4 zon
e 'back_yard' with: (person)]
10/20/21 04:54:36.769808 zm_mlapi[25758] DBG2 mlapi:261 [mlapi:detect: parsing 'ml_sequence']
10/20/21 04:54:36.772975 zm_mlapi[25758] DBG2 pyzm_utils:1277 [parse_sub: secret token found in 'ml_sequence:object:s
equence' -> aws_access_key_id='{[AWS_ACCESS_KEY_ID]}']
10/20/21 04:54:36.774995 zm_mlapi[25758] DBG2 pyzm_utils:1277 [parse_sub: secret token found in 'ml_sequence:object:s
equence' -> aws_secret_access_key='{[AWS_SECRET_ACCESS_KEY]}']
10/20/21 04:54:36.776916 zm_mlapi[25758] DBG2 mlapi:280 [mlapi:detect: found 'stream_sequence' in '/home/baudneo/Pychar
mProjects/my_mlapi/mlapi/mlapiconfig.ini']
10/20/21 04:54:36.778841 zm_mlapi[25758] DBG1 mlapi:294 [mlapi:detect: ZMES sent 'resize' in stream_sequence -> width
=800]
10/20/21 04:54:36.780694 zm_mlapi[25758] DBG1 mlapi:311 [mlapi:detect: monitor ID '3' has overrides configured, setti
ng options with overrides...]
10/20/21 04:54:36.782584 zm_mlapi[25758] DBG2 mlapi:364 [mlapi:detect: overriding global key 'frame_set' with monitor
override -> snapshot,70,110,160,snapshot,alarm,210,280...]
10/20/21 04:54:36.784441 zm_mlapi[25758] DBG2 mlapi:364 [mlapi:detect: overriding global key 'max_detection_size' wit
h monitor override -> 65%...]
10/20/21 04:54:36.7863 zm_mlapi[25758] DBG2 mlapi:364 [mlapi:detect: overriding global key 'object_detection_pattern'
with monitor override -> (person|dog|cat)...]
10/20/21 04:54:36.788157 zm_mlapi[25758] DBG2 mlapi:364 [mlapi:detect: overriding global key 'person_min_confidence'
with monitor override -> 0.60...]
10/20/21 04:54:36.790418 zm_mlapi[25758] DBG2 Media:160 [media: setting 'image' as type for event -> '41097']
10/20/21 04:54:36.792559 zm_mlapi[25758] DBG2 Media:195 [media: processing a maximum of 8 frames-> ['snapshot', '70',
'110', '160', 'snapshot', 'alarm', '210', '280']]
10/20/21 04:54:36.794767 zm_mlapi[25758] DBG2 Media:226 [media: using API calls for event -> 41097]
10/20/21 04:54:36.796792 zm_mlapi[25758] DBG2 detect_sequence:1001 [ml:portalocker: using manual locking for single m
odel -> 'object']
10/20/21 04:54:36.798972 zm_mlapi[25758] DBG1 Media:458 [media:read:image: about to process first frame!]
10/20/21 04:54:36.801152 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:37.386991 zm_mlapi[25758] DBG2 Media:528 [media:read:image: converting event -> 41097 'snapshot' to a
frame ID 's-105']
10/20/21 04:54:37.389295 zm_mlapi[25758] DBG2 Media:682 [api:make_req: 'get'-><hidden>/index.php?view=image&eid=41097
&fid=105 query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:37.865036 zm_mlapi[25758] DBG1 Media:748 [media:read: API returned frame with dimensions -> (1080, 192
0), using 'resize' of 800=(450, 800)]
10/20/21 04:54:37.867756 zm_mlapi[25758] DBG1 detect_sequence:1048 [ml: 'resize width'=800 polygon=[{'name': 'parking
_pad', 'value': [(5, 408), (660, 175), (1695, 100), (1910, 275), (1910, 1070), (0, 1080)], 'pattern': '(person|dog|ca
t)'}]]
10/20/21 04:54:37.871041 zm_mlapi[25758] DBG2 detect_sequence:371 [ml: rescaled polygons ('down') using factors: x=0.
4167 y=0.4167 -> OLD: [[{'name': 'parking_pad', 'value': [(5, 408), (660, 175), (1695, 100), (1910, 275), (1910, 107
0), (0, 1080)], 'pattern': '(person|dog|cat)'}]] --- NEW:[[{'name': 'parking_pad', 'value': [(2, 170), (275, 72), (70
6, 41), (795, 114), (795, 445), (0, 450)], 'pattern': '(person|dog|cat)'}]]]
10/20/21 04:54:37.873643 zm_mlapi[25758] DBG1 detect_sequence:1069 [ml: after rescaling polygon=[{'name': 'parking_pa
d', 'value': [(2, 170), (275, 72), (706, 41), (795, 114), (795, 445), (0, 450)], 'pattern': '(person|dog|cat)'}]]
10/20/21 04:54:37.87562 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: s-105 [strategy:'first'] (1 of 8) - model:
'object' [strategy:'first'] (1 of 1) - sequence: 'coral::MobileNETv2-SSD' [strategy:'most'] (1 of 2)]
10/20/21 04:54:37.877794 zm_mlapi[25758] DBG2 coral_edgetpu:188 [coral: pre processing resize for coral model request
ed (w*h) -> 312*312]
10/20/21 04:54:37.88701 zm_mlapi[25758] DBG2 coral_edgetpu:52 [Waiting for pyzm_uid1000_TPU_lock portalock...]
10/20/21 04:54:37.889683 zm_mlapi[25758] DBG2 coral_edgetpu:54 [portalock: got 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:37.891876 zm_mlapi[25758] DBG1 coral_edgetpu:206 [coral: 'coral::MobileNETv2-SSD' input image (w*h): 8
00*450 resized by tpu_model_width/height to 312*312]
10/20/21 04:54:37.912855 zm_mlapi[25758] DBG2 coral_edgetpu:71 [portalock: released 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:37.915038 zm_mlapi[25758] DBG1 coral_edgetpu:226 [perf:coral: 'coral::MobileNETv2-SSD' detection took:
18.61 ms]
10/20/21 04:54:37.917196 zm_mlapi[25758] DBG2 coral_edgetpu:245 [coral: the image was resized before processing, scal
ing bounding boxes in image back up by factors of -> x=2.564 y=1.442]
10/20/21 04:54:37.919368 zm_mlapi[25758] DBG1 coral_edgetpu:265 [coral returning [] -- [] -- []]
10/20/21 04:54:37.921286 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'coral::MobileNETv2-SSD'
found 0 detections -> ]
10/20/21 04:54:37.923222 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: s-105 [strategy:'first'] (1 of 8) - model:
'object' [strategy:'first'] (1 of 1) - sequence: 'DarkNet::v4 Pre-Trained' [strategy:'most'] (2 of 2)]
10/20/21 04:54:37.925887 zm_mlapi[25758] DBG2 yolo:77 [portalock: acquired -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:37.928062 zm_mlapi[25758] DBG1 yolo:206 [yolo: 'DarkNet::v4 Pre-Trained' (GPU) [input image w*h 800*45
0 - resized by model_width/height to w*h: 416*416]]
10/20/21 04:54:38.028298 zm_mlapi[25758] DBG2 yolo:92 [portalock: released -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:38.483324 zm_mlapi[25758] DBG2 yolo:270 [perf:yolo:GPU: 'DarkNet::v4 Pre-Trained' detection took: 552.
89 ms]
10/20/21 04:54:38.485673 zm_mlapi[25758] DBG1 yolo:272 [yolo:DBG!: data for monitoring (GPU reset add-on) -> ['outs=3
', 'out=8112', 'out=2028', 'out=507']]
10/20/21 04:54:38.487884 zm_mlapi[25758] DBG1 yolo:299 [yolo returning ['toilet'] -- [[48, 52, 598, 448]] -- [0.24316
40625]]
10/20/21 04:54:38.49249 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'DarkNet::v4 Pre-Trained'
found 1 detection -> toilet]
10/20/21 04:54:38.494594 zm_mlapi[25758] DBG1 detect_sequence:425 [>>> detected 'toilet (1/1)' confidence: 0.24]
10/20/21 04:54:38.496755 zm_mlapi[25758] DBG1 detect_sequence:474 ['toilet (1/1)' minimum confidence found: (object_m
in_conf:sequence->DarkNet::v4 Pre-Trained) -> '0.56']
10/20/21 04:54:38.498806 zm_mlapi[25758] DBG2 detect_sequence:478 [confidence: 24.32 is lower than minimum of 56.00,
removing...]
10/20/21 04:54:38.500913 zm_mlapi[25758] DBG2 detect_sequence:904 [detection: 'toilet (1/1)' has FAILED filtering]
10/20/21 04:54:38.502923 zm_mlapi[25758] DBG2 detect_sequence:1531 [ml: all 'object' matches in frame s-105 were filt
ered out]
10/20/21 04:54:38.504936 zm_mlapi[25758] DBG2 detect_sequence:1546 [perf:frame: s-105 took 637.29 ms]
10/20/21 04:54:38.507148 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=1 --- self.fids_proc
essed=['s-105'] --- self.frame_set[self.frame_set_index]='70' --- self.get_last_frame()='s-105' --- self.max_frames=8
]
10/20/21 04:54:38.509281 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:39.096621 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=70 current frame buffer length '1
95' last API call frame buffer length was '175']
10/20/21 04:54:39.096848 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=False --- self.skip_all_count=0]
10/20/21 04:54:39.101174 zm_mlapi[25758] DBG2 Media:682 [api:make_req: 'get'-><hidden>/index.php?view=image&eid=41097
&fid=70 query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:39.574092 zm_mlapi[25758] DBG1 Media:748 [media:read: API returned frame with dimensions -> (1080, 192
0), using 'resize' of 800=(450, 800)]
10/20/21 04:54:39.576529 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 70 [strategy:'first'] (2 of 8) - model: 'o
bject' [strategy:'first'] (1 of 1) - sequence: 'coral::MobileNETv2-SSD' [strategy:'most'] (1 of 2)]
10/20/21 04:54:39.578791 zm_mlapi[25758] DBG2 coral_edgetpu:188 [coral: pre processing resize for coral model request
ed (w*h) -> 312*312]
10/20/21 04:54:39.588083 zm_mlapi[25758] DBG2 coral_edgetpu:52 [Waiting for pyzm_uid1000_TPU_lock portalock...]
10/20/21 04:54:39.590702 zm_mlapi[25758] DBG2 coral_edgetpu:54 [portalock: got 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:39.592893 zm_mlapi[25758] DBG1 coral_edgetpu:206 [coral: 'coral::MobileNETv2-SSD' input image (w*h): 8
00*450 resized by tpu_model_width/height to 312*312]
10/20/21 04:54:39.614606 zm_mlapi[25758] DBG2 coral_edgetpu:71 [portalock: released 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:39.616978 zm_mlapi[25758] DBG1 coral_edgetpu:226 [perf:coral: 'coral::MobileNETv2-SSD' detection took:
19.12 ms]
10/20/21 04:54:39.619459 zm_mlapi[25758] DBG2 coral_edgetpu:245 [coral: the image was resized before processing, scal
ing bounding boxes in image back up by factors of -> x=2.564 y=1.442]
10/20/21 04:54:39.621736 zm_mlapi[25758] DBG1 coral_edgetpu:265 [coral returning [] -- [] -- []]
10/20/21 04:54:39.624691 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'coral::MobileNETv2-SSD'
found 0 detections -> ]
10/20/21 04:54:39.627077 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 70 [strategy:'first'] (2 of 8) - model: 'o
bject' [strategy:'first'] (1 of 1) - sequence: 'DarkNet::v4 Pre-Trained' [strategy:'most'] (2 of 2)]
10/20/21 04:54:39.630164 zm_mlapi[25758] DBG2 yolo:77 [portalock: acquired -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:39.63243 zm_mlapi[25758] DBG1 yolo:206 [yolo: 'DarkNet::v4 Pre-Trained' (GPU) [input image w*h 800*450
- resized by model_width/height to w*h: 416*416]]
10/20/21 04:54:39.714486 zm_mlapi[25758] DBG2 yolo:92 [portalock: released -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:40.185939 zm_mlapi[25758] DBG2 yolo:270 [perf:yolo:GPU: 'DarkNet::v4 Pre-Trained' detection took: 551.
11 ms]
10/20/21 04:54:40.188298 zm_mlapi[25758] DBG1 yolo:272 [yolo:DBG!: data for monitoring (GPU reset add-on) -> ['outs=3
', 'out=8112', 'out=2028', 'out=507']]
10/20/21 04:54:40.190614 zm_mlapi[25758] DBG1 yolo:299 [yolo returning ['car', 'bottle'] -- [[36, 30, 594, 448], [195
, 192, 247, 264]] -- [0.455322265625, 0.310546875]]
10/20/21 04:54:40.19517 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'DarkNet::v4 Pre-Trained'
found 2 detections -> car, bottle]
10/20/21 04:54:40.197315 zm_mlapi[25758] DBG1 detect_sequence:425 [>>> detected 'car (1/2)' confidence: 0.46]
10/20/21 04:54:40.199529 zm_mlapi[25758] DBG1 detect_sequence:474 ['car (1/2)' minimum confidence found: (object_min_
conf:sequence->DarkNet::v4 Pre-Trained) -> '0.56']
10/20/21 04:54:40.20161 zm_mlapi[25758] DBG2 detect_sequence:478 [confidence: 45.53 is lower than minimum of 56.00, r
emoving...]
10/20/21 04:54:40.203762 zm_mlapi[25758] DBG2 detect_sequence:419 [detection: 'car (1/2)' has FAILED filtering]
10/20/21 04:54:40.2059 zm_mlapi[25758] DBG1 detect_sequence:425 [>>> detected 'bottle (2/2)' confidence: 0.31]
10/20/21 04:54:40.208175 zm_mlapi[25758] DBG1 detect_sequence:474 ['bottle (2/2)' minimum confidence found: (object_m
in_conf:sequence->DarkNet::v4 Pre-Trained) -> '0.56']
10/20/21 04:54:40.2103 zm_mlapi[25758] DBG2 detect_sequence:478 [confidence: 31.05 is lower than minimum of 56.00, re
moving...]
10/20/21 04:54:40.212445 zm_mlapi[25758] DBG2 detect_sequence:904 [detection: 'bottle (2/2)' has FAILED filtering]
10/20/21 04:54:40.214477 zm_mlapi[25758] DBG2 detect_sequence:1531 [ml: all 'object' matches in frame 70 were filtere
d out]
10/20/21 04:54:40.216467 zm_mlapi[25758] DBG2 detect_sequence:1546 [perf:frame: 70 took 639.95 ms]
10/20/21 04:54:40.21861 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=2 --- self.fids_proce
ssed=['s-105', '70'] --- self.frame_set[self.frame_set_index]='110' --- self.get_last_frame()='70' --- self.max_frame
s=8]
10/20/21 04:54:40.220771 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:40.833486 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=110 current frame buffer length '
208' last API call frame buffer length was '195']
10/20/21 04:54:40.833733 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=False --- self.skip_all_count=0]
10/20/21 04:54:40.838253 zm_mlapi[25758] DBG2 Media:682 [api:make_req: 'get'-><hidden>/index.php?view=image&eid=41097
&fid=110 query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:41.325181 zm_mlapi[25758] DBG1 Media:748 [media:read: API returned frame with dimensions -> (1080, 192
0), using 'resize' of 800=(450, 800)]
10/20/21 04:54:41.327744 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 110 [strategy:'first'] (3 of 8) - model: '
object' [strategy:'first'] (1 of 1) - sequence: 'coral::MobileNETv2-SSD' [strategy:'most'] (1 of 2)]
10/20/21 04:54:41.330113 zm_mlapi[25758] DBG2 coral_edgetpu:188 [coral: pre processing resize for coral model request
ed (w*h) -> 312*312]
10/20/21 04:54:41.339743 zm_mlapi[25758] DBG2 coral_edgetpu:52 [Waiting for pyzm_uid1000_TPU_lock portalock...]
10/20/21 04:54:41.342499 zm_mlapi[25758] DBG2 coral_edgetpu:54 [portalock: got 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:41.344819 zm_mlapi[25758] DBG1 coral_edgetpu:206 [coral: 'coral::MobileNETv2-SSD' input image (w*h): 8
00*450 resized by tpu_model_width/height to 312*312]
10/20/21 04:54:41.366912 zm_mlapi[25758] DBG2 coral_edgetpu:71 [portalock: released 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:41.369413 zm_mlapi[25758] DBG1 coral_edgetpu:226 [perf:coral: 'coral::MobileNETv2-SSD' detection took:
19.43 ms]
10/20/21 04:54:41.372268 zm_mlapi[25758] DBG2 coral_edgetpu:245 [coral: the image was resized before processing, scal
ing bounding boxes in image back up by factors of -> x=2.564 y=1.442]
10/20/21 04:54:41.374631 zm_mlapi[25758] DBG1 coral_edgetpu:265 [coral returning [] -- [] -- []]
10/20/21 04:54:41.376696 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'coral::MobileNETv2-SSD'
found 0 detections -> ]
10/20/21 04:54:41.378764 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 110 [strategy:'first'] (3 of 8) - model: '
object' [strategy:'first'] (1 of 1) - sequence: 'DarkNet::v4 Pre-Trained' [strategy:'most'] (2 of 2)]
10/20/21 04:54:41.381937 zm_mlapi[25758] DBG2 yolo:77 [portalock: acquired -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:41.384417 zm_mlapi[25758] DBG1 yolo:206 [yolo: 'DarkNet::v4 Pre-Trained' (GPU) [input image w*h 800*45
0 - resized by model_width/height to w*h: 416*416]]
10/20/21 04:54:41.479019 zm_mlapi[25758] DBG2 yolo:92 [portalock: released -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:41.925356 zm_mlapi[25758] DBG2 yolo:270 [perf:yolo:GPU: 'DarkNet::v4 Pre-Trained' detection took: 538.
51 ms]
10/20/21 04:54:41.927819 zm_mlapi[25758] DBG1 yolo:272 [yolo:DBG!: data for monitoring (GPU reset add-on) -> ['outs=3
', 'out=8112', 'out=2028', 'out=507']]
10/20/21 04:54:41.930125 zm_mlapi[25758] DBG1 yolo:299 [yolo returning ['toaster'] -- [[44, 53, 594, 447]] -- [0.2739
2578125]]
10/20/21 04:54:41.934921 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'DarkNet::v4 Pre-Trained
' found 1 detection -> toaster]
10/20/21 04:54:41.937146 zm_mlapi[25758] DBG1 detect_sequence:425 [>>> detected 'toaster (1/1)' confidence: 0.27]
10/20/21 04:54:41.939535 zm_mlapi[25758] DBG1 detect_sequence:474 ['toaster (1/1)' minimum confidence found: (object_
min_conf:sequence->DarkNet::v4 Pre-Trained) -> '0.56']
10/20/21 04:54:41.941764 zm_mlapi[25758] DBG2 detect_sequence:478 [confidence: 27.39 is lower than minimum of 56.00,
removing...]
10/20/21 04:54:41.943961 zm_mlapi[25758] DBG2 detect_sequence:904 [detection: 'toaster (1/1)' has FAILED filtering]
10/20/21 04:54:41.946076 zm_mlapi[25758] DBG2 detect_sequence:1531 [ml: all 'object' matches in frame 110 were filter
ed out]
10/20/21 04:54:41.948127 zm_mlapi[25758] DBG2 detect_sequence:1546 [perf:frame: 110 took 620.48 ms]
10/20/21 04:54:41.950308 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=3 --- self.fids_proc
essed=['s-105', '70', '110'] --- self.frame_set[self.frame_set_index]='160' --- self.get_last_frame()='110' --- self.
max_frames=8]
10/20/21 04:54:41.952531 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:42.572721 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=160 current frame buffer length '
208' last API call frame buffer length was '208']
10/20/21 04:54:42.572963 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=False --- self.skip_all_count=1]
10/20/21 04:54:42.577391 zm_mlapi[25758] DBG2 Media:682 [api:make_req: 'get'-><hidden>/index.php?view=image&eid=41097
&fid=160 query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:43.101528 zm_mlapi[25758] DBG1 Media:748 [media:read: API returned frame with dimensions -> (1080, 192
0), using 'resize' of 800=(450, 800)]
10/20/21 04:54:43.104194 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 160 [strategy:'first'] (4 of 8) - model: '
object' [strategy:'first'] (1 of 1) - sequence: 'coral::MobileNETv2-SSD' [strategy:'most'] (1 of 2)]
10/20/21 04:54:43.10665 zm_mlapi[25758] DBG2 coral_edgetpu:188 [coral: pre processing resize for coral model requeste
d (w*h) -> 312*312]
10/20/21 04:54:43.116329 zm_mlapi[25758] DBG2 coral_edgetpu:52 [Waiting for pyzm_uid1000_TPU_lock portalock...]
10/20/21 04:54:43.119151 zm_mlapi[25758] DBG2 coral_edgetpu:54 [portalock: got 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:43.121434 zm_mlapi[25758] DBG1 coral_edgetpu:206 [coral: 'coral::MobileNETv2-SSD' input image (w*h): 8
00*450 resized by tpu_model_width/height to 312*312]
10/20/21 04:54:43.143881 zm_mlapi[25758] DBG2 coral_edgetpu:71 [portalock: released 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:43.146279 zm_mlapi[25758] DBG1 coral_edgetpu:226 [perf:coral: 'coral::MobileNETv2-SSD' detection took:
19.82 ms]
10/20/21 04:54:43.148712 zm_mlapi[25758] DBG2 coral_edgetpu:245 [coral: the image was resized before processing, scal
ing bounding boxes in image back up by factors of -> x=2.564 y=1.442]
10/20/21 04:54:43.15104 zm_mlapi[25758] DBG1 coral_edgetpu:265 [coral returning [] -- [] -- []]
10/20/21 04:54:43.153075 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'coral::MobileNETv2-SSD'
found 0 detections -> ]
10/20/21 04:54:43.155122 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 160 [strategy:'first'] (4 of 8) - model: '
object' [strategy:'first'] (1 of 1) - sequence: 'DarkNet::v4 Pre-Trained' [strategy:'most'] (2 of 2)]
10/20/21 04:54:43.158229 zm_mlapi[25758] DBG2 yolo:77 [portalock: acquired -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:43.160536 zm_mlapi[25758] DBG1 yolo:206 [yolo: 'DarkNet::v4 Pre-Trained' (GPU) [input image w*h 800*45
0 - resized by model_width/height to w*h: 416*416]]
10/20/21 04:54:43.240435 zm_mlapi[25758] DBG2 yolo:92 [portalock: released -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:43.680702 zm_mlapi[25758] DBG2 yolo:270 [perf:yolo:GPU: 'DarkNet::v4 Pre-Trained' detection took: 517.
77 ms]
10/20/21 04:54:43.68333 zm_mlapi[25758] DBG1 yolo:272 [yolo:DBG!: data for monitoring (GPU reset add-on) -> ['outs=3'
, 'out=8112', 'out=2028', 'out=507']]
10/20/21 04:54:43.685587 zm_mlapi[25758] DBG1 yolo:299 [yolo returning [] -- [] -- []]
10/20/21 04:54:43.690617 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'DarkNet::v4 Pre-Trained
' found 0 detections -> ]
10/20/21 04:54:43.692761 zm_mlapi[25758] DBG2 detect_sequence:1526 [ml: no 'object' matches at all in frame: 160]
10/20/21 04:54:43.694837 zm_mlapi[25758] DBG2 detect_sequence:1546 [perf:frame: 160 took 590.65 ms]
10/20/21 04:54:43.697013 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=4 --- self.fids_proc
essed=['s-105', '70', '110', '160'] --- self.frame_set[self.frame_set_index]='snapshot' --- self.get_last_frame()='16
0' --- self.max_frames=8]
10/20/21 04:54:43.699251 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:44.393347 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=snapshot current frame buffer len
gth '208' last API call frame buffer length was '208']
10/20/21 04:54:44.395684 zm_mlapi[25758] DBG2 Media:528 [media:read:image: converting event -> 41097 'snapshot' to a
frame ID 's-105']
10/20/21 04:54:44.395851 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=False --- self.skip_all_count=2]
10/20/21 04:54:44.400072 zm_mlapi[25758] DBG1 Media:649 [media:read:image: skipping current frame ID -> '105' as it h
as already been processed on this run. Frame ID's processed --> ['s-105', '70', '110', '160']]
10/20/21 04:54:44.402342 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=5 --- self.fids_proc
essed=['s-105', '70', '110', '160'] --- self.frame_set[self.frame_set_index]='alarm' --- self.get_last_frame()='160'
--- self.max_frames=8]
10/20/21 04:54:44.404655 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:45.003772 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=alarm current frame buffer length
'208' last API call frame buffer length was '208']
10/20/21 04:54:45.007834 zm_mlapi[25758] DBG1 Media:493 [media: the frame buffer (208) is not growing anymore for eve
nt '41097', all out of bounds frame ID's will now be skipped instead of reduced to the last available frame ID]
10/20/21 04:54:45.011849 zm_mlapi[25758] DBG2 Media:520 [media:read:image: converting event -> 41097 'alarm' to a fra
me ID 'a-105']
10/20/21 04:54:45.012067 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=True --- self.skip_all_count=3]
10/20/21 04:54:45.020182 zm_mlapi[25758] DBG1 Media:649 [media:read:image: skipping current frame ID -> '105' as it h
as already been processed on this run. Frame ID's processed --> ['s-105', '70', '110', '160']]
10/20/21 04:54:45.024481 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=6 --- self.fids_proc
essed=['s-105', '70', '110', '160'] --- self.frame_set[self.frame_set_index]='210' --- self.get_last_frame()='160' --
- self.max_frames=8]
10/20/21 04:54:45.028803 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:45.652521 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=210 current frame buffer length '
208' last API call frame buffer length was '208']
10/20/21 04:54:45.655106 zm_mlapi[25758] DBG1 Media:493 [media: the frame buffer (208) is not growing anymore for eve
nt '41097', all out of bounds frame ID's will now be skipped instead of reduced to the last available frame ID]
10/20/21 04:54:45.655263 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=True --- self.skip_all_count=4]
10/20/21 04:54:45.660528 zm_mlapi[25758] DBG1 Media:578 [media:read:image: monitor 3 is running at 10 FPS - threshold
of 4 converts to 40 frames. frames over by -> 2 / fps -> 0.2 seconds]
10/20/21 04:54:45.662998 zm_mlapi[25758] DBG1 Media:589 [media:read:oob: the current requested frame ID '210' is out
of bounds of the current frame buffer length '208' by -> 2 frames. '210' is within 4 seconds based on monitor 3 @ 10
fps. setting attempt loops at 3 with a wait period of 1.6633333333333333 seconds]
10/20/21 04:54:45.665491 zm_mlapi[25758] DBG2 Media:682 [api:make_req: 'get'-><hidden>/index.php?view=image&eid=41097
&fid=210 query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:45.731156 zm_mlapi[25758] DBG4 Media:682 [api: raising BAD_IMAGE ValueError as Content-Length:0]
10/20/21 04:54:46.390137 zm_mlapi[25758] DBG1 Media:695 [media:read:image: IN FID GRAB ERROR LOOP, OOB frame call cha
nging fid to last available frame ID and retrying]
10/20/21 04:54:46.393077 zm_mlapi[25758] DBG1 Media:701 [self.last_frame_id_read=206]
10/20/21 04:54:46.395769 zm_mlapi[25758] DBG2 Media:682 [api:make_req: 'get'-><hidden>/index.php?view=image&eid=41097
&fid=206 query={'token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:47.657026 zm_mlapi[25758] DBG1 Media:748 [media:read: API returned frame with dimensions -> (1080, 192
0), using 'resize' of 800=(450, 800)]
10/20/21 04:54:47.659653 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 210 [strategy:'first'] (7 of 8) - model: '
object' [strategy:'first'] (1 of 1) - sequence: 'coral::MobileNETv2-SSD' [strategy:'most'] (1 of 2)]
10/20/21 04:54:47.662373 zm_mlapi[25758] DBG2 coral_edgetpu:188 [coral: pre processing resize for coral model request
ed (w*h) -> 312*312]
10/20/21 04:54:47.671814 zm_mlapi[25758] DBG2 coral_edgetpu:52 [Waiting for pyzm_uid1000_TPU_lock portalock...]
10/20/21 04:54:47.674515 zm_mlapi[25758] DBG2 coral_edgetpu:54 [portalock: got 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:47.676854 zm_mlapi[25758] DBG1 coral_edgetpu:206 [coral: 'coral::MobileNETv2-SSD' input image (w*h): 8
00*450 resized by tpu_model_width/height to 312*312]
10/20/21 04:54:47.698312 zm_mlapi[25758] DBG2 coral_edgetpu:71 [portalock: released 'pyzm_uid1000_TPU_lock']
10/20/21 04:54:47.701098 zm_mlapi[25758] DBG1 coral_edgetpu:226 [perf:coral: 'coral::MobileNETv2-SSD' detection took:
18.94 ms]
10/20/21 04:54:47.703454 zm_mlapi[25758] DBG2 coral_edgetpu:245 [coral: the image was resized before processing, scal
ing bounding boxes in image back up by factors of -> x=2.564 y=1.442]
10/20/21 04:54:47.705761 zm_mlapi[25758] DBG1 coral_edgetpu:265 [coral returning [] -- [] -- []]
10/20/21 04:54:47.707823 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'coral::MobileNETv2-SSD'
found 0 detections -> ]
10/20/21 04:54:47.709865 zm_mlapi[25758] DBG2 detect_sequence:1160 [frame: 210 [strategy:'first'] (7 of 8) - model: '
object' [strategy:'first'] (1 of 1) - sequence: 'DarkNet::v4 Pre-Trained' [strategy:'most'] (2 of 2)]
10/20/21 04:54:47.712921 zm_mlapi[25758] DBG2 yolo:77 [portalock: acquired -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:47.715325 zm_mlapi[25758] DBG1 yolo:206 [yolo: 'DarkNet::v4 Pre-Trained' (GPU) [input image w*h 800*45
0 - resized by model_width/height to w*h: 416*416]]
10/20/21 04:54:47.810906 zm_mlapi[25758] DBG2 yolo:92 [portalock: released -> 'pyzm_uid1000_GPU_lock']
10/20/21 04:54:48.262044 zm_mlapi[25758] DBG2 yolo:270 [perf:yolo:GPU: 'DarkNet::v4 Pre-Trained' detection took: 544.
24 ms]
10/20/21 04:54:48.264534 zm_mlapi[25758] DBG1 yolo:272 [yolo:DBG!: data for monitoring (GPU reset add-on) -> ['outs=3
', 'out=8112', 'out=2028', 'out=507']]
10/20/21 04:54:48.266869 zm_mlapi[25758] DBG1 yolo:299 [yolo returning [] -- [] -- []]
10/20/21 04:54:48.271537 zm_mlapi[25758] DBG2 detect_sequence:1237 [ml: model: 'object' seq: 'DarkNet::v4 Pre-Trained
' found 0 detections -> ]
10/20/21 04:54:48.273596 zm_mlapi[25758] DBG2 detect_sequence:1526 [ml: no 'object' matches at all in frame: 210]
10/20/21 04:54:48.275654 zm_mlapi[25758] DBG2 detect_sequence:1546 [perf:frame: 210 took 616.10 ms]
10/20/21 04:54:48.277836 zm_mlapi[25758] DBG1 Media:452 [media:read:image: self.frames_processed=7 --- self.fids_proc
essed=['s-105', '70', '110', '160', '206'] --- self.frame_set[self.frame_set_index]='280' --- self.get_last_frame()='
206' --- self.max_frames=8]
10/20/21 04:54:48.280126 zm_mlapi[25758] DBG2 Media:469 [api:make_req: 'get'-><hidden>/api/events/41097.json query={'
token': 'eyJ0eXAiOiJKV1QiLCJhbGciO...'}]
10/20/21 04:54:48.874191 zm_mlapi[25758] DBG1 Media:485 [media:read:image: DBG! fid=280 current frame buffer length '
208' last API call frame buffer length was '208']
10/20/21 04:54:48.876536 zm_mlapi[25758] DBG1 Media:493 [media: the frame buffer (208) is not growing anymore for eve
nt '41097', all out of bounds frame ID's will now be skipped instead of reduced to the last available frame ID]
10/20/21 04:54:48.876692 zm_mlapi[25758] ERR Media:558 [media:read:image: skip_all=True --- self.skip_all_count=5]
10/20/21 04:54:48.88116 zm_mlapi[25758] DBG1 Media:624 [media:read:image: skipping out of bound frame -> '280' as eve
nt '41097' has not written anymore frames to disk since the last frame was called]
10/20/21 04:54:48.883192 zm_mlapi[25758] DBG1 detect_sequence:1012 [ml: ran out of frames to read, breaking out of fr
ame loop]
10/20/21 04:54:48.885447 zm_mlapi[25758] DBG2 coral_edgetpu:67 [pyzm_uid1000_TPU_lock portalock already released]
10/20/21 04:54:48.887526 zm_mlapi[25758] DBG1 detect_sequence:1642 [perf:detect stream:FINAL: '3->41097': complete de
tection sequence took: 12097.22 ms]
10/20/21 04:54:48.889395 zm_mlapi[25758] DBG1 mlapi:491 [mlapi:detect: no detections to return]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment