Blacklist

[vasrc]

My HS device Publish stopped working for one device (3474) and I found this in the debug log:

mcsmqtt debug.txt:5/21/2021 2:07:02 PM 2255711 | HSEvent VALUE_SET| 2048| | 0| 0| 3474
mcsmqtt debug.txt:5/21/2021 2:07:02 PM 2255711 | 3474 has been blacklisted from event callbacks

I see this in one of you update notes:

• PR640 3/19/2021 5.15.3.0 Optimized handling of HSEvent callback to blacklist unused references

How do I clear the blacklist?
I haven't restarted the PI yet..

Thanks

[Michael McSharry]

The blacklist is built when HS does an HSEvent callback and the Ref is not a device that has been associated with a mcsMQTT publish Topic. It is dynamically built after a plugin restart. The question is why device 3474 is not in the list of associated devices? Is it visible in the Association tab with A column checkbox checked?

Restarting the plugin will clear the blacklist, but unless the root cause of 3474 being added to the blacklist is understood then it will be added to it again.

[vasrc]

Yes, 3474 is listed in the Edit/Add section and does have the A checkbox checked. It's worked previously, just stopped (blacklisted) yesterday.

Here's another clue:

mcsmqtt debug.txt:5/22/2021 12:54:50 PM 84323871 | HSEvent VALUE_SET| 2048| ShelterOneWire/Driveway/Alarm| 99.13| 99.13| 2114

