From a6217ca9b9ac197d691cbba6ecf56e5fe2794675 Mon Sep 17 00:00:00 2001 From: Erik Montnemery Date: Wed, 21 Dec 2022 23:20:50 +0100 Subject: [PATCH] Improve error message when an automation fails to validate (#83977) --- .../components/automation/__init__.py | 34 +--- homeassistant/components/automation/config.py | 173 +++++++++++++----- tests/components/automation/test_init.py | 146 +++++++++++++-- tests/components/calendar/test_trigger.py | 2 +- tests/components/config/test_automation.py | 30 +++ .../lutron_caseta/test_device_trigger.py | 6 +- tests/components/rfxtrx/test_device_action.py | 8 +- .../components/rfxtrx/test_device_trigger.py | 8 +- .../components/shelly/test_device_trigger.py | 8 +- tests/components/tag/test_trigger.py | 2 +- tests/components/zha/test_device_trigger.py | 6 +- 11 files changed, 312 insertions(+), 111 deletions(-) diff --git a/homeassistant/components/automation/__init__.py b/homeassistant/components/automation/__init__.py index 9581a6b1c40..b0be5359d38 100644 --- a/homeassistant/components/automation/__init__.py +++ b/homeassistant/components/automation/__init__.py @@ -8,9 +8,8 @@ import logging from typing import Any, Protocol, cast import voluptuous as vol -from voluptuous.humanize import humanize_error -from homeassistant.components import blueprint, websocket_api +from homeassistant.components import websocket_api from homeassistant.components.blueprint import CONF_USE_BLUEPRINT from homeassistant.const import ( ATTR_ENTITY_ID, @@ -92,7 +91,7 @@ from homeassistant.helpers.typing import ConfigType from homeassistant.loader import bind_hass from homeassistant.util.dt import parse_datetime -from .config import AutomationConfig, async_validate_config_item +from .config import AutomationConfig from .const import ( CONF_ACTION, CONF_INITIAL_STATE, @@ -121,8 +120,6 @@ ATTR_SOURCE = "source" ATTR_VARIABLES = "variables" SERVICE_TRIGGER = "trigger" -_LOGGER = logging.getLogger(__name__) - class IfAction(Protocol): """Define the format of if_action.""" @@ -682,32 +679,11 @@ async def _prepare_automation_config( """Parse configuration and prepare automation entity configuration.""" automation_configs: list[AutomationEntityConfig] = [] - conf: list[ConfigType | blueprint.BlueprintInputs] = config[DOMAIN] + conf: list[ConfigType] = config[DOMAIN] for list_no, config_block in enumerate(conf): - raw_blueprint_inputs = None - raw_config = None - if isinstance(config_block, blueprint.BlueprintInputs): - blueprint_inputs = config_block - raw_blueprint_inputs = blueprint_inputs.config_with_inputs - - try: - raw_config = blueprint_inputs.async_substitute() - config_block = cast( - dict[str, Any], - await async_validate_config_item(hass, raw_config), - ) - except vol.Invalid as err: - LOGGER.error( - "Blueprint %s generated invalid automation with inputs %s: %s", - blueprint_inputs.blueprint.name, - blueprint_inputs.inputs, - humanize_error(config_block, err), - ) - continue - else: - raw_config = cast(AutomationConfig, config_block).raw_config - + raw_config = cast(AutomationConfig, config_block).raw_config + raw_blueprint_inputs = cast(AutomationConfig, config_block).raw_blueprint_inputs automation_configs.append( AutomationEntityConfig( config_block, list_no, raw_blueprint_inputs, raw_config diff --git a/homeassistant/components/automation/config.py b/homeassistant/components/automation/config.py index ec35e617b07..bd87e359d7a 100644 --- a/homeassistant/components/automation/config.py +++ b/homeassistant/components/automation/config.py @@ -2,17 +2,16 @@ from __future__ import annotations import asyncio +from collections.abc import Mapping from contextlib import suppress from typing import Any import voluptuous as vol +from voluptuous.humanize import humanize_error from homeassistant.components import blueprint -from homeassistant.components.device_automation.exceptions import ( - InvalidDeviceAutomationConfig, -) from homeassistant.components.trace import TRACE_CONFIG_SCHEMA -from homeassistant.config import async_log_exception, config_without_domain +from homeassistant.config import config_without_domain from homeassistant.const import ( CONF_ALIAS, CONF_CONDITION, @@ -26,7 +25,7 @@ from homeassistant.helpers import config_per_platform, config_validation as cv, from homeassistant.helpers.condition import async_validate_conditions_config from homeassistant.helpers.trigger import async_validate_trigger_config from homeassistant.helpers.typing import ConfigType -from homeassistant.loader import IntegrationNotFound +from homeassistant.util.yaml.input import UndefinedSubstitution from .const import ( CONF_ACTION, @@ -36,6 +35,7 @@ from .const import ( CONF_TRIGGER, CONF_TRIGGER_VARIABLES, DOMAIN, + LOGGER, ) from .helpers import async_get_blueprints @@ -65,67 +65,156 @@ PLATFORM_SCHEMA = vol.All( ) -async def async_validate_config_item( +async def _async_validate_config_item( hass: HomeAssistant, config: ConfigType, - full_config: ConfigType | None = None, -) -> blueprint.BlueprintInputs | dict[str, Any]: + warn_on_errors: bool, +) -> AutomationConfig: """Validate config item.""" - if blueprint.is_blueprint_instance_config(config): - blueprints = async_get_blueprints(hass) - return await blueprints.async_inputs_from_config(config) + raw_config = None + raw_blueprint_inputs = None + uses_blueprint = False + with suppress(ValueError): + raw_config = dict(config) - config = PLATFORM_SCHEMA(config) + def _log_invalid_automation( + err: Exception, + automation_name: str, + problem: str, + config: ConfigType, + ) -> None: + """Log an error about invalid automation.""" + if not warn_on_errors: + return - config[CONF_TRIGGER] = await async_validate_trigger_config( - hass, config[CONF_TRIGGER] - ) + if uses_blueprint: + LOGGER.error( + "Blueprint '%s' generated invalid automation with inputs %s: %s", + blueprint_inputs.blueprint.name, + blueprint_inputs.inputs, + humanize_error(config, err) if isinstance(err, vol.Invalid) else err, + ) + return - if CONF_CONDITION in config: - config[CONF_CONDITION] = await async_validate_conditions_config( - hass, config[CONF_CONDITION] + LOGGER.error( + "%s %s and has been disabled: %s", + automation_name, + problem, + humanize_error(config, err) if isinstance(err, vol.Invalid) else err, ) + return - config[CONF_ACTION] = await script.async_validate_actions_config( - hass, config[CONF_ACTION] - ) + if blueprint.is_blueprint_instance_config(config): + uses_blueprint = True + blueprints = async_get_blueprints(hass) + try: + blueprint_inputs = await blueprints.async_inputs_from_config(config) + except blueprint.BlueprintException as err: + if warn_on_errors: + LOGGER.error( + "Failed to generate automation from blueprint: %s", + err, + ) + raise - return config + raw_blueprint_inputs = blueprint_inputs.config_with_inputs + + try: + config = blueprint_inputs.async_substitute() + raw_config = dict(config) + except UndefinedSubstitution as err: + if warn_on_errors: + LOGGER.error( + "Blueprint '%s' failed to generate automation with inputs %s: %s", + blueprint_inputs.blueprint.name, + blueprint_inputs.inputs, + err, + ) + raise HomeAssistantError from err + + automation_name = "Unnamed automation" + if isinstance(config, Mapping): + if CONF_ALIAS in config: + automation_name = f"Automation with alias '{config[CONF_ALIAS]}'" + elif CONF_ID in config: + automation_name = f"Automation with ID '{config[CONF_ID]}'" + + try: + validated_config = PLATFORM_SCHEMA(config) + except vol.Invalid as err: + _log_invalid_automation(err, automation_name, "could not be validated", config) + raise + + try: + validated_config[CONF_TRIGGER] = await async_validate_trigger_config( + hass, validated_config[CONF_TRIGGER] + ) + except ( + vol.Invalid, + HomeAssistantError, + ) as err: + _log_invalid_automation( + err, automation_name, "failed to setup triggers", validated_config + ) + raise + + if CONF_CONDITION in validated_config: + try: + validated_config[CONF_CONDITION] = await async_validate_conditions_config( + hass, validated_config[CONF_CONDITION] + ) + except ( + vol.Invalid, + HomeAssistantError, + ) as err: + _log_invalid_automation( + err, automation_name, "failed to setup conditions", validated_config + ) + raise + + try: + validated_config[CONF_ACTION] = await script.async_validate_actions_config( + hass, validated_config[CONF_ACTION] + ) + except ( + vol.Invalid, + HomeAssistantError, + ) as err: + _log_invalid_automation( + err, automation_name, "failed to setup actions", validated_config + ) + raise + + automation_config = AutomationConfig(validated_config) + automation_config.raw_blueprint_inputs = raw_blueprint_inputs + automation_config.raw_config = raw_config + return automation_config class AutomationConfig(dict): """Dummy class to allow adding attributes.""" raw_config: dict[str, Any] | None = None + raw_blueprint_inputs: dict[str, Any] | None = None async def _try_async_validate_config_item( hass: HomeAssistant, config: dict[str, Any], - full_config: dict[str, Any] | None = None, -) -> AutomationConfig | blueprint.BlueprintInputs | None: +) -> AutomationConfig | None: """Validate config item.""" - raw_config = None - with suppress(ValueError): - raw_config = dict(config) - try: - validated_config = await async_validate_config_item(hass, config, full_config) - except ( - vol.Invalid, - HomeAssistantError, - IntegrationNotFound, - InvalidDeviceAutomationConfig, - ) as ex: - async_log_exception(ex, DOMAIN, full_config or config, hass) + return await _async_validate_config_item(hass, config, True) + except (vol.Invalid, HomeAssistantError): return None - if isinstance(validated_config, blueprint.BlueprintInputs): - return validated_config - automation_config = AutomationConfig(validated_config) - automation_config.raw_config = raw_config - return automation_config +async def async_validate_config_item( + hass: HomeAssistant, + config: dict[str, Any], +) -> AutomationConfig | None: + """Validate config item, called by EditAutomationConfigView.""" + return await _async_validate_config_item(hass, config, False) async def async_validate_config(hass: HomeAssistant, config: ConfigType) -> ConfigType: @@ -135,7 +224,7 @@ async def async_validate_config(hass: HomeAssistant, config: ConfigType) -> Conf lambda x: x is not None, await asyncio.gather( *( - _try_async_validate_config_item(hass, p_config, config) + _try_async_validate_config_item(hass, p_config) for _, p_config in config_per_platform(config, DOMAIN) ) ), diff --git a/tests/components/automation/test_init.py b/tests/components/automation/test_init.py index 1ce6cb616da..51d7f0a0852 100644 --- a/tests/components/automation/test_init.py +++ b/tests/components/automation/test_init.py @@ -1332,20 +1332,81 @@ async def test_automation_not_trigger_on_bootstrap(hass): assert ["hello.world"] == calls[0].data.get(ATTR_ENTITY_ID) -async def test_automation_bad_trigger(hass, caplog): - """Test bad trigger configuration.""" +@pytest.mark.parametrize( + "broken_config, problem, details", + ( + ( + {}, + "could not be validated", + "required key not provided @ data['action']", + ), + ( + { + "trigger": {"platform": "automation"}, + "action": [], + }, + "failed to setup triggers", + "Integration 'automation' does not provide trigger support.", + ), + ( + { + "trigger": {"platform": "event", "event_type": "test_event"}, + "condition": { + "condition": "state", + # The UUID will fail being resolved to en entity_id + "entity_id": "abcdabcdabcdabcdabcdabcdabcdabcd", + "state": "blah", + }, + "action": [], + }, + "failed to setup conditions", + "Unknown entity registry entry abcdabcdabcdabcdabcdabcdabcdabcd.", + ), + ( + { + "trigger": {"platform": "event", "event_type": "test_event"}, + "action": { + "condition": "state", + # The UUID will fail being resolved to en entity_id + "entity_id": "abcdabcdabcdabcdabcdabcdabcdabcd", + "state": "blah", + }, + }, + "failed to setup actions", + "Unknown entity registry entry abcdabcdabcdabcdabcdabcdabcdabcd.", + ), + ), +) +async def test_automation_bad_config_validation( + hass: HomeAssistant, caplog, broken_config, problem, details +): + """Test bad trigger configuration which can be detected during validation.""" assert await async_setup_component( hass, automation.DOMAIN, { - automation.DOMAIN: { - "alias": "hello", - "trigger": {"platform": "automation"}, - "action": [], - } + automation.DOMAIN: [ + {"alias": "bad_automation", **broken_config}, + { + "alias": "good_automation", + "trigger": {"platform": "event", "event_type": "test_event"}, + "action": { + "service": "test.automation", + "entity_id": "hello.world", + }, + }, + ] }, ) - assert "Integration 'automation' does not provide trigger support." in caplog.text + + # Check we get the expected error message + assert ( + f"Automation with alias 'bad_automation' {problem} and has been disabled: {details}" + in caplog.text + ) + + # Make sure one bad automation does not prevent other automations from setting up + assert hass.states.async_entity_ids("automation") == ["automation.good_automation"] async def test_automation_with_error_in_script( @@ -1885,7 +1946,36 @@ async def test_blueprint_automation(hass, calls): ] -async def test_blueprint_automation_bad_config(hass, caplog): +@pytest.mark.parametrize( + "blueprint_inputs, problem, details", + ( + ( + # No input + {}, + "Failed to generate automation from blueprint", + "Missing input a_number, service_to_call, trigger_event", + ), + ( + # Missing input + {"trigger_event": "blueprint_event", "a_number": 5}, + "Failed to generate automation from blueprint", + "Missing input service_to_call", + ), + ( + # Wrong input + { + "trigger_event": "blueprint_event", + "service_to_call": {"dict": "not allowed"}, + "a_number": 5, + }, + "Blueprint 'Call service based on event' generated invalid automation", + "value should be a string for dictionary value @ data['action'][0]['service']", + ), + ), +) +async def test_blueprint_automation_bad_config( + hass, caplog, blueprint_inputs, problem, details +): """Test blueprint automation with bad inputs.""" assert await async_setup_component( hass, @@ -1894,16 +1984,42 @@ async def test_blueprint_automation_bad_config(hass, caplog): "automation": { "use_blueprint": { "path": "test_event_service.yaml", - "input": { - "trigger_event": "blueprint_event", - "service_to_call": {"dict": "not allowed"}, - "a_number": 5, - }, + "input": blueprint_inputs, } } }, ) - assert "generated invalid automation" in caplog.text + assert problem in caplog.text + assert details in caplog.text + + +async def test_blueprint_automation_fails_substitution(hass, caplog): + """Test blueprint automation with bad inputs.""" + with patch( + "homeassistant.components.blueprint.models.BlueprintInputs.async_substitute", + side_effect=yaml.UndefinedSubstitution("blah"), + ): + assert await async_setup_component( + hass, + "automation", + { + "automation": { + "use_blueprint": { + "path": "test_event_service.yaml", + "input": { + "trigger_event": "test_event", + "service_to_call": "test.automation", + "a_number": 5, + }, + } + } + }, + ) + assert ( + "Blueprint 'Call service based on event' failed to generate automation with inputs " + "{'trigger_event': 'test_event', 'service_to_call': 'test.automation', 'a_number': 5}:" + " No substitution found for input blah" in caplog.text + ) async def test_trigger_service(hass, calls): diff --git a/tests/components/calendar/test_trigger.py b/tests/components/calendar/test_trigger.py index 24b4b06b493..ac2547c81f7 100644 --- a/tests/components/calendar/test_trigger.py +++ b/tests/components/calendar/test_trigger.py @@ -462,7 +462,7 @@ async def test_invalid_calendar_id(hass, caplog): }, ) await hass.async_block_till_done() - assert "Invalid config for [automation]" in caplog.text + assert "Entity ID invalid-calendar-id is an invalid entity ID" in caplog.text async def test_legacy_entity_type(hass, caplog): diff --git a/tests/components/config/test_automation.py b/tests/components/config/test_automation.py index 0a5a79c7d15..dd1eda385ff 100644 --- a/tests/components/config/test_automation.py +++ b/tests/components/config/test_automation.py @@ -76,6 +76,36 @@ async def test_update_automation_config( assert new_data[1] == {"id": "moon", "trigger": [], "condition": [], "action": []} +@pytest.mark.parametrize("automation_config", ({},)) +async def test_update_automation_config_with_error( + hass: HomeAssistant, hass_client, hass_config_store, setup_automation, caplog +): + """Test updating automation config with errors.""" + with patch.object(config, "SECTIONS", ["automation"]): + await async_setup_component(hass, "config", {}) + + assert sorted(hass.states.async_entity_ids("automation")) == [] + + client = await hass_client() + + orig_data = [{"id": "sun"}, {"id": "moon"}] + hass_config_store["automations.yaml"] = orig_data + + resp = await client.post( + "/api/config/automation/config/moon", + data=json.dumps({}), + ) + await hass.async_block_till_done() + assert sorted(hass.states.async_entity_ids("automation")) == [] + + assert resp.status != HTTPStatus.OK + result = await resp.json() + validation_error = "required key not provided @ data['trigger']" + assert result == {"message": f"Message malformed: {validation_error}"} + # Assert the validation error is not logged + assert validation_error not in caplog.text + + @pytest.mark.parametrize("automation_config", ({},)) async def test_update_remove_key_automation_config( hass: HomeAssistant, hass_client, hass_config_store, setup_automation diff --git a/tests/components/lutron_caseta/test_device_trigger.py b/tests/components/lutron_caseta/test_device_trigger.py index e7688f62f06..b8afba1fbec 100644 --- a/tests/components/lutron_caseta/test_device_trigger.py +++ b/tests/components/lutron_caseta/test_device_trigger.py @@ -396,7 +396,7 @@ async def test_validate_trigger_config_unknown_device(hass, calls, device_reg): assert len(calls) == 0 -async def test_validate_trigger_invalid_triggers(hass, device_reg): +async def test_validate_trigger_invalid_triggers(hass, device_reg, caplog): """Test for click_event with invalid triggers.""" config_entry_id = await _async_setup_lutron_with_picos(hass) data: LutronCasetaData = hass.data[DOMAIN][config_entry_id] @@ -415,7 +415,7 @@ async def test_validate_trigger_invalid_triggers(hass, device_reg): CONF_PLATFORM: "device", CONF_DOMAIN: DOMAIN, CONF_DEVICE_ID: device_id, - CONF_TYPE: "press", + CONF_TYPE: "invalid", CONF_SUBTYPE: "on", }, "action": { @@ -427,6 +427,8 @@ async def test_validate_trigger_invalid_triggers(hass, device_reg): }, ) + assert "value must be one of ['press', 'release']" in caplog.text + async def test_if_fires_on_button_event_late_setup(hass, calls): """Test for press trigger firing with integration getting setup late.""" diff --git a/tests/components/rfxtrx/test_device_action.py b/tests/components/rfxtrx/test_device_action.py index 7dda64bbe62..69ba983cd5d 100644 --- a/tests/components/rfxtrx/test_device_action.py +++ b/tests/components/rfxtrx/test_device_action.py @@ -169,7 +169,7 @@ async def test_action( rfxtrx.transport.send.assert_called_once_with(bytearray.fromhex(expected)) -async def test_invalid_action(hass, device_reg: DeviceRegistry): +async def test_invalid_action(hass, device_reg: DeviceRegistry, caplog): """Test for invalid actions.""" device = DEVICE_LIGHTING_1 @@ -201,8 +201,4 @@ async def test_invalid_action(hass, device_reg: DeviceRegistry): ) await hass.async_block_till_done() - assert len(notifications := hass.states.async_all("persistent_notification")) == 1 - assert ( - "The following integrations and platforms could not be set up" - in notifications[0].attributes["message"] - ) + assert "Subtype invalid not found in device commands" in caplog.text diff --git a/tests/components/rfxtrx/test_device_trigger.py b/tests/components/rfxtrx/test_device_trigger.py index b783d10ed27..57d604ce64f 100644 --- a/tests/components/rfxtrx/test_device_trigger.py +++ b/tests/components/rfxtrx/test_device_trigger.py @@ -155,7 +155,7 @@ async def test_firing_event(hass, device_reg: DeviceRegistry, rfxtrx, event): assert calls[0].data["some"] == "device" -async def test_invalid_trigger(hass, device_reg: DeviceRegistry): +async def test_invalid_trigger(hass, device_reg: DeviceRegistry, caplog): """Test for invalid actions.""" event = EVENT_LIGHTING_1 @@ -188,8 +188,4 @@ async def test_invalid_trigger(hass, device_reg: DeviceRegistry): ) await hass.async_block_till_done() - assert len(notifications := hass.states.async_all("persistent_notification")) == 1 - assert ( - "The following integrations and platforms could not be set up" - in notifications[0].attributes["message"] - ) + assert "Subtype invalid not found in device triggers" in caplog.text diff --git a/tests/components/shelly/test_device_trigger.py b/tests/components/shelly/test_device_trigger.py index ec74745da15..13ccf3f843e 100644 --- a/tests/components/shelly/test_device_trigger.py +++ b/tests/components/shelly/test_device_trigger.py @@ -324,7 +324,7 @@ async def test_validate_trigger_rpc_device_not_ready( assert calls[0].data["some"] == "test_trigger_single_push" -async def test_validate_trigger_invalid_triggers(hass, mock_block_device): +async def test_validate_trigger_invalid_triggers(hass, mock_block_device, caplog): """Test for click_event with invalid triggers.""" entry = await init_integration(hass, 1) dev_reg = async_get_dev_reg(hass) @@ -352,8 +352,4 @@ async def test_validate_trigger_invalid_triggers(hass, mock_block_device): }, ) - assert len(notifications := hass.states.async_all("persistent_notification")) == 1 - assert ( - "The following integrations and platforms could not be set up" - in notifications[0].attributes["message"] - ) + assert "Invalid (type,subtype): ('single', 'button3')" in caplog.text diff --git a/tests/components/tag/test_trigger.py b/tests/components/tag/test_trigger.py index 3976c3193d1..379319be502 100644 --- a/tests/components/tag/test_trigger.py +++ b/tests/components/tag/test_trigger.py @@ -101,7 +101,7 @@ async def test_exception_bad_trigger(hass, calls, caplog): }, ) await hass.async_block_till_done() - assert "Invalid config for [automation]" in caplog.text + assert "Unnamed automation could not be validated" in caplog.text async def test_multiple_tags_and_devices_trigger(hass, tag_setup, calls): diff --git a/tests/components/zha/test_device_trigger.py b/tests/components/zha/test_device_trigger.py index 49eeacc0e42..0081ba04d16 100644 --- a/tests/components/zha/test_device_trigger.py +++ b/tests/components/zha/test_device_trigger.py @@ -327,7 +327,7 @@ async def test_exception_no_triggers(hass, mock_devices, calls, caplog): }, ) await hass.async_block_till_done() - assert "Invalid config for [automation]" in caplog.text + assert "Invalid trigger configuration" in caplog.text async def test_exception_bad_trigger(hass, mock_devices, calls, caplog): @@ -369,7 +369,7 @@ async def test_exception_bad_trigger(hass, mock_devices, calls, caplog): }, ) await hass.async_block_till_done() - assert "Invalid config for [automation]" in caplog.text + assert "Invalid trigger configuration" in caplog.text @pytest.mark.skip(reason="Temporarily disabled until automation validation is improved") @@ -408,4 +408,4 @@ async def test_exception_no_device(hass, mock_devices, calls, caplog): }, ) await hass.async_block_till_done() - assert "Invalid config for [automation]" in caplog.text + assert "Invalid trigger configuration" in caplog.text