Detection process fails

[zmevtuser]

Hello,
I had both zoneminder and zmeventnotification running without any issues for years but recently notification stopped working with the following symptoms:
event start hook exits with code .
zmeventnotification.log:

Code: Select all

06/27/2023 00:40:37.831528 zmeventnotification[20987].DB1 [main:1035] [|----> FORK:Kalitka (2), eid:1172732 hook start returned with text: json:[] exit:1]

zmesdetect_m2.log has the following lines:

Code: Select all

06/27/23 00:40:37 zmesdetect_m2[20991] INF ZMLog.py:292 [Setting up signal handler for logs]
06/27/23 00:40:37 zmesdetect_m2[20991] INF ZMLog.py:301 [Switching global logger to ZMLog]
06/27/23 00:40:37 zmesdetect_m2[20991] INF zm_detect.py:283 [---------| app:6.1.28, pyzm:0.3.56, ES:6.1.28
 , OpenCV:4.5.0|------------]
06/27/23 00:40:37 zmesdetect_m2[20991] INF utils.py:405 [Reading config from: /etc/zm/objectconfig.ini]
06/27/23 00:40:37 zmesdetect_m2[20991] INF utils.py:410 [Reading secrets from: /etc/zm/secrets.ini]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !ZM_PORTAL]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !ZM_USER]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !ZM_PASSWORD]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !ZM_API_PORTAL]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !ML_USER]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !ML_PASSWORD]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:382 [Secret token found in config: !PLATEREC_ALPR_KEY]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG1 utils.py:445 [allowing self-signed certs to work...]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:455 [Now checking for monitor overrides]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:174 [import_zm_zones: match_reason=False and reason=Motion Outside]
06/27/23 00:40:37 zmesdetect_m2[20991] DBG2 utils.py:177 [Getting ZM zones using http://localhost/zm/api/zones/forMonitor/2.json?username=xxx&password=yyy&user=xxx&pass=yyy]
06/27/23 00:40:37 zmesdetect_m2[20991] ERR utils.py:202 [HTTP Error in import_zm_zones:HTTP Error 500: Internal Server Error]
06/27/23 00:40:37 zmesdetect_m2[20991] ERR utils.py:514 [Error parsing config:/etc/zm/objectconfig.ini]
06/27/23 00:40:37 zmesdetect_m2[20991] ERR utils.py:515 [Error was:HTTP Error 500: Internal Server Error]
06/27/23 00:40:37 zmesdetect_m2[20991] FAT utils.py:516 [error: Traceback:Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/zmes_hook_helpers/utils.py", line 499, in process_config
    import_zm_zones(args.get('monitorid'), args.get('reason'))
  File "/usr/local/lib/python3.7/dist-packages/zmes_hook_helpers/utils.py", line 200, in import_zm_zones
    input_file = opener.open(url)
  File "/usr/lib/python3.7/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/usr/lib/python3.7/urllib/request.py", line 641, in http_response
    'http', request, response, code, msg, hdrs)
  File "/usr/lib/python3.7/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 503, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 649, in http_error_default
    raise HTTPError(req.full_url, code, msg, hdrs, fp)
urllib.error.HTTPError: HTTP Error 500: Internal Server Error
]

Tried to manually invoke zm_detect.py and it completes without any issues.

ZM 1.36.33 Debian 10

[iconnor]

Permissions problem on /etc/zm/objdetect.ini maybe?

[zmevtuser]

Permissions problem on /etc/zm/objdetect.ini maybe?

This file doesn't even exist. There is /etc/zm/objectconfig.ini and it is readable by all, including www-data.

[Magic919]

It's hard to understand how it will run manually as the www-data user and yet fail in use.

[zmevtuser]

Update: after system reboot some (but not many of all) of the detection runs seem to be successful, as I can see in the zmesdetect_m*.log files. At the same time zmc processes now consume all of the CPU, presumably because of the debug turned on.
Edit:
sometimes error is slightly different:

Code: Select all

