openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.56k forks source link

[MQTT] publishing messages to topics from JSR223 works for 10 seconds, then fails for 10 seconds, then works again for 10 seconds,.... #9325

Open galexey opened 3 years ago

galexey commented 3 years ago

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.

Expected Behavior

action.publishMQTT(..) should publish the message to the topic

Current Behavior

the message is not published. action.publishMQTT does not raise an Exception in MQTT log (loglevel TRACE) I just see a “failed!” message. Also no Exception. (see mqtt-log attached)

mqtt-log.log

Possible Solution

Steps to Reproduce (for Bugs)

My bridge is configured in a .things file like this:

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

    }

I create an action in JSR223:

MQTT_BRIDGE_out="mqtt:broker:mosquitto_out"
actionOut=actions.get("mqtt", MQTT_BRIDGE_out)

in JSR223 I register a listener for commands on items.

class CommandListener(core.jsr223.scope.SimpleRule):

            def __init__(self, item, topicname, callback):
                self.callback=callback
                self.item=item
                self.itemname = item.name
                self.topicname=topicname
                self.triggers = [ItemCommandTrigger(self.itemname).trigger]

            def execute(self, module, inputs): 
                try:
                    log.info("-----------------------------------------------command triggered for '{}':'{}".format(self.itemname,inputs["command"]))

                    self.callback(self,module,inputs) 
                except Exception as e:
                    utils.logExceptionAndTrace(log,"failed to call UpdateListener callback",e)

for example the "testNumber" Item installes the Listener-rule with:

aItem=oh.itemRegistry.getItem("testNumber")
cl=CommandListener(aItem,topic,commandCallback)
core.jsr223.get_automation_manager().addRule(cl)

within that CommandListener I send with

actionOut.publishMQTT()

(Its irrelevant if I chose retained True or False Its also irrelevant which QOS level I choose in the bridge configuration in the .things file)

create a sitemap and add a slider or button to change the testNumber item

now keep klicking the button to send commands to the item. watch the mqtt-log and/or install MQTT-Explorer to see incoming and missing messages.

I´m logging thread ID and threadname. As you can see in my attached logile there seems to be a pool of 4 threads in round robin, a lambda-function seems to actually send the message. This mechanic seems to work fine:

RxComputationThreadPool-1-method:lambda$1
RxComputationThreadPool-2-method:lambda$1
RxComputationThreadPool-3-method:lambda$1
RxComputationThreadPool-4-method:lambda$1

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)

Context

I want to send MQTT-messages for every command an item receives

maybe 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 for every topic). 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 the CommandListener )

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

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

Your Environment

OH 2.5.10, MQTT:2.5.10, running on a Ubuntu 18.04.5 LTS (GNU/Linux 4.15.0-123-generic x86_64) within a Virtual box mosquitto:1.6.12 not running on same machine as openhab.

lsiepel commented 6 months ago

@galexey unfortunately this issue wasn't picked up earlier. As many changed to mqtt binding, openHAB runtime have been committed, it would be usefull if you can confirm this issue is still occuring on openHAB 4.1.x

stale[bot] commented 4 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.