ZoneMinder / zmeventnotification

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

How to improve initial detection? #287

Closed scottgrobinson closed 4 years ago

scottgrobinson commented 4 years ago

Event Server version

v5.15.6

The version of ZoneMinder you are using:

v1.34.16

What is the nature of your issue

Question

Details

The initial detection of objects appears to be slow. I'm going to assume this isn't code related, but I'm struggling to work out how this can be improved.

Running it for a second time still takes 6 - 7 seconds. I don't see any cpu bottlenecks when running htop at the same time as as the zm_event_start.sh script.

07/27/20 15:50:08.498349 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 22828 1 "Gate (Front Zone)" "Motion Front" "/var/cache/zoneminder/events/1/2020-07-27/22828"]
07/27/20 15:50:35.976794 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 hook start returned with text:[a] detected:car json:[{"type": "object", "label": "car", "box": [964, 242, 1174, 342], "confidence": "98.97%"}] exit:0]

Debug Logs (if applicable)


07/27/20 15:50:07.490007 zmeventnotification[546].INF [main:892] [PARENT: New event 22828 reported for Monitor:1 (Name:Gate (Front Zone)) Motion Front[last processed eid:22826]]
07/27/20 15:50:08.472160 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:08.486066 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:08.497476 zmeventnotification[101265].DBG [main:883] [PARENT: Forked process:101265 to handle alarm eid:22828]
07/27/20 15:50:08.497652 zmeventnotification[101265].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Event from Events WHERE Id = 22828]
07/27/20 15:50:08.498349 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 22828 1 "Gate (Fron
t Zone)" "Motion Front" "/var/cache/zoneminder/events/1/2020-07-27/22828"]
07/27/20 15:50:12.489335 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:12.489502 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:12.489621 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:12.489671 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:17.489970 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:17.490074 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:17.490158 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:17.490214 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:17.490362 zmeventnotification[546].INF [main:892] [PARENT: New event 22829 reported for Monitor:2 (Name:Gate (Drive Zone)) Motion Drive[last processed eid:22827]]
07/27/20 15:50:17.622870 zmeventnotification[101283].DBG [main:883] [PARENT: Forked process:101283 to handle alarm eid:22829]
07/27/20 15:50:17.623058 zmeventnotification[101283].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Event from Events WHERE Id = 22829]
07/27/20 15:50:17.623863 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 22829 2 "Gate (Driv
e Zone)" "Motion Drive" "/var/cache/zoneminder/events/2/2020-07-27/22829"]
07/27/20 15:50:22.489322 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:22.489496 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:22.489636 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:22.489707 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:27.489400 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:27.542961 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:27.543295 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:27.543511 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:32.489222 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:32.489408 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:32.489592 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:32.489710 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:35.861019 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 hook start returned with text:[a] detected:car json:[{"type": "object", "label": "car", "box": [594,
223, 990, 353], "confidence": "99.99%"}] exit:0]
07/27/20 15:50:35.861233 zmeventnotification[101283].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:35.861349 zmeventnotification[101283].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:35.861452 zmeventnotification[101283].INF [main:892] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Event 22829 for Monitor 2 has finished]
07/27/20 15:50:35.976794 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 hook start returned with text:[a] detected:car json:[{"type": "object", "label": "car", "box": [964,
242, 1174, 342], "confidence": "98.97%"}] exit:0]
07/27/20 15:50:35.976954 zmeventnotification[101265].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:35.977073 zmeventnotification[101265].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:35.977154 zmeventnotification[101265].INF [main:892] [|----> FORK:Gate (Front Zone) (1), eid:22828 Event 22828 for Monitor 1 has finished]
07/27/20 15:50:37.490366 zmeventnotification[546].DBG [main:883] [PARENT: updating Notes clause for Event:22829 with:[a] detected:car ]
07/27/20 15:50:37.550663 zmeventnotification[546].DBG [main:883] [PARENT: updating Notes clause for Event:22828 with:[a] detected:car ]
07/27/20 15:50:37.605183 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:37.605328 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:37.605606 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:37.605702 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:38.017154 zmeventnotification[101283].INF [main:892] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Sending push over API as it is allowed for event_start]
07/27/20 15:50:38.049238 zmeventnotification[101283].INF [main:892] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Executing API script command for event_start /var/lib/zmeventnotification/bin/pushapi_pushover.py 22829 2  "Gate (Drive Zone)"  "[a] detected:car Motion Drive"  event_start "/var/cache/zoneminder/events/2/2020-07-27/22829"]
07/27/20 15:50:38.085507 zmeventnotification[101265].INF [main:892] [|----> FORK:Gate (Front Zone) (1), eid:22828 Sending push over API as it is allowed for event_start]
07/27/20 15:50:38.182150 zmeventnotification[101265].INF [main:892] [|----> FORK:Gate (Front Zone) (1), eid:22828 Executing API script command for event_start /var/lib/zmeventnotification/bin/pushapi_pushover.py 22828 1  "Gate (Front Zone)"  "[a] detected:car Motion Front"  event_start "/var/cache/zoneminder/events/1/2020-07-27/22828"]
07/27/20 15:50:42.489247 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:42.489450 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:42.489632 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:42.489844 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:47.489262 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:47.489450 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:47.489605 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:47.489707 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:52.489611 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:52.490143 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:52.490698 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:52.491091 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:50:57.489375 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:50:57.489676 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:50:57.490028 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:50:57.490203 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:01.917177 zmeventnotification[101283].INF [main:892] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Returned from /var/lib/zmeventnotification/bin/pushapi_pushover.py 22829 2  "Gate (Drive Zone)"  "[a] detected:car Motion Drive"  event_start "/var/cache/zoneminder/events/2/2020-07-27/22829"]
07/27/20 15:51:02.255745 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 API push script returned : 0]
07/27/20 15:51:02.255892 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Matching alarm to connection rules...]
07/27/20 15:51:02.256052 zmeventnotification[101283].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:51:02.256392 zmeventnotification[101283].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:02.490653 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:51:02.490792 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:51:02.490926 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:51:02.491007 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:02.855665 zmeventnotification[101265].INF [main:892] [|----> FORK:Gate (Front Zone) (1), eid:22828 Returned from /var/lib/zmeventnotification/bin/pushapi_pushover.py 22828 1  "Gate (Front Zone)"  "[a] detected:car Motion Front"  event_start "/var/cache/zoneminder/events/1/2020-07-27/22828"]
07/27/20 15:51:03.377770 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 API push script returned : 0]
07/27/20 15:51:03.379179 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Matching alarm to connection rules...]
07/27/20 15:51:03.379639 zmeventnotification[101265].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:51:03.380074 zmeventnotification[101265].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:51:04.262109 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 22829 2 "Gate (Drive Zone)" "[a] detected:car Motion: Drive" "/var/cache/zoneminder/events/2/2020-07-27/22829"]
07/27/20 15:51:04.273304 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 hook end returned with text:[a] detected:car Motion: Drive  json:[] exit:0]
07/27/20 15:51:04.273446 zmeventnotification[101283].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:51:04.273587 zmeventnotification[101283].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:05.380675 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 22828 1 "Gate (Front Zone)" "[a] detected:car Motion: Front" "/var/cache/zoneminder/events/1/2020-07-27/22828"]
07/27/20 15:51:05.383575 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 hook end returned with text:[a] detected:car Motion: Front  json:[] exit:0]
07/27/20 15:51:05.383674 zmeventnotification[101265].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:51:05.383811 zmeventnotification[101265].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:51:06.274185 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Not sending event_end push over API as send_event_end_notification is no]
07/27/20 15:51:06.409897 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Matching alarm to connection rules...]
07/27/20 15:51:06.410337 zmeventnotification[101283].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:51:06.410829 zmeventnotification[101283].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:07.384055 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Not sending event_end push over API as send_event_end_notification is no]
07/27/20 15:51:07.384127 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Matching alarm to connection rules...]
07/27/20 15:51:07.384187 zmeventnotification[101265].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:51:07.384262 zmeventnotification[101265].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:51:07.489595 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:51:07.490190 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:51:07.490787 zmeventnotification[546].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:51:07.491062 zmeventnotification[546].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:08.411404 zmeventnotification[101283].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963705344 for 2]
07/27/20 15:51:08.411717 zmeventnotification[101283].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 2: 1]
07/27/20 15:51:09.384583 zmeventnotification[101265].DBG [ZoneMinder::Memory::Mapped:84] [zmMemAttach already attached at 140175963709440 for 1]
07/27/20 15:51:09.384803 zmeventnotification[101265].DBG [ZoneMinder::Memory:300] [Shared data appears valid for monitor 1: 1]
07/27/20 15:51:10.412245 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 exiting]
07/27/20 15:51:10.547309 zmeventnotification[101283].DBG [main:883] [|----> FORK:Gate (Drive Zone) (2), eid:22829 Ending process:101283 to handle alarms]
07/27/20 15:51:11.385060 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 exiting]
07/27/20 15:51:11.385174 zmeventnotification[101265].DBG [main:883] [|----> FORK:Gate (Front Zone) (1), eid:22828 Ending process:101265 to handle alarms]
pliablepixels commented 4 years ago

https://zmeventnotification.readthedocs.io/en/latest/guides/hooks.html#general-observations is why (load time vs detection time)

scottgrobinson commented 4 years ago

@pliablepixels Appreciate the quick reply - That makes sense. I'll investigate getting ml_gateway setup, thank you.