06/27/23 11:16:38 zmesdetect_m2[13852] INF ZMLog.py:292 [Setting up signal handler for logs]
06/27/23 11:16:38 zmesdetect_m2[13852] INF ZMLog.py:301 [Switching global logger to ZMLog]
06/27/23 11:16:38 zmesdetect_m2[13852] INF zm_detect.py:283 [---------| app:6.1.28, pyzm:0.3.56, ES:6.1.28
 , OpenCV:4.5.0|------------]
06/27/23 11:16:38 zmesdetect_m2[13852] INF utils.py:405 [Reading config from: /etc/zm/objectconfig.ini]
06/27/23 11:16:38 zmesdetect_m2[13852] INF utils.py:410 [Reading secrets from: /etc/zm/secrets.ini]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !ZM_PORTAL]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !ZM_USER]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !ZM_PASSWORD]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !ZM_API_PORTAL]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !ML_USER]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !ML_PASSWORD]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:382 [Secret token found in config: !PLATEREC_ALPR_KEY]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG1 utils.py:445 [allowing self-signed certs to work...]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:455 [Now checking for monitor overrides]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:174 [import_zm_zones: match_reason=False and reason=Motion Kalitka]
06/27/23 11:16:38 zmesdetect_m2[13852] DBG2 utils.py:177 [Getting ZM zones using http://localhost/zm/api/zones/forMonitor/2.json?username=xxx&password=yyy&user=xxx&pass=yyy]
06/27/23 11:16:38 zmesdetect_m2[13852] ERR utils.py:202 [HTTP Error in import_zm_zones:HTTP Error 500: Internal Server Error]
06/27/23 11:16:38 zmesdetect_m2[13852] ERR utils.py:514 [Error parsing config:/etc/zm/objectconfig.ini]
06/27/23 11:16:38 zmesdetect_m2[13852] ERR utils.py:515 [Error was:HTTP Error 500: Internal Server Error]
06/27/23 11:16:38 zmesdetect_m2[13852] FAT utils.py:516 [error: Traceback:Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/zmes_hook_helpers/utils.py", line 499, in process_config
    import_zm_zones(args.get('monitorid'), args.get('reason'))
  File "/usr/local/lib/python3.7/dist-packages/zmes_hook_helpers/utils.py", line 200, in import_zm_zones
    input_file = opener.open(url)
  File "/usr/lib/python3.7/urllib/request.py", line 531, in open
    response = meth(req, response)
  File "/usr/lib/python3.7/urllib/request.py", line 641, in http_response
    'http', request, response, code, msg, hdrs)
  File "/usr/lib/python3.7/urllib/request.py", line 569, in error
    return self._call_chain(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 503, in _call_chain
    result = func(*args)
  File "/usr/lib/python3.7/urllib/request.py", line 649, in http_error_default
    raise HTTPError(req.full_url, code, msg, hdrs, fp)
urllib.error.HTTPError: HTTP Error 500: Internal Server Error
]

[zmevtuser]

Update 2:
Found collateral messages in nginx error_log:

Code: Select all

2023/06/27 12:48:03 [error] 15320#15320: *6475 FastCGI sent in stderr: "PHP message: Unable to connect to ZM DB SQLSTATE[HY000] [1203] User zmuser already has more than 'max_user_connections' active connections" while reading response header from upstream, client: ::1, server: _, request: "GET /zm/api/zones/forMonitor/5.json?username=***&password=***&user=***&pass=*** HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.3-fpm.sock:", host: "localhost"

Mariadb max_user_connections = 20

I have 8 configured and 5 running cameras, and this number of connections was enough until the recent time. Will increase the number and see if it helps.

[Magic919]

Ok, so you have NGINX not able to respond and causing problems when ZMES hits the API to get the zones.

[zmevtuser]

Ok, so you have NGINX not able to respond and causing problems when ZMES hits the API to get the zones.

It seems so, and to be more precise, it is the script that has to return the zones fails unable to connect to DB

[Magic919]

Have a look at the output of mysqltuner for DB optimisation.

[zmevtuser]

Have a look at the output of mysqltuner for DB optimisation.

Thank you, will do that.

Meanwhile, the problem seems to be resolved by increasing max_user_connections to 40.