Plugin fails to connect to Mosquitto
tilegg opened this issue · 1 comments
tilegg commented
What were you doing?
I'm trying to connect to my local mqtt-instance.
- Set MQTT-Host, leave everything else default (the server requires no authentication or anything else special)
- Click save
What did you expect to happen?
The plugin should connect to the MQTT-Broker.
What happened instead?
The plugin attempts to connect to the MQTT server but seemingly fails to do so at some point. The only thing that happens, is the 'octoPrint/mqtt' topic is set to 'octoPrint/mqtt' (the default will-topic). So the connection itself seem to work to some extent.
Version of OctoPrint
Octoprint Version: 1.9.3
Version of the MQTT plugin
OctoPrint-MQTT Version: 0.8.13
Used MQTT broker and its version
MQTT-Broker: mosquitto version 1.5.7
Link to octoprint.log
octoprint.log
2023-11-02 12:28:07,280 - octoprint.plugins.mqtt - INFO - Connected to mqtt broker
Syslog has an exception-message:
Nov 2 12:28:07 octopi octoprint[8287]: 2023-11-02 12:28:07,280 - octoprint.plugins.mqtt - INFO - Connected to mqtt broker#033[0m
Nov 2 12:28:07 octopi octoprint[8287]: Exception in thread Thread-65:
Nov 2 12:28:07 octopi octoprint[8287]: Traceback (most recent call last):
Nov 2 12:28:07 octopi octoprint[8287]: File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
Nov 2 12:28:07 octopi octoprint[8287]: self.run()
Nov 2 12:28:07 octopi octoprint[8287]: File "/usr/lib/python3.9/threading.py", line 892, in run
Nov 2 12:28:07 octopi octoprint[8287]: self._target(*self._args, **self._kwargs)
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 3591, in _thread_main
Nov 2 12:28:07 octopi octoprint[8287]: self.loop_forever(retry_first_connection=True)
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
Nov 2 12:28:07 octopi octoprint[8287]: rc = self._loop(timeout)
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1164, in _loop
Nov 2 12:28:07 octopi octoprint[8287]: rc = self.loop_read()
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1556, in loop_read
Nov 2 12:28:07 octopi octoprint[8287]: rc = self._packet_read()
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
Nov 2 12:28:07 octopi octoprint[8287]: rc = self._packet_handle()
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 3039, in _packet_handle
Nov 2 12:28:07 octopi octoprint[8287]: return self._handle_connack()
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 3138, in _handle_connack
Nov 2 12:28:07 octopi octoprint[8287]: on_connect(
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/octoprint_mqtt/__init__.py", line 443, in _on_mqtt_connect
Nov 2 12:28:07 octopi octoprint[8287]: self._mqtt.subscribe(subbed_topics)
Nov 2 12:28:07 octopi octoprint[8287]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1484, in subscribe
Nov 2 12:28:07 octopi octoprint[8287]: raise ValueError('Invalid topic.')
Nov 2 12:28:07 octopi octoprint[8287]: ValueError: Invalid topic.
Excerpt from the broker log (debug-mode):
1698924487: New connection from 192.168.1.xxx on port 1883.
1698924487: New client connected from 192.168.1.xxx as 53c746fa-1e41-43ce-a8dc-f1ad93176fe1 (c1, k59).
1698924487: Will message specified (12 bytes) (r1, q1).
1698924487: octoPrint/mqtt
1698924487: Sending CONNACK to 53c746fa-1e41-43ce-a8dc-f1ad93176fe1 (0, 0)
[...]
1698924575: Client 53c746fa-1e41-43ce-a8dc-f1ad93176fe1 has exceeded timeout, disconnecting.
1698924575: Socket error on client 53c746fa-1e41-43ce-a8dc-f1ad93176fe1, disconnecting.
1698924576: Sending PUBLISH to mqtt-explorer-aedfedb5 (d0, q0, r0, m0, 'octoPrint/mqtt', ... (12 bytes))
tilegg commented
The Issue seems to affect only re-connects (e.g. after config-changes). When octoprint is restarted the plugin connects just fine.
Issue seems to be here:
OctoPrint-MQTT/octoprint_mqtt/__init__.py
Line 443 in ee6b4d0
subbed_topics seems to hold an invalid value. I did some debugging:
subbed_topics = list(map(lambda t: (t, 0), {topic for topic, _, _, _ in self._mqtt_subscriptions}))
self._logger.info("listing topics to sub:")
for topic in subbed_topics:
self._logger.info(f"subbing topic: {topic}")
if subbed_topics:
self._mqtt.subscribe(subbed_topics)
self._logger.debug("Subscribed to topics")which yields:
Nov 2 12:54:57 octopi octoprint[9103]: 2023-11-02 12:54:57,190 - octoprint.plugins.mqtt - INFO - Connected to mqtt broker#033[0m
Nov 2 12:54:57 octopi octoprint[9103]: Exception in thread Thread-49:
Nov 2 12:54:57 octopi octoprint[9103]: 2023-11-02 12:54:57,202 - octoprint.plugins.mqtt - INFO - listing topics to sub:#033[0m
Nov 2 12:54:57 octopi octoprint[9103]: 2023-11-02 12:54:57,202 - octoprint.plugins.mqtt - INFO - subbing topic: ('', 0)#033[0m
Nov 2 12:54:57 octopi octoprint[9103]: Traceback (most recent call last):
Nov 2 12:54:57 octopi octoprint[9103]: File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
Nov 2 12:54:57 octopi octoprint[9103]: self.run()
Nov 2 12:54:57 octopi octoprint[9103]: File "/usr/lib/python3.9/threading.py", line 892, in run
Nov 2 12:54:57 octopi octoprint[9103]: self._target(*self._args, **self._kwargs)
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 3591, in _thread_main
Nov 2 12:54:57 octopi octoprint[9103]: self.loop_forever(retry_first_connection=True)
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
Nov 2 12:54:57 octopi octoprint[9103]: rc = self._loop(timeout)
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1164, in _loop
Nov 2 12:54:57 octopi octoprint[9103]: rc = self.loop_read()
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1556, in loop_read
Nov 2 12:54:57 octopi octoprint[9103]: rc = self._packet_read()
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
Nov 2 12:54:57 octopi octoprint[9103]: rc = self._packet_handle()
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 3039, in _packet_handle
Nov 2 12:54:57 octopi octoprint[9103]: return self._handle_connack()
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 3138, in _handle_connack
Nov 2 12:54:57 octopi octoprint[9103]: on_connect(
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/octoprint_mqtt/__init__.py", line 447, in _on_mqtt_connect
Nov 2 12:54:57 octopi octoprint[9103]: self._mqtt.subscribe(subbed_topics)
Nov 2 12:54:57 octopi octoprint[9103]: File "/home/tilegg/oprint/lib/python3.9/site-packages/paho/mqtt/client.py", line 1484, in subscribe
Nov 2 12:54:57 octopi octoprint[9103]: raise ValueError('Invalid topic.')
Nov 2 12:54:57 octopi octoprint[9103]: ValueError: Invalid topic.
Looks like the plugin is trying to subscribe to emptystring as a topic (which would -for all I know- indeed not be valid). Not sure how it makes its way into subbed_topics, as it is only refered to here from what I can tell:
OctoPrint-MQTT/octoprint_mqtt/__init__.py
Line 390 in ee6b4d0