-
-
Notifications
You must be signed in to change notification settings - Fork 127
Description
Event Server version
6.1.28
Hooks version (if you are using Object Detection)
app:6.1.28, pyzm:0.3.56
Are you using MLAPI? (Y/N)
No
The version of ZoneMinder you are using:
1.37.23
What is the nature of your issue
Bug
Details
Start event is sent, but End event not sent due to "Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed". I can see the start message in my MQTT. Note, I have set
use_fcm = no
It is still showing as enabled, which could be generating an error preventing the start script from running properly.
Also note, I have three camera, two monitors per camera. The one's suffixed with "Motion" are lower resolution and the one's I intend to have trigger, then trigger the higher resolution monitor via Link.
Debug Logs (if applicable)
sudo -u www-data /usr/bin/zmeventnotification.pl --debug
09/26/2022 12:25:19.725406 zmeventnotification[1340971].INF [main:329] [Running on WebSocket library version:0.004]
INF:2022-09-26,12:25:19 PARENT: using config file: /etc/zm/zmeventnotification.ini
09/26/2022 12:25:19.765859 zmeventnotification[1340971].INF [main:1006] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
INF:2022-09-26,12:25:19 PARENT: using secrets file: /etc/zm/secrets.ini
09/26/2022 12:25:19.774250 zmeventnotification[1340971].INF [main:1006] [PARENT: using secrets file: /etc/zm/secrets.ini]
DBG-2:2022-09-26,12:25:19 PARENT: Got secret token !ZMES_PICTURE_URL
DBG-2:2022-09-26,12:25:19 PARENT: Got secret token !ZM_USER
DBG-2:2022-09-26,12:25:19 PARENT: Got secret token !ZM_PASSWORD
DBG-2:2022-09-26,12:25:19 PARENT: config string substitution: {{base_data_path}} is '/var/lib/zmeventnotification'
DBG-2:2022-09-26,12:25:19 PARENT: config string substitution: {{base_data_path}} is '/var/lib/zmeventnotification'
Configuration (read /etc/zm/zmeventnotification.ini):
Secrets file.......................... /etc/zm/secrets.ini
Base data path........................ /var/lib/zmeventnotification
Restart interval (secs)............... 7200
Use admin interface .................. yes
Admin interface password.............. (defined)
Admin interface persistence file ..... /var/lib/zmeventnotification/misc/escontrol_interface.dat
Port ................................. 9000
Address .............................. [::]
Event check interval ................. 5
Monitor reload interval .............. 90
Skipped monitors...................... (undefined)
Auth enabled ......................... yes
Auth timeout ......................... 20
Use API Push.......................... no
API Push Script....................... (undefined)
Use FCM .............................. yes
Use FCM V1 APIs....................... yes
FCM Date Format....................... %I:%M %p, %d-%b
Only show latest FCMv1 message........ no
Android FCM push priority............. high
Android FCM push ttl.................. (undefined)
Log FCM message ID.................... NONE
Log RAW FCM Messages.................. no
FCM V1 URL............................ https://us-central1-zoneminder-ninja.cloudfunctions.net/send_push
FCM V1 Key............................ default
Token file ........................... /var/lib/zmeventnotification/push/tokens.txt
Use MQTT ............................. yes
MQTT Server .......................... 10.27.200.5
MQTT Topic ........................... zoneminder
MQTT Username ........................ jody
MQTT Password ........................ (defined)
MQTT Retain .......................... yes
MQTT Tick Interval ................... 15
MQTT TLS CA .......................... (undefined)
MQTT TLS Cert ........................ (undefined)
MQTT TLS Key ......................... (undefined)
MQTT TLS Insecure .................... no
SSL enabled .......................... yes
SSL cert file ........................ /etc/letsencrypt/live/tiberiansun.us/cert.pem
SSL key file ......................... /etc/letsencrypt/live/tiberiansun.us/privkey.pem
Verbose .............................. yes
ES Debug level........................ 4
Read alarm cause ..................... yes
Tag alarm event id ................... yes
Use custom notification sound ........ no
Send event start notification......... yes
Send event end notification........... yes
Monitor rules JSON file............... (undefined)
Use Hooks............................. yes
Max Parallel Hooks.................... 0
Hook Script on Event Start ........... '/var/lib/zmeventnotification/bin/zm_event_start.sh'
User Script on Event Start............ (undefined)
Hook Script on Event End.............. '/var/lib/zmeventnotification/bin/zm_event_end.sh'
User Script on Event End.............. (undefined)
Hook Skipped monitors................. (undefined)
Notify on Event Start (hook success).. all
Notify on Event Start (hook fail)..... all
Notify on Event End (hook success).... all
Notify on Event End (hook fail)....... all
Notify End only if Start success...... yes
Use Hook Description.................. yes
Keep frame match type................. yes
Store Frame in ZM..................... yes
Picture URL .......................... https://zm.tiberiansun.us:2417/zm/index.php?view=image&eid=EVENTID&fid=objdetect&width=800
Include picture....................... yes
Picture username ..................... admin
Picture password ..................... (defined)
INF:2022-09-26,12:25:19 PARENT: Push enabled via FCM
09/26/2022 12:25:19.915922 zmeventnotification[1340971].INF [main:1006] [PARENT: Push enabled via FCM]
DBG-2:2022-09-26,12:25:19 PARENT: fcmv1: --> FCM V1 APIs: 1
INF:2022-09-26,12:25:19 PARENT: MQTT Enabled
09/26/2022 12:25:19.918594 zmeventnotification[1340971].INF [main:1006] [PARENT: MQTT Enabled]
INF:2022-09-26,12:25:19 PARENT: |------- Starting ES version: 6.1.28 ---------|
09/26/2022 12:25:19.918647 zmeventnotification[1340971].INF [main:1006] [PARENT: |------- Starting ES version: 6.1.28 ---------|]
DBG-2:2022-09-26,12:25:19 PARENT: Started with: perl:/usr/bin/perl and command:/usr/bin/zmeventnotification.pl
Can't ignore signal CHLD, forcing to default.
DBG-1:2022-09-26,12:25:20 PARENT: ES invoked manually. Will handle restarts ourselves
DBG-2:2022-09-26,12:25:20 PARENT: Parent<--Child pipe ready
INF:2022-09-26,12:25:20 PARENT: Event Notification daemon v 6.1.28 starting
09/26/2022 12:25:20.054647 zmeventnotification[1340971].INF [main:1006] [PARENT: Event Notification daemon v 6.1.28 starting]
DBG-1:2022-09-26,12:25:20 PARENT: Initializing FCM tokens...
Odd number of elements in anonymous hash at /usr/bin/zmeventnotification.pl line 2867.
Odd number of elements in anonymous hash at /usr/bin/zmeventnotification.pl line 2867.
INF:2022-09-26,12:25:20 PARENT: Initializing MQTT with auth connection...
09/26/2022 12:25:20.055113 zmeventnotification[1340971].INF [main:1006] [PARENT: Initializing MQTT with auth connection...]
DBG-1:2022-09-26,12:25:20 PARENT: Intialized MQTT with auth
DBG-1:2022-09-26,12:25:20 PARENT: Total event client connections: 3
DBG-1:2022-09-26,12:25:20 PARENT: -->checkNewEvents: Connection 1: ID->1664213120 IP->(none) Token->:... Plat: Push:
DBG-1:2022-09-26,12:25:20 PARENT: -->checkNewEvents: Connection 2: ID->1664213120 IP->(none) Token->:... Plat: Push:
DBG-1:2022-09-26,12:25:20 PARENT: -->checkNewEvents: Connection 3: ID-> IP->(none) Token->:... Plat: Push:
INF:2022-09-26,12:25:20 PARENT: Re-loading monitors
09/26/2022 12:25:20.055835 zmeventnotification[1340971].INF [main:1006] [PARENT: Re-loading monitors]
DBG-1:2022-09-26,12:25:20 PARENT: Loading Cam-1
DBG-1:2022-09-26,12:25:20 PARENT: Loading Cam-3
DBG-1:2022-09-26,12:25:20 PARENT: Loading Cam-2
DBG-1:2022-09-26,12:25:20 PARENT: Loading Cam-1 Motion
DBG-1:2022-09-26,12:25:20 PARENT: Loading Cam-3 Motion
DBG-1:2022-09-26,12:25:20 PARENT: Loading Cam-2 Motion
DBG-2:2022-09-26,12:25:20 PARENT: ESCONTROL_INTERFACE: Saving admin interfaces to /var/lib/zmeventnotification/misc/escontrol_interface.dat
DBG-2:2022-09-26,12:25:20 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:20 PARENT: About to start listening to socket
INF:2022-09-26,12:25:20 PARENT: Secure WS(WSS) is enabled...
09/26/2022 12:25:20.064653 zmeventnotification[1340971].INF [main:1006] [PARENT: Secure WS(WSS) is enabled...]
INF:2022-09-26,12:25:20 PARENT: Web Socket Event Server listening on port 9000
09/26/2022 12:25:20.064705 zmeventnotification[1340971].INF [main:1006] [PARENT: Web Socket Event Server listening on port 9000]
DBG-2:2022-09-26,12:25:25 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:25 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:25 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:25:25 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:25 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:25:25 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2022-09-26,12:25:30 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:30 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:30 PARENT: There are 0 active child forks & 0 zm_detect processes running...
INF:2022-09-26,12:25:30 PARENT: New event 60258 reported for Monitor:1 (Name:Cam-1) Forced Web[last processed eid:]
09/26/2022 12:25:30.066949 zmeventnotification[1340971].INF [main:1006] [PARENT: New event 60258 reported for Monitor:1 (Name:Cam-1) Forced Web[last processed eid:]]
DBG-2:2022-09-26,12:25:30 PARENT: checkEvents() new events found=1
DBG-2:2022-09-26,12:25:30 PARENT: There are 1 new Events to process
DBG-2:2022-09-26,12:25:30 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2022-09-26,12:25:30 PARENT: Forked process:1340992 to handle alarm eid:60258
DBG-2:2022-09-26,12:25:30 |----> FORK:Cam-1 (1), eid:60258 Adding event path:/var/cache/zoneminder/events/1/2022-09-26/60258 to hook for image storage
DBG-1:2022-09-26,12:25:30 |----> FORK:Cam-1 (1), eid:60258 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 60258 1 "Cam-1" "Forced Web" "/var/cache/zoneminder/events/1/2022-09-26/60258"
DBG-2:2022-09-26,12:25:35 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:35 PARENT: MQTT tick interval (15 sec) elapsed.
DBG-2:2022-09-26,12:25:35 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:35 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add
DBG-2:2022-09-26,12:25:35 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:25:35 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:25:35 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:35 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:25:35 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:25:40 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:40 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:40 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:25:40 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:25:40 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:40 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:25:40 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:25:45 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:45 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:45 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:25:45 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:25:45 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:45 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:25:45 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:25:50 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:50 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:50 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:25:50 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:25:50 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:50 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:25:50 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:25:55 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:25:55 PARENT: MQTT tick interval (15 sec) elapsed.
DBG-2:2022-09-26,12:25:55 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:25:55 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:25:55 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:25:55 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:25:55 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:25:55 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:26:00 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:26:00 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:00 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:26:00 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:00 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:00 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:00 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:26:05 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:26:05 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:05 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:26:05 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:05 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:05 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:05 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:26:10 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:26:10 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:10 PARENT: There are 1 active child forks & 1 zm_detect processes running...
DBG-2:2022-09-26,12:26:10 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:10 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:10 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:10 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 1)<--------------
DBG-2:2022-09-26,12:26:14 |----> FORK:Cam-1 (1), eid:60258 parse of hook: and [] from
DBG-1:2022-09-26,12:26:14 |----> FORK:Cam-1 (1), eid:60258 hook start returned with text: json:[] exit:1
DBG-2:2022-09-26,12:26:15 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 1 running for:1 min)<--------------
DBG-2:2022-09-26,12:26:15 PARENT: MQTT tick interval (15 sec) elapsed.
DBG-2:2022-09-26,12:26:15 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:15 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del
DBG-2:2022-09-26,12:26:15 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:15 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:15 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:15 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:15 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 rules: Checking rules for alarm caused by eid:60258, monitor:1, at: Mon Sep 26 12:26:16 2022 with cause:Forced Web
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 rules: No rules found for Monitor, allowing:1
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Matching alarm to connection rules...
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Checking alarm conditions for token ending in:...
ERR:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 interval not found for mid 1
09/26/2022 12:26:16.659070 zmeventnotification[1340992].ERR [main:1022] [|----> FORK:Cam-1 (1), eid:60258 interval not found for mid 1]
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Monitor 1 event: last time not found, so should send
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 token is unique, shouldSendEventToConn returned true, so calling sendEvent
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 isAllowedChannel: got type:event_start resCode:1
INF:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Sending event_start notification over FCM
09/26/2022 12:26:16.659390 zmeventnotification[1340992].INF [main:1006] [|----> FORK:Cam-1 (1), eid:60258 Sending event_start notification over FCM]
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 fcmv1: FCM called when hook failed, so making sure we do not use objdetect in url
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Unknown platform
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 fcmv1: Final JSON using FCMV1 being sent is: {"token":null,"title":"Cam-1 Alarm (60258)","log_message_id":"NONE","data":{"eid":"60258","notification_foreground":"true","mid":"1"},"badge":1,"sound":"default","body":"Forced Web at 12:26 PM, 26-Sep","image_url":"https://zm.tiberiansun.us:2417/zm/index.php?view=image&eid=60258&fid=snapshot&width=800&username=admin&password=xxx} to token: ...
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 fcmv1: FCM push message error {"Error":"No Token Found"}
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 child finished writing to parent
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Checking alarm conditions for token ending in:...
ERR:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 interval not found for mid 1
09/26/2022 12:26:16.979947 zmeventnotification[1340992].ERR [main:1022] [|----> FORK:Cam-1 (1), eid:60258 interval not found for mid 1]
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Monitor 1 event: last time not found, so should send
DBG-1:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 token is unique, shouldSendEventToConn returned true, so calling sendEvent
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 isAllowedChannel: got type:event_start resCode:1
INF:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Sending event_start notification over FCM
09/26/2022 12:26:16.980229 zmeventnotification[1340992].INF [main:1006] [|----> FORK:Cam-1 (1), eid:60258 Sending event_start notification over FCM]
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 fcmv1: FCM called when hook failed, so making sure we do not use objdetect in url
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 Unknown platform
DBG-2:2022-09-26,12:26:16 |----> FORK:Cam-1 (1), eid:60258 fcmv1: Final JSON using FCMV1 being sent is: {"data":{"eid":"60258","mid":"1","notification_foreground":"true"},"body":"Forced Web at 12:26 PM, 26-Sep","badge":1,"sound":"default","image_url":"https://zm.tiberiansun.us:2417/zm/index.php?view=image&eid=60258&fid=snapshot&width=800&username=admin&password=xxx} to token: ...
DBG-1:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 fcmv1: FCM push message error {"Error":"No Token Found"}
DBG-2:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 child finished writing to parent
DBG-1:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 Checking alarm conditions for MQTT 10.27.200.5
ERR:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 interval not found for mid 1
09/26/2022 12:26:17.283292 zmeventnotification[1340992].ERR [main:1022] [|----> FORK:Cam-1 (1), eid:60258 interval not found for mid 1]
DBG-1:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 Monitor 1 event: last time not found, so should send
DBG-1:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 token is unique, shouldSendEventToConn returned true, so calling sendEvent
DBG-2:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 isAllowedChannel: got type:event_start resCode:1
INF:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 Sending event_start notification for EID:60258 over MQTT
09/26/2022 12:26:17.283524 zmeventnotification[1340992].INF [main:1006] [|----> FORK:Cam-1 (1), eid:60258 Sending event_start notification for EID:60258 over MQTT]
DBG-2:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 requesting MQTT Publishing Job for EID:60258
DBG-2:2022-09-26,12:26:17 |----> FORK:Cam-1 (1), eid:60258 child finished writing to parent
DBG-2:2022-09-26,12:26:20 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:20 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:20 PARENT: RAW TEXT-->fcm_notification--TYPE----SPLIT--1--SPLIT--0--SPLIT--8
DBG-2:2022-09-26,12:26:20 PARENT: GOT JOB==> update badge to 1, count to 0 for: , at: 8
DBG-2:2022-09-26,12:26:20 PARENT: RAW TEXT-->timestamp--TYPE--1664213120--SPLIT--1--SPLIT--1664213176.65921
DBG-2:2022-09-26,12:26:20 PARENT: Job: Update last sent timestamp of monitor:1 to 1664213176.65921 for id:1664213120
DBG-2:2022-09-26,12:26:20 PARENT: RAW TEXT-->fcm_notification--TYPE----SPLIT--1--SPLIT--0--SPLIT--8
DBG-2:2022-09-26,12:26:20 PARENT: GOT JOB==> update badge to 1, count to 0 for: , at: 8
DBG-2:2022-09-26,12:26:20 PARENT: RAW TEXT-->timestamp--TYPE--1664213120--SPLIT--1--SPLIT--1664213176.98011
DBG-2:2022-09-26,12:26:20 PARENT: Job: Update last sent timestamp of monitor:1 to 1664213176.98011 for id:1664213120
DBG-2:2022-09-26,12:26:20 PARENT: RAW TEXT-->mqtt_publish--TYPE----SPLIT--zoneminder/1--SPLIT--{"hookvalue":"1","state":"alarm","monitor":"1","eventtype":"event_start","detection":[],"name":"Cam-1:(60258) Forced Web","eventid":"60258"}
DBG-2:2022-09-26,12:26:20 PARENT: Job: MQTT Publish on topic: zoneminder/1
DBG-2:2022-09-26,12:26:20 PARENT: Job: MQTT Publish with retain
DBG-2:2022-09-26,12:26:20 PARENT: RAW TEXT-->timestamp--TYPE----SPLIT--1--SPLIT--1664213177.28341
DBG-2:2022-09-26,12:26:20 PARENT: Job: Update last sent timestamp of monitor:1 to 1664213177.28341 for id:
DBG-2:2022-09-26,12:26:20 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:20 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:20 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:20 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:20 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:25 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:25 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:25 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:25 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:25 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:25 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:25 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:30 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:30 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:30 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:30 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:30 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:30 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:30 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:35 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:35 PARENT: MQTT tick interval (15 sec) elapsed.
DBG-2:2022-09-26,12:26:35 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:35 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:35 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:35 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:35 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:35 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:40 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:40 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:40 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:40 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:40 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:40 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:40 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:45 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:45 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:45 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:45 PARENT: We've already worked on Monitor:1, Event:60258, not doing anything more
DBG-2:2022-09-26,12:26:45 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:45 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:45 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:47 |----> FORK:Cam-1 (1), eid:60258 For 1 (Cam-1), SHM says: state=1, eid=60258
INF:2022-09-26,12:26:47 |----> FORK:Cam-1 (1), eid:60258 Event 60258 for Monitor 1 has finished
09/26/2022 12:26:47.290141 zmeventnotification[1340992].INF [main:1006] [|----> FORK:Cam-1 (1), eid:60258 Event 60258 for Monitor 1 has finished]
DBG-2:2022-09-26,12:26:47 |----> FORK:Cam-1 (1), eid:60258 Event end object is: state=>pending with cause=>Forced Web:
DBG-2:2022-09-26,12:26:49 |----> FORK:Cam-1 (1), eid:60258 Adding event path:/var/cache/zoneminder/events/1/2022-09-26/60258 to hook for image storage
DBG-1:2022-09-26,12:26:49 |----> FORK:Cam-1 (1), eid:60258 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 60258 1 "Cam-1" "Forced Web: " "/var/cache/zoneminder/events/1/2022-09-26/60258"
DBG-2:2022-09-26,12:26:49 |----> FORK:Cam-1 (1), eid:60258 parse of hook:Forced Web: and [] from Forced Web:
DBG-1:2022-09-26,12:26:49 |----> FORK:Cam-1 (1), eid:60258 hook end returned with text:Forced Web: json:[] exit:0
DBG-2:2022-09-26,12:26:50 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:50 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:50 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add
DBG-2:2022-09-26,12:26:50 PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del
DBG-2:2022-09-26,12:26:50 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-2:2022-09-26,12:26:50 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:50 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:50 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-2:2022-09-26,12:26:51 |----> FORK:Cam-1 (1), eid:60258 rules: Checking rules for alarm caused by eid:60258, monitor:1, at: Mon Sep 26 12:26:51 2022 with cause:Forced Web
DBG-1:2022-09-26,12:26:51 |----> FORK:Cam-1 (1), eid:60258 rules: No rules found for Monitor, allowing:1
INF:2022-09-26,12:26:51 |----> FORK:Cam-1 (1), eid:60258 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed
09/26/2022 12:26:51.297847 zmeventnotification[1340992].INF [main:1006] [|----> FORK:Cam-1 (1), eid:60258 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
DBG-2:2022-09-26,12:26:55 PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:2 min)<--------------
DBG-2:2022-09-26,12:26:55 PARENT: MQTT tick interval (15 sec) elapsed.
DBG-2:2022-09-26,12:26:55 PARENT: After tick: TOTAL: 3 , ES_CONTROL: 0, FCM+WEB: 0, FCM: 0, WEB: 0, MQTT:1, invalid WEB: 0, PENDING: 0
DBG-2:2022-09-26,12:26:55 PARENT: There are 1 active child forks & 0 zm_detect processes running...
DBG-1:2022-09-26,12:26:55 PARENT: Total event client connections: 3
DBG-1:2022-09-26,12:26:55 PARENT: -->checkNewEvents: Connection 1: ID->1664213120 IP->(none) Token->:... Plat: Push:
DBG-1:2022-09-26,12:26:55 PARENT: -->checkNewEvents: Connection 2: ID->1664213120 IP->(none) Token->:... Plat: Push:
DBG-1:2022-09-26,12:26:55 PARENT: -->checkNewEvents: Connection 3: ID-> IP->(none) Token->:... Plat: Push:
INF:2022-09-26,12:26:55 PARENT: Re-loading monitors
09/26/2022 12:26:55.071363 zmeventnotification[1340971].INF [main:1006] [PARENT: Re-loading monitors]
DBG-1:2022-09-26,12:26:55 PARENT: Loading Cam-1
DBG-1:2022-09-26,12:26:55 PARENT: Loading Cam-3
DBG-1:2022-09-26,12:26:55 PARENT: Loading Cam-2
DBG-1:2022-09-26,12:26:55 PARENT: Loading Cam-1 Motion
DBG-1:2022-09-26,12:26:55 PARENT: Loading Cam-3 Motion
DBG-1:2022-09-26,12:26:55 PARENT: Loading Cam-2 Motion
DBG-2:2022-09-26,12:26:55 PARENT: ESCONTROL_INTERFACE: Saving admin interfaces to /var/lib/zmeventnotification/misc/escontrol_interface.dat
DBG-2:2022-09-26,12:26:55 PARENT: checkEvents() new events found=0
DBG-2:2022-09-26,12:26:55 PARENT: There are 0 new Events to process
DBG-2:2022-09-26,12:26:55 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2022-09-26,12:26:55 |----> FORK:Cam-1 (1), eid:60258 exiting
DBG-1:2022-09-26,12:26:55 |----> FORK:Cam-1 (1), eid:60258 Ending process:1340992 to handle alarms
^CDBG-1:2022-09-26,12:26:59 PARENT: Received request to shutdown, please wait
INF:2022-09-26,12:27:00 PARENT: Event Server Terminating
09/26/2022 12:27:00.065515 zmeventnotification[1340971].INF [main:1006] [PARENT: Event Server Terminating]