Shutdown Delay and MQTT Shutdown Warning

Add-ons Bindings
1

I have noticed that shutting down OpenHAB takes a while. The log looks fairly normal except for a 15 second delay before a series of warnings from the MQTT addon:

2020-05-14 11:07:34.689 [TRACE] [masternet.internal.ControllerHandler] - Read result 'OK'
2020-05-14 11:07:50.268 [WARN ] [g.mqtt.handler.AbstractBrokerHandler] - Tried to unsubscribe org.openhab.binding.mqtt.homie.internal.discovery.Homie300Discovery@583d092e from  discovery topic homeassistant/# on broker mqtt:broker:b6427774 but topic not registered for listener. Check discovery logic!
2020-05-14 11:07:50.293 [WARN ] [g.mqtt.handler.AbstractBrokerHandler] - Tried to unsubscribe org.openhab.binding.mqtt.homeassistant.internal.discovery.HomeAssistantDiscovery@a717225 from  discovery topic +/+/$homie on broker mqtt:broker:b6427774 but topic not registered at all. Check discovery logic!
2020-05-14 11:07:50.295 [WARN ] [g.mqtt.handler.AbstractBrokerHandler] - Tried to unsubscribe org.openhab.binding.mqtt.homeassistant.internal.discovery.HomeAssistantDiscovery@a717225 from  discovery topic homeassistant/# on broker mqtt:broker:b6427774 but topic not registered at all. Check discovery logic!
2020-05-14 11:07:50.295 [WARN ] [g.mqtt.handler.AbstractBrokerHandler] - Tried to unsubscribe org.openhab.binding.mqtt.homeassistant.internal.discovery.HomeAssistantDiscovery@a717225 from  discovery topic +/+/$homie on broker mqtt:broker:b6427774 but topic not registered at all. Check discovery logic!
2020-05-14 11:07:50.442 [INFO ] [io.openhabcloud.internal.CloudClient] - Shutting down openHAB Cloud service connection
2020-05-14 11:07:50.446 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = [UUID], base URL = http://localhost:8080)
2020-05-14 11:07:50.612 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2020-05-14 11:07:58.764 [DEBUG] [masternet.internal.ControllerHandler] - Cancelling existing poller
2020-05-14 11:07:58.764 [DEBUG] [masternet.internal.ControllerHandler] - Disconnecting from [HOSTNAME]:10102
2020-05-14 11:07:58.864 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2020-05-14 11:07:58.872 [INFO ] [.dashboard.internal.DashboardService] - Stopped Dashboard

This is with OpenHAB 2.5.3 on Arch Linux.

Are these MQTT shutdown messages correct?

2

If you see this during a shutdown I don’t think they are anything to worry about. I suspect that the Thing get’s unloaded before the binding is done unloading causing the topics to be unsubscribed from twice, once on the unload and once on the shutdown. I see these warnings from time to time and they do not appear to be related to a delay, at least when I’ve seen it.

3

Thanks Rich. I’ll use jstack to dig further…