search

ZoneMinder / zmeventnotification

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

Push notification minimum timer does not work. #320

Closed aaronsta1 closed 4 years ago

aaronsta1 commented 4 years ago

Before you create an issue, please make sure you have read the FAQ. Common questions on API, no image etc are covered there. Please also read HOWTO REPORT ISSUES

The version of zmNinja you are reporting:

1.6

The version and OS of ZoneMinder you are using:

1.34.21 ubuntu 20.04

Platform zmNinja is running on

oneplus 6t

Did you build the package from source code yourself? No

Describe the bug The push notification delay timer is not working

Debug logs

Screenshots If applicable, add screenshots to help explain your problem.

Additional context i tested by setting the min push notification to 5000 seconds and walked around in the camera and it ignored that value and sent the push notification anyway.

i checked the tokens.txt file and the numbers are there.

{"tokens":{"KEY REMOVED":{"monlist":"1,2,3,4,5","intlist":"5000,5000,5000,5000,5000","appversion":"1.6.000","platform":"android","invocations":{"at":"9","count":"203"},"pushstate":"enabled"}}}

5000 seconds is like 83 minutes.. its noticeable that it does not work.

pliablepixels commented 4 years ago

Please post debug logs on the ES side when this happens.

aaronsta1 commented 4 years ago

this is what the log says, as you can see monitor 5 sent 3 push notifications in about 1 minute.

2020-10-17 03:10:30 zmeventnotification   6297 INF \ ----> FORK:Monitor-5 (5), eid:1581266 Event 1581266 for Monitor 5 has finished zmeventnotification.pl  
2020-10-17 03:10:23 zmeventnotification   6297 INF |----> FORK:Monitor-5 (5), eid:1581266 Sending event_start notification over FCM zmeventnotification.pl  
2020-10-17 03:10:18 zmeventnotification   2245 INF PARENT: New event 1581267 reported for Monitor:4 (Name:Monitor-4) Motion Driveway2[last processed eid:1581261] zmeventnotification.pl  
2020-10-17 03:10:13 zmeventnotification   2245 INF PARENT: New event 1581266 reported for Monitor:5 (Name:Monitor-5) Motion All[last processed eid:1581264] zmeventnotification.pl  
2020-10-17 03:09:38 zmeventnotification   6171 INF |----> FORK:Monitor-5 (5), eid:1581264 Not sending event end notification as send_event_end_notification is no zmeventnotification.pl  
2020-10-17 03:09:34 zmeventnotification   6171 INF |----> FORK:Monitor-5 (5), eid:1581264 Event 1581264 for Monitor 5 has finished zmeventnotification.pl  
2020-10-17 03:09:33 zmeventnotification   6171 INF |----> FORK:Monitor-5 (5), eid:1581264 Sending event_start notification over FCM zmeventnotification.pl  
2020-10-17 03:09:28 zmeventnotification   2245 INF PARENT: Re-loading monitors zmeventnotification.pl  
2020-10-17 03:09:23 zmeventnotification   2245 INF PARENT: New event 1581264 reported for Monitor:5 (Name:Monitor-5) Motion All[last processed eid:1581263] zmeventnotification.pl  
2020-10-17 03:09:20 zmeventnotification   6033 INF |----> FORK:Monitor-5 (5), eid:1581263 Not sending event end notification as send_event_end_notification is no zmeventnotification.pl  
2020-10-17 03:09:16 zmeventnotification   6033 INF |----> FORK:Monitor-5 (5), eid:1581263 Event 1581263 for Monitor 5 has finished zmeventnotification.pl  
2020-10-17 03:09:13 zmeventnotification   6033 INF |----> FORK:Monitor-5 (5), eid:1581263 Sending event_start notification over FCM zmeventnotification.pl  
2020-10-17 03:09:03 zmeventnotification   2245 INF PARENT: New event 1581263 reported for Monitor:5 (Name:Monitor-5) Motion All[last processed eid:1581259]

it used to say something like not sending push because 30 is less than 300 or whatever i had it at.

pliablepixels commented 4 years ago

No, I need debug logs.

aaronsta1 commented 4 years ago

ok let me figure how to turn those on.

aaronsta1 commented 4 years ago

its on level 2 what level do i need to set it for debug log? it says level 2 is normal.

