Need help with the "cause_has" field

[Jsalas424]

Event Server version

jon@zoneminder:~$ sudo /usr/bin/zmeventnotification.pl --version
6.1.25

Are you using MLAPI? (Y/N)

N

The version of ZoneMinder you are using:

v1.34.26

What is the nature of your issue

Question about using the cause_has field in the rules section

Details

I'm using the cause_has field wrong but I can't figure out how so. I have the following rule configured to mute messages beterrn 6:00-23:59 when "cause_has":"Motion Doorway" .

jon@zoneminder:~$ cat /etc/zm/es_rules.json
{
    "notifications": {
        "monitors":{
            "1": {
                "rules": [{
                    "time_format":"%H:%M",
                    "from":"6:00",
                    "to":"23:59",
                    "action":"mute",
                    "cause_has":"Motion Doorway"

                }]
            }
        }
    }
}

The rule works correctly for the time but then doesn't work as expected for the cause_has.

DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules:(eid: 37900)  seeing if cause_has:Motion Doorway is part of Motion Doorway:
DBG-1:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: (eid: 37900) Skipping this rule as Motion Doorway does not pattern match Motion Doorway

This is what the event that initiates the notification looks like in the logs:

INF:2021-07-07,20:32:25 PARENT: New event 37900 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]
07/07/21 20:32:25.226470 zmeventnotification[10426].INF [main:1022] [PARENT: New event 37900 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]]

Debug Logs (if applicable)

Full Debug logs:

jon@zoneminder:~$ sudo -u www-data /usr/bin/zmeventnotification.pl --debug
07/07/21 20:32:04.480769 zmeventnotification[10426].INF [main:331] [Running on WebSocket library version:0.004]
INF:2021-07-07,20:32:04 PARENT: using config file: /etc/zm/zmeventnotification.ini
07/07/21 20:32:04.589498 zmeventnotification[10426].INF [main:1022] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
INF:2021-07-07,20:32:04 PARENT: using secrets file: /etc/zm/secrets.ini
07/07/21 20:32:04.617007 zmeventnotification[10426].INF [main:1022] [PARENT: using secrets file: /etc/zm/secrets.ini]
DBG-2:2021-07-07,20:32:04 PARENT: Got secret token !ZMES_PICTURE_URL
DBG-2:2021-07-07,20:32:04 PARENT: Got secret token !ZM_USER
DBG-2:2021-07-07,20:32:04 PARENT: Got secret token !ZM_PASSWORD
DBG-2:2021-07-07,20:32:04 PARENT: rules: Loading es rules json: /etc/zm/es_rules.json
DBG-2:2021-07-07,20:32:04 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)............... 0

Use admin interface .................. no
Admin interface password.............. (undefined)
Admin interface persistence file ..... /var/lib/zmeventnotification/misc/escontrol_interface.dat

Port ................................. 9000
Address .............................. [::]
Event check interval ................. 5
Monitor reload interval .............. 300
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)

Token file ........................... /var/lib/zmeventnotification/push/tokens.txt

Use MQTT ............................. no
MQTT Server .......................... 127.0.0.1
MQTT Topic ........................... zoneminder
MQTT Username ........................ (undefined)
MQTT Password ........................ (undefined)
MQTT Retain .......................... no
MQTT Tick Interval ................... 15
MQTT TLS CA ........................ (undefined)
MQTT TLS Cert ........................ (undefined)
MQTT TLS Key ........................ (undefined)
MQTT TLS Insecure ........................ no

SSL enabled .......................... no
SSL cert file ........................ /etc/zm/ssl/zoneminder.crt
SSL key file ......................... /etc/zm/ssl/zoneminder.key

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................/etc/zm/es_rules.json

Use Hooks............................. no
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.............. (undefined)
User Script on Event End...............(undefined)
Hook Skipped monitors................. (undefined)

Notify on Event Start (hook success).. all
Notify on Event Start (hook fail)..... none
Notify on Event End (hook success).... fcm,web,api
Notify on Event End (hook fail)....... none
Notify End only if Start success...... yes

Use Hook Description.................. yes
Keep frame match type................. yes
Store Frame in ZM......................yes

Picture URL .......................... https://portal/zm/index.php?view=image&eid=EVENTID&fid=objdetect&width=600
Include picture....................... yes
Picture username ..................... jon
Picture password ..................... (defined)

