search

ZoneMinder / zmeventnotification

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

fcmv1: FCM push message Error:400 Bad Request #329

Closed fennec622 closed 3 years ago

fennec622 commented 3 years ago

Before you create an issue, please make sure you have read the README. If you are asking about the object detection part, I don't provide support for it unless you've tried hard enough.

Event Server version 6.0.5 You can get the version by doing:

/usr/bin/zmeventnotification.pl --version

The version of ZoneMinder you are using:

1.34.21

What is the nature of your issue

bug

Details

fcmv1: FCM push message Error:400 Bad Request

Debug Logs (if applicable)

Important: Please post DEBUG logs NOT INF logs. Instructions on how to enable debug logs are posted HERE



23/10/2020 15:38:22.677413 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Executing API script command for event_start /home/fennec/scripts/pushalarme2.py 4237530 3  "parking"  "[a] detected:person:90%   All"  event_start "/var/cache/zoneminder/events/3/2020-10-23/4237530"]
23/10/2020 15:38:23.151660 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Returned from /home/fennec/scripts/pushalarme2.py 4237530 3  "parking"  "[a] detected:person:90%   All"  event_start "/var/cache/zoneminder/events/3/2020-10-23/4237530"]
23/10/2020 15:38:23.178458 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:23.613076 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:23.630442 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:24.066523 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:24.086813 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:24.453422 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:24.468662 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:24.865294 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:25.238590 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:25.253717 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:25.846769 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:25.863547 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:26.350415 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:26.380231 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:26.739288 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:26.753552 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:27.134612 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:27.148303 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:27.577435 zmeventnotification[836656].INF [main:972] [PARENT: New event 4237532 reported for Monitor:3 (Name:parking)  All[last processed eid:4237530]]
23/10/2020 15:38:27.658263 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:27.669357 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:28.149479 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]
23/10/2020 15:38:28.163684 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification for EID:4237530 over MQTT]
23/10/2020 15:38:28.180419 zmeventnotification[855317].INF [main:972] [|----> FORK:parking (3), eid:4237530 Sending event_start notification over FCM]
23/10/2020 15:38:28.640096 zmeventnotification[855317].ERR [main:988] [|----> FORK:parking (3), eid:4237530 fcmv1: FCM push message Error:400 Bad Request]```

After restart all is ok

Thanks!
pliablepixels commented 3 years ago
  1. Your message says after restart all is ok. So is there a problem?
  2. These are not DEBUG logs. Please see link above in issue template
fennec622 commented 3 years ago

I use debug

what files do you want

this morning monitor 12

'''10/24/20 13:42:02 zmesdetect_m12[965285] INF zm_detect.py:196 [---------| pyzm version: 0.1.30, ES version: 6.0.5 , OpenCV version: 4.4.0|------------]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:300 [secret filename: /etc/zm/secrets.ini]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !ZM_PORTAL]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !ZM_API_PORTAL]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !ZM_USER]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !ZM_PASSWORD]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:268 [Section [animation] missing in config file, using key:create_animation default: no]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:268 [Section [animation] missing in config file, using key:animation_types default: mp4]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:268 [Section [animation] missing in config file, using key:animation_width default: 400]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:268 [Section [animation] missing in config file, using key:animation_retry_sleep default: 15]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:268 [Section [animation] missing in config file, using key:animation_max_tries default: 3]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:268 [Section [animation] missing in config file, using key:fast_gif default: no]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !ML_USER]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !ML_PASSWORD]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:273 [Secret token found in config: !PLATEREC_ALPR_KEY]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:323 [strict SSL cert checking is on...]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:402 [key [object_config] is '/var/lib/zmeventnotification/models/yolov4/yolov4.cfg' after substitution]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:402 [key [object_weights] is '/var/lib/zmeventnotification/models/yolov4/yolov4.weights' after substitution]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:402 [key [object_labels] is '/var/lib/zmeventnotification/models/yolov4/coco.names' after substitution]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:402 [key [known_images_path] is '/var/lib/zmeventnotification/known_faces' after substitution]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:402 [key [unknown_images_path] is '/var/lib/zmeventnotification/unknown_faces' after substitution]
10/24/20 13:42:02 zmesdetect_m12[965285] INF zm_detect.py:229 [Importing remote shim classes for Object/Face]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:176 [Trying to download http://10.0.0.1/zm/index.php?view=image&eid=4251229&fid=alarm&username=julien&password=*****]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 utils.py:195 [Trying to download http://10.0.0.1/zm/index.php?view=image&eid=4251229&fid=snapshot&username=julien&password=*****]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 zm_detect.py:282 [No polygon area specfied, so adding a full image polygon:[{'name': 'full_image', 'value': [(0, 0), (1280, 0), (1280, 720), (0, 720)], 'pattern': '(person|cat|dog)'}]]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 zm_detect.py:286 [resizing to 1200 before analysis...]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 utils.py:37 [resized polygons x=0.9375/y=0.9375: [{'name': 'full_image', 'value': [(0, 0), (1200, 0), (1200, 675), (0, 675)], 'pattern': '(person|cat|dog)'}]]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 zm_detect.py:308 [User ALPR if vehicle found: False]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 zm_detect.py:360 [using g.config['object_detection_pattern']=(person|cat|dog)]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 zm_detect.py:393 [Using model: object with /var/lib/zmeventnotification/images/4251229-alarm.jpg]
10/24/20 13:42:02 zmesdetect_m12[965285] INF zm_detect.py:44 [Detecting using remote API Gateway http://127.0.0.1:5000/api/v1]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 zm_detect.py:52 [Found token file, checking if token has not expired]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG1 zm_detect.py:66 [Access token is valid for 3000 more seconds]
10/24/20 13:42:02 zmesdetect_m12[965285] DBG2 zm_detect.py:110 [Invoking mlapi with url:http://127.0.0.1:5000/api/v1/detect/object?type=object]
10/24/20 13:42:04 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(842, 325), (1052, 325), (1052, 405), (842, 405)]]
10/24/20 13:42:04 zmesdetect_m12[965285] INF image_manip.py:313 [discarding "car" as it does not match your filters]
10/24/20 13:42:04 zmesdetect_m12[965285] DBG1 image_manip.py:316 [full_image intersects object:car[[(842, 325), (1052, 325), (1052, 405), (842, 405)]] but does NOT match your detect pattern filter]
10/24/20 13:42:04 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(678, 342), (810, 342), (810, 638), (678, 638)]]
10/24/20 13:42:04 zmesdetect_m12[965285] DBG2 image_manip.py:307 [full_image intersects object:person[[(678, 342), (810, 342), (810, 638), (678, 638)]]]
10/24/20 13:42:04 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(1071, 332), (1125, 332), (1125, 358), (1071, 358)]]
10/24/20 13:42:05 zmesdetect_m12[965285] INF image_manip.py:313 [discarding "car" as it does not match your filters]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 image_manip.py:316 [full_image intersects object:car[[(1071, 332), (1125, 332), (1125, 358), (1071, 358)]] but does NOT match your detect pattern filter]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(32, 390), (722, 390), (722, 674), (32, 674)]]
10/24/20 13:42:05 zmesdetect_m12[965285] INF image_manip.py:313 [discarding "car" as it does not match your filters]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 image_manip.py:316 [full_image intersects object:car[[(32, 390), (722, 390), (722, 674), (32, 674)]] but does NOT match your detect pattern filter]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(599, 382), (703, 382), (703, 522), (599, 522)]]
10/24/20 13:42:05 zmesdetect_m12[965285] INF image_manip.py:313 [discarding "parking meter" as it does not match your filters]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 image_manip.py:316 [full_image intersects object:parking meter[[(599, 382), (703, 382), (703, 522), (599, 522)]] but does NOT match your detect pattern filter]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(783, 396), (819, 396), (819, 476), (783, 476)]]
10/24/20 13:42:05 zmesdetect_m12[965285] INF image_manip.py:313 [discarding "backpack" as it does not match your filters]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 image_manip.py:316 [full_image intersects object:backpack[[(783, 396), (819, 396), (819, 476), (783, 476)]] but does NOT match your detect pattern filter]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(212, 432), (310, 432), (310, 520), (212, 520)]]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:307 [full_image intersects object:dog[[(212, 432), (310, 432), (310, 520), (212, 520)]]]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:294 [intersection: polygon in process=[(113, 428), (315, 428), (315, 570), (113, 570)]]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 image_manip.py:307 [full_image intersects object:dog[[(113, 428), (315, 428), (315, 570), (113, 570)]]]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 zm_detect.py:612 [ALPR not in use, no need for look aheads in processing]
10/24/20 13:42:05 zmesdetect_m12[965285] INF zm_detect.py:630 [labels found: ['person', 'dog', 'dog']]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 zm_detect.py:631 [match found in /var/lib/zmeventnotification/images/4251229-alarm.jpg, breaking file loop...]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 zm_detect.py:646 [detection mode is set to first, breaking out of model loop...]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG2 zm_detect.py:698 [Drawing boxes around objects]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 zm_detect.py:722 [Writing detected image to /var/cache/zoneminder/events/12/2020-10-24/4251229/objdetect.jpg]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 zm_detect.py:727 [Writing JSON output to /var/cache/zoneminder/events/12/2020-10-24/4251229/objects.json]
10/24/20 13:42:05 zmesdetect_m12[965285] INF zm_detect.py:779 [Prediction string:[a] detected:person:96% dog:34% ]
10/24/20 13:42:05 zmesdetect_m12[965285] DBG1 zm_detect.py:782 [Prediction string JSON:[{"type": "object", "label": "person", "box": [678, 342, 810, 638], "confidence": "95.63%"}, {"type": "object", "label": "dog", "box": [212, 432, 310, 520], "confidence": "34.46%"}, {"type": "object", "label": "dog", "box": [113, 428, 315, 570], "confidence": "27.66%"}]]

and error


'''24/10/2020 13:30:19.285828 zmeventnotification[956248].INF [main:972] [PARENT: Re-loading monitors]
24/10/2020 13:35:20.286815 zmeventnotification[956248].INF [main:972] [PARENT: Re-loading monitors]
24/10/2020 13:39:57.284858 zmeventnotification[956248].INF [main:972] [PARENT: Time to restart ES as it has been running more that 7200 seconds]
24/10/2020 13:39:57.298837 zmeventnotification[956248].INF [main:972] [PARENT: Exiting, zmdc will restart me]
24/10/2020 13:39:58.721252 zmeventnotification[965025].INF [main:972] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
24/10/2020 13:39:58.745541 zmeventnotification[965025].INF [main:972] [PARENT: using secrets file: /etc/zm/secrets.ini]
24/10/2020 13:39:58.936273 zmeventnotification[965025].INF [main:972] [PARENT: Push enabled via FCM]
24/10/2020 13:39:58.951305 zmeventnotification[965025].INF [main:972] [PARENT: Pushes will be sent through APIs and will use /home/fennec/scripts/pushalarme2.py]
24/10/2020 13:39:58.967857 zmeventnotification[965025].INF [main:972] [PARENT: MQTT Enabled]
24/10/2020 13:39:58.983469 zmeventnotification[965025].INF [main:972] [PARENT: |------- Starting ES version: 6.0.5 ---------|]
24/10/2020 13:39:59.148906 zmeventnotification[965025].INF [main:972] [PARENT: Event Notification daemon v 6.0.5 starting]
24/10/2020 13:39:59.180559 zmeventnotification[965025].INF [main:972] [PARENT: Initializing MQTT without auth connection...]
24/10/2020 13:39:59.199468 zmeventnotification[965025].INF [main:972] [PARENT: Re-loading monitors]
24/10/2020 13:39:59.226678 zmeventnotification[965025].INF [main:972] [PARENT: Secure WS(WSS) is enabled...]
24/10/2020 13:39:59.238995 zmeventnotification[965025].INF [main:972] [PARENT: Web Socket Event Server listening on port 9000]
24/10/2020 13:41:21.257487 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251219 reported for Monitor:2 (Name:porte)  All[last processed eid:]]
24/10/2020 13:41:27.101934 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending push over API as it is allowed for event_start]
24/10/2020 13:41:27.116238 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Executing API script command for event_start /home/fennec/scripts/pushalarme2.py 4251219 2  "porte"  "[a] detected:person:63%   All"  event_start "/var/cache/zoneminder/events/2/2020-10-24/4251219"]
24/10/2020 13:41:27.544977 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Returned from /home/fennec/scripts/pushalarme2.py 4251219 2  "porte"  "[a] detected:person:63%   All"  event_start "/var/cache/zoneminder/events/2/2020-10-24/4251219"]
24/10/2020 13:41:27.562034 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:27.947001 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:27.961369 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:28.456392 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:28.481043 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:28.845938 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:28.874571 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:29.146945 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:29.161170 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:29.260209 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251222 reported for Monitor:3 (Name:parking)  All[last processed eid:]]
24/10/2020 13:41:29.543014 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:29.556228 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:30.149747 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:30.163738 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:30.552398 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:30.566099 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:30.956811 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:30.973965 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:31.255592 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:31.269146 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:31.653031 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:32.145122 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:32.160559 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:32.560017 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:32.586575 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification over FCM]
24/10/2020 13:41:32.959439 zmeventnotification[965125].ERR [main:988] [|----> FORK:porte (2), eid:4251219 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:32.982019 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Sending event_start notification for EID:4251219 over MQTT]
24/10/2020 13:41:33.002728 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Event 4251219 for Monitor 2 has finished]
24/10/2020 13:41:35.153447 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending push over API as it is allowed for event_start]
24/10/2020 13:41:35.166694 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Executing API script command for event_start /home/fennec/scripts/pushalarme2.py 4251222 3  "parking"  "[a] detected:person:53%   All"  event_start "/var/cache/zoneminder/events/3/2020-10-24/4251222"]
24/10/2020 13:41:35.580418 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Returned from /home/fennec/scripts/pushalarme2.py 4251222 3  "parking"  "[a] detected:person:53%   All"  event_start "/var/cache/zoneminder/events/3/2020-10-24/4251222"]
24/10/2020 13:41:35.605195 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:36.063550 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:36.089732 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:36.545487 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:36.559667 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:36.961234 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:36.992173 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:37.033122 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.047280 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.061153 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.094299 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.112101 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.125253 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.138493 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.151664 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.165233 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.185803 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.206459 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.219471 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.232430 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.245811 zmeventnotification[965125].INF [main:972] [|----> FORK:porte (2), eid:4251219 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:37.348978 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:37.362776 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:37.663794 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:37.680138 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:38.079232 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:38.128112 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:38.444768 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:38.457967 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:38.845557 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:38.878038 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:39.261300 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:39.281437 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:39.751669 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:40.152521 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:40.166633 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:40.558365 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:40.573235 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification over FCM]
24/10/2020 13:41:40.948257 zmeventnotification[965159].ERR [main:988] [|----> FORK:parking (3), eid:4251222 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:40.967414 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Sending event_start notification for EID:4251222 over MQTT]
24/10/2020 13:41:49.257318 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251226 reported for Monitor:12 (Name:portier)  All[last processed eid:]]
24/10/2020 13:41:52.991590 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Event 4251222 for Monitor 3 has finished]
24/10/2020 13:41:55.369377 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending push over API as it is allowed for event_start]
24/10/2020 13:41:55.383437 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Executing API script command for event_start /home/fennec/scripts/pushalarme2.py 4251226 12  "portier"  "[a] detected:person:59%   All"  event_start "/var/cache/zoneminder/events/12/2020-10-24/4251226"]
24/10/2020 13:41:55.808146 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Returned from /home/fennec/scripts/pushalarme2.py 4251226 12  "portier"  "[a] detected:person:59%   All"  event_start "/var/cache/zoneminder/events/12/2020-10-24/4251226"]
24/10/2020 13:41:55.821766 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:56.256242 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:56.271264 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:56.757196 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:56.771142 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:57.012323 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.027673 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.041002 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.058406 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.085454 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.098457 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.113426 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.126493 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.143224 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:57.148002 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.166021 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:57.168572 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.191738 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.210065 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.225599 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.238748 zmeventnotification[965159].INF [main:972] [|----> FORK:parking (3), eid:4251222 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:41:57.454993 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:57.471006 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:57.759557 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:57.775866 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:58.267553 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:58.281946 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:58.658147 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:58.671656 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:59.094615 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:59.113774 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:59.547985 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:59.561613 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:41:59.967443 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:41:59.993882 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:42:00.363540 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:00.380077 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification over FCM]
24/10/2020 13:42:00.758887 zmeventnotification[965236].ERR [main:988] [|----> FORK:portier (12), eid:4251226 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:00.770991 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Sending event_start notification for EID:4251226 over MQTT]
24/10/2020 13:42:00.785884 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Event 4251226 for Monitor 12 has finished]
24/10/2020 13:42:01.261566 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251229 reported for Monitor:12 (Name:portier)  All[last processed eid:4251226]]
24/10/2020 13:42:04.823968 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.840330 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.855194 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.873046 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.888733 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.901943 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.914492 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.927555 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.940438 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.953103 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.972127 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:04.987976 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:05.022687 zmeventnotification[965236].INF [main:972] [|----> FORK:portier (12), eid:4251226 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:05.330510 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Event 4251229 for Monitor 12 has finished]
24/10/2020 13:42:07.348065 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending push over API as it is allowed for event_start]
24/10/2020 13:42:07.369042 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Executing API script command for event_start /home/fennec/scripts/pushalarme2.py 4251229 12  "portier"  "[a] detected:person:96% dog:34%   All"  event_start "/var/cache/zoneminder/events/12/2020-10-24/4251229"]
24/10/2020 13:42:07.788236 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Returned from /home/fennec/scripts/pushalarme2.py 4251229 12  "portier"  "[a] detected:person:96% dog:34%   All"  event_start "/var/cache/zoneminder/events/12/2020-10-24/4251229"]
24/10/2020 13:42:07.802659 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:08.178205 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:08.191434 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:08.561862 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:08.573067 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:08.948755 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:08.960228 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:09.363765 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:09.377655 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:09.890127 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:09.904102 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:10.271078 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:10.285566 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:10.564258 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:10.578608 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:10.967674 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:10.992575 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:11.360129 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:11.377366 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:11.757428 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:11.771000 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:12.148712 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:12.162273 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification over FCM]
24/10/2020 13:42:12.555686 zmeventnotification[965281].ERR [main:988] [|----> FORK:portier (12), eid:4251229 fcmv1: FCM push message Error:400 Bad Request]
24/10/2020 13:42:12.572071 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Sending event_start notification for EID:4251229 over MQTT]
24/10/2020 13:42:16.593760 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.604807 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.621048 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.636276 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.661552 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.695108 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.713827 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.732013 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.745333 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.769586 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.788686 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.817190 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:16.830293 zmeventnotification[965281].INF [main:972] [|----> FORK:portier (12), eid:4251229 Not sending event end notification as send_event_end_notification is no]
24/10/2020 13:42:34.257120 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251237 reported for Monitor:12 (Name:portier)  All[last processed eid:4251229]]
24/10/2020 13:42:36.259942 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251240 reported for Monitor:3 (Name:parking)  All[last processed eid:4251222]]
24/10/2020 13:42:43.858615 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Event 4251237 for Monitor 12 has finished]
24/10/2020 13:42:45.872884 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending push over API as it is not allowed for event_start]
24/10/2020 13:42:45.887626 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:45.911773 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:45.937584 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:45.962476 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:45.987760 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.025836 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.042926 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.061607 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.075210 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.086691 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Event 4251240 for Monitor 3 has finished]
24/10/2020 13:42:46.116286 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.137847 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.156449 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:46.169111 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending over MQTT as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:47.258731 zmeventnotification[965025].INF [main:972] [PARENT: New event 4251241 reported for Monitor:12 (Name:portier)  All[last processed eid:4251237]]
24/10/2020 13:42:48.126226 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending push over API as it is not allowed for event_start]
24/10/2020 13:42:48.146026 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.160086 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.173760 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.187142 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.200346 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.216411 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.229855 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.243046 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.256728 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.269997 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.283618 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.304692 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.318421 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over FCM as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:48.331705 zmeventnotification[965488].INF [main:972] [|----> FORK:parking (3), eid:4251240 Not sending over MQTT as notify filters are on_success:fcm,mqtt,api and on_fail:none]
24/10/2020 13:42:50.190681 zmeventnotification[965457].INF [main:972] [|----> FORK:portier (12), eid:4251237 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
24/10/2020 13:42:52.375184'''```
pliablepixels commented 3 years ago

