Not receiving notifications since the EOL announcement

[mfauvain]

First of all, thank you for the excellent work all those years. Absolutely brilliant. Quick question before I dig in : I've stopped receiving notifications since the EOL annoucement and haven't touched a thing/updated. Is it pure coincidence or is is normal behaviour? thx again, hope this project is picked up and kept alive!

[pliablepixels]

Pure coincidence. Check your ES debug logs. I've not removed anything (and push works for me)

[mfauvain]

ok, doing the readthedocs debug procedure I don't see anything obvious (no error messages), Token is being generated, however the token says "pushstate":"disabled". In zmeventnotification.ini I have use_api_push=no but fcm enabled and use_fcmv1 = yes. Is this correct (as api_push is disabled) ?

[pliablepixels]

Please post full ES debug logs of what happens when an alarm is generated

[mfauvain]

This is the zmeventnotification debug :

INF:2021-07-15,11:01:40 PARENT: New event 1267635 reported for Monitor:7 (Name:FrontDoor) Forced Web[last processed eid:]
07/15/2021 11:01:40.951939 zmeventnotification[255436].INF [main:1022] [PARENT: New event 1267635 reported for Monitor:7 (Name:FrontDoor) Forced Web[last processed eid:]]
DBG-2:2021-07-15,11:01:40 PARENT: checkEvents() new events found=1
DBG-2:2021-07-15,11:01:40 PARENT: There are 1 new Events to process
DBG-2:2021-07-15,11:01:40 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2021-07-15,11:01:40 PARENT: Forked process:255461 to handle alarm eid:1267635
DBG-2:2021-07-15,11:01:40 |----> FORK:FrontDoor (7), eid:1267635 Adding event path:/var/lib/zoneminder/events/7/2021-07-15/1267635 to hook for image storage
DBG-1:2021-07-15,11:01:40 |----> FORK:FrontDoor (7), eid:1267635 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 1267635 7 "FrontDoor" "Forced Web" "/var/lib/zoneminder/events/7/2021-07-15/1267635"
DBG-2:2021-07-15,11:01:45 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-15,11:01:45 PARENT: After tick: TOTAL: 2,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 2, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-07-15,11:01:45 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add
DBG-2:2021-07-15,11:01:45 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2021-07-15,11:01:45 PARENT: checkEvents() new events found=0
DBG-2:2021-07-15,11:01:45 PARENT: There are 0 new Events to process
DBG-2:2021-07-15,11:01:45 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 parse of hook: and []
DBG-1:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 hook start returned with text: json:[] exit:1
DBG-2:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 For 7 (FrontDoor), SHM says: state=4, eid=1267635
INF:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 Event 1267635 for Monitor 7 has finished
07/15/2021 11:01:49.427163 zmeventnotification[255461].INF [main:1022] [|----> FORK:FrontDoor (7), eid:1267635 Event 1267635 for Monitor 7 has finished]
DBG-2:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 Event end object is: state=>pending with cause=>Forced Web: 
DBG-2:2021-07-15,11:01:50 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2021-07-15,11:01:50 PARENT: After tick: TOTAL: 2,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 2, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-07-15,11:01:50 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del
DBG-2:2021-07-15,11:01:50 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-15,11:01:50 PARENT: checkEvents() new events found=0
DBG-2:2021-07-15,11:01:50 PARENT: There are 0 new Events to process
DBG-2:2021-07-15,11:01:50 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 rules: Checking rules for alarm caused by eid:1267635, monitor:7, at: Thu Jul 15 11:01:51 2021 with cause:Forced Web
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 rules: No rules found for Monitor, allowing:7
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 Matching alarm to connection rules...
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 Checking alarm conditions for token ending in:...zrDBesHC0k
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 Monitor 7 event: last time not found, so should send
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 token is unique, shouldSendEventToConn returned true, so calling sendEvent
DBG-2:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 isAllowedChannel: got type:event_start resCode:1
INF:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 Not sending over FCM as notify filters are on_success:all and on_fail:none
07/15/2021 11:01:51.429648 zmeventnotification[255461].INF [main:1022] [|----> FORK:FrontDoor (7), eid:1267635 Not sending over FCM as notify filters are on_success:all and on_fail:none]
DBG-2:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 child finished writing to parent
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 Checking alarm conditions for token ending in:...qipdZDM8Oj
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 Monitor 7 event: last time not found, so should send
DBG-1:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 token is unique, shouldSendEventToConn returned true, so calling sendEvent
DBG-2:2021-07-15,11:01:51 |----> FORK:FrontDoor (7), eid:1267635 child finished writing to parent
INF:2021-07-15,11:01:53 |----> FORK:FrontDoor (7), eid:1267635 end hooks/use hooks not being used, going to directly send out a notification if checks pass
07/15/2021 11:01:53.431032 zmeventnotification[255461].INF [main:1022] [|----> FORK:FrontDoor (7), eid:1267635 end hooks/use hooks not being used, going to directly send out a notification if checks pass]
DBG-2:2021-07-15,11:01:55 |----> FORK:FrontDoor (7), eid:1267635 rules: Checking rules for alarm caused by eid:1267635, monitor:7, at: Thu Jul 15 11:01:55 2021 with cause:Forced Web
DBG-1:2021-07-15,11:01:55 |----> FORK:FrontDoor (7), eid:1267635 rules: No rules found for Monitor, allowing:7
INF:2021-07-15,11:01:55 |----> FORK:FrontDoor (7), eid:1267635 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed
07/15/2021 11:01:55.431550 zmeventnotification[255461].INF [main:1022] [|----> FORK:FrontDoor (7), eid:1267635 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
DBG-2:2021-07-15,11:01:55 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-15,11:01:55 PARENT: After tick: TOTAL: 2,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 2, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-07-15,11:01:55 PARENT: RAW TEXT-->timestamp--TYPE--1626364865.92759--SPLIT--7--SPLIT--1626364911.42942
DBG-2:2021-07-15,11:01:55 PARENT: Job: Update last sent timestamp of monitor:7 to 1626364911.42942 for id:1626364865.92759
DBG-2:2021-07-15,11:01:55 PARENT: RAW TEXT-->timestamp--TYPE--1626364865.92761--SPLIT--7--SPLIT--1626364911.43002
DBG-2:2021-07-15,11:01:55 PARENT: Job: Update last sent timestamp of monitor:7 to 1626364911.43002 for id:1626364865.92761
DBG-2:2021-07-15,11:01:55 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-15,11:01:55 PARENT: checkEvents() new events found=0
DBG-2:2021-07-15,11:01:55 PARENT: There are 0 new Events to process
DBG-2:2021-07-15,11:01:55 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2021-07-15,11:01:59 |----> FORK:FrontDoor (7), eid:1267635 exiting
DBG-1:2021-07-15,11:01:59 |----> FORK:FrontDoor (7), eid:1267635 Ending process:255461 to handle alarms
DBG-2:2021-07-15,11:02:00 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-15,11:02:00 PARENT: After tick: TOTAL: 2,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 2, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0
DBG-2:2021-07-15,11:02:00 PARENT: RAW TEXT-->active_event_delete--TYPE--7--SPLIT--1267635
DBG-2:2021-07-15,11:02:00 PARENT: Job: Deleting active_event eid:1267635, mid:7
DBG-2:2021-07-15,11:02:00 PARENT: There are 0 active child forks & 0 zm_detect processes running...

in the meantime I've uninstalled and reinstalled the ios app and debug logs on the server now shows PARENT: JOB: Storing token ...o9OfvzsMrx,monlist:1,2,3,4,5,6,7,10,11,12,13,14,15,intlist:0,0,0,0,0,0,0,0,0,0,0,0,0,pushstate:enabled

[pliablepixels]

DBG-2:2021-07-15,11:01:45 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 parse of hook: and []
DBG-1:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 hook start returned with text: json:[] exit:1
DBG-2:2021-07-15,11:01:49 |----> FORK:FrontDoor (7), eid:1267635 For 7 (FrontDoor), SHM says: state=4, eid=1267635
INF:2021-07-15,11:01

Your hooks failed to find an object, so message was not sent.

[mfauvain]

This was an alarm generated by me from the zm web and there was no object, so I guess this is normal? with an object detected I know see the error:

DBG-1:2021-07-15,11:39:58 |----> FORK:Kitchen (11), eid:1267787 fcmv1: FCM push message error Can't connect to us-central1-ninja-1105.cloudfunctions.net:443 (Name or service not known) Name or service not known at /usr/share/perl5/vendor_perl/LWP/Protocol/http.pm line 50. `

[mfauvain]

found it.. DNS issue on my side that started same day as the EOL notification... pure coincidence, sorry... thx for the help.