Not connecting to MQTT in 1.2

[daveonkels]

I've been running 1.1 for several months without a hiccup. For some reason 1.2 isn't able to connect to my MQTT server. The logs were strangely devoid of useful information. Before I dig deeper, was there any change to the config file format that I'm missing? I've included sample configs below.

config.yaml

hass_discovery: true
hass_topic_root: homeassistant
mqtt_clean_session: false
mqtt_client_id: wyze2mqtt
mqtt_host: 10.10.0.199
mqtt_keepalive: 60
mqtt_password: mqtt
mqtt_port: 1883
mqtt_qos: 2
mqtt_retain: true
mqtt_username: mqtt
publish_sensor_name: true
self_topic_root: wyze2mqtt
usb_dongle: auto

sensors.yaml

'778AFDFC':
  class: window
  name: Den Window Right
  invert_state: false
'779B2633':
  class: motion
  name: Network Closet Motion
  invert_state: false

log excerpt

Logging initialized...

Initializing configuration...

Connecting to MQTT host 10.10.0.80

Connecting to dongle /dev/hidraw0

Dongle /dev/hidraw0: [ MAC: 7796137F, VER: 0.0.0.30 V1.4 Dongle UD3U, ENR: b'\xce\xc4ho|\xb2\xe6f\x935\x86\xdblF\x80M']

Reading sensors configuration...

Publishing discovery topics for 778AFDFC

MQTT publish error: The client is not currently connected.

  homeassistant/binary_sensor/wyzesense_778AFDFC/state/config

  {"name": "Den Window Right", "dev_cla": "window", "pl_on": "1", "pl_off": "0", "json_attr_t": "wyze2mqtt/778AFDFC", "val_tpl": "{{ value_json.state }}", "uniq_id": "wyzesense_778AFDFC_state", "stat_t": "wyze2mqtt/778AFDFC", "dev": {"identifiers": ["wyzesense_778AFDFC", "778AFDFC"], "manufacturer": "Wyze", "model": "Sense Contact Sensor", "name": "Den Window Right", "sw_version": ""}}

[AK5nowman]

The mqtt host you have configured doesn’t appear to be the one it’s trying to connect to.

Looks like a race condition, 1.2 calls connect_async so there is no guarantee that it will actually be connected to the mqtt server before the sensors are initialized and the publish topic function is called. If you trigger a sensor does it give the same error message or is the message actually published successfully?

[raetha]

Hi @daveonkels. There were quite a few changes in 1.2, particularly around handling non-existant configs, or updating existing ones with new features. Also tried to fix number of MQTT connection issues, but I noted that using Paho's easy config might not cut it, and might need to switch to a commented out version that I left in place in case issues persist.

I do know that to @AK5nowman's point, there is an expected race condition on startup where publishes are queued before the connection may be completed. Paho automatically handles queuing of messages when the connection is down, but as soon as it is completed the messages should go through. You will however see some publish errors early on, but then should see the messages send later in the log file.

Can you confirm if you are seeing something like that? If not, it would be helpful to change the logging level to DEBUG for the file handler in your logging.yaml file, start things up, wait a few minutes, then reset logging back to INFO, or whatever value you have been using. Seeing the more complete startup log may help us diagnose and see if we can work around your issue.

[TechIsCool]

This seems to occur because the MQTT client has not connected yet when it publishes the entities. I changed connect_async to connect and now everything's working. https://github.com/raetha/wyzesense2mqtt/blob/eb2daa2762ab1a0e55ecb66983fa09fb77a3290f/wyzesense2mqtt/wyzesense2mqtt.py#L126

[amd989]

Seeing same issue on my end. Applying @TechIsCool fix above fixed the issue, now I can see the entities in HA

Log before:

2021-06-25T11:26:16.704128528Z Logging initialized...
2021-06-25T11:26:16.704278994Z Initializing configuration...
2021-06-25T11:26:16.710390156Z Connecting to MQTT host 192.168.1.101
2021-06-25T11:26:16.715214358Z Connecting to dongle /dev/hidraw0
2021-06-25T11:26:17.283915005Z Dongle /dev/hidraw0: [ MAC: 777C6FDD, VER: 0.0.0.33 V1.4 Dongle UD3U, ENR: b'\x82\xc8.I&\x82:\xbb\x96\x8f\x94\xc7\xb8\xdb\\|']
2021-06-25T11:26:17.283979652Z Reading sensors configuration...
2021-06-25T11:26:25.389007603Z Publishing discovery topics for 777DEA13
2021-06-25T11:26:25.389283518Z MQTT publish error: The client is not currently connected.
2021-06-25T11:26:25.389368094Z   homeassistant/binary_sensor/wyzesense_777DEA13/state/config
2021-06-25T11:26:25.389452395Z   {"name": "Main Door", "dev_cla": "door", "pl_on": "1", "pl_off": "0", "json_attr_t": "wyzesense2mqtt/777DEA13", "val_tpl": "{{ value_json.state }}", "uniq_id": "wyzesense_777DEA13_state", "stat_t": "wyzesense2mqtt/777DEA13", "dev": {"identifiers": ["wyzesense_777DEA13", "777DEA13"], "manufacturer": "Wyze", "model": "Sense Contact Sensor", "name": "Main Door", "sw_version": ""}}
2021-06-25T11:26:25.389606064Z MQTT publish error: The client is not currently connected.

Log after:

2021-06-25T11:42:18.364277532Z Initializing configuration...
2021-06-25T11:42:18.458976404Z Connecting to MQTT host 192.168.1.101
2021-06-25T11:42:18.468931975Z Sending CONNECT (u0, p0, wr0, wq0, wf0, c0, k60) client_id=b'wyzesense2mqtt'
2021-06-25T11:42:18.473747326Z Connecting to dongle /dev/hidraw0
2021-06-25T11:42:19.043631784Z Dongle /dev/hidraw0: [ MAC: 777C6FDD, VER: 0.0.0.33 V1.4 Dongle UD3U, ENR: b'\x82\xc8.I&\x82:\xbb\x96\x8f\x94\xc7\xb8\xdb\\|']
2021-06-25T11:42:19.043682688Z Reading sensors configuration...
2021-06-25T11:42:27.148471312Z Publishing discovery topics for 777DEA13
2021-06-25T11:42:27.153011929Z Sending PUBLISH (d0, q0, r1, m1), 'b'homeassistant/binary_sensor/wyzesense_777DEA13/state/config'', ... (380 bytes)
2021-06-25T11:42:27.153787471Z   homeassistant/binary_sensor/wyzesense_777DEA13/state/config
2021-06-25T11:42:27.153882970Z   {"name": "Main Door", "dev_cla": "door", "pl_on": "1", "pl_off": "0", "json_attr_t": "wyzesense2mqtt/777DEA13", "val_tpl": "{{ value_json.state }}", "uniq_id": "wyzesense_777DEA13_state", "stat_t": "wyzesense2mqtt/777DEA13", "dev": {"identifiers": ["wyzesense_777DEA13", "777DEA13"], "manufacturer": "Wyze", "model": "Sense Contact Sensor", "name": "Main Door", "sw_version": ""}}
2021-06-25T11:42:27.154030910Z Sending PUBLISH (d0, q0, r1, m2), 

[drinfernoo]

I sometimes do have this issue, but as @raetha points out, it seems that paho does indeed end up sending the messages later.