WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 33)

[jacoscar (Jacopo)]

A few errors and warnings when I restart, what can I do?

Currently running on VirtualBox with 6GB RAM
Something must be wrong with MQTT as between a flick of a switch in the dashboard and the actual toggle of the lights there are sometimes 2 to 5 seconds, but after the first time, it is instantaneous

2021-05-04 09:29:54 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform mqtt is taking over 10 seconds.
2021-05-04 09:29:54 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform mqtt is taking over 10 seconds.
2021-05-04 09:29:54 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform mqtt is taking over 10 seconds.
2021-05-04 09:32:06 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:32:06 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:32:06 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [140371228983056] Disconnected: Received non-Text message.
2021-05-04 09:32:06 WARNING (MainThread) [homeassistant.components.binary_sensor] Updating workday binary_sensor took longer than the scheduled update interval 0:00:30
2021-05-04 09:32:06 WARNING (MainThread) [homeassistant.components.binary_sensor] Updating ping binary_sensor took longer than the scheduled update interval 0:00:30
2021-05-04 09:32:06 WARNING (MainThread) [homeassistant.components.sensor] Updating tado sensor took longer than the scheduled update interval 0:00:30
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 11)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 12)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 13)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 14)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 15)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 16)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 17)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 18)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 19)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 20)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 21)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 22)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 23)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 24)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 25)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 26)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 27)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 28)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 29)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 30)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 31)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 32)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 33)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 34)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 35)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 36)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 37)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 38)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 39)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 40)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 41)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 42)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 43)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 44)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 45)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 46)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 47)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 48)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 49)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 50)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 51)
2021-05-04 09:32:15 WARNING (MainThread) [homeassistant.components.mqtt] No ACK from MQTT server in 10 seconds (mid: 52)
2021-05-04 09:32:16 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_protocol.py", line 422, in _handle_request
    resp = await self._request_handler(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_app.py", line 499, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_middlewares.py", line 119, in impl
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 56, in security_filter_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 18, in request_context_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 74, in ban_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 135, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 131, in handle
    result = await result
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/http.py", line 43, in get
    return await WebSocketHandler(request.app["hass"], request).async_handle()
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/http.py", line 142, in async_handle
    await wsock.prepare(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_ws.py", line 135, in prepare
    payload_writer = await super().prepare(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_response.py", line 378, in prepare
    return await self._start(request)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_response.py", line 386, in _start
    await self._write_headers()
  File "/usr/local/lib/python3.8/site-packages/aiohttp/web_response.py", line 458, in _write_headers
    await writer.write_headers(status_line, self._headers)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/http_writer.py", line 119, in write_headers
    self._write(buf)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/http_writer.py", line 67, in _write
    raise ConnectionResetError("Cannot write to closing transport")
ConnectionResetError: Cannot write to closing transport
2021-05-04 09:35:54 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:35:54 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:40:47 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:40:48 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:50:51 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 09:50:51 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 10:29:39 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 10:29:40 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 10:55:18 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 10:55:18 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 11:12:32 WARNING (MainThread) [homeassistant.components.automation.new_code] New Code: Already running
2021-05-04 11:32:46 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 11:32:46 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-05-04 11:47:10 WARNING (MainThread) [homeassistant.components.http.ban] Login attempt or request with invalid authentication from vodafone.broadband (192.168.0.1). (Mozilla/5.0 (iPhone; CPU iPhone OS 14_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Home Assistant/2021.4.1 (io.robbie.HomeAssistant; build:2021.115; iOS 14.5.0) Mobile/HomeAssistant, like Safari)
``

[maxym]

Can it be related to this?
If so, you can downgrade to v5.1 if you have a backup.

MQTT 5.11 issue

Was only joking. And I do get the nervousness you’re experiencing, I had that twice during the beta, when without any notification in the log the DB was migrated. Some users showed they had a warning in the log, but I couldn’t see that, so had no clue why it took almost 8 minutes. What worries me more is why no-one is bothered to check the MQTT issues with 5.11, even after some heavy talk in the Issue, that seems abandoned by the dev’s https://github.com/home-assistant/addons/issues/1887 and M…

Mosquitto 5.1.1 is broken.

[Anton-Ka]

Tell me, plz, where is a problem?
I see warnings in my log.

Logger: homeassistant.components.mqtt.mixins
Source: components/mqtt/mixins.py:240
Integration: MQTT (documentation, issues)
First occurred: 00:50:07 (198 occurrences)
Last logged: 09:00:18

JSON result was not a dictionary

I can’t find answers.

[francisp (Francis)]

Better open a new topic. And provide a little bit more information.

[Anton-Ka]

I can open new topic, but it’s a all information, what I have. I thinking what is too small.
I can’t understand where is a problem.

[francisp (Francis)]

Add this to configuration.yaml, and restart HA. It will show more meaningful error messages :

logger:
  logs:
    homeassistant.components.mqtt: debug

[Anton-Ka]

See only this warning message.

2021-10-31 12:30:22 DEBUG (Thread-5) [paho.mqtt.client] Received PUBLISH (d0, q0, r0, m0), 'lumi/light', ...  (15 bytes)
2021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on lumi/light: b'{"state":"OFF"}'
2021-10-31 12:30:22 DEBUG (Thread-5) [paho.mqtt.client] Received PUBLISH (d0, q0, r0, m0), 'lumi/button/action', ...  (1 bytes)
2021-10-31 12:30:22 DEBUG (Thread-5) [paho.mqtt.client] Received PUBLISH (d0, q0, r0, m0), 'lumi/button/action', ...  (1 bytes)
2021-10-31 12:30:22 DEBUG (Thread-5) [paho.mqtt.client] Received PUBLISH (d0, q0, r0, m0), 'homeassistant/light/lumi_light/config', ...  (272 bytes)
2021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on lumi/button/action: b'0'
2021-10-31 12:30:22 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on lumi/button/action: b'0'
2021-10-31 12:30:22 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on homeassistant/light/lumi_light/config: b'{"name":"Lumi Light","uniq_id":"lumi_light","schema":"json","rgb":true,"brightness":true,"stat_t":"lumi/light","cmd_t":"lumi/light/set","device":{"identifiers":["xiaomi_gateway"],"name":"Xiaomi_Gateway","sw_version":"1.0","model":"Xiaomi Gateway","manufacturer":"Xiaomi"}}'
2021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt.discovery] Process discovery payload {'name': 'Lumi Light', 'unique_id': 'lumi_light', 'schema': 'json', 'rgb': True, 'brightness': True, 'state_topic': 'lumi/light', 'command_topic': 'lumi/light/set', 'device': {'identifiers': ['xiaomi_gateway'], 'name': 'Xiaomi_Gateway', 'sw_version': '1.0', 'model': 'Xiaomi Gateway', 'manufacturer': 'Xiaomi'}, 'platform': 'mqtt'}
2021-10-31 12:30:22 INFO (MainThread) [homeassistant.components.mqtt.discovery]

What this may be?
I use Xiaomi Gateway with OWRT and lumi.

[francisp (Francis)]

@Anton-Ka

021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on lumi/button/action: b'0'
2021-10-31 12:30:22 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary
2021-10-31 12:30:22 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on lumi/button/action: b'0'
2021-10-31 12:30:22 WARNING (MainThread) [homeassistant.components.mqtt.mixins] JSON result was not a dictionary

b’0’ is not a JSON message, but I don’t knpw how to fix that, as I don’t have a Xiaomi Gateway with OWRT. Better file an issue on github, as it comes from the integration.

[Anton-Ka]

I understand you.
Thanks for your help.