pliablepixels commented 4 years ago

Pretty much the same thing we discussed last time - the debug logs will be in another file - it will have DBG-1 and DBG-2 In my case, it is in /var/log/zm/zmeventnotification.log

aaronsta1 commented 4 years ago

yeah i see that, but it has the same thing i just sent you in it.

10/17/2020 03:25:42.004141 zmeventnotification[9091].INF [main:963] [PARENT: using config file: /etc/zm/zmeventnotification.ini] 10/17/2020 03:25:42.207049 zmeventnotification[9091].INF [main:963] [PARENT: using secrets file: /etc/zm/secrets.ini] 10/17/2020 03:25:42.438006 zmeventnotification[9091].INF [main:963] [PARENT: Push enabled via FCM] 10/17/2020 03:25:42.565272 zmeventnotification[9091].INF [main:963] [PARENT: MQTT Disabled] 10/17/2020 03:25:42.716358 zmeventnotification[9091].INF [main:963] [PARENT: |------- Starting ES version: 6.0.2 ---------|] 10/17/2020 03:25:43.056665 zmeventnotification[9091].INF [main:963] [PARENT: Event Notification daemon v 6.0.2 starting] 10/17/2020 03:25:43.309791 zmeventnotification[9091].INF [main:963] [PARENT: Re-loading monitors] 10/17/2020 03:25:43.500575 zmeventnotification[9091].INF [main:963] [PARENT: New event 1581302 reported for Monitor:5 (Name:Monitor-5) Motion All[last processed eid:]] 10/17/2020 03:25:43.654204 zmeventnotification[9091].INF [main:963] [PARENT: Secure WS(WSS) is enabled...] 10/17/2020 03:25:43.817017 zmeventnotification[9091].INF [main:963] [PARENT: Web Socket Event Server listening on port 9000] 10/17/2020 03:26:19.107593 zmeventnotification[9091].INF [main:963] [PARENT: New event 1581306 reported for Monitor:5 (Name:Monitor-5) Motion All[last processed eid:1581302]] 10/17/2020 03:26:25.257639 zmeventnotification[9250].INF [main:963] [|----> FORK:Monitor-5 (5), eid:1581306 Sending event_start notification over FCM] 10/17/2020 03:26:25.822699 zmeventnotification[9250].INF [main:963] [|----> FORK:Monitor-5 (5), eid:1581306 Event 1581306 for Monitor 5 has finished] 10/17/2020 03:26:29.933690 zmeventnotification[9250].INF [main:963] [|----> FORK:Monitor-5 (5), eid:1581306 Not sending event end notification as send_event_end_notification is no] 10/17/2020 03:26:59.108000 zmeventnotification[9091].INF [main:963] [PARENT: New event 1581307 reported for Monitor:5 (Name:Monitor-5) Motion All[last processed eid:1581306]] 10/17/2020 03:27:09.355776 zmeventnotification[9373].INF [main:963] [|----> FORK:Monitor-5 (5), eid:1581307 Event 1581307 for Monitor 5 has finished] 10/17/2020 03:27:13.494169 zmeventnotification[9373].INF [main:963] [|----> FORK:Monitor-5 (5), eid:1581307 Not sending event end notification as send_event_end_notification is no] 10/17/2020 03:30:34.107354 zmeventnotification[9091].INF [main:963] [PARENT: New event 1581310 reported for Monitor:4 (Name:Monitor-4) Driveway2[last processed eid:]] 10/17/2020 03:30:42.003244 zmeventnotification[9805].INF [main:963] [|----> FORK:Monitor-4 (4), eid:1581310 Event 1581310 for Monitor 4 has finished] 10/17/2020 03:30:44.117197 zmeventnotification[9091].INF [main:963] [PARENT: Re-loading monitors] 10/17/2020 03:30:44.140733 zmeventnotification[9805].INF [main:963] [|----> FORK:Monitor-4 (4), eid:1581310 Not sending over FCM as notify filters are on_success:all and on_fail:none] 10/17/2020 03:30:48.500417 zmeventnotification[9805].INF [main:963] [|----> FORK:Monitor-4 (4), eid:1581310 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]

pliablepixels commented 4 years ago

Go to ZM-Logging