Can you share the debug logs for zmeventnotification.ini at the time of this error? I need to see what FCM message was sent.

fennec622 commented 3 years ago

Capture d’écran 2020-10-24 à 14 36 28 Whats levels ? ZM in 2 and ES in 2

Capture d’écran 2020-10-24 à 14 37 35 Capture d’écran 2020-10-24 à 14 37 46

fennec622 commented 3 years ago

Ok i have space on DEBUG_TARGET so no debug for ES

now it's ok

24/10/2020 14:50:43.249278 zmeventnotification[976883].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140501397893120 for 2] 24/10/2020 14:50:43.249392 zmeventnotification[976883].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1] 24/10/2020 14:50:43.249507 zmeventnotification[976883].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140501398183936 for 1] 24/10/2020 14:50:43.249583 zmeventnotification[976883].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1] 24/10/2020 14:50:43.249691 zmeventnotification[976883].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140501397889024 for 3] 24/10/2020 14:50:43.249756 zmeventnotification[976883].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 3: 1] 24/10/2020 14:50:43.249866 zmeventnotification[976883].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140501375787008 for 12] 24/10/2020 14:50:43.249943 zmeventnotification[976883].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 12: 1] 24/10/2020 14:50:43.250051 zmeventnotification[976883].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140501375791104 for 9] 24/10/2020 14:50:43.250127 zmeventnotification[976883].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 9: 1] 24/10/2020 14:50:43.250252 zmeventnotification[976883].DBG [main:963] [PARENT: checkEvents() new events found=0] 24/10/2020 14:50:43.250307 zmeventnotification[976883].DBG [main:963] [PARENT: There are 0 new Events to process] 24/10/2020 14:50:43.250374 zmeventnotification[976883].DBG [main:963] [PARENT: ---------->Tick END<--------------] 24/10/2020 14:50:43.261523 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 Checking alarm conditions for token ending in:...x4c4ommaCd] 24/10/2020 14:50:43.261689 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 Monitor 2 event: last time not found, so should send] 24/10/2020 14:50:43.261805 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 shouldSendEventToConn returned true, so calling sendEvent] 24/10/2020 14:50:43.261977 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 isAllowedChannel: got type:event_start resCode:0] 24/10/2020 14:50:43.262093 zmeventnotification[976968].INF [main:972] [|----> FORK:porte (2), eid:4251614 Sending event_start notification over FCM] 24/10/2020 14:50:43.278551 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 fcmv1: Alarm frame matched, changing picture url to:https://url/zm/index.php?view=image&eid=4251614&fid=objdetect&width=1000&username=julien&password=xxx ] 24/10/2020 14:50:43.278925 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 fcmv1: Final JSON using FCMV1 being sent is: {"image_url":"https://url/zm/index.php?view=image&eid=4251614&fid=objdetect&width=1000&username=julien&password=xxx}},"sound":"default","data":{"mid":"2","eid":"4251614","notification_foreground":"true"},"token":"c2wMc_URhVA:APA91bFBrPjE0gtgUQDtHF3xezdTNowFljod02mgmSkQzLlYm-rXg-Ip5afix904LmPs01idHHbDuitZxrETRNaBetKj0uCTHP0MO7A1Y3y3kAwCAxB2GG_zsRpC5bjqlSx4c4ommaCd"} to token: ...ommaCd] 24/10/2020 14:50:43.654844 zmeventnotification[976968].ERR [main:988] [|----> FORK:porte (2), eid:4251614 fcmv1: FCM push message Error:400 Bad Request] 24/10/2020 14:50:43.669072 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 Checking alarm conditions for token ending in:...blfUuc2vVP] 24/10/2020 14:50:43.669199 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 Monitor 2 event: last time not found, so should send] 24/10/2020 14:50:43.669285 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 shouldSendEventToConn returned true, so calling sendEvent] 24/10/2020 14:50:43.669503 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 isAllowedChannel: got type:event_start resCode:0] 24/10/2020 14:50:43.669579 zmeventnotification[976968].INF [main:972] [|----> FORK:porte (2), eid:4251614 Sending event_start notification over FCM] 24/10/2020 14:50:43.689872 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 fcmv1: Alarm frame matched, changing picture url to:https://url/zm/index.php?view=image&eid=4251614&fid=objdetect&width=1000&username=julien&password=xxx ] 24/10/2020 14:50:43.690099 zmeventnotification[976968].DBG [main:963] [|----> FORK:porte (2), eid:4251614 fcmv1: Final JSON using FCMV1 being sent is: {"image_url":"https://url/zm/index.php?view=image&eid=4251614&fid=objdetect&width=1000&username=julien&password=xxx},"badge":1,"sound":"default","ios":{"thread_id":"zmninja_alarm","headers":{"apns-push-type":"alert","apns-priority":"10"}}} to token: ...uc2vVP] 24/10/2020 14:50:43.967817 zmeventnotification[976968].ERR [main:988] [|----> FORK:porte (2), eid:4251614 fcmv1: FCM push message Error:400 Bad Request]

