From 65d1dfba625db5f4803f4afcaa5685d72df4ec4d Mon Sep 17 00:00:00 2001 From: Phil Bruckner Date: Wed, 22 Jul 2020 10:55:49 -0500 Subject: [PATCH] Update automation logger to include object_id like scripts (#37948) --- .../components/automation/__init__.py | 28 +++++++++++----- homeassistant/helpers/script.py | 32 +++++++++++++------ tests/helpers/test_script.py | 19 +++++++++++ 3 files changed, 61 insertions(+), 18 deletions(-) diff --git a/homeassistant/components/automation/__init__.py b/homeassistant/components/automation/__init__.py index 3cbb98d85bd..599160534aa 100644 --- a/homeassistant/components/automation/__init__.py +++ b/homeassistant/components/automation/__init__.py @@ -23,7 +23,13 @@ from homeassistant.const import ( SERVICE_TURN_ON, STATE_ON, ) -from homeassistant.core import Context, CoreState, HomeAssistant, callback +from homeassistant.core import ( + Context, + CoreState, + HomeAssistant, + callback, + split_entity_id, +) from homeassistant.exceptions import HomeAssistantError from homeassistant.helpers import condition, extract_domain_configs import homeassistant.helpers.config_validation as cv @@ -260,6 +266,7 @@ class AutomationEntity(ToggleEntity, RestoreEntity): self._is_enabled = False self._referenced_entities: Optional[Set[str]] = None self._referenced_devices: Optional[Set[str]] = None + self._logger = _LOGGER @property def name(self): @@ -337,13 +344,18 @@ class AutomationEntity(ToggleEntity, RestoreEntity): """Startup with initial state or previous state.""" await super().async_added_to_hass() + self._logger = logging.getLogger( + f"{__name__}.{split_entity_id(self.entity_id)[1]}" + ) + self.action_script.update_logger(self._logger) + state = await self.async_get_last_state() if state: enable_automation = state.state == STATE_ON last_triggered = state.attributes.get("last_triggered") if last_triggered is not None: self._last_triggered = parse_datetime(last_triggered) - _LOGGER.debug( + self._logger.debug( "Loaded automation %s with state %s from state " " storage last state %s", self.entity_id, @@ -352,7 +364,7 @@ class AutomationEntity(ToggleEntity, RestoreEntity): ) else: enable_automation = DEFAULT_INITIAL_STATE - _LOGGER.debug( + self._logger.debug( "Automation %s not in state storage, state %s from default is used", self.entity_id, enable_automation, @@ -360,7 +372,7 @@ class AutomationEntity(ToggleEntity, RestoreEntity): if self._initial_state is not None: enable_automation = self._initial_state - _LOGGER.debug( + self._logger.debug( "Automation %s initial state %s overridden from " "config initial_state", self.entity_id, @@ -403,12 +415,12 @@ class AutomationEntity(ToggleEntity, RestoreEntity): context=trigger_context, ) - _LOGGER.info("Executing %s", self._name) + self._logger.info("Executing %s", self._name) try: await self.action_script.async_run(variables, trigger_context) except Exception: # pylint: disable=broad-except - _LOGGER.exception("While executing automation %s", self.entity_id) + self._logger.exception("While executing automation %s", self.entity_id) async def async_will_remove_from_hass(self): """Remove listeners when removing automation from Home Assistant.""" @@ -476,13 +488,13 @@ class AutomationEntity(ToggleEntity, RestoreEntity): results = await asyncio.gather(*triggers) if None in results: - _LOGGER.error("Error setting up trigger %s", self._name) + self._logger.error("Error setting up trigger %s", self._name) removes = [remove for remove in results if remove is not None] if not removes: return None - _LOGGER.info("Initialized trigger %s", self._name) + self._logger.info("Initialized trigger %s", self._name) @callback def remove_triggers(): diff --git a/homeassistant/helpers/script.py b/homeassistant/helpers/script.py index 32a22fab9e5..475beb02690 100644 --- a/homeassistant/helpers/script.py +++ b/homeassistant/helpers/script.py @@ -620,13 +620,7 @@ class Script: self.name = name self.change_listener = change_listener self.script_mode = script_mode - if logger: - self._logger = logger - else: - logger_name = __name__ - if name: - logger_name = ".".join([logger_name, slugify(name)]) - self._logger = logging.getLogger(logger_name) + self._set_logger(logger) self._log_exceptions = log_exceptions self.last_action = None @@ -638,12 +632,30 @@ class Script: self._queue_lck = asyncio.Lock() self._config_cache: Dict[Set[Tuple], Callable[..., bool]] = {} self._repeat_script: Dict[int, Script] = {} - self._choose_data: Dict[ - int, List[Tuple[List[Callable[[HomeAssistant, Dict], bool]], Script]] - ] = {} + self._choose_data: Dict[int, Dict[str, Any]] = {} self._referenced_entities: Optional[Set[str]] = None self._referenced_devices: Optional[Set[str]] = None + def _set_logger(self, logger: Optional[logging.Logger] = None) -> None: + if logger: + self._logger = logger + else: + logger_name = __name__ + if self.name: + logger_name = ".".join([logger_name, slugify(self.name)]) + self._logger = logging.getLogger(logger_name) + + def update_logger(self, logger: Optional[logging.Logger] = None) -> None: + """Update logger.""" + self._set_logger(logger) + for script in self._repeat_script.values(): + script.update_logger(self._logger) + for choose_data in self._choose_data.values(): + for _, script in choose_data["choices"]: + script.update_logger(self._logger) + if choose_data["default"]: + choose_data["default"].update_logger(self._logger) + def _changed(self): if self.change_listener: self._hass.async_run_job(self.change_listener) diff --git a/tests/helpers/test_script.py b/tests/helpers/test_script.py index 8a27c1c4e7e..4001b6a3215 100644 --- a/tests/helpers/test_script.py +++ b/tests/helpers/test_script.py @@ -1255,3 +1255,22 @@ async def test_shutdown_after(hass, caplog): "Stopping scripts running too long after shutdown: test script" in caplog.text ) + + +async def test_update_logger(hass, caplog): + """Test updating logger.""" + sequence = cv.SCRIPT_SCHEMA({"event": "test_event"}) + script_obj = script.Script(hass, sequence) + + await script_obj.async_run() + await hass.async_block_till_done() + + assert script.__name__ in caplog.text + + log_name = "testing.123" + script_obj.update_logger(logging.getLogger(log_name)) + + await script_obj.async_run() + await hass.async_block_till_done() + + assert log_name in caplog.text