INF:2021-07-07,20:32:04 PARENT: Push enabled via FCM
07/07/21 20:32:04.918327 zmeventnotification[10426].INF [main:1022] [PARENT: Push enabled via FCM]
DBG-2:2021-07-07,20:32:04 PARENT: fcmv1: --> FCM V1 APIs: 1
INF:2021-07-07,20:32:04 PARENT: MQTT Disabled
07/07/21 20:32:04.927038 zmeventnotification[10426].INF [main:1022] [PARENT: MQTT Disabled]
INF:2021-07-07,20:32:04 PARENT: |------- Starting ES version: 6.1.25 ---------|
07/07/21 20:32:04.935172 zmeventnotification[10426].INF [main:1022] [PARENT: |------- Starting ES version: 6.1.25 ---------|]
DBG-2:2021-07-07,20:32:04 PARENT: Started with: perl:/usr/bin/perl and command:/usr/bin/zmeventnotification.pl
Can't ignore signal CHLD, forcing to default.
DBG-1:2021-07-07,20:32:05 PARENT: ES invoked manually. Will handle restarts ourselves
WAR:2021-07-07,20:32:05 PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted
07/07/21 20:32:05.173353 zmeventnotification[10426].WAR [main:1030] [PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted]
DBG-2:2021-07-07,20:32:05 PARENT: Parent<--Child pipe ready
INF:2021-07-07,20:32:05 PARENT: Event Notification daemon v 6.1.25 starting

07/07/21 20:32:05.182411 zmeventnotification[10426].INF [main:1022] [PARENT: Event Notification daemon v 6.1.25 starting]
DBG-1:2021-07-07,20:32:05 PARENT: Initializing FCM tokens...
DBG-1:2021-07-07,20:32:05 PARENT: Total event client connections: 2

DBG-1:2021-07-07,20:32:05 PARENT: -->checkNewEvents: Connection 1: ID->1625704325.19131 IP->(none) Token->:...5Cxfsxtt27 Plat:android Push:enabled
DBG-1:2021-07-07,20:32:05 PARENT: -->checkNewEvents: Connection 2: ID->1625704325.19136 IP->(none) Token->:...kKsbRYv5w_ Plat:ios Push:enabled
INF:2021-07-07,20:32:05 PARENT: Re-loading monitors
07/07/21 20:32:05.192058 zmeventnotification[10426].INF [main:1022] [PARENT: Re-loading monitors]
DBG-1:2021-07-07,20:32:05 PARENT: Loading TracheCam.1
DBG-2:2021-07-07,20:32:05 PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data
DBG-2:2021-07-07,20:32:05 PARENT: checkEvents() new events found=0
INF:2021-07-07,20:32:05 PARENT: Secure WS is disabled...
07/07/21 20:32:05.204110 zmeventnotification[10426].INF [main:1022] [PARENT: Secure WS is disabled...]
INF:2021-07-07,20:32:05 PARENT: Web Socket Event Server listening on port 9000
07/07/21 20:32:05.212382 zmeventnotification[10426].INF [main:1022] [PARENT: Web Socket Event Server listening on port 9000]
DBG-2:2021-07-07,20:32:10 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-07,20:32:10 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-07,20:32:10 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-07,20:32:10 PARENT: checkEvents() new events found=0
DBG-2:2021-07-07,20:32:10 PARENT: There are 0 new Events to process
DBG-2:2021-07-07,20:32:10 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-07,20:32:15 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-07,20:32:15 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-07,20:32:15 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-07,20:32:15 PARENT: checkEvents() new events found=0
DBG-2:2021-07-07,20:32:15 PARENT: There are 0 new Events to process
DBG-2:2021-07-07,20:32:15 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-07,20:32:20 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-07,20:32:20 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-07,20:32:20 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-07,20:32:20 PARENT: checkEvents() new events found=0
DBG-2:2021-07-07,20:32:20 PARENT: There are 0 new Events to process
DBG-2:2021-07-07,20:32:20 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-07,20:32:25 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-07,20:32:25 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-07,20:32:25 PARENT: There are 0 active child forks & 0 zm_detect processes running...
INF:2021-07-07,20:32:25 PARENT: New event 37900 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]
07/07/21 20:32:25.226470 zmeventnotification[10426].INF [main:1022] [PARENT: New event 37900 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]]
DBG-2:2021-07-07,20:32:25 PARENT: checkEvents() new events found=1
DBG-2:2021-07-07,20:32:25 PARENT: There are 1 new Events to process
DBG-2:2021-07-07,20:32:25 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2021-07-07,20:32:25 PARENT: Forked process:10430 to handle alarm eid:37900
INF:2021-07-07,20:32:25 |----> FORK:TracheCam.1 (1), eid:37900 use hooks/start hook not being used, going to directly send out a notification if checks pass
07/07/21 20:32:25.244812 zmeventnotification[10430].INF [main:1022] [|----> FORK:TracheCam.1 (1), eid:37900 use hooks/start hook not being used, going to directly send out a notification if checks pass]
DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: Checking rules for alarm caused by eid:37900, monitor:1, at: Wed Jul  7 20:32:27 2021 with cause:Motion Doorway
DBG-1:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: (eid: 37900) -- Processing rule: 1 --
DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: parsing rule 6:00/23:59 using format:%H:%M
DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: parsed time from: Thu Jan  1 06:00:00 1970 and to:Thu Jan  1 23:59:00 1970
DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules:(eid: 37900)  seeing if now:Thu Jan  1 20:32:00 1970 is between:Thu Jan  1 06:00:00 1970 and Thu Jan  1 23:59:00 1970
DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules:(eid: 37900)  seeing if now:Wed is part of:
DBG-2:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules:(eid: 37900)  seeing if cause_has:Motion Doorway is part of Motion Doorway:
DBG-1:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: (eid: 37900) Skipping this rule as Motion Doorway does not pattern match Motion Doorway
DBG-1:2021-07-07,20:32:27 |----> FORK:TracheCam.1 (1), eid:37900 rules: (eid: 37900) No rules matched

