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

mqtt_json device tracker broken - seems to try to start before MQTT integration has started and fails #91093

Closed
KennethLavrsen opened this issue Apr 8, 2023 · 9 comments · Fixed by #91164
Closed

mqtt_json device tracker broken - seems to try to start before MQTT integration has started and fails #91093

KennethLavrsen opened this issue Apr 8, 2023 · 9 comments · Fixed by #91164
Assignees
@jbouwh
Labels
integration: mqtt_json

Comments

@KennethLavrsen
Copy link

The problem

I use the mqtt based device tracker. It has worked stable and fine until 2023.4 when it fails to load

The error message says that MQTT is not enabled. Well. I have 100s of items based on MQTT in home assistant and they all work just fine

The error happens at restart of HA and the integration does not even attempt to try again. It just fails

What version of Home Assistant Core has the issue?

core-2023.04.01

What was the last working version of Home Assistant Core?

core-2023.03

What type of installation are you running?

Home Assistant OS

Integration causing the issue

mqtt_json

Link to integration documentation on our website

https://www.home-assistant.io/integrations/mqtt_json/

Diagnostics information

This is the error log

2023-04-08 20:24:49.158 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform legacy mqtt_json
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py", line 288, in async_setup_legacy
setup = await self.platform.async_setup_scanner(
File "/usr/src/homeassistant/homeassistant/components/mqtt_json/device_tracker.py", line 76, in async_setup_scanner
await mqtt.async_subscribe(hass, topic, async_message_received, qos)
File "/usr/src/homeassistant/homeassistant/components/mqtt/client.py", line 166, in async_subscribe
raise HomeAssistantError(
homeassistant.exceptions.HomeAssistantError: Cannot subscribe to topic 'location/testtracker', MQTT is not enabled

Example YAML snippet

This is the config in yaml

device_tracker:
  - platform: mqtt_json
    devices:
      testtracker: 'location/testtracker'

Anything in the logs that might be useful for us?

No response

Additional information

No response
@home-assistant
Copy link

home-assistant bot commented Apr 8, 2023

mqtt_json documentation
mqtt_json source

@tbclark3
Copy link

tbclark3 commented Apr 9, 2023

I am seeing the same thing, and it is inconsistent. It sometimes takes 2 or 3 restarts, but it eventually works without errors.

@KennethLavrsen
Copy link
Author

I have not seen it succeed even once. It probably depends on how large an MQTT setup you have. It seems the code should be waiting for mqtt instead of failing. Maybe it waits but then it gives up too quickly

@KennethLavrsen
Copy link
Author

I asked in the Discored developer general channel for help assigning a developer as it seems the manifast has none defined

I can add one more data point. This failing integration reports a start up time of 0:00 so it fails immediately. I think it tried to query the MQTT server before the rest of the system is up and fails. There is some runtime dependency that seems lost

@KennethLavrsen
Copy link
Author

@jbouwh
@emontnemery

I just raised a bug for an other MQTT related bug and you got auto assigned. Isn't this one supposed to be assigned to you? If not then I am sorry

@jbouwh
Copy link
Contributor

jbouwh commented Apr 10, 2023

I'll have a look a this one.

@jbouwh jbouwh self-assigned this Apr 10, 2023
@KennethLavrsen
Copy link
Author

I ran the boot with all of HA in debug logging

I cannot see anything obvious but again context may help.

2023-04-10 12:48:38.831 DEBUG (MainThread) [synology_dsm.synology_dsm] Request Method: GET
2023-04-10 12:48:38.833 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'sensor': <sensor: 2 / 0>, 'frigate': <frigate: 0 / 1>, 'tasmota': <tasmota: 0 / 1>, 'rtsp_to_webrtc': <rtsp_to_webrtc: 0 / 1>, 'switch': <switch: 0 / 1>, 'mobile_app': <mobile_app: 0 / 1>, 'default_config': <default_config: 0 / 1>, 'energidataservice': <energidataservice: 0 / 1>, 'radio_browser': <radio_browser: 0 / 1>, 'stream': <stream: 0 / 1>, 'squeezebox': <squeezebox: 0 / 1>, 'notify': <notify: 1 / 0>, 'ios': <ios: 0 / 1>, 'template': <template: 0 / 3>, 'watchman': <watchman: 0 / 1>, 'broadlink': <broadlink: 0 / 1>, 'discovery': <discovery: 0 / 1>, 'hacs': <hacs: 0 / 1>, 'camera': <camera: 0 / 1>, 'generic': <generic: 0 / 1>, 'heos': <heos: 0 / 1>, 'utility_meter': <utility_meter: 0 / 1>, 'deconz': <deconz: 0 / 1>, 'zwave_js': <zwave_js: 0 / 1>, 'esphome': <esphome: 0 / 1>, 'cast': <cast: 0 / 1>, 'kodi': <kodi: 0 / 1>, 'miele': <miele: 0 / 1>, 'google': <google: 0 / 1>, 'onvif': <onvif: 0 / 1>, 'device_tracker': <device_tracker: 1 / 0>, 'binary_sensor': <binary_sensor: 2 / 0>}
2023-04-10 12:48:38.834 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'sensor.nordpool': 9.76872, 'group': 9.734051, 'switch_as_x': 9.725189, 'sun': 9.530145, 'notify': 9.499429, 'samsungtv': 3.560575, 'synology_dsm': 3.288519, 'brother': 2.849421, 'dlna_dms': 2.469132, 'denonavr': 1.569922, 'ipp': 1.340537, 'unifi': 1.162033, 'alexa_media': 0.794265, 'mqtt': 0.703801, 'meater': 0.677947, 'device_tracker': 0.618813, 'binary_sensor.group': 0.569354, 'octoprint': 0.058862, 'sensor.sun': 0.035544}
2023-04-10 12:48:38.837 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=binary_sensor.doors_windows, old_state=None, new_state=<state binary_sensor.doors_windows=unavailable; friendly_name=Doors & Windows @ 2023-04-10T12:48:38.837509+02:00>>
2023-04-10 12:48:38.838 INFO (MainThread) [homeassistant.components.device_tracker] Setting up device_tracker.mqtt_json
2023-04-10 12:48:38.839 DEBUG (SyncWorker_1) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/logbook/translations/en.json
2023-04-10 12:48:38.839 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/logbook/translations/en-GB.json
2023-04-10 12:48:38.840 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/input_datetime/translations/en-GB.json
2023-04-10 12:48:38.840 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/system_health/translations/en-GB.json
2023-04-10 12:48:38.841 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/input_text/translations/en-GB.json
2023-04-10 12:48:38.841 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/schedule/translations/en-GB.json
2023-04-10 12:48:38.841 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/input_button/translations/en-GB.json
2023-04-10 12:48:38.842 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/input_select/translations/en-GB.json
2023-04-10 12:48:38.843 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/uptime/translations/sensor.en-GB.json
2023-04-10 12:48:38.843 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/synology_dsm/translations/en-GB.json
2023-04-10 12:48:38.843 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/media_source/translations/en-GB.json
2023-04-10 12:48:38.843 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/brother/translations/en-GB.json
2023-04-10 12:48:38.844 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/light/translations/en-GB.json
2023-04-10 12:48:38.844 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/scene/translations/en-GB.json
2023-04-10 12:48:38.845 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/conversation/translations/en-GB.json
2023-04-10 12:48:38.845 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/dlna_dms/translations/en-GB.json
2023-04-10 12:48:38.846 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/timer/translations/en-GB.json
2023-04-10 12:48:38.847 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/input_number/translations/en-GB.json
2023-04-10 12:48:38.847 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/counter/translations/en-GB.json
2023-04-10 12:48:38.847 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/ffmpeg/translations/en-GB.json
2023-04-10 12:48:38.838 ERROR (MainThread) [homeassistant.components.device_tracker] Error setting up platform legacy mqtt_json
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/device_tracker/legacy.py", line 288, in async_setup_legacy
    setup = await self.platform.async_setup_scanner(
  File "/usr/src/homeassistant/homeassistant/components/mqtt_json/device_tracker.py", line 76, in async_setup_scanner
    await mqtt.async_subscribe(hass, topic, async_message_received, qos)
  File "/usr/src/homeassistant/homeassistant/components/mqtt/client.py", line 166, in async_subscribe
    raise HomeAssistantError(
homeassistant.exceptions.HomeAssistantError: Cannot subscribe to topic 'location/testtracker', MQTT is not enabled
2023-04-10 12:48:38.848 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/denonavr/translations/en-GB.json
2023-04-10 12:48:38.849 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/input_boolean/translations/en-GB.json
2023-04-10 12:48:38.849 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/wake_on_lan/translations/en-GB.json
2023-04-10 12:48:38.849 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/application_credentials/translations/en-GB.json
2023-04-10 12:48:38.850 DEBUG (SyncWorker_6) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/zone/translations/en-GB.json
2023-04-10 12:48:38.852 DEBUG (SyncWorker_1) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/uptime/translations/sensor.en.json
2023-04-10 12:48:38.855 DEBUG (SyncWorker_1) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/media_source/translations/en.json
2023-04-10 12:48:38.865 DEBUG (SyncWorker_1) [homeassistant.util.json] JSON file not found: /usr/src/homeassistant/homeassistant/components/ffmpeg/translations/en.json
2023-04-10 12:48:38.882 INFO (MainThread) [homeassistant.setup] Setting up energidataservice

@jbouwh jbouwh mentioned this issue Apr 10, 2023
Merged
20 tasks
@jbouwh
Copy link
Contributor

jbouwh commented Apr 18, 2023

@KennethLavrsen Could you check if #91454 resolves your issue? Please share some logs. Waiting for MQTT should not be needed if dependencies are processed correctly.

@jbouwh jbouwh mentioned this issue Apr 18, 2023
Merged
20 tasks
@KennethLavrsen
Copy link
Author

I am travelling on business so it will be in the weekend I can look at trying this.

@github-actions github-actions bot locked and limited conversation to collaborators May 20, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@jbouwh jbouwh

Labels
integration: mqtt_json
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Make sure MQTT client is available when starting depending platforms jbouwh/core
3 participants
@tbclark3 @jbouwh @KennethLavrsen