Object detection and event filters problem.

[asker]

Looking at your logs, for event 34857, I don't see an "event end" occurrence where it logs "exiting". The DB overwrite check happens there. I see it for 34854, but that did not detect objects.

Edited: however I do see the end notice her for event 34885. So question - does 34885 have detection notes? If so, that patch seems to have worked.

Code: Select all

26/02/20 13:01:46.934082 zmeventnotification[4492].DBG [main:827] [|----> FORK:Courtyard (3), eid:34885 Making sure the detection text was not overwritten by ZM]
26/02/20 13:01:46.935084 zmeventnotification[4492].DBG [main:827] [|----> FORK:Courtyard (3), eid:34885 ZM overwrote detection, adding detection notes back into DB [[a] detected:person:86% ]]
26/02/20 13:01:46.935247 zmeventnotification[4492].DBG [main:827] [|----> FORK:Courtyard (3), eid:34885 updating Notes clause for Event:34885 with:[a] detected:person:86%   ]
26/02/20 13:01:46.936265 zmeventnotification[4492].DBG [main:827] [|----> FORK:Courtyard (3), eid:34885 exiting]

[russell_i_brown]

In short.... dunno about 34885. My zm_event_end.sh deleted it as there was no "detected:" string.

I've changed my zm_event_end.sh so it'll save a copy of the event data before asking ZM to delete it and I am seeing quite a few (four since I made the change 15 mins ago) deleted events that have an objdetect.jpg in the directory; which is obviously wrong - they should not be deleted).

Looking at the first log in my previous, it seems that when zm_event_end.sh is called (13:01:40.842977) "detected:" has been taken out by ZM and you're re-injecting it afterwards (13:01:46.935084).

Code: Select all

26/02/20 13:01:01.700385 zmeventnotification[31038].INF [main:836] [PARENT: Force updating event 34885 with desc:[a] detected:person:86% ]
26/02/20 13:01:40.842977 zmeventnotification[4492].INF [main:836] [|----> FORK:Courtyard (3), eid:34885 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 34885 3 "Courtyard" "Linked: Car PortMotion: Courtyard" "/var/cache/zoneminder/events/3/2020-02-26/34885"]
26/02/20 13:01:46.935084 zmeventnotification[4492].DBG [main:827] [|----> FORK:Courtyard (3), eid:34885 ZM overwrote detection, adding detection notes back into DB [[a] detected:person:86% ]]

If this is a pain.... I see that you're now? passing the Storage Path for the event as $5 to zm_event_end.sh. It would be trivial for me to check if $5/objdetect.jpg exists and if so refrain from deleting the event. You add back the Notes so the final result would be the same.

[asker]

Looking at the first log in my previous, it seems that when zm_event_end.sh is called (13:01:40.842977) "detected:" has been taken out by ZM and you're re-injecting it afterwards (13:01:46.935084).

Ah yes. So you want it done _before_ your end script? Ok, I made that update - please pull master (did not change version)

If this is a pain.... I see that you're now? passing the Storage Path for the event as $5 to zm_event_end.sh. It would be trivial for me to check if $5/objdetect.jpg exists and if so refrain from deleting the event. You add back the Notes so the final result would be the same.

I may do that, but its not the right solution. The ES should preserve its detected check

[russell_i_brown]

Installed and monitoring. Will report back.

FWIW, please do leave the Storage Path as $5 - a belt'n'braces check never goes amiss and it's only an fstat(2) call for bash; probable more efficient than a string compare with "*detected:*"

[russell_i_brown]

Good News(TM).

After exhaustive testing of some 17 hours that seems to have resolved the issue. Thank you.

There is one related, minor, problem for events where the object detection matched a previous detection.

In this situation, zmeventnotification quite rightly does not update the Notes with "detected:" but it leaves objdetect.jpg and objects.json in the events storage directory. This confused my belt'n'braces routine (if [ -f ${5}/objdetect.jpg ]...) as it's an event that should be deleted (no "detected:" in Notes) but which had objdetect.jpg indicating that it shouldn't.

Might I suggest adding another field to the JSON in objects.json for such matched events so it's something like:

Code: Select all

{"frame": "alarm", "detections": [{"type": "object", "label": "person", "box": [498, 240, 638, 476], "confidence": "31.46%"}], "approximate_match": "true"}

I can then use that in zm_event_end.sh to detect this class of event and handle it correctly.

I'll stick the final version of my zm_event_end.sh script on this thread but would you like me to formalise it a bit more with an option in objectconfig.ini, documentation etc and do a pull?

[asker]

There is one related, minor, problem for events where the object detection matched a previous detection.

Can you expand on this? What do you mean when object detection matches a previous detection? Do you mean for a long running single event when object detection is called multiple times within the same event? Does that actually result in the detection being called multiple times or just once?

[russell_i_brown]

What do you mean when object detection matches a previous detection?

I have "match_past_detections=yes" in my objectconfig.ini.

I've only seen this for single events with motion detection called once. I do see quite a lot of "27/02/20 14:36:21.272223 zmeventnotification[10335].DBG [main:827] [PARENT: We've already worked on Monitor:6, Event:36797, not doing anything more" type entries (1421 so far today) but I don't know that this is anything to do with the "approximately matches" problem.