Thanks!

[pliablepixels]

Please try with the updated zmeventnotification.pl in master

[Jsalas424]

Please try with the updated zmeventnotification.pl in master

Now it's tripping on the times. It correctly parsed the time in my rule as "Thu Jan 1 06:00:00 1970 and to:Thu Jan 1 11:59:00 1970". When it checked "seeing if now:Thu Jan 1 17:51:00 1970 is between:Thu Jan 1 06:00:00 1970 and Thu Jan 1 11:59:00 1970" it failed. Now "Thu Jan 1 17:51:00 1970" IS between "Thu Jan 1 06:00:00 1970 and Thu Jan 1 11:59:00 1970" but it still skipped the rule and sent a notification.

DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: parsing rule 6:00/11:59 using format:%H:%M
DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: parsed time from: Thu Jan  1 06:00:00 1970 and to:Thu Jan  1 11:59:00 1970
DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules:(eid: 38024)  seeing if now:Thu Jan  1 17:51:00 1970 is between:Thu Jan  1 06:00:00 1970 and Thu Jan  1 11:59:00 1970
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: Skipping this rule as times don't match..
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: (eid: 38024) No rules matched
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 Matching alarm to connection rules...

Rules:

jon@zoneminder:/etc/zm$ cat es_rules.json
{
    "notifications": {
        "monitors":{
            "1": {
                "rules": [{
                    "time_format":"%H:%M",
                    "from":"6:00",
                    "to":"11:59",
                    "action":"mute",
                    "cause_has":"Motion Doorway"
                }]
            }
        }
    }
}

Debug logs:

jon@zoneminder:/etc/zm$ sudo -u www-data /usr/bin/zmeventnotification.pl --debug
07/08/21 17:51:05.554078 zmeventnotification[6634].INF [main:336] [Running on WebSocket library version:0.004]
INF:2021-07-08,17:51:05 PARENT: using config file: /etc/zm/zmeventnotification.ini
07/08/21 17:51:05.633833 zmeventnotification[6634].INF [main:1036] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
INF:2021-07-08,17:51:05 PARENT: using secrets file: /etc/zm/secrets.ini
07/08/21 17:51:05.658552 zmeventnotification[6634].INF [main:1036] [PARENT: using secrets file: /etc/zm/secrets.ini]
DBG-2:2021-07-08,17:51:05 PARENT: Got secret token !ZMES_PICTURE_URL
DBG-2:2021-07-08,17:51:05 PARENT: Got secret token !ZM_USER
DBG-2:2021-07-08,17:51:05 PARENT: Got secret token !ZM_PASSWORD
DBG-2:2021-07-08,17:51:05 PARENT: rules: Loading es rules json: /etc/zm/es_rules.json
DBG-2:2021-07-08,17:51:05 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)............... 0

