home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.78k stars 30.88k forks source link

Exception in message_received when handling MQTT msg #98344

Closed Jarikk closed 1 year ago

Jarikk commented 1 year ago

The problem

I have my HA log full of identical errors. They appear after receiving an update message from Moes BHT-002-GCLZB Thermostate device connected to Zigbee2Mqtt.

What version of Home Assistant Core has the issue?

core-2023.8.2

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

MQTT

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2023-08-13 18:22:18.101 ERROR (MainThread) [homeassistant.util.logging] Exception in message_received when handling msg on 'zigbee2mqtt_livingroom/Balcony, thermostat': '{"child_lock":null,"current_heating_setpoint":23,"deadzone_temperature":null,"heat":"OFF","last_seen":"2023-08-13T18:22:15+03:00","linkquality":51,"local_temperature":25.5,"local_temperature_calibration":null,"max_temperature_limit":null,"min_temperature_limit":null,"preset":"hold","preset_mode":"hold","program":null,"running_state":"idle","sensor":null,"system_mode":"off"}'
Traceback (most recent call last):
File "/lsiopy/lib/python3.11/site-packages/homeassistant/components/mqtt/debug_info.py", line 44, in wrapper
msg_callback(msg)
File "/lsiopy/lib/python3.11/site-packages/homeassistant/components/mqtt/sensor.py", line 293, in message_received
_update_state(msg)
File "/lsiopy/lib/python3.11/site-packages/homeassistant/components/mqtt/sensor.py", line 244, in _update_state
payload = self._template(msg.payload, PayloadSentinel.DEFAULT)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/lsiopy/lib/python3.11/site-packages/homeassistant/components/mqtt/models.py", line 251, in async_render_with_possible_json_value
rendered_payload = self._value_template.async_render_with_possible_json_value(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/lsiopy/lib/python3.11/site-packages/homeassistant/helpers/template.py", line 735, in async_render_with_possible_json_value
return _render_with_context(self.template, compiled, **variables).strip()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/lsiopy/lib/python3.11/site-packages/homeassistant/helpers/template.py", line 2179, in _render_with_context
return template.render(**kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/lsiopy/lib/python3.11/site-packages/jinja2/environment.py", line 1301, in render
self.environment.handle_exception()
File "/lsiopy/lib/python3.11/site-packages/jinja2/environment.py", line 936, in handle_exception
raise rewrite_traceback_stack(source=source)
File "<template>", line 1, in top-level template code
File "/lsiopy/lib/python3.11/site-packages/jinja2/filters.py", line 870, in do_truncate
if len(s) <= length + leeway:
^^^^^^
TypeError: object of type 'NoneType' has no len()

Additional information

No response

home-assistant[bot] commented 1 year ago

Hey there @emontnemery, @jbouwh, mind taking a look at this issue as it has been labeled with an integration (mqtt) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `mqtt` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign mqtt` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)


mqtt documentation mqtt source (message by IssueLinks)

jbouwh commented 1 year ago

Seems there's an issue with the value template of the entity. It should be addressed an issue with Zigbee2MQTT.

jbouwh commented 1 year ago

To get more information you can turn on MQTT debug logging.

You can add this to your configuration.yaml:

# Example configuration.yaml entry
logger:
  default: info
  logs:
    homeassistant.components.mqtt: debug
Jarikk commented 1 year ago

Here is the debug message.

Shouldn't this template {{ value_json.program|default("") | truncate(254, True, '', 0) }} handle the case when "value_json.program" is NULL?

2023-08-13 19:53:40.820 DEBUG (MainThread) [homeassistant.components.mqtt.models] Rendering incoming payload '{"child_lock":null,"current_heating_setpoint":23,"deadzone_temperature":null,"heat":"OFF","last_seen":"2023-08-13T19:53:40+03:00","linkquality":51,"local_temperature":26,"local_temperature_calibration":null,"max_temperature_limit":null,"min_temperature_limit":null,"preset":"hold","preset_mode":"hold","program":null,"running_state":"idle","sensor":null,"system_mode":"off"}' with variables {'entity_id': 'sensor.0x60a423fffeb27fa1_program', 'name': 'program', 'this': <template TemplateStateFromEntityId(sensor.0x60a423fffeb27fa1_program)>} with default value 'default' and Template<template=({{ value_json.program|default("") | truncate(254, True, '', 0) }}) renders=0>

jbouwh commented 1 year ago

Shouldn't this template {{ value_json.program|default("") | truncate(254, True, '', 0) }} handle the case when "value_json.program" is NULL?

H'm that seem weird indeed.

jbouwh commented 1 year ago

This works in the template debugger.

{% set value_json={"child_lock":null,"current_heating_setpoint":23,"deadzone_temperature":null,"heat":"OFF","last_seen":"2023-08-13T19:53:40+03:00","linkquality":51,"local_temperature":26,"local_temperature_calibration":null,"max_temperature_limit":null,"min_temperature_limit":null,"preset":"hold","preset_mode":"hold","program":null,"running_state":"idle","sensor":null,"system_mode":"off"} %}
{{ value_json.program|default("") | truncate(254, True, '', 0) }}

When I try to reproduce I get (new logging code):

2023-08-13 18:58:10.774 ERROR (MainThread) [homeassistant.components.mqtt.models] TypeError: object of type 'NoneType' has no len() rendering template for entity 'sensor.bedroom_temperature_mqtt_sensor', template: '{{ value_json.program|default('') | truncate(254, True, '', 0) }}', default value: default and payload: {
  "child_lock": null,
  "current_heating_setpoint": 23,
  "deadzone_temperature": null,
  "heat": "OFF",
  "last_seen": "2023-08-13T19:53:40+03:00",
  "linkquality": 51,
  "local_temperature": 26,
  "local_temperature_calibration": null,
  "max_temperature_limit": null,
  "min_temperature_limit": null,
  "preset": "hold",
  "preset_mode": "hold",
  "program": null,
  "running_state": "idle",
  "sensor": null,
  "system_mode": "off"
}'
Jarikk commented 1 year ago

There is the following config inside the MQTT topic "homeassistant/sensor/0x60a423fffeb27fa1/program/config", in case it might be helpful:

{
  "availability": [
    {
      "topic": "zigbee2mqtt_livingroom/bridge/state",
      "value_template": "{{ value_json.state }}"
    },
    {
      "topic": "zigbee2mqtt_livingroom/Balcony, thermostat/availability",
      "value_template": "{{ value_json.state }}"
    }
  ],
  "availability_mode": "all",
  "device": {
    "identifiers": [
      "zigbee2mqtt_0x60a423fffeb27fa1"
    ],
    "manufacturer": "Moes",
    "model": "Moes BHT series Thermostat (BHT-002-GCLZB)",
    "name": "Balcony, thermostat"
  },
  "enabled_by_default": true,
  "name": "Balcony, thermostat program",
  "state_topic": "zigbee2mqtt_livingroom/Balcony, thermostat",
  "unique_id": "0x60a423fffeb27fa1_program_zigbee2mqtt_livingroom",
  "value_template": "{{ value_json.program|default(\"\") | truncate(254, True, '', 0) }}"
}
jbouwh commented 1 year ago

I understand, but it is the value template that is not working. The truncate function does not allow None. The default filter is not working as program is not undefined.

The template should be changed. This should work though:

{{ value_json.program or '' | truncate(254, True, '', 0) }}
jbouwh commented 1 year ago

As this not an issue with MQTT or Home Assistant please open one for Zigbee2MQTT

jbouwh commented 1 year ago

Linked PR will address the logging that could be improved. As this issue is addressed for Z2M I'll close it here, as this is not an issue with MQTT or Home Assistant/