MQTT Homie Thing handle leak resulting in multiple triggers

Tags: #<Tag:0x00007f61706accb8> #<Tag:0x00007f61706acbf0>

This one is for @David_Graeff :slight_smile:

I’ve seen it a couple of times before but now I know how to reproduce it.

There is some kind of handle leak when a Homie thing goes away unexpectedly.
It results in triggers being duplicated. I had 20 at a time after a development session when I was repeatedly uploading new code to the Homie device (ESP8266).

Please look at the events and mosquitto log files here

You can see that there’s several triggers for every event, and it seems to grow by one every time I
restart the esp8266.

2019-07-04 00:30:05.848 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.851 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.854 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.856 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.859 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.862 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.865 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.869 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.872 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED
2019-07-04 00:30:05.875 [vent.ChannelTriggeredEvent] - mqtt:homie300:examplehomiedev:nodeid1#doorbell triggered PRESSED

At 2019-07-04 00:31:01.906 you can see that I remove the Homie Thing and create it again.
At that point there’s only ONE trigger per event, as expected.

Then I restart the ESP8266 a few more times and it grows again.

It only seems to affect triggers.

A different problem, perhaps related, is the huge amount of items like this in the openhab log:

2019-07-04 00:30:33.570 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler HomieThingHandler of thing mqtt:homie300:examplehomiedev tried triggering channel nodeid1#doorsensor although the handler was already disposed.
2019-07-04 00:30:45.716 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler HomieThingHandler of thing mqtt:homie300:examplehomiedev tried triggering channel nodeid1#doorsensor although the handler was already disposed.
2019-07-04 00:30:52.572 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler HomieThingHandler of thing mqtt:homie300:examplehomiedev tried triggering channel nodeid1#doorbell although the handler was already disposed.
2019-07-04 00:30:57.574 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler HomieThingHandler of thing mqtt:homie300:examplehomiedev tried triggering channel nodeid1#doorbell although the handler was already disposed.

That’s clearly a bug. Could you please open a bug report on github with all your findings? Thanks.

1 Like

Done. I don’t have lots of time to spend on it but I’ve posted with the same level of detail as I posted here. Let me know if you need my help to reproduce it. It looks like it should be obvious though. :slight_smile:

Another thing (unrelated) – when you add a new Homie Thing, wouldn’t it make sense for the default name of the thing to be based on the $name payload of the Homie device, instead of the base topic name?

For example, my topic name is homie/workstationmcu but the homie/workstationmcu/$name topic payload is Workstation MCU.

Right now it looks like $name isn’t being used at all, as the Thing gets named workstationmcu instead of Workstation MCU.