Use admin interface .................. no
Admin interface password.............. (undefined)
Admin interface persistence file ..... /var/lib/zmeventnotification/misc/escontrol_interface.dat

Port ................................. 9000
Address .............................. [::]
Event check interval ................. 5
Monitor reload interval .............. 300
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

Token file ........................... /var/lib/zmeventnotification/push/tokens.txt

Use MQTT ............................. no
MQTT Server .......................... 127.0.0.1
MQTT Topic ........................... zoneminder
MQTT Username ........................ (undefined)
MQTT Password ........................ (undefined)
MQTT Retain .......................... no
MQTT Tick Interval ................... 15
MQTT TLS CA ........................ (undefined)
MQTT TLS Cert ........................ (undefined)
MQTT TLS Key ........................ (undefined)
MQTT TLS Insecure ........................ no

SSL enabled .......................... no
SSL cert file ........................ /etc/zm/ssl/zoneminder.crt
SSL key file ......................... /etc/zm/ssl/zoneminder.key

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............no
Monitor rules JSON file................/etc/zm/es_rules.json

Use Hooks............................. no
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.............. (undefined)
User Script on Event End...............(undefined)
Hook Skipped monitors................. (undefined)

Notify on Event Start (hook success).. all
Notify on Event Start (hook fail)..... none
Notify on Event End (hook success).... fcm,web,api
Notify on Event End (hook fail)....... none
Notify End only if Start success...... yes

Use Hook Description.................. yes
Keep frame match type................. yes
Store Frame in ZM......................yes

Picture URL .......................... http://zoneminder.trachenet/zm/index.php?view=image&eid=EVENTID&fid=objdetect_mp4&width=600
Include picture....................... yes
Picture username ..................... jon
Picture password ..................... (defined)

INF:2021-07-08,17:51:05 PARENT: Push enabled via FCM
07/08/21 17:51:05.953407 zmeventnotification[6634].INF [main:1036] [PARENT: Push enabled via FCM]
DBG-2:2021-07-08,17:51:05 PARENT: fcmv1: --> FCM V1 APIs: 1
INF:2021-07-08,17:51:05 PARENT: MQTT Disabled
07/08/21 17:51:05.963495 zmeventnotification[6634].INF [main:1036] [PARENT: MQTT Disabled]
INF:2021-07-08,17:51:05 PARENT: |------- Starting ES version: 6.1.25 ---------|
07/08/21 17:51:05.973695 zmeventnotification[6634].INF [main:1036] [PARENT: |------- Starting ES version: 6.1.25 ---------|]
DBG-2:2021-07-08,17:51:05 PARENT: Started with: perl:/usr/bin/perl and command:/usr/bin/zmeventnotification.pl
Can't ignore signal CHLD, forcing to default.
DBG-1:2021-07-08,17:51:06 PARENT: ES invoked manually. Will handle restarts ourselves
WAR:2021-07-08,17:51:06 PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted
07/08/21 17:51:06.332399 zmeventnotification[6634].WAR [main:1044] [PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted]
DBG-2:2021-07-08,17:51:06 PARENT: Parent<--Child pipe ready
INF:2021-07-08,17:51:06 PARENT: Event Notification daemon v 6.1.25 starting

07/08/21 17:51:06.345907 zmeventnotification[6634].INF [main:1036] [PARENT: Event Notification daemon v 6.1.25 starting]
DBG-1:2021-07-08,17:51:06 PARENT: Initializing FCM tokens...
DBG-1:2021-07-08,17:51:06 PARENT: Total event client connections: 2

