MQTT publish failed

Without good metrics there is nothing that I can do here.

It might be the underlying paho Mqtt library. I have updated that recently, should be in snapshots.

It might be the rs223 engine. This will get better with java11. OH is java 11 compatible since a few weeks.

It might be the actions support code. I’ve seen that recently and it’s crap. But I do not have time to get that in order.

Cheers, David

1 Like

So i had created a rule which would restart Eclipse SmartHome MQTT Transport Bundle whenever my MQTT broker thing went offline. This was working for a long time. But now it seems that this bundle doesn’t exist anymore.

The problem has resurfaced and i can’t figure out which bundle I should restart?

Any ideas @David_Graeff?

I am running 2.5,5 i assume something has changed

Have you listed bundles to see? I think all eclipse stuff got moved to openhab.

I did this is the only bundle with mqtt in the name

openhab> bundle:list |grep mqtt
218 x Active x 80 x 1.1.2 x hivemq-mqtt-client

I changed my rule to restart this bundle and it doesn’t appear to have any effect.

Ok im dumb and forget linux grep was case sensitive. Did it again and now i see the paho client. will try and have that restart and see if it works.

openhab> bundle:list |grep MQTT
203 x Active x 80 x 1.2.2 x Paho MQTT Client
260 x Active x 80 x 2.5.5 x openHAB Add-ons :: Bundles :: MQTT Broker Binding
261 x Active x 81 x 2.5.5 x openHAB Add-ons :: Bundles :: MQTT Things and Channels
262 x Active x 82 x 2.5.5 x openHAB Add-ons :: Bundles :: MQTT HomeAssistant Convention
263 x Active x 82 x 2.5.5 x openHAB Add-ons :: Bundles :: MQTT Homie Convention
279 x Active x 80 x 2.5.0 x openHAB Core :: Bundles :: MQTT Transport

1 Like

try bundle:list -s (show symbols) and also grep -i (case insensitive)

1 Like

I see another facette of maybe the same problem? (OH 2.5.10, MQTT:2.5.10,mosquitto:1.6.12 )
Every 10 seconds I can not send messages using jsr223 and the action.publishMQTT(String topic, String value, Boolean retained) method.
(I´m sending within a “On Command” Rule)

in MQTT log (loglevel TRACE) I just see a “failed!” message. No Exception.

02-Dec-2020 16:39:24.330 [DEBUG] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$0 - MQTT publish to test/out/allItems/commands/myClock performed
02-Dec-2020 16:39:24.534 [DEBUG] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$0 - MQTT publish to test/out/allItems/commands/myClock performed
02-Dec-2020 16:39:24.749 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:25.157 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:25.258 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:25.460 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:25.768 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:25.974 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:26.176 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:26.395 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:26.621 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:26.723 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:27.130 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:27.348 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:27.552 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:27.754 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:27.858 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:28.064 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:28.266 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:28.468 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:28.669 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:28.880 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:28.981 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:29.199 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:29.401 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:29.602 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:29.812 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:30.041 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:30.141 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:30.342 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:30.545 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:30.746 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:30.948 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:31.155 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:31.436 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:31.536 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:31.741 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:31.943 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:32.167 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:32.380 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:32.581 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:32.783 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:32.884 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:33.086 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:33.296 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:33.498 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:33.700 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:33.902 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:34.103 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:34.315 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:34.512 [WARN ] [org.openhab.binding.mqtt.action.MQTTActions ]-364,RxComputationThreadPool-3-method:lambda$1 - MQTT publish to test/out/allItems/commands/myClock failed!
02-Dec-2020 16:39:34.714 [DEBUG] [org.openhab.binding.mqtt.action.MQTTActions ]-365,RxComputationThreadPool-4-method:lambda$0 - MQTT publish to test/out/allItems/commands/myClock performed
02-Dec-2020 16:39:34.916 [DEBUG] [org.openhab.binding.mqtt.action.MQTTActions ]-362,RxComputationThreadPool-1-method:lambda$0 - MQTT publish to test/out/allItems/commands/myClock performed
02-Dec-2020 16:39:35.121 [DEBUG] [org.openhab.binding.mqtt.action.MQTTActions ]-363,RxComputationThreadPool-2-method:lambda$0 - MQTT publish to test/out/allItems/commands/myClock performed

My bridge is configured like this:

Bridge mqtt:broker:mosquitto_out “Mosquitto” @ “Systems” [ host=“10.10.20.117”,port=1883, secure=false,clientID=“OpenHAB2_test_out”,qos=0] // ,retainMessages=false, retain=true, clientid=“OpenHAB2_test”]
{

}

Its irrelevant if I chose retained True or False
Its also irrelevant which QOS level I choose
Interesting though: after 10 seconds I can send messages again. Its always after 10 seconds.
I´m logging the threadID and Threadname. As you can see there seems to be a pool of 4 threads. that mechanic seems to work fine.
Then I can send for 10 seconds. After that it fails again for 10 seconds.

Also interesting:
during the 10 seconds in which I can´t send, I do get messages in (over another handler(another thing), but still the same MQTT-Binding)

maybe even more interesting:
I wanted to see how reliable the MQTT-Binging and mosquitto works and therefore I wrote a tester(jsr223) which sends a specified set of messages (100 topics 20 messages each). A Consumer checks if everything is coming in.
Interestingly this test works perfectly well all the time.
This test is triggered by loading the module in jsr223 (not within “on command”)

On the other side of the communication I use a python script using paho 1.5.1
I don´t see any issues there.

As a workaround I tried to decouple things a bit and created a senderthread (started when jsr223 module is loaded) which picks the next message from a List, sends it and then sleeps a little bit.
Nice ida, but didn´t work.

Without a reliable MQTT openHAB is dramatically degraded for me.

From what I can see in the forums, there are a couple of people having or had similar problems.
How can I help to identify the cause of the issue?

Hm, this is a response to my message. But I’m afraid I can’t help here.

My original mqtt.actions implementations is done on top of the openHAB actions support, and I have no insights on which thread pool those actions are performed. My guess is that mqtt publishing is blocking those threads for a while and debug statements are required to proof this theory.

This bug is very old and I’m surprised that it is still not fixed.

Anyway - Thanks David.