Driveway Alarm is RefID: 3136 not 2114. It is associated MQTT device as well, but just subscription not publish (it receives it's data from another MQTT device)

The 3474 device only shows up as a pink Pub device linked to a virtual HS4 device.

Thanks

[Michael McSharry]

"ShelterOneWire/Driveway/Alarm" is the address property of the device. It is not used for anything by the plugin. It is set when the device feature is created. This property of other device features can be observed from \deviceutility to see if a pattern can be identified between address property and MQTT sub topic.

One thing I noticed is that is is possible that a HSEvent callback can be generated before initialization is complete so this could result in the ref being blacklisted. Did the plugin start at 5/21/2021 2:07:02 PM or was this sometime later? To deal with the initialization I put protection in the attached.

[vasrc]

OK, couple things going on now.. This is related to the previous IFCHANGE:

After a restart.. The PUBLISHED value is missing on startup (of course) and it doesn't seem to like it..

5/22/2021 2:24:36 PM 373762 | ApplyExression IFCHANGE(99.61,,0.2) at Eval3.tokenizer.RaiseError(String msg, Exception ex)
at Eval3.tokenizer.RaiseUnexpectedToken(String msg)
at Eval3.parser.ParseExpr(opCode Acc, ePriority priority)
at Eval3.parser.ParseParameters(Boolean& brackets)
at Eval3.parser.ParseIdentifier(opCode& ValueLeft)
at Eval3.parser.ParseExpr(opCode Acc, ePriority priority)
at Eval3.parser.Parse(String str)
at Eval3.Evaluator.Parse(String str)
at MCSMQTTHS4_2020.MqttAppModule.ApplyExpression(String sTransformExpression) in C:\Users\Public\Documents\TFVC\HS\MQTT\MCSMQTTHS4_2020\MqttA ppModule.vb:line 3629
Line 0 No Expression found; Unexpected comma : at position 16 0 No Expression found; Unexpected comma : at position 16

I removed the IFCHANGE and replaced it with $$VALUE: then put the IFCHANGE back and get this:

5/22/2021 2:38:41 PM 523505 | ActOnMessageForTrigger QueueSize=0 ,Topic SHELTERMONITOR2/system/water/level,Payload IFCHANGE(100.52,IFCHANGE(100.53,IFCHANGE(100.57,IFCHANGE(100 .62,IFCHANGE(100.64,IFCHANGE(100.65,IFCHANGE(100.67,IFCHANGE (100.71,IFCHANGE(100.72,IFCHANGE(100.77,IFCHANGE(100.79,IFCH ANGE(100.82,IFCHANGE(100.86,IFCHANGE(100.89,IFCHANGE(100.94, IFCHANGE(100.97,IFCHANGE(101,IFCHANGE(101.05,IFCHANGE(101.07 ,IFCHANGE(101.11,IFCHANGE(101.16,IFCHANGE(101.2,IFCHANGE(101 .22,101.26,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>, 0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2) >>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>,0.2)>>

Restarted PI without IFCHANGE. There are no new debug messages now. Last is Shutdown IO. Stopped PI, deleted Debug.txt and restarted, all looks OK now..

Except for:

Issue #2 (Blacklisting):
With new code (can't confirm it did or didn't with previous vers), I get a lot of blacklists now. Just about every Event Change is blacklisted.

[vasrc]

Addendum...
OK, looks like blacklists are mostly HS devices that should NOT have event change set??

Here's an example:
Device ID: 31
ShelterMonitor/mcsMQTT/House/Temperatures/Temperature_Attic

That device has never been setup to Publish?
Do I have something set to autopublish HS devices??

Thanks

[vasrc]

Added IFCHANGE back and it's working again, now that there's a $$PUBLISHED: value available..

[vasrc]

Looking OK, except for the PI restart error.

Back to original question:
mcsmqtt debug.txt:5/22/2021 2:54:21 PM 401142 | HSEvent VALUE_SET| 2048| | 100| 100| 3474
mcsmqtt debug.txt:5/22/2021 2:54:21 PM 401142 | 3474 has been blacklisted from event callbacks

So what should I look for to see why it's blacklisting?
BTW, it's a String change. HS4 device "Status" shows correctly.



Thanks

[Michael McSharry]

The attached takes care of the $$PUBLISHED: initialization.

HSEvent callback is generated for every HS device feature value being set (or changed). It is not possible to tell HS to filter it to some subset of Ref's. The purpose of the blacklist logic is to provide the filter so minimum CPU is used when a HSEvent callback occurs and the Ref is not of interest.

There was a question about when the 3474 was blacklisted. Was it during plugin startup or was it sometime later. If at the start then the update will fix it. If later then something else is happening.

The String vs. Value change should have no bearing on the blacklisting. However, good observation.

[vasrc]

Stopped working on 5/21/21 after the IFCHANGE code was installed. Can't say if it was a restart or not. I was working on a different part of the code in the ESP32 and didn't pay attention to this specific publish value. It's mostly for display, not for control.

I just tested it again with the new code (did not restart PI) and curiously, when I make a String change using hs.setDeviceString(3474,"inactive",TRUE) I get this:

5/22/2021 3:46:39 PM 82103 | HSEvent VALUE_SET| 2048| | 100| 100| 3474
5/22/2021 3:46:39 PM 82103 | 3474 has been blacklisted from event callbacks

Which is the Value (100), not the string..

So what actually causes the blacklist message? Did the MQTT Publish rcd look correct?

Thanks,
Z

[Michael McSharry]

It appears HS4 is also sending a VALUE_SET event for the string change. See if the attached helps. If not then I will add more debug.

Your Edit tab screenshot looks good.

[vasrc]

Now we're "talking" again
Shows "STRING_CHANGE" as well..
5/22/20214:39:20 PM 58821 | HSEvent STRING_CHANGE| 64| | inactive| 3474

Thanks for the fixes.

Still confused why RefID 2114 (Well Depth) shows RefID 3136 name (Driveway Alarm).. That's a topic you're showing, not the Callback array?

mcsmqtt debug.txt:5/22/2021 4:43:40 PM 318198 | HSEvent VALUE_CHANGE| 1024| ShelterOneWire/Driveway/Alarm| 107.01| 107.14| 2114

I'll look into it more tomorrow..


Thanks again,
Z

[Michael McSharry]

ShelterOneWire/Driveway/Alarm is passed to the Event Callback as the Address property of device 2114. This property is set by the pluigin when a device feature is created. It is based upon the sub topic for which an association is being made. It exists only to assist with filtering of HS Device views. The fist step in researching it is to look at other device features to see if a pattern can be found for why the topic is not the one that is expected. If this one was created by the HS3 plugin then it just may be a transition issue. The HS3 plugin did not originally have Address being populated.

[vasrc]

I see the problem now, thanks, I was looking at 3136 not 2114's Address..
That whole device is totally mucked up.. Not sure what I did to it.. May have been part of the "magic" HS3 -> HS4 root/child conversions, who knows..

Thanks again..
“Once again the world is spinning in greased grooves"

Z