DBG-1:2021-07-08,17:51:06 PARENT: -->checkNewEvents: Connection 1: ID->1625781066.35669 IP->(none) Token->:...5Cxfsxtt27 Plat:android Push:enabled
DBG-1:2021-07-08,17:51:06 PARENT: -->checkNewEvents: Connection 2: ID->1625781066.35681 IP->(none) Token->:...kKsbRYv5w_ Plat:ios Push:enabled
INF:2021-07-08,17:51:06 PARENT: Re-loading monitors
07/08/21 17:51:06.358029 zmeventnotification[6634].INF [main:1036] [PARENT: Re-loading monitors]
DBG-1:2021-07-08,17:51:06 PARENT: Loading TracheCam.1
DBG-2:2021-07-08,17:51:06 PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data
DBG-2:2021-07-08,17:51:06 PARENT: checkEvents() new events found=0
INF:2021-07-08,17:51:06 PARENT: Secure WS is disabled...
07/08/21 17:51:06.373383 zmeventnotification[6634].INF [main:1036] [PARENT: Secure WS is disabled...]
INF:2021-07-08,17:51:06 PARENT: Web Socket Event Server listening on port 9000
07/08/21 17:51:06.382731 zmeventnotification[6634].INF [main:1036] [PARENT: Web Socket Event Server listening on port 9000]
DBG-2:2021-07-08,17:51:11 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,17:51:11 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-08,17:51:11 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,17:51:11 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,17:51:11 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,17:51:11 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,17:51:16 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,17:51:16 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-08,17:51:16 PARENT: There are 0 active child forks & 0 zm_detect processes running...
INF:2021-07-08,17:51:16 PARENT: New event 38024 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]
07/08/21 17:51:16.402700 zmeventnotification[6634].INF [main:1036] [PARENT: New event 38024 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]]
DBG-2:2021-07-08,17:51:16 PARENT: checkEvents() new events found=1
DBG-2:2021-07-08,17:51:16 PARENT: There are 1 new Events to process
DBG-2:2021-07-08,17:51:16 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2021-07-08,17:51:16 PARENT: Forked process:6638 to handle alarm eid:38024
INF:2021-07-08,17:51:16 |----> FORK:TracheCam.1 (1), eid:38024 use hooks/start hook not being used, going to directly send out a notification if checks pass
07/08/21 17:51:16.425820 zmeventnotification[6638].INF [main:1036] [|----> FORK:TracheCam.1 (1), eid:38024 use hooks/start hook not being used, going to directly send out a notification if checks pass]
DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: Checking rules for alarm caused by eid:38024, monitor:1, at: Thu Jul  8 17:51:18 2021 with cause:Motion Doorway
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: (eid: 38024) -- Processing rule: 1 --
DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: parsing rule 6:00/11:59 using format:%H:%M
DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: parsed time from: Thu Jan  1 06:00:00 1970 and to:Thu Jan  1 11:59:00 1970
DBG-2:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules:(eid: 38024)  seeing if now:Thu Jan  1 17:51:00 1970 is between:Thu Jan  1 06:00:00 1970 and Thu Jan  1 11:59:00 1970
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: Skipping this rule as times don't match..
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 rules: (eid: 38024) No rules matched
DBG-1:2021-07-08,17:51:18 |----> FORK:TracheCam.1 (1), eid:38024 Matching alarm to connection rules...

[pliablepixels]

Thu Jan 1 17:51:00 1970" IS between "Thu Jan 1 06:00:00 1970 and Thu Jan 1 11:59:00 1970"

It is not. You are using 24h format so you probably mean 23:59

[Jsalas424]

Thu Jan 1 17:51:00 1970" IS between "Thu Jan 1 06:00:00 1970 and Thu Jan 1 11:59:00 1970"

It is not. You are using 24h format so you probably mean 23:59

Thank you for pointing out my dumb and obvious mistake! Everything is working as expected now, full logs attached.

jon@zoneminder:/etc/zm$ sudo -u www-data /usr/bin/zmeventnotification.pl --debug07/08/21 22:52:40.112229 zmeventnotification[8302].INF [main:336] [Running on WebSocket library version:0.004]
INF:2021-07-08,22:52:40 PARENT: using config file: /etc/zm/zmeventnotification.ini
07/08/21 22:52:40.379943 zmeventnotification[8302].INF [main:1036] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
INF:2021-07-08,22:52:40 PARENT: using secrets file: /etc/zm/secrets.ini
07/08/21 22:52:40.411539 zmeventnotification[8302].INF [main:1036] [PARENT: using secrets file: /etc/zm/secrets.ini]
DBG-2:2021-07-08,22:52:40 PARENT: Got secret token !ZMES_PICTURE_URL
DBG-2:2021-07-08,22:52:40 PARENT: Got secret token !ZM_USER
DBG-2:2021-07-08,22:52:40 PARENT: Got secret token !ZM_PASSWORD
DBG-2:2021-07-08,22:52:40 PARENT: rules: Loading es rules json: /etc/zm/es_rules.json
DBG-2:2021-07-08,22:52:40 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)............... 0