pliablepixels commented 3 years ago

There is something wrong. Here is what mine looks like:

Final JSON using FCMV1 being sent is: {"body":"[a] detected:person:42%  Motion pri area at 10:02 AM, 24-Oct","token":"cs3JsP39aEuC<etc>MDM","data":{"mid":"8","eid":"158763","notification_foreground":"true"},"badge":9,"ios":{"headers":{"apns-push-type":"alert","apns-priority":"10"},"thread_id":"zmninja_alarm"},"sound":"default","image_url":"<url>} to token: ...LhfMDM]

A lot of elements are missing for you.

fennec622 commented 3 years ago

Very strange because sometimes is ok

I try to see whats happen now have full debug

For information i use mlapi with tpu coral i use yolo4 with processor TPU


# This is an optional file
# If specified, you can specify tokens with secret values in that file
# and onlt refer to the tokens in your main config file

secrets=./secrets.ini
#secrets=./secrets.mine

# port that mlapi will listen on. Default 5000
port=5000

# Maximum # of processes that will be forked
# to handle requests. Note that each process will
# have its own copy of the model, so memory can 
# build up very quickly
# This number also dictates how many requests will be executed in parallel
# The rest will be queued

# For now, keep this to 1 if you are on a GPU
processes=1

# the secret key that will be used to sign
# JWT tokens. Make sure you change the value
# in your secrets.ini
mlapi_secret_key=!MLAPI_SECRET_KEY

# folder where images will be uploaded
# default ./images
images_path=./images

# folder where the user DB will be stored
db_path=./db

# If specified, will limit detected object size to this amount of
# the total image size passed. Can help avoiding weird detections
# You can specify as % or px. Default is px
# Remember the image is resized to 416x416 internally. better
# to keep in %
max_detection_size=100%

# You can now limit the # of detection process
# per target processor. If not specified, default is 1
# Other detection processes will wait to acquire lock

cpu_max_processes=5
tpu_max_processes=1
gpu_max_processes=1

# NEW: Time to wait in seconds per processor to be free, before
# erroring out. Default is 120 (2 mins)
cpu_max_lock_wait=120
tpu_max_lock_wait=120
gpu_max_lock_wait=120

[object]

object_min_confidence=0.2

# for Yolov3
#object_framework=opencv
#object_processor=cpu
#object_config=./models/yolov3/yolov3.cfg
#object_weights=./models/yolov3/yolov3.weights
#object_labels=./models/yolov3/coco.names

# for Tiny Yolov3
#object_framework=opencv
#object_processor=tpu
#object_config=./models/tinyyolov3/yolov3-tiny.cfg
#object_weights=./models/tinyyolov3/yolov3-tiny.weights
#object_labels=./models/tinyyolov3/coco.names

# for Yolov4
object_framework=opencv
object_processor=tpu
object_config=./models/yolov4/yolov4.cfg
object_weights=./models/yolov4/yolov4.weights
object_labels=./models/yolov4/coco.names

# for Tiny Yolov4
#object_framework=opencv
#object_processor=cpu
#object_config=./models/tinyyolov4/yolov4-tiny.cfg
#object_weights=./models/tinyyolov4/yolov4-tiny.weights
#object_labels=./models/tinyyolov4/coco.names

# for Google Coral Edge TPU
#object_framework=coral_edgetpu
#object_processor=tpu
#object_weights=./models/coral_edgetpu/ssd_mobilenet_v2_coco_quant_postprocess_edgetpu.tflite
#object_labels=./models/coral_edgetpu/coco_indexed.names

[face]
#face_detection_framework=dlib
#face_recognition_framework=dlib
#face_num_jitters=0
#face_upsample_times=1
#face_model=cnn
#face_train_model=hog
#face_recog_dist_threshold=0.6
#face_recog_knn_algo=ball_tree

#known_images_path=./known_faces
#unknown_images_path=./unknown_faces

#unknown_face_name=unknown face
#save_unknown_faces=yes
#save_unknown_faces_leeway_pixels=50

[alpr]

#alpr_use_after_detection_only=yes
#alpr_api_type=cloud

# -----| If you are using plate recognizer | ------
#alpr_service=plate_recognizer
#alpr_key=!PLATEREC_ALPR_KEY
#platerec_stats=yes
#platerec_regions=['us','cn','kr']
#platerec_min_dscore=0.1
#platerec_min_score=0.2

# ----| If you are using openALPR |-----
#alpr_service=open_alpr
#alpr_key=!OPENALPR_ALPR_KEY
#openalpr_recognize_vehicle=1
#openalpr_country=us
#openalpr_state=ca
# openalpr returns percents, but we convert to between 0 and 1
#openalpr_min_confidence=0.3

# ----| If you are using openALPR command line |-----
#openalpr_cmdline_binary=alpr
#openalpr_cmdline_params=-j -d
#openalpr_cmdline_min_confidence=0.3```
fennec622 commented 3 years ago

Is it normal no " after url image ?

{"data":{"eid":"4253431","mid":"2","notification_foreground":"true"},"title":"porte Alarm (4253431)","sound":"default","body":"[a] detected:person:24% All at 19:51, 24-oct.","image_url":"https://url/zm/index.php?view=image&eid=4253431&fid=objdetect&width=1000&username=user&password=xxx}},"token":""} to token: ...ITZ8MH]

and for information my password finish with @

pliablepixels commented 3 years ago

Yes it’s a string replace issue when I’m removing passwords in the logs. In your latest message i see title and body. In your old one it was not there? Also your token string is empty?

fennec622 commented 3 years ago

perhaps me after

this is last log

24/10/2020 19:51:14.362521 zmeventnotification[29536].DBG [main:963] [|----> FORK:porte (2), eid:4253431 fcmv1: Final JSON using FCMV1 being sent is: {"data":{"eid":"4253431","mid":"2","notification_foreground":"true"},"title":"porte Alarm (4253431)","sound":"default","body":"[a] detected:person:24% All at 19:51, 24-oct.","image_url":"https://url/zm/index.php?view=image&eid=4253431&fid=objdetect&width=1000&username=julien&password=xxx}},"token":"dk2hOY16gvw:APA91bGLZNml3pHbEhtfG54YxlBAniG5uR1lJPnh4jP_smjB_DGAwFdU7IYM-dES0yS7lIraBoui64UV6Ey2euibKpGRwg2koF9EWFMBznU4T6nTvshn0j7VLGHAQCWy2IDVenITZ8MH"} to token: ...ITZ8MH] 24/10/2020 19:51:14.630338 zmeventnotification[29536].ERR [main:988] [|----> FORK:porte (2), eid:4253431 fcmv1: FCM push message Error:400 Bad Request]

what is wrong ?

pliablepixels commented 3 years ago

The message looks good. What happens if you: a) Delete zmNinja app b) Stop ES c) Clear out tokens.txt d) Restart ES d) Reinstall zmNinja

In this case you will get a new token. I wonder if its token related.

fennec622 commented 3 years ago

Very strange i do nothing and now is ok

Do you have a limit FCM request ?

pliablepixels commented 3 years ago

The 400 Bad Request can be sent if the token is invalid (expired) (one of many reasons). If the token is expired, you can stop ES, delete the token file, restart ES and run zmNinja again to register a new token.

fennec622 commented 3 years ago

OK thanks

i renew token, thanks for you help