1. LOG_LEVEL_FILE = Debug
2. Make sure LOG_DEBUG is checked (super important)
3. LOG_DEBUG_TARGET = _zmesdetect|_zmeventnotification
4. LOG_DEBUG_LEVEL = 2
5. LOG_DEBUG_FILE = empty

may need to restart ZM (should not be necessary)

aaronsta1 commented 4 years ago

ok i found this 10/17/2020 03:41:38.020213 zmeventnotification[11157].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581327 rules: Checking rules for alarm caused by eid:1581327, monitor:5, at: Sat Oct 17 03:41:38 2020 with cause:GPU detected: person: 96% Monitor-5 Motion All] 10/17/2020 03:41:38.020294 zmeventnotification[11157].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581327 rules: No rules found for Monitor, allowing:5] 10/17/2020 03:41:38.020359 zmeventnotification[11157].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581327 Matching alarm to connection rules...] 10/17/2020 03:41:38.020436 zmeventnotification[11157].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581327 Checking alarm conditions for token ending in:...73BeXhkXjf] 10/17/2020 03:41:38.020569 zmeventnotification[11157].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581327 Monitor 5 event: should NOT send this out as 36.086620092392 is less than interval of 120]

but it sent it anyway.

aaronsta1 commented 4 years ago

ok the log as this a bunch of times. 10/17/2020 03:41:01.913301 zmeventnotification[11086].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581326 Monitor 5 event: last time not found, so should send] 10/17/2020 03:41:01.913357 zmeventnotification[11086].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581326 shouldSendEventToConn returned true, so calling sendEvent]

so im guessing the time isnt saving correctly? i did install Time::Piece Time::Piece is up to date (1.3401).

aaronsta1 commented 4 years ago

this is strange, turning on debug fixed it. ugh all day long i been getting like 100 push message an hour and now it seems to be working. 10/17/2020 04:08:13.030548 zmeventnotification[13146].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581373 rules: Checking rules for alarm caused by eid:1581373, monitor:5, at: Sat Oct 17 04:08:13 2020 with cause:GPU detected: person: 90% Monitor-5 Motion All] 10/17/2020 04:08:13.030679 zmeventnotification[13146].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581373 rules: No rules found for Monitor, allowing:5] 10/17/2020 04:08:13.030862 zmeventnotification[13146].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581373 Matching alarm to connection rules...] 10/17/2020 04:08:13.031033 zmeventnotification[13146].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581373 Checking alarm conditions for token ending in:...73BeXhkXjf] 10/17/2020 04:08:13.031352 zmeventnotification[13146].DBG [main:954] [|----> FORK:Monitor-5 (5), eid:1581373 Monitor 5 event: should NOT send this out as 31.0829699039459 is less than interval of 120]

i didnt even change anything but enabling debug and hitting save.

aaronsta1 commented 4 years ago

i uninstalled and reinstalled Time::Piece just incase it wasnt working right and i rebooted the computer.. so far i think it fixed itself. or something. thanks for the help again.

i still havent gotten cv2 working.. :( no matter what i do www-data user cannot import it.

aaronsta1 commented 4 years ago

ok that didnt take very long. there is a problem. it seems to reset the timer after a failed detection.. even if there was no push message. so what i witnessed, was monitor 4 had a false alarm. detected nothing. didnt sent a push message. then it did detect something.. but then said it wont send a message because 30 seconds is less than 300 seconds but t his time it should have sent a message because it was a good detection.

then it detected something again.. this time another false alarm.. but this time it says it has no start time and it should send a push because its never sent one. so then i ended up getting a push message. its doing that pretty often where it says there is no start time and it should send a message anyway. even if it just sent one. if i restart the PC it goes back to working, but not for very long..

to test it i turned off the hook and i just get constant push messages.

the thing with monitor 4 is it looks out over the street and at night the headlights from the cars trigger it.. so all night long i am getting push messages with a white out picture.. even tho the detect has not detected a person.

i dont know how else to debug this.. its worked just fine for a couple years until being forced to upgrade to the new event server version because of the new FCM or whatever.

now my phone is blowing up with push notifications. even tho i have it set to 300 seconds in the tokens.txt for the monitors. sometimes i get 6 in a row. 1 second apart.

pliablepixels commented 4 years ago

Please try master.