mlapi debug help - Githubissues

Event Server: 6.1.23 Hooks: app:6.1.23, pyzm:0.3.48 mlapi: 2.2.18 ZoneMinder: 1.35.28

First, sorry, debug help is probably the wrong title. This must be operator/user error. I have walked through the instructions three times over the past couple of days but so far no luck figuring out what I have done wrong. Thank you in advance for any pointers.

I have mirrored my secrets.ini files on the zm/eventserver and mlapi server. I have also copy/pasted the working detection sections from my zm/eventserver objectconfig.ini into the mlapi server mlapiconfig.ini

mlapi server is working for every manual test I can do from the client (zm/eventserver) does work. For example, running this on the zm server (I copy/paste the usernames and passwords from the secrets.ini file): $ curl -XPOST "http://10.8.2.54:5000/api/v1/detect/object?delete=false" -d "url=https://zm.server/zm/cgi-bin/nph-zms?mode=single%26maxfps=5%26buffer=1000%26monitor=7%26user=zmuser%26pass=zmpass" -H "Authorization: Bearer ${ACCESS_TOKEN}" Returns:

[{"type": "object", "label": "car", "confidence": "58.52%", "box": [162, 26, 752, 494]}]

On the mlapi server when run $python3 ./mlapi.py -c /etc/zm/mlapiconfig.ini and the eventserver calls mlapi, this is the output:

