MQTT strange logger warnings on OH shutdown

I get several warnings from the MQTT binding when shutting down openHAB as shown below. The messages relate to HomeAssistantDiscovery, Homie300Discovery, and EspMilightHubDiscoveryService – which I do not use in anyway at all. Any idea what is going on here? And how to eliminate these messages? (Running OH 3.1.0-SNAPSHOT #2324 on a Pi-4)

.. [WARN] [..AbstractBrokerHandler] - Tried to unsubscribe .. but topic not registered for listener. Check discovery logic!

and

.. [WARN] [..AbstractBrokerHandler] - Tried to unsubscribe .. but topic not registered at all. Check discovery logic!

Never looked into shutdown part of the logs. Checked my last shutdown log now and found the same messages.
I’m on 3.1.0 Snapshot #2227.

On the Broker Thing there is an option (in the UI check “Show Advanced” and it’s at the bottom) called “Enable Discovery”. Turn that toggle off and the warnings should go away. If not, file an issue on the binding as that is what that toggle is supposed to do, turn off auto discovery.

1 Like

Rich, I understand that is a work around. But IMHO it is not a fix. When OH is being shut down, it should not have discovery logic still running. And certainly not scaring users with logger warnings.

If you look at the warning, it’s complaining that it cannot unsubscribe from the discovery topics. So are you arguing that when OH is shutting down it shouldn’t unsubscribe from the topics but just end? That’s not very nice to the broker and will generate errors.

It’s not a work around. If you disable discovery you will not subscribe to those topics in the first place. Therefore there will be no reason to unsubscribe. But if you are using discovery, you need to unsubscribe from those topics in order to shutdown cleanly.

1 Like

Given that I did not subscribe, I don’t want a warning when it fails to unsubscribe. It should “just work”.

Then flip that little switch to off so that you don’t subscribe.

It’s a setting like all the rest. It is set to on be default. You want it off. So override the default.

In my case cade this option was on (probably as a default setting), you did switch it to off?

Look Rich, the log says “Tried to unsubscribe but topic not registered”. This is a bug.

Yeah sure, flipping the switch might make me not see it. But its still a bug.

Then file the issue.

I will probably fix it myself. Thanks.

Have you looked at the warnings at boot time, too? Are those failures to subscribe not as scary?

I don’t see such warnings. If there were such, then the unsubscribe ones would be less of a concern methinks.

So it’s a fair bet that it does successfully subscribe (why should it not, even if no message ever comes) and the unsubscribing is probably messing up (let’s guess maybe everything is unsubscribed en-bloc before the discovery services get round to it).

I will have a look into the code tomorrow. Thanks for the tip.

@rossko57 having looked into the code, I think your hypothesis is correct; it looks as though there are three override classes (EspMilight, Homie, HomeAssistant) that extend from the “generic” class, so my guess is that the override classes are doing stuff themselves that the “generic” class is wrongly trying to clean up for them; so I have filed a new issue; but I have not yet had time to fix the code.

2 Likes

I made a tentative PR (see below) HOWEVER because of all the dependencies, it require a rebuild of the OH Core; and I don’t have the skills to do that; so the solution is not tested; hopefully someone else can pick up where I left off…

[mqtt] Discovery services shall not unsubscribe unless they have already subscribed by andrewfg · Pull Request #10566 · openhab/openhab-addons · GitHub

Wouldn’t it be simpler for discovery service just to not do unsubscribe at shutdown, seeing as the broker Thing takes care of it anyway? Or are there other circumstances it needs to happen.

Thanks for the feedback.

The broker doesn’t do the clean up on its own. It is the discovery service that tells the broker to cleanup, and in this case it is wrongly telling the broker to clean up subscriptions that it had never actually made.

So in other words, I think it is the duty of the disco service to behave properly (eat your own dog food), rather than expect the other module to catch its mistakes.

Okay, I don’t understand (and don’t need to) but I thought the subscriptions were made successfully (albeit never used)