ZoneMinder / zmeventnotification

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

Fix call to g.logger.Debug() that was causing an TypeError exception. #301

Closed neillbell closed 4 years ago

neillbell commented 4 years ago

I'm curious. This problem has been around for a bit because it was not logged. Is there any way to ensure that errors like this get logged?

pliablepixels commented 4 years ago

I'm not sure I understand your ask. I think this issue crept in when I migrated logging from inbuilt to pyzm. The level option was at the end before, so it never created the issue. Now it was in front, so it did not work. I suppose inside the implementation of the logger I can check the type of the object, if that is what you mean, but I'm not sure it's worth that extra check for every log.

neillbell commented 4 years ago

It was not immediately obvious from looking at the logs that there was a problem at all. Is it possible to have an all-encompassing try/catch that would allow us to log this sort of simple error?

pliablepixels commented 4 years ago

Yes, that's my point. This issue was:

def foo(level=1, msg=message)
    print (f"level={level} MESSAGE={message}")

If I call it as

foo('Hello')

It is not an error, "Hello" is taken to be the first parameter. I should be modifying my code to do

foo(1,'Hello') 
or
foo(msg='Hello')

So try/catch does not catch these issues. I have try catch routines already which make sure non critical things don't exit zmdetect.

neillbell commented 4 years ago

I understand the error. I was just wondering if there was a way to keep the system from failing silently.

pliablepixels commented 4 years ago

Okay, so I looked into the issue more.

  1. This was actually generating an exception
  2. It was not being reported in zmdetect logs (but I suppose it would be there in zmdc logs)
  3. Your ask is to log this in zmdetect

The reason this did not log into zmdetect logs was this was invoked at root level of zmdetect.py, outside of try/catch modules.

I might look at wrapping the main execution in a try catch as well just so I can log it.

neillbell commented 4 years ago

Looking back over this I realize that I did a poor job of explaining the problem. Thanks for looking further into it.

pliablepixels commented 4 years ago

Please see if this fixes it for you.

neillbell commented 4 years ago

The late import of cv2 is causing a problem. When I put back the early import it logs errors wonderfully. It even logs the missing cv2!

08/27/20 11:37:02 zmesdetect_m12[19951] INF zm_detect.py:194 [---------| hook version: 0.1.24, ES version: 6.0.0 , OpenCV version: 4.4.0-dev|------------]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 utils.py:297 [secret filename: /etc/zm/secrets.ini]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !ZM_PORTAL]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !ZM_API_PORTAL]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !ZM_USER]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !ZM_PASSWORD]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !ML_USER]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !ML_PASSWORD]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:270 [Secret token found in config: !PLATEREC_ALPR_KEY]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 utils.py:318 [allowing self-signed certs to work...]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:337 [[monitor-12] overrides key:frame_id with value:bestmatch]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:337 [[monitor-12] overrides key:object_detection_pattern with value:^(?!fire hydrant|parking meter)]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:337 [[monitor-12] overrides key:match_past_detections with value:yes]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:382 [key [object_config] is '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg' after substitution]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:382 [key [object_weights] is '/var/lib/zmeventnotification/models/yolov4/yolov4.weights' after substitution]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:382 [key [object_labels] is '/var/lib/zmeventnotification/models/yolov4/coco.names' after substitution]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:382 [key [known_images_path] is '/var/lib/zmeventnotification/known_faces' after substitution]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:382 [key [unknown_images_path] is '/var/lib/zmeventnotification/unknown_faces' after substitution]
08/27/20 11:37:02 zmesdetect_m12[19951] INF zm_detect.py:226 [Importing remote shim classes for Object/Face]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 utils.py:173 [Trying to download https://waterhouse.hoopaloo.org/zm/index.php?view=image&eid=745525&fid=alarm&username=neill&password=*****]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 utils.py:192 [Trying to download https://waterhouse.hoopaloo.org/zm/index.php?view=image&eid=745525&fid=snapshot&username=neill&password=*****]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 zm_detect.py:279 [No polygon area specfied, so adding a full image polygon:[{'name': 'full_image', 'value': [(0, 0), (1920, 0), (1920, 1080), (0, 1080)]}]]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 zm_detect.py:282 [resizing to 1200 before analysis...]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 utils.py:38 [resized polygons x=0.625/y=0.625: [{'name': 'full_image', 'value': [(0, 0), (1200, 0), (1200, 675), (0, 675)]}]]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 zm_detect.py:303 [User ALPR if vehicle found: False]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 zm_detect.py:355 [using g.config['object_detection_pattern']=^(?!fire hydrant|parking meter)]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 zm_detect.py:388 [Using model: object with /var/lib/zmeventnotification/images/745525-alarm.jpg]
08/27/20 11:37:02 zmesdetect_m12[19951] INF zm_detect.py:42 [Detecting using remote API Gateway http://localhost:5000/api/v1]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG2 zm_detect.py:50 [Found token file, checking if token has not expired]
08/27/20 11:37:02 zmesdetect_m12[19951] DBG1 zm_detect.py:65 [Access token is valid for 1450 more seconds]
08/27/20 11:37:02 zmesdetect_m12[19951] ERR zm_detect.py:397 [Error executing remote API: name 'cv2' is not defined]
08/27/20 11:37:02 zmesdetect_m12[19951] FAT zm_detect.py:849 [Unrecoverable error:name 'cv2' is not defined Traceback:Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 846, in <module>
    main_handler()
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 395, in main_handler
    b, l, c = remote_detect(original_image, model)
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 101, in remote_detect
    ret, jpeg = cv2.imencode('.jpg', image)
NameError: name 'cv2' is not defined
pliablepixels commented 4 years ago

Can you elaborate? import cv2 on line 9 is commented out. If you uncomment it, it is not inside try/catch of main and will not be caught/logged.

import cv2 at line 190 is already inside a try catch and should be logged

neillbell commented 4 years ago

When I run the code unmodified from the repository, I get an error as shown. If I put the "import cv2" back in, it works as expected.

I just checked. If I use direct detection then it works properly. If I use ml_gateway, it generates the error shown in the log above.

pliablepixels commented 4 years ago

Don’t follow. Please post code for what you are trying and logs for what you are seeing.

neillbell commented 4 years ago

Sorry for the delay.

The cv2 module is not properly imported when running with remote detection via ml_gateway. With the code unmodified from the repository, I get the following when running a detection:

09/01/20 11:33:53 zmesdetect_m12[7944] FAT zm_detect.py:850 [Unrecoverable error:name 'cv2' is not defined Traceback:Traceback (most recent call last):
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 847, in <module>
    main_handler()
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 396, in main_handler
    b, l, c = remote_detect(original_image, model)
  File "/var/lib/zmeventnotification/bin/zm_detect.py", line 102, in remote_detect
    ret, jpeg = cv2.imencode('.jpg', image)
NameError: name 'cv2' is not defined

This occurs because the remote_detect() function makes calls to cv2 although that module has apparently not been imported. Looking at the code, it seems like it is imported beforehand, but it's not somehow. If I import cv2 within remote_detect(), the error no longer occurs.

def remote_detect(image, model=None):
    import requests
    # Import the missing module
    import cv2
    bbox = []
    label = []
    conf = []
    api_url = g.config['ml_gateway']