Use admin interface .................. no
Admin interface password.............. (undefined)
Admin interface persistence file ..... /var/lib/zmeventnotification/misc/escontrol_interface.dat

Port ................................. 9000
Address .............................. [::]
Event check interval ................. 5
Monitor reload interval .............. 300
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

Token file ........................... /var/lib/zmeventnotification/push/tokens.txt

Use MQTT ............................. no
MQTT Server .......................... 127.0.0.1
MQTT Topic ........................... zoneminder
MQTT Username ........................ (undefined)
MQTT Password ........................ (undefined)
MQTT Retain .......................... no
MQTT Tick Interval ................... 15
MQTT TLS CA ........................ (undefined)
MQTT TLS Cert ........................ (undefined)
MQTT TLS Key ........................ (undefined)
MQTT TLS Insecure ........................ no

SSL enabled .......................... no
SSL cert file ........................ /etc/zm/ssl/zoneminder.crt
SSL key file ......................... /etc/zm/ssl/zoneminder.key

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............no
Monitor rules JSON file................/etc/zm/es_rules.json

Use Hooks............................. no
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.............. (undefined)
User Script on Event End...............(undefined)
Hook Skipped monitors................. (undefined)

Notify on Event Start (hook success).. all
Notify on Event Start (hook fail)..... none
Notify on Event End (hook success).... fcm,web,api
Notify on Event End (hook fail)....... none
Notify End only if Start success...... yes

Use Hook Description.................. yes
Keep frame match type................. yes
Store Frame in ZM......................yes

Picture URL .......................... http://zoneminder.trachenet/zm/index.php?view=image&eid=EVENTID&fid=objdetect_mp4&width=600
Include picture....................... yes
Picture username ..................... jon
Picture password ..................... (defined)

INF:2021-07-08,22:52:40 PARENT: Push enabled via FCM
07/08/21 22:52:40.801930 zmeventnotification[8302].INF [main:1036] [PARENT: Push enabled via FCM]
DBG-2:2021-07-08,22:52:40 PARENT: fcmv1: --> FCM V1 APIs: 1
INF:2021-07-08,22:52:40 PARENT: MQTT Disabled
07/08/21 22:52:40.814155 zmeventnotification[8302].INF [main:1036] [PARENT: MQTT Disabled]
INF:2021-07-08,22:52:40 PARENT: |------- Starting ES version: 6.1.25 ---------|
07/08/21 22:52:40.823969 zmeventnotification[8302].INF [main:1036] [PARENT: |------- Starting ES version: 6.1.25 ---------|]
DBG-2:2021-07-08,22:52:40 PARENT: Started with: perl:/usr/bin/perl and command:/usr/bin/zmeventnotification.pl
Can't ignore signal CHLD, forcing to default.
DBG-1:2021-07-08,22:52:41 PARENT: ES invoked manually. Will handle restarts ourselves
WAR:2021-07-08,22:52:41 PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted
07/08/21 22:52:41.198302 zmeventnotification[8302].WAR [main:1044] [PARENT: WARNING: SSL is disabled, which means all traffic will be unencrypted]
DBG-2:2021-07-08,22:52:41 PARENT: Parent<--Child pipe ready
INF:2021-07-08,22:52:41 PARENT: Event Notification daemon v 6.1.25 starting

07/08/21 22:52:41.215657 zmeventnotification[8302].INF [main:1036] [PARENT: Event Notification daemon v 6.1.25 starting]
DBG-1:2021-07-08,22:52:41 PARENT: Initializing FCM tokens...
DBG-1:2021-07-08,22:52:41 PARENT: Total event client connections: 2

