Embedded MQTT Broker failing on 0.48.0

[halfluck]

Hey Guys,

There is quite a bit of chatter here about 0.48 Breaking the Embedded MQTT Broker ==> https://community.home-assistant.io/t/mqtt-not-working-0-47-1-0-48-0-upgrade/20824

Here is my log

2017-07-02 11:04:53 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "C:\Python36\lib\asyncio\tasks.py", line 179, in _step result = coro.send(None) File "C:\Users\Halfluck\AppData\Roaming.homeassistant\deps\hbmqtt\broker.py", line 336, in stream_connected yield from self.client_connected(listener_name, StreamReaderAdapter(reader), StreamWriterAdapter(writer)) File "C:\Users\Halfluck\AppData\Roaming.homeassistant\deps\hbmqtt\broker.py", line 469, in client_connected yield from self.publish_retained_messages_for_subscription(subscription, client_session) File "C:\Users\Halfluck\AppData\Roaming.homeassistant\deps\hbmqtt\broker.py", line 719, in publish_retained_messages_for_subscription handler.mqtt_publish( AttributeError: 'NoneType' object has no attribute 'mqtt_publish'

and another users

    2017-07-01 20:40:22 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 237, in _step
    result = next(coro)
  File "/home/homeassistant/.homeassistant/deps/hbmqtt/broker.py", line 336, in stream_connected
    yield from self.client_connected(listener_name, StreamReaderAdapter(reader), StreamWriterAdapter(writer))
  File "/home/homeassistant/.homeassistant/deps/hbmqtt/broker.py", line 469, in client_connected
    yield from self.publish_retained_messages_for_subscription(subscription, client_session)

File "/home/homeassistant/.homeassistant/deps/hbmqtt/broker.py", line 719, in publish_retained_messages_for_subscription
handler.mqtt_publish(
AttributeError: 'NoneType' object has no attribute 'mqtt_publish'

Thanks Rob.

[heinemml]

Happening here too:

2017-07-03 19:17:45 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 237, in _step
    result = next(coro)
  File "/opt/homeassistant/.homeassistant/deps/hbmqtt/broker.py", line 336, in stream_connected
    yield from self.client_connected(listener_name, StreamReaderAdapter(reader), StreamWriterAdapter(writer))
  File "/opt/homeassistant/.homeassistant/deps/hbmqtt/broker.py", line 469, in client_connected
    yield from self.publish_retained_messages_for_subscription(subscription, client_session)
  File "/opt/homeassistant/.homeassistant/deps/hbmqtt/broker.py", line 719, in publish_retained_messages_for_subscription
    handler.mqtt_publish(
AttributeError: 'NoneType' object has no attribute 'mqtt_publish'

Raspbian jessie on Pi 3 with Python 3.4.2

[epleypa]

Also having this issue, per the original post in the forums. Will add here that tls_insecure: false in configuration.yaml does remove the error from the error log, however mqtt does not appear to accept updates from devices. Hope that helps with troubleshooting.

[karlw00t]

I'm trying to reproduce this issue, but I could use some help on troubleshooting. I'm running a clean install of HA, off of the 0.48 branch. I've added the following to my configuration.yaml:

 80 mqtt:
 81 
 82 sensor:
 83   - platform: mqtt
 84     state_topic: "home/bedroom/temperature"

And I'm able to run HA $ hass --open-ui, and I don't see any errors in my logs. Could someone give some details on how to reproduce this issue?

[heinemml]

I'm using the MQTT Light and the MQTT Sensor Components.

When I comment out the MQTT Light configuration I don't see the error message posted above anymore. But I still don't get any readings from my sensors in HASS.

When I look on one of my MQTT Sensors I see that they can connect to the broker. So this seems to be started (I can see a python3 listener on port 1883 as well with netstat). The problem seems to be somewhere in the connection from HASS to the built in MQTT broker.

Do you get any readings from your test sensor?

[karlw00t]

My dummy sensor doesn't have any data in it, i'm pretty new to MQTT in general, so I'm just trying to bootstrap my setup. I was able to get a similar error when shutting down my dev server:

2017-07-03 14:19:42 ERROR (Dummy-3) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/Cellar/python3/3.6.1/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/tasks.py", line 179, in _step
    result = coro.send(None)
  File "/Users/kw/python3/hass/lib/python3.6/site-packages/hbmqtt/broker.py", line 666, in _broadcast_loop
    handler.mqtt_publish(broadcast['topic'], broadcast['data'], qos, retain=False),
AttributeError: 'NoneType' object has no attribute 'mqtt_publish'
Exception ignored in: <generator object ProtocolHandler.mqtt_deliver_next_message at 0x10699e780>
Traceback (most recent call last):

But I haven't been able to reproduce the error. The only change I've seen in the change log in 0.48 was upgrading the mqtt client (#8125). I don't know why this would raise an exception in the broker, but I was going to try to get something that was consistently reproducible, then try downgrading the mqtt client.

[matust7]

I am using mosquitto and mqtt has stopped working after I updated from 47.1 > 48. I am using AIO on a RP3. I can get it working again by commenting out tls_insecure: True in the config file.

When not working my log file shows

2017-07-04 07:52:36 ERROR (MainThread) [homeassistant.setup] Error during setup of component mqtt
Traceback (most recent call last):
  File "/srv/homeassistant/homeassistant_venv/lib/python3.4/site-packages/homeassistant/setup.py", line 187, in _async_setup_component
    result = yield from component.async_setup(hass, processed_config)
  File "/srv/homeassistant/homeassistant_venv/lib/python3.4/site-packages/homeassistant/components/mqtt/__init__.py", line 364, in async_setup
    will_message, birth_message, tls_version)
  File "/srv/homeassistant/homeassistant_venv/lib/python3.4/site-packages/homeassistant/components/mqtt/__init__.py", line 456, in __init__
    self._mqttc.tls_insecure_set(tls_insecure)
  File "/home/homeassistant/.homeassistant/deps/paho/mqtt/client.py", line 727, in tls_insecure_set
    raise ValueError('Must configure SSL context before using tls_insecure_set.')

[karlw00t]

That does appear to be an something that is called out in 1.2.3 to 1.3.0 in paho-mqtt changelog (BREAKING tls_insecure_set() must now be called after tls_set().). @matust7 can you put your config for your mqtt section into a gist and link it here?

[matust7]

@karlw00t I can be more help tonight, I'm about to walk out the door to work. This is my mqtt setup

  broker: 192.168.1.133
  port: 1883
  client_id: home-assistant-1
  keepalive: 60
  username: !secret mqtt_username
  password: !secret mqtt_password_own
  protocol: 3.1
  tls_insecure: True
  tls_version: auto 

[karlw00t]

i was able to reproduce something similar by creating a slider that tries to push it value to mqtt. When i try to shutdown hass, i get this error:

Traceback (most recent call last):
  File "/usr/local/Cellar/python3/3.6.1/Frameworks/Python.framework/Versions/3.6/lib/python3.6/asyncio/tasks.py", line 179, in _step
    result = coro.send(None)
  File "/Users/kw/python3/hass/lib/python3.6/site-packages/hbmqtt/broker.py", line 666, in _broadcast_loop
    handler.mqtt_publish(broadcast['topic'], broadcast['data'], qos, retain=False),
AttributeError: 'NoneType' object has no attribute 'mqtt_publish'

i downgraded the paho-mqtt client to version to 1.2.3, and I'm still getting the above error. Which makes sense, the above error is in the broker, not the client.

[karlw00t]

Just to put a fine tip on it, downgrading to 0.47, everything work as expected and I don't get an error on shutdown.

[karlw00t]

Here's my setup that I'm using to troubleshoot:

mqtt:
  tls_insecure: false

sensor:
  - platform: mqtt
    state_topic: "home/bedroom/temperature"

input_slider:
  target_temp:
    name: Target Heater Temperature Slider
    min: 1
    max: 30
    step: 1
    unit_of_measurement: step  
    icon: mdi:target

automation:
  - alias: Temp slider moved
    trigger:
      platform: state
      entity_id: input_slider.target_temp
    action:
      service: mqtt.publish
      data_template:
        topic: "home/bedroom/temperature"
        retain: true
        payload: '{{ states.input_slider.target_temp.state | int }}'

$ git checkout 0.48
$ hass
play with the slider, and nothing happens to the MQTT sensor in HA. Close hass using ctrl-c, and i get the error i have above.
$ git checkout 0.47
$ hass
play with the slider and the value is updated in HA. Closing hass (ctrl-c) and I exit cleanly (no stacktrace)

[karlw00t]

it's possible that the upgraded client is also causing issues. From the changelog:

Allow zero length client ids when using MQTT v3.1.1.

But in (https://github.com/beerfactory/hbmqtt/blob/master/hbmqtt/broker.py#L747), the client id does a truthy check, and a zero length client id evaluates to False, and returns None from the _get_handler function.

[karlw00t]

I added a client_id to my mqtt config and things seemed to be working. Can someone who's actually seeing this issue try adding a client_id to their config to see if that gets them pass the error.

I added this:

  client_id: 1234

[matust7]

I'm using mosquitto rather than the embedded mqtt so I am probably not the best person to test this. My setup already had client_id: home-assistant-1, changing to client_id: 1234 still produces the same error.

[karlw00t]

@matust7 I think you are having a separate issue, I cut this issue: #8329

[matust7]

No probs, thanks

[heinemml]

I can confirm that adding client_id: foo fixed the problem with the internal broker for me.

👍

[JNPrince]

Adding the client_id line fixed it for me as well

[halfluck]

Hey Guys,

client_id is also working for me, which is strange because according to the HA doc
client_id: "Default is a randomly generated one."

https://home-assistant.io/docs/mqtt/broker/#embedded-broker

Cheers Rob.

[karlw00t]

This is from the paho-mqtt client:

457 def init(self, client_id="", clean_session=True, userdata=None,
458 protocol=MQTTv311, transport="tcp"):
459 """client_id is the unique client id string used when connecting to the
460 broker. If client_id is zero length or None, then the behaviour is
461 defined by which protocol version is in use. If using MQTT v3.1.1, then
462 a zero length client id will be sent to the broker and the broker will
463 generate a random for the client. If using MQTT v3.1 then an id will be
464 randomly generated. In both cases, clean_session must be True. If this
465 is not the case a ValueError will be raised.

The client defaults to protocol=MQTTv311. Looking at the spec (http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html), it states:

A Server MAY allow a Client to supply a ClientId that has a length of zero bytes, however if it does so the Server MUST treat this as a special case and assign a unique ClientId to that Client. It MUST then process the CONNECT packet as if the Client had provided that unique ClientId

I'd like for someone a little more clueful to take a look at this before I open a issue with hbmqtt, but it looks like hbmqtt should either reject the zero length client id or generate a unique id for the client.

[karlw00t]

@halfluck it appears that was a behavior of paho-client 1.2.3. This is from that tag in their git repo:

472 def init(self, client_id="", clean_session=True, userdata=None, protocol=MQTTv311, transport="tcp"):
473 """client_id is the unique client id string used when connecting to the
474 broker. If client_id is zero length or None, then one will be randomly
475 generated.

[halfluck]

Hey Guys,

I'm still getting this error after upgrading to 0.48.1, If i manually add client_id to the config.yaml goes away and mqtt works.

Thanks Rob.

2017-07-06 19:00:59 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "C:\Python36\lib\asyncio\tasks.py", line 179, in _step
    result = coro.send(None)
  File "C:\Users\Halfluck\AppData\Roaming\.homeassistant\deps\hbmqtt\broker.py", line 336, in stream_connected
    yield from self.client_connected(listener_name, StreamReaderAdapter(reader), StreamWriterAdapter(writer))
  File "C:\Users\Halfluck\AppData\Roaming\.homeassistant\deps\hbmqtt\broker.py", line 469, in client_connected
    yield from self.publish_retained_messages_for_subscription(subscription, client_session)
  File "C:\Users\Halfluck\AppData\Roaming\.homeassistant\deps\hbmqtt\broker.py", line 719, in publish_retained_messages_for_subscription
    handler.mqtt_publish(
AttributeError: 'NoneType' object has no attribute 'mqtt_publish'

[heinemml]

I just had a quick glance at the code.

Isn't the elif case in Line 322 the one that applies when only mqtt: is in the config?

Currently the workaround is only in the case where a config but no client_id is given.

The first fix (0b60400) would have caught both cases.

[halfluck]

Yes, I completely understand. I'm not sure why for me in 2 different environments it fails if only mqtt: is in the config.

[heinemml]

@halfluck: sorry if that came out wrong. The failure seems not to be your configuration but the fix simply doesn't seem to fix the case when a completely empty mqtt: config is passed in (as you do).

[halfluck]

That's great, thanks for confirming.

[migromao]

Hi,
I'm runing 0.48.1 and MQTT was not working with error mentionned.
It's just adding the client_id: whatever and will do the trick and issues will just disapear and everything wouild be runing ok.
thank you Rob and comunity