search

ZoneMinder / zmeventnotification

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

End hook not skipped when monitor is in hook skip list #422

Open Ilia-SB opened 1 year ago

Ilia-SB commented 1 year ago

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) N The version of ZoneMinder you are using: 1.36.31 What is the nature of your issue Bug Details When the monitor is in hooks skip list (hook_skip_monitors), event_start_hook is getting skipped just fine, but event_end_hook still gets executed. To reproduce, don't use skip_monitors setting, add a monitor to hook_skip_monitors and see the event end script still being run for the skipped monitor. Debug Logs (if applicable)

20.10.2022 14:23:40.641189 zmeventnotification[2987785].DB1 [ZoneMinder::Logger:321] [LogOpts: level=DB3/DB1, screen=OFF, database=INF, logfile=DB1->/var/log/zm/zmeventnotification.log, syslog=INF]
20.10.2022 14:23:40.685094 zmeventnotification[2987785].INF [main:338] [Running on WebSocket library version:0.004]
20.10.2022 14:23:40.747541 zmeventnotification[2987785].INF [main:1048] [PARENT: using config file: /etc/zm/zmeventnotification.ini]
20.10.2022 14:23:40.779621 zmeventnotification[2987785].INF [main:1048] [PARENT: using secrets file: /etc/zm/secrets.ini]
20.10.2022 14:23:40.796197 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Got secret token !ZMES_PICTURE_URL]
20.10.2022 14:23:40.796419 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Got secret token !ZM_USER]
20.10.2022 14:23:40.796525 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Got secret token !ZM_PASSWORD]
20.10.2022 14:23:40.796696 zmeventnotification[2987785].DB1 [main:1036] [PARENT: config string substitution: {{base_data_path}} is '/var/lib/zmeventnotification']
20.10.2022 14:23:40.796849 zmeventnotification[2987785].DB1 [main:1036] [PARENT: config string substitution: {{base_data_path}} is '/var/lib/zmeventnotification']
20.10.2022 14:23:40.949193 zmeventnotification[2987785].INF [main:1048] [PARENT: Push enabled via FCM]
20.10.2022 14:23:40.960350 zmeventnotification[2987785].DB1 [main:1036] [PARENT: fcmv1: --> FCM V1 APIs: 1]
20.10.2022 14:23:40.960949 zmeventnotification[2987785].INF [main:1048] [PARENT: MQTT Disabled]
20.10.2022 14:23:40.970431 zmeventnotification[2987785].INF [main:1048] [PARENT: |------- Starting ES version: 6.1.28 ---------|]
20.10.2022 14:23:40.982695 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Started with: perl:/usr/bin/perl and command:/usr/bin/zmeventnotification.pl]
20.10.2022 14:23:41.135135 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ES invoked via ZMDC. Will exit when needed and have zmdc restart it]
20.10.2022 14:23:41.135693 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Parent<--Child pipe ready]
20.10.2022 14:23:41.136574 zmeventnotification[2987785].INF [main:1048] [PARENT: Event Notification daemon v 6.1.28 starting]
20.10.2022 14:23:41.148557 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Initializing FCM tokens...]
20.10.2022 14:23:41.149356 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Total event client connections: 1]
20.10.2022 14:23:41.149500 zmeventnotification[2987785].DB1 [main:1036] [PARENT: -->checkNewEvents: Connection 1: ID->1666265021.14911 IP->(none) Token->:...XsB7eUo4EB Plat:android Push:enabled]
20.10.2022 14:23:41.150075 zmeventnotification[2987785].INF [main:1048] [PARENT: Re-loading monitors]
20.10.2022 14:23:41.162886 zmeventnotification[2987785].DB1 [main:1036] [PARENT: 1 is in skip list, not going to process]
20.10.2022 14:23:41.163746 zmeventnotification[2987785].DB1 [main:1036] [PARENT: Loading Cam-1-LowRes]
20.10.2022 14:23:41.164024 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ESCONTROL_INTERFACE is disabled. Not saving control data]
20.10.2022 14:23:41.164412 zmeventnotification[2987785].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
20.10.2022 14:23:41.164521 zmeventnotification[2987785].DB1 [main:1036] [PARENT: About to start listening to socket]
20.10.2022 14:23:41.170510 zmeventnotification[2987785].INF [main:1048] [PARENT: Secure WS(WSS) is enabled...]
20.10.2022 14:23:41.181210 zmeventnotification[2987785].INF [main:1048] [PARENT: Web Socket Event Server listening on port 9000]
...
20.10.2022 14:24:01.220090 zmeventnotification[2988209].DB1 [main:1036] [PARENT: Forked process:2988209 to handle alarm eid:1034300]
**20.10.2022 14:24:01.220880 zmeventnotification[2988209].INF [main:1048] [|----> FORK:Cam-1-LowRes (2), eid:1034300 2 is in hook skip list, not using hooks]**
20.10.2022 14:24:03.231325 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 rules: Checking rules for alarm caused by eid:1034300, monitor:2, at: Thu Oct 20 14:24:03 2022 with cause:Forced Web]
20.10.2022 14:24:03.231624 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 rules: No rules found for Monitor, allowing:2]
20.10.2022 14:24:03.231918 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Matching alarm to connection rules...]
20.10.2022 14:24:03.232074 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Checking alarm conditions for token ending in:...XsB7eUo4EB]
20.10.2022 14:24:03.232179 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 should NOT send alarm as Monitor 2 is excluded]
20.10.2022 14:24:06.196834 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------]
20.10.2022 14:24:06.197021 zmeventnotification[2987785].DB1 [main:1036] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
20.10.2022 14:24:06.197080 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
20.10.2022 14:24:06.197416 zmeventnotification[2987785].DB1 [main:1036] [PARENT: We've already worked on Monitor:2, Event:1034300, not doing anything more]
20.10.2022 14:24:06.197485 zmeventnotification[2987785].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
20.10.2022 14:24:06.197532 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 0 new Events to process]
20.10.2022 14:24:06.197585 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------]
20.10.2022 14:24:11.196490 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------]
20.10.2022 14:24:11.196786 zmeventnotification[2987785].DB1 [main:1036] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
20.10.2022 14:24:11.196950 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
20.10.2022 14:24:11.197538 zmeventnotification[2987785].DB1 [main:1036] [PARENT: We've already worked on Monitor:2, Event:1034300, not doing anything more]
20.10.2022 14:24:11.197692 zmeventnotification[2987785].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
20.10.2022 14:24:11.197850 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 0 new Events to process]
20.10.2022 14:24:11.198020 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------]
20.10.2022 14:24:16.196201 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------]
20.10.2022 14:24:16.196543 zmeventnotification[2987785].DB1 [main:1036] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
20.10.2022 14:24:16.196719 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
20.10.2022 14:24:16.197250 zmeventnotification[2987785].DB1 [main:1036] [PARENT: We've already worked on Monitor:2, Event:1034300, not doing anything more]
20.10.2022 14:24:16.197402 zmeventnotification[2987785].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
20.10.2022 14:24:16.197553 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 0 new Events to process]
20.10.2022 14:24:16.197732 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------]
20.10.2022 14:24:19.236124 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 For 2 (Cam-1-LowRes), SHM says: state=1, eid=1034300]
20.10.2022 14:24:19.236613 zmeventnotification[2988209].INF [main:1048] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Event 1034300 for Monitor 2 has finished]
20.10.2022 14:24:19.248598 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Event end object is: state=>pending with cause=>Forced Web: ]
20.10.2022 14:24:21.196324 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------]
20.10.2022 14:24:21.196623 zmeventnotification[2987785].DB1 [main:1036] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
20.10.2022 14:24:21.196806 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
20.10.2022 14:24:21.197342 zmeventnotification[2987785].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
20.10.2022 14:24:21.197501 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 0 new Events to process]
20.10.2022 14:24:21.197668 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------]
20.10.2022 14:24:21.250493 zmeventnotification[2988209].DB1 [ZoneMinder::Object:126] [Loading ZoneMinder::Event from Events WHERE Id = 1034300]
20.10.2022 14:24:21.253500 zmeventnotification[2988209].DB1 [ZoneMinder::Object:126] [Loading ZoneMinder::Storage from Storage WHERE Id = 1]
20.10.2022 14:24:21.257225 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Adding event path:/mnt/storage/zm/events/2/2022-10-20/1034300 to hook for image storage]
**20.10.2022 14:24:21.257503 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 1034300 2 "Cam-1-LowRes" "Forced Web: " "/mnt/storage/zm/events/2/2022-10-20/1
034300"]**
20.10.2022 14:24:21.269903 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 parse of hook:Forced Web:  and []]
20.10.2022 14:24:21.270024 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 hook end returned with text:Forced Web:   json:[] exit:0]
20.10.2022 14:24:23.270930 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 rules: Checking rules for alarm caused by eid:1034300, monitor:2, at: Thu Oct 20 14:24:23 2022 with cause:Forced Web]
20.10.2022 14:24:23.271186 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 rules: No rules found for Monitor, allowing:2]
20.10.2022 14:24:23.271420 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Matching alarm to connection rules...]
20.10.2022 14:24:23.271638 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Skipping FCM notification as Monitor:Cam-1-LowRes(2) is excluded from zmNinja monitor list]
20.10.2022 14:24:26.196111 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ----------> Tick START (active forks:1, total forks:1, active hooks: 0 running for:1 min)<--------------]
20.10.2022 14:24:26.196404 zmeventnotification[2987785].DB1 [main:1036] [PARENT: After tick: TOTAL: 1,  ES_CONTROL: 0, FCM+WEB: 0, FCM: 1, WEB: 0, MQTT:0, invalid WEB: 0, PENDING: 0]
20.10.2022 14:24:26.197509 zmeventnotification[2987785].DB1 [main:1036] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--add]
20.10.2022 14:24:26.198110 zmeventnotification[2987785].DB1 [main:1036] [PARENT: RAW TEXT-->update_parallel_hooks--TYPE--del]
20.10.2022 14:24:26.198306 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 1 active child forks & 0 zm_detect processes running...]
20.10.2022 14:24:26.198860 zmeventnotification[2987785].DB1 [main:1036] [PARENT: checkEvents() new events found=0]
20.10.2022 14:24:26.199014 zmeventnotification[2987785].DB1 [main:1036] [PARENT: There are 0 new Events to process]
20.10.2022 14:24:26.199194 zmeventnotification[2987785].DB1 [main:1036] [PARENT: ---------->Tick END (active forks:1, total forks:1, active hooks: 0)<--------------]
20.10.2022 14:24:27.272813 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 exiting]
20.10.2022 14:24:27.273120 zmeventnotification[2988209].DB1 [main:1036] [|----> FORK:Cam-1-LowRes (2), eid:1034300 Ending process:2988209 to handle alarms]