DBG-1:2021-07-08,22:52:41 PARENT: -->checkNewEvents: Connection 1: ID->1625799161.22775 IP->(none) Token->:...5Cxfsxtt27 Plat:android Push:enabled
DBG-1:2021-07-08,22:52:41 PARENT: -->checkNewEvents: Connection 2: ID->1625799161.22784 IP->(none) Token->:...kKsbRYv5w_ Plat:ios Push:enabled
INF:2021-07-08,22:52:41 PARENT: Re-loading monitors
07/08/21 22:52:41.229067 zmeventnotification[8302].INF [main:1036] [PARENT: Re-loading monitors]
DBG-1:2021-07-08,22:52:41 PARENT: Loading TracheCam.1
DBG-2:2021-07-08,22:52:41 PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data
DBG-2:2021-07-08,22:52:41 PARENT: checkEvents() new events found=0
INF:2021-07-08,22:52:41 PARENT: Secure WS is disabled...
07/08/21 22:52:41.244559 zmeventnotification[8302].INF [main:1036] [PARENT: Secure WS is disabled...]
INF:2021-07-08,22:52:41 PARENT: Web Socket Event Server listening on port 9000
07/08/21 22:52:41.254295 zmeventnotification[8302].INF [main:1036] [PARENT: Web Socket Event Server listening on port 9000]
DBG-2:2021-07-08,22:52:46 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:52:46 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-08,22:52:46 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:52:46 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:52:46 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:52:46 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:52:51 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:52:51 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-08,22:52:51 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:52:51 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:52:51 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:52:51 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:52:56 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:52:56 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-08,22:52:56 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:52:56 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:52:56 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:52:56 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:53:01 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:01 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-08,22:53:01 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:53:01 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:53:01 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:53:01 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
xDBG-2:2021-07-08,22:53:06 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:06 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-08,22:53:06 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:53:06 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:53:06 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:53:06 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:53:11 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:11 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-08,22:53:11 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:53:11 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:53:11 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:53:11 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:53:16 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:16 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-08,22:53:16 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:53:16 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:53:16 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:53:16 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:53:21 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:21 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-08,22:53:21 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:53:21 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:53:21 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:53:21 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:53:26 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:26 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-08,22:53:26 PARENT: There are 0 active child forks & 0 zm_detect processes running...
DBG-2:2021-07-08,22:53:26 PARENT: checkEvents() new events found=0
DBG-2:2021-07-08,22:53:26 PARENT: There are 0 new Events to process
DBG-2:2021-07-08,22:53:26 PARENT: ---------->Tick END (active forks:0, total forks:0, active hooks: 0)<--------------
DBG-2:2021-07-08,22:53:31 PARENT: ----------> Tick START (active forks:0, total forks:0, active hooks: 0 running for:1 min)<--------------
DBG-2:2021-07-08,22:53:31 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-08,22:53:31 PARENT: There are 0 active child forks & 0 zm_detect processes running...
INF:2021-07-08,22:53:31 PARENT: New event 38070 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]
07/08/21 22:53:31.267416 zmeventnotification[8302].INF [main:1036] [PARENT: New event 38070 reported for Monitor:1 (Name:TracheCam.1) Motion Doorway[last processed eid:]]
DBG-2:2021-07-08,22:53:31 PARENT: checkEvents() new events found=1
DBG-2:2021-07-08,22:53:31 PARENT: There are 1 new Events to process
DBG-2:2021-07-08,22:53:31 PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------
DBG-1:2021-07-08,22:53:31 PARENT: Forked process:8306 to handle alarm eid:38070
INF:2021-07-08,22:53:31 |----> FORK:TracheCam.1 (1), eid:38070 use hooks/start hook not being used, going to directly send out a notification if checks pass
07/08/21 22:53:31.320869 zmeventnotification[8306].INF [main:1036] [|----> FORK:TracheCam.1 (1), eid:38070 use hooks/start hook not being used, going to directly send out a notification if checks pass]
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules: Checking rules for alarm caused by eid:38070, monitor:1, at: Thu Jul  8 22:53:33 2021 with cause:Motion Doorway
DBG-1:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules: (eid: 38070) -- Processing rule: 1 --
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules: parsing rule 6:00/23:59 using format:%H:%M
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules: parsed time from: Thu Jan  1 06:00:00 1970 and to:Thu Jan  1 23:59:00 1970
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules:(eid: 38070)  seeing if now:Thu Jan  1 22:53:00 1970 is between:Thu Jan  1 06:00:00 1970 and Thu Jan  1 23:59:00 1970
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules:(eid: 38070)  seeing if now:Thu is part of:
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules:(eid: 38070)  seeing if cause_has: ->Motion Doorway<- is part of ->Motion Doorway<-
DBG-1:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules: (eid: 38070) mute rule matched
DBG-4:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 rules: Not processing start notifications as rules checks failed
DBG-2:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 For 1 (TracheCam.1), SHM says: state=0, eid=38070
INF:2021-07-08,22:53:33 |----> FORK:TracheCam.1 (1), eid:38070 Event 38070 for Monitor 1 has finished