The event in question found an object but didn't set "detected:" in Event.Notes because it matched a previous detection in the previous event; this behaviour is as expected.

Here's an extract from zmesdetect_m1.log

Code: Select all

02/27/20 14:28:08 zmesdetect_m1[13890] INF zm_detect.py:571 [labels found: ['car', 'car', 'truck', 'car', 'car', 'truck']]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG zm_detect.py:574 [match found in /var/lib/zmeventnotification/images/36787-alarm.jpg, breaking file loop...]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG zm_detect.py:588 [detection mode is set to first, breaking out of model loop...]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG zm_detect.py:628 [Writing out debug bounding box image to /var/lib/zmeventnotification/images/36787-alarm-bbox.jpg...]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG zm_detect.py:634 [Writing detected image to /var/cache/zoneminder/events/1/2020-02-27/36787/objdetect.jpg]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG zm_detect.py:638 [Writing JSON output to /var/cache/zoneminder/events/1/2020-02-27/36787/objects.json]
02/27/20 14:28:08 zmesdetect_m1[13890] INF zm_detect.py:649 [Removing matches to past detections]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:28 [trying to load /var/lib/zmeventnotification/images/monitor-1-data.pkl]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:98 [past detection car@[(102, 206), (300, 206), (300, 320), (102, 206)] approximately matches car@[(102, 204), (302, 204), (302, 320), (102, 204)] removing]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:98 [past detection car@[(399, 62), (457, 62), (457, 116), (399, 62)] approximately matches car@[(399, 61), (457, 61), (457, 117), (399, 61)] removing]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:98 [past detection truck@[(354, 142), (492, 142), (492, 260), (354, 142)] approximately matches truck@[(360, 142), (496, 142), (496, 262), (360, 142)] removing]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:98 [past detection car@[(313, 54), (357, 54), (357, 118), (313, 54)] approximately matches car@[(313, 54), (357, 54), (357, 118), (313, 54)] removing]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:98 [past detection car@[(558, 250), (640, 250), (640, 390), (558, 250)] approximately matches car@[(558, 250), (640, 250), (640, 388), (558, 250)] removing]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG image_manip.py:98 [past detection truck@[(154, 79), (308, 79), (308, 183), (154, 79)] approximately matches truck@[(154, 80), (310, 80), (310, 184), (154, 80)] removing]
02/27/20 14:28:08 zmesdetect_m1[13890] DBG zm_detect.py:655 [Saving detections for monitor 1 for future match]

all of the detections were removed because they "approximately matched"... which is Good.

The corresponding from zmeventnotification.log (grep 36787 zmeventnotification.log for brevity):

Code: Select all

27/02/20 14:28:06.271617 zmeventnotification[10335].INF [main:836] [PARENT: New event 36787 reported for Monitor:1 (Name:Carpark) Motion Close]
27/02/20 14:28:06.285030 zmeventnotification[13886].INF [main:836] [PARENT: Forked process:13886 to handle alarm eid:36787]
27/02/20 14:28:06.287011 zmeventnotification[13886].DBG [ZoneMinder::Object:115] [Loading ZoneMinder::Event from Events WHERE Id = 36787]
27/02/20 14:28:06.289860 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 Adding event path:/var/cache/zoneminder/events/1/2020-02-27/36787 to hook for image storage]
27/02/20 14:28:06.290041 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Invoking hook on event start:'/var/lib/zmeventnotification/bin/zm_event_start.sh' 36787 1 "Carpark" "Motion Close" "/var/cache/zoneminder/events/1/2020-02-27/36787"]
27/02/20 14:28:08.206241 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 parse of hook: and []]
27/02/20 14:28:08.206428 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 hook start returned with text: json:[] exit:1]
27/02/20 14:28:10.207991 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Matching alarm to connection rules...]
27/02/20 14:28:10.209394 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Checking alarm rules for MQTT 192.168.1.125]
27/02/20 14:28:10.210446 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Monitor 1 event: should send out as  4.76916003227234 is >= interval of ]
27/02/20 14:28:10.211009 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 shouldSendEventToConn returned true, so calling sendEvent]
27/02/20 14:28:10.211100 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 isAllowedChannel: got type:event_start resCode:1]
27/02/20 14:28:10.211155 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Not sending over MQTT as notify filters are on_success:all and on_fail:none]
27/02/20 14:28:10.211740 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 child finished writing to parent]
27/02/20 14:28:11.266663 zmeventnotification[10335].DBG [main:827] [PARENT: We've already worked on Monitor:1, Event:36787, not doing anything more]
27/02/20 14:28:16.270862 zmeventnotification[10335].DBG [main:827] [PARENT: We've already worked on Monitor:1, Event:36787, not doing anything more]
27/02/20 14:28:21.267194 zmeventnotification[10335].DBG [main:827] [PARENT: We've already worked on Monitor:1, Event:36787, not doing anything more]
27/02/20 14:28:26.267834 zmeventnotification[10335].DBG [main:827] [PARENT: We've already worked on Monitor:1, Event:36787, not doing anything more]
27/02/20 14:28:28.216316 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 For 1 (Carpark), SHM says: state=0, eid=36787]
27/02/20 14:28:28.216516 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Event 36787 for Monitor 1 has finished]
27/02/20 14:28:28.219166 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 Event end object is: state=>pending with cause=>Motion: Close]
27/02/20 14:28:30.219880 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 Adding event path:/var/cache/zoneminder/events/1/2020-02-27/36787 to hook for image storage]
27/02/20 14:28:30.220154 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Invoking hook on event end:'/var/lib/zmeventnotification/bin/zm_event_end.sh' 36787 1 "Carpark" "Motion: Close" "/var/cache/zoneminder/events/1/2020-02-27/36787"]
27/02/20 14:28:30.284537 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 parse of hook:Motion: Close
27/02/20 14:28:30.284714 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 hook end returned with text:Motion: Close
27/02/20 14:28:32.286416 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Not sending event end alarm, as we did not send a start alarm for this, or start hook processing failed]
27/02/20 14:28:36.288509 zmeventnotification[13886].DBG [main:827] [|----> FORK:Carpark (1), eid:36787 exiting]
27/02/20 14:28:36.288795 zmeventnotification[13886].INF [main:836] [|----> FORK:Carpark (1), eid:36787 Ending process:13886 to handle alarms]
27/02/20 14:28:41.261941 zmeventnotification[10335].DBG [main:827] [PARENT: RAW TEXT-->active_event_delete--TYPE--1--SPLIT--36787]
27/02/20 14:28:41.262017 zmeventnotification[10335].DBG [main:827] [PARENT: Job: Deleting active_event eid:36787, mid:1]

