Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Plugin fails to connect to Mosquitto #143

Open
tilegg opened this issue Nov 2, 2023 · 1 comment
Open

Plugin fails to connect to Mosquitto #143

tilegg opened this issue Nov 2, 2023 · 1 comment

Comments

@tilegg
Copy link

tilegg commented Nov 2, 2023 •
edited
Loading

What were you doing?

I'm trying to connect to my local mqtt-instance.

  1. Set MQTT-Host, leave everything else default (the server requires no authentication or anything else special)
  2. 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
Copy link
Author

tilegg commented Nov 2, 2023 •
edited
Loading

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

self._mqtt.subscribe(subbed_topics)

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

subbed_topics = [subbed_topic for subbed_topic, subbed_callback, _, _ in self._mqtt_subscriptions if callback == subbed_callback and (topic is None or topic == subbed_topic)]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@tilegg