May 15 2021 19:59:32.902528 [DBG 1] Monitor ID 7 provided & matching config found in mlapi, ignoring objectconfig.ini
May 15 2021 19:59:32.902677 [DBG 4] Overriding global ml_sequence with {
'general': {
'model_sequence...
May 15 2021 19:59:32.902744 [DBG 4] Overriding global stream_sequence with {
'frame_strategy': 'most_mode...
May 15 2021 19:59:32.902787 [DBG 4] Overriding global match_past_detections with yes...
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 2464, in __call__
    return self.wsgi_app(environ, start_response)
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 2450, in wsgi_app
    response = self.handle_exception(e)
  File "/usr/local/lib/python3.8/dist-packages/flask_restful/__init__.py", line 272, in error_router
    return original_handler(e)
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 1867, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python3.8/dist-packages/flask/_compat.py", line 38, in reraise
    raise value.with_traceback(tb)
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 2447, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 1952, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python3.8/dist-packages/flask_restful/__init__.py", line 272, in error_router
    return original_handler(e)
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 1821, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python3.8/dist-packages/flask/_compat.py", line 38, in reraise
    raise value.with_traceback(tb)
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.8/dist-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/usr/local/lib/python3.8/dist-packages/flask_restful/__init__.py", line 468, in wrapper
    resp = resource(*args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/flask/views.py", line 89, in view
    return self.dispatch_request(*args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/flask_restful/__init__.py", line 583, in dispatch_request
    resp = meth(*args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/flask_jwt_extended/view_decorators.py", line 108, in wrapper
    return fn(*args, **kwargs)
  File "./mlapi.py", line 132, in post
    g.logger.Debug(4, 'Overriding global {} with {}...'.format(key, g.monitor_config[mid][key][:30]))
TypeError: 'int' object is not subscriptable
^CTraceback (most recent call last):
  File "./mlapi.py", line 415, in <module>
    bjoern.run(app,host='0.0.0.0',port=g.config['port'])
  File "/usr/local/lib/python3.8/dist-packages/bjoern.py", line 95, in run
    server_run(sock, wsgi_app, statsd)
  File "/usr/local/lib/python3.8/dist-packages/bjoern.py", line 48, in server_run
    _bjoern.server_run(*args)

This is in the /var/log/zm/zmesdetect_m7.log:

05/15/21 19:59:32 zmesdetect_m7[99859] ERR zm_detect.py:392 [Error with remote mlapi:500 Server Error: Internal Server Error for url: http://10.8.2.54:5000/api/v1/detect/object?type=object&delete=True&response_format=zm_detect]

If I check the above url on from the zm/eventserver this is the response:

message "The method is not allowed for the requested URL."

On the zm/eventserver running sudo -u www-data /usr/bin/zmeventnotification.pl --debug, this is the corresponding output (I have ml_fallback_local=yes):

DBG-2:2021-05-15,19:59:31 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-05-15,19:59:31 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,19:59:31 PARENT: There are 0 active child forks & 0 zm_detect processes running...
INF:2021-05-15,19:59:31 PARENT: New event 149005 reported for Monitor:7 (Name:Garage) Motion All[last processed eid:]
05/15/2021 19:59:31.822294 zmeventnotification[99832].INF [main:1022] [PARENT: New event 149005 reported for Monitor:7 (Name:Garage) Motion All[last processed eid:]]
DBG-2:2021-05-15,19:59:31 PARENT: checkEvents() new events found=1
DBG-2:2021-05-15,19:59:31 PARENT: There are 1 new Events to process
DBG-2:2021-05-15,19:59:31 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2021-05-15,19:59:31 PARENT: Forked process:99855 to handle alarm eid:149005
DBG-2:2021-05-15,19:59:31 |----> FORK:Garage (7), eid:149005 Adding event path:/var/cache/zoneminder/events/7/2021-05-15/149005 to hook for image storage
DBG-1:2021-05-15,19:59:31 |----> FORK:Garage (7), eid:149005 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 149005 7 "Garage" "Motion All" "/var/cache/zoneminder/events/7/2021-05-15/149005"
[ WARN:0] global /tmp/pip-req-build-jr1ur_cf/opencv/modules/dnn/src/dnn.cpp (1442) setUpNet DNN module was not built with CUDA backend; switching to CPU
DBG-2:2021-05-15,19:59:36 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-05-15,19:59:36 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,19:59:36 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add
DBG-2:2021-05-15,19:59:36 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,19:59:36 PARENT: We've already worked on Monitor:7, Event:149005, not doing anything more
DBG-2:2021-05-15,19:59:36 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,19:59:36 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,19:59:36 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,19:59:41 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-05-15,19:59:41 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,19:59:41 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,19:59:41 PARENT: We've already worked on Monitor:7, Event:149005, not doing anything more
DBG-2:2021-05-15,19:59:41 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,19:59:41 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,19:59:41 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,19:59:46 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-05-15,19:59:46 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,19:59:46 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,19:59:46 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,19:59:46 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,19:59:46 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,19:59:51 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-05-15,19:59:51 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,19:59:51 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,19:59:51 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,19:59:51 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,19:59:51 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,19:59:56 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-05-15,19:59:56 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,19:59:56 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,19:59:56 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,19:59:56 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,19:59:56 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,20:00:01 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-05-15,20:00:01 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,20:00:01 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,20:00:01 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,20:00:01 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,20:00:01 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,20:00:06 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-05-15,20:00:06 PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-05-15,20:00:06 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-05-15,20:00:06 PARENT: checkEvents() new events found=0
DBG-2:2021-05-15,20:00:06 PARENT: There are 0 new Events to process
DBG-2:2021-05-15,20:00:06 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-05-15,20:00:06 |----> FORK:Garage (7), eid:149005 parse of hook:[a] detected:person:96% truck:40% Dave:100%  and {"labels": ["person", "truck", "Dave"], "boxes": [[1, 88, 397, 498], [191, 26, 751, 494], [55, 169, 197, 310]], "frame_id": "alarm", "confidences": [0.9585224390029907, 0.39799749851226807, 1], "image_dimensions": {"original": [800, 1280], "resized": [500, 800]}}
DBG-1:2021-05-15,20:00:06 |----> FORK:Garage (7), eid:149005 hook start returned with text:[a] detected:person:96% truck:40% Dave:100%  json:{"labels": ["person", "truck", "Dave"], "boxes": [[1, 88, 397, 498], [191, 26, 751, 494], [55, 169, 197, 310]], "frame_id": "alarm", "confidences": [0.9585224390029907, 0.39799749851226807, 1], "image_dimensions": {"original": [800, 1280], "resized": [500, 800]}} exit:0
DBG-3:2021-05-15,20:00:06 |----> FORK:Garage (7), eid:149005 For 7 (Garage), SHM says: state=0, eid=149005
INF:2021-05-15,20:00:06 |----> FORK:Garage (7), eid:149005 Event 149005 for Monitor 7 has finished
05/15/2021 20:00:06.909333 zmeventnotification[99855].INF [main:1022] [|----> FORK:Garage (7), eid:149005 Event 149005 for Monitor 7 has finished]
DBG-3:2021-05-15,20:00:06 |----> FORK:Garage (7), eid:149005 Event end object is: state=>pending with cause=>Motion: All
DBG-2:2021-05-15,20:00:08 |----> FORK:Garage (7), eid:149005 rules: Checking rules for alarm caused by eid:149005, monitor:7, at: Sat May 15 20:00:08 2021 with cause:[a] detected:person:96% truck:40% Dave:100%  Motion All
DBG-1:2021-05-15,20:00:08 |----> FORK:Garage (7), eid:149005 rules: No rules found for Monitor, allowing:7
DBG-1:2021-05-15,20:00:08 |----> FORK:Garage (7), eid:149005 Matching alarm to connection rules...
DBG-1:2021-05-15,20:00:08 |----> FORK:Garage (7), eid:149005 Checking alarm conditions for token ending in:...jkr491yN_J
DBG-1:2021-05-15,20:00:08 |----> FORK:Garage (7), eid:149005 should NOT send alarm as Monitor 7 is excluded
DBG-1:2021-05-15,20:00:10 |----> FORK:Garage (7), eid:149005 ZM overwrote detection DB, current notes: [Motion: All], adding detection notes back into DB [[a] detected:person:96% truck:40% Dave:100% ]
DBG-1:2021-05-15,20:00:10 |----> FORK:Garage (7), eid:149005 updating Notes clause for Event:149005 with:[a] detected:person:96% truck:40% Dave:100%
INF:2021-05-15,20:00:10 |----> FORK:Garage (7), eid:149005 end hooks/use hooks not being used, going to directly send out a notification if checks pass
05/15/2021 20:00:10.917840 zmeventnotification[99855].INF [main:1022] [|----> FORK:Garage (7), eid:149005 end hooks/use hooks not being used, going to directly send out a notification if checks pass]

ZoneMinder / zmeventnotification

mlapi debug help #394