Line 27/02/20 14:28:30.220154 in the above zmeventnotification.log shows where it calls zm_event_end.sh with no "detected:" in the Notes string; again as expected because the detections were removed as "approximately matches".

I noticed the problem because I had events showing the the ZM console with no detection link; my zm_event_end.sh didn't delete them because there was a valid objdetect.jpg. I've seen 10 of these in the last 20 hours.

What I would like to do in zm_event_end.sh is something like:

Code: Select all

 if [ -f ${5}/objdetect.jpg ]
                        then
                                if grep -q approximate_match ${5}/objects.json
                                then
                                        delete_event "$@"
                                else
                                        ( echo -n "$(date) ${cmd}[$$] Not Deleting Event ${1} \"${2}-${3}\" \"${4}\" " ;
                                        echo "as it has object detected and was not an approximate match" ) >> $LOGPATH 2>&1
                                fi
                        else
                                delete_event "$@"
                        fi

Does this make sense?

<edit>PS - Thinking about the chain of processes here... If it's more convenient for zm_detect.py to write a file in the event's storage location (it's already writing other files there) indicating it was ignored because of a 100% approximate match that would be peachy too.

[russell_i_brown]

Never having written a line of Python code in my life but this seems to work. Lives just before the line "# end of matched file"

Code: Select all

	# record number of objects removed by almostmatches
	if g.config['write_image_to_zm'] == 'yes' and args['monitorid'] and pre_pastdetections > 0 and post_pastdetections == 0:
        	if (args['eventpath']):
            		g.logger.debug('Writing pastdetections removal count to {}/pastdetections.json'.format(
                		args['eventpath']))
            		jf = args['eventpath'] + '/pastdetections.json'
            		final_json = {'original_objectcount': pre_pastdetections}
          		g.logger.debug('Writing JSON output to {}'.format(jf))
            		with open(jf, 'w') as jo:
                		json.dump(final_json, jo)
                
                 print(pred + '--SPLIT--' + jos)

	# end of matched_file

There are couple of lines to set pre_pastdetections and post_pastdetections:

Code: Select all

	# point detections to post processed data set
        pre_pastdetections = len(label)
        g.logger.info('Removing matches to past detections')
        bbox_t, label_t, conf_t = img.processPastDetection(
            bbox, label, conf, args['monitorid'])
        post_pastdetections = len(label_t)
        g.logger.debug('Matches to past detections removed {}'.format(int(pre_pastdetections - post_pastdetections)))
        # save current objects for future comparisons

Asker - would this be OK? Would you like me to do a fork/pull for this or is the above enough?

<edit>Actually let me play with the above a bit more - my lack of Python might be showing through.

[asker]

I think all we need to do is not create objects.json if all detections are removed after matchPastDetections.
I committed some code to master to do that https://github.com/pliablepixels/zmeven ... b29b8d42cf

Please update master. I am also working on some other features (like 3rd party API pushes) that are part of master now too - hopefully that doesn't cause issues.

[russell_i_brown]

That's a much cleaner solution than my Python hackery. It seems to be working well.

I've created a pull request for the small changes to objectconfig.ini and zm_event_end.sh. Please excuse me if the whole fork/push/pullrequest thing isn't right - not something I've really used before.

[russell_i_brown]

I said I'd upload my final script and I have in a thread on the User Contribution section of the forum.

See here viewtopic.php?f=9&t=29137