Improve error logging on invalid MQTT entity state (#118006)

* Improve error logging on invalid MQTT entity state

* Explain not hanlding TpeError and ValueError

* Move length check closer to source

* use _LOGGER.exception
This commit is contained in:
Jan Bouwhuis 2024-05-24 13:11:52 +02:00 committed by GitHub
parent 7d44321f0f
commit f12aee28a8
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
7 changed files with 106 additions and 12 deletions

View File

@ -373,14 +373,14 @@ class EntityTopicState:
def process_write_state_requests(self, msg: MQTTMessage) -> None:
"""Process the write state requests."""
while self.subscribe_calls:
_, entity = self.subscribe_calls.popitem()
entity_id, entity = self.subscribe_calls.popitem()
try:
entity.async_write_ha_state()
except Exception:
_LOGGER.exception(
"Exception raised when updating state of %s, topic: "
"Exception raised while updating state of %s, topic: "
"'%s' with payload: %s",
entity.entity_id,
entity_id,
msg.topic,
msg.payload,
)

View File

@ -49,6 +49,7 @@ from .models import (
ReceivePayloadType,
)
from .schemas import MQTT_ENTITY_COMMON_SCHEMA
from .util import check_state_too_long
_LOGGER = logging.getLogger(__name__)
@ -242,7 +243,10 @@ class MqttSensor(MqttEntity, RestoreSensor):
else:
self._attr_native_value = new_value
return
if self.device_class in {None, SensorDeviceClass.ENUM}:
if self.device_class in {
None,
SensorDeviceClass.ENUM,
} and not check_state_too_long(_LOGGER, new_value, self.entity_id, msg):
self._attr_native_value = new_value
return
try:

View File

@ -49,6 +49,7 @@ from .models import (
ReceivePayloadType,
)
from .schemas import MQTT_ENTITY_COMMON_SCHEMA
from .util import check_state_too_long
_LOGGER = logging.getLogger(__name__)
@ -180,6 +181,8 @@ class MqttTextEntity(MqttEntity, TextEntity):
def handle_state_message_received(msg: ReceiveMessage) -> None:
"""Handle receiving state message via MQTT."""
payload = str(self._value_template(msg.payload))
if check_state_too_long(_LOGGER, payload, self.entity_id, msg):
return
self._attr_native_value = payload
add_subscription(topics, CONF_STATE_TOPIC, handle_state_message_received)

View File

@ -4,6 +4,7 @@ from __future__ import annotations
import asyncio
from functools import lru_cache
import logging
import os
from pathlib import Path
import tempfile
@ -12,7 +13,7 @@ from typing import Any
import voluptuous as vol
from homeassistant.config_entries import ConfigEntry, ConfigEntryState
from homeassistant.const import Platform
from homeassistant.const import MAX_LENGTH_STATE_STATE, STATE_UNKNOWN, Platform
from homeassistant.core import HomeAssistant
from homeassistant.helpers import config_validation as cv, template
from homeassistant.helpers.typing import ConfigType
@ -31,7 +32,7 @@ from .const import (
DEFAULT_RETAIN,
DOMAIN,
)
from .models import DATA_MQTT, DATA_MQTT_AVAILABLE
from .models import DATA_MQTT, DATA_MQTT_AVAILABLE, ReceiveMessage
AVAILABILITY_TIMEOUT = 30.0
@ -261,6 +262,28 @@ async def async_create_certificate_temp_files(
await hass.async_add_executor_job(_create_temp_dir_and_files)
def check_state_too_long(
logger: logging.Logger, proposed_state: str, entity_id: str, msg: ReceiveMessage
) -> bool:
"""Check if the processed state is too long and log warning."""
if (state_length := len(proposed_state)) > MAX_LENGTH_STATE_STATE:
logger.warning(
"Cannot update state for entity %s after processing "
"payload on topic %s. The requested state (%s) exceeds "
"the maximum allowed length (%s). Fall back to "
"%s, failed state: %s",
entity_id,
msg.topic,
state_length,
MAX_LENGTH_STATE_STATE,
STATE_UNKNOWN,
proposed_state[:8192],
)
return True
return False
def get_file_path(option: str, default: str | None = None) -> str | None:
"""Get file path of a certificate file."""
temp_dir = Path(tempfile.gettempdir()) / TEMP_DIR_NAME

View File

@ -931,7 +931,11 @@ async def test_handle_logging_on_writing_the_entity_state(
assert state is not None
assert state.state == "initial_state"
assert "Invalid value for sensor" in caplog.text
assert "Exception raised when updating state of" in caplog.text
assert (
"Exception raised while updating "
"state of sensor.test_sensor, topic: 'test/state' "
"with payload: b'payload causing errors'" in caplog.text
)
async def test_receiving_non_utf8_message_gets_logged(

View File

@ -110,6 +110,36 @@ async def test_setting_sensor_value_via_mqtt_message(
assert state.attributes.get("unit_of_measurement") == "fav unit"
@pytest.mark.parametrize(
"hass_config",
[
{
mqtt.DOMAIN: {
sensor.DOMAIN: {
"name": "test",
"state_topic": "test-topic",
}
}
},
],
)
async def test_setting_sensor_to_long_state_via_mqtt_message(
hass: HomeAssistant,
mqtt_mock_entry: MqttMockHAClientGenerator,
caplog: pytest.LogCaptureFixture,
) -> None:
"""Test the setting of the value via MQTT."""
await mqtt_mock_entry()
async_fire_mqtt_message(hass, "test-topic", "".join("x" for _ in range(310)))
state = hass.states.get("sensor.test")
await hass.async_block_till_done()
assert state.state == STATE_UNKNOWN
assert "Cannot update state for entity sensor.test" in caplog.text
@pytest.mark.parametrize(
("hass_config", "device_class", "native_value", "state_value", "log"),
[

View File

@ -142,7 +142,7 @@ async def test_forced_text_length(
state = hass.states.get("text.test")
assert state.state == "12345"
assert (
"ValueError: Entity text.test provides state 123456 "
"Entity text.test provides state 123456 "
"which is too long (maximum length 5)" in caplog.text
)
@ -152,7 +152,7 @@ async def test_forced_text_length(
state = hass.states.get("text.test")
assert state.state == "12345"
assert (
"ValueError: Entity text.test provides state 1 "
"Entity text.test provides state 1 "
"which is too short (minimum length 5)" in caplog.text
)
# Valid update
@ -200,7 +200,7 @@ async def test_controlling_validation_state_via_topic(
async_fire_mqtt_message(hass, "state-topic", "other")
await hass.async_block_till_done()
assert (
"ValueError: Entity text.test provides state other which does not match expected pattern (y|n)"
"Entity text.test provides state other which does not match expected pattern (y|n)"
in caplog.text
)
state = hass.states.get("text.test")
@ -211,7 +211,7 @@ async def test_controlling_validation_state_via_topic(
async_fire_mqtt_message(hass, "state-topic", "yesyesyesyes")
await hass.async_block_till_done()
assert (
"ValueError: Entity text.test provides state yesyesyesyes which is too long (maximum length 10)"
"Entity text.test provides state yesyesyesyes which is too long (maximum length 10)"
in caplog.text
)
state = hass.states.get("text.test")
@ -222,7 +222,7 @@ async def test_controlling_validation_state_via_topic(
async_fire_mqtt_message(hass, "state-topic", "y")
await hass.async_block_till_done()
assert (
"ValueError: Entity text.test provides state y which is too short (minimum length 2)"
"Entity text.test provides state y which is too short (minimum length 2)"
in caplog.text
)
state = hass.states.get("text.test")
@ -285,6 +285,36 @@ async def test_attribute_validation_max_not_greater_then_max_state_length(
assert "max text length must be <= 255" in caplog.text
@pytest.mark.parametrize(
"hass_config",
[
{
mqtt.DOMAIN: {
text.DOMAIN: {
"name": "test",
"command_topic": "command-topic",
"state_topic": "state-topic",
}
}
}
],
)
async def test_validation_payload_greater_then_max_state_length(
hass: HomeAssistant,
mqtt_mock_entry: MqttMockHAClientGenerator,
caplog: pytest.LogCaptureFixture,
) -> None:
"""Test the max value of of max configuration attribute."""
assert await mqtt_mock_entry()
state = hass.states.get("text.test")
assert state.state == STATE_UNKNOWN
async_fire_mqtt_message(hass, "state-topic", "".join("x" for _ in range(310)))
assert "Cannot update state for entity text.test" in caplog.text
@pytest.mark.parametrize(
"hass_config",
[