"""The tests for the Logger component.""" from collections import defaultdict import logging from typing import Any from unittest.mock import Mock, patch import pytest from homeassistant.components import logger from homeassistant.components.logger import LOGSEVERITY from homeassistant.core import HomeAssistant from homeassistant.setup import async_setup_component HASS_NS = "unused.homeassistant" COMPONENTS_NS = f"{HASS_NS}.components" ZONE_NS = f"{COMPONENTS_NS}.zone" GROUP_NS = f"{COMPONENTS_NS}.group" CONFIGED_NS = "otherlibx" UNCONFIG_NS = "unconfigurednamespace" INTEGRATION = "test_component" INTEGRATION_NS = f"homeassistant.components.{INTEGRATION}" async def test_log_filtering( hass: HomeAssistant, caplog: pytest.LogCaptureFixture ) -> None: """Test logging filters.""" assert await async_setup_component( hass, "logger", { "logger": { "default": "warning", "logs": { "test.filter": "info", }, "filters": { "test.filter": [ "doesntmatchanything", ".*shouldfilterall.*", "^filterthis:.*", "in the middle", ], "test.other_filter": [".*otherfilterer"], }, } }, ) await hass.async_block_till_done() filter_logger = logging.getLogger("test.filter") def msg_test(logger, result, message, *args): logger.error(message, *args) formatted_message = message % args assert (formatted_message in caplog.text) == result caplog.clear() msg_test( filter_logger, False, "this line containing shouldfilterall should be filtered" ) msg_test(filter_logger, True, "this line should not be filtered filterthis:") msg_test(filter_logger, False, "this in the middle should be filtered") msg_test(filter_logger, False, "filterthis: should be filtered") msg_test(filter_logger, False, "format string shouldfilter%s", "all") msg_test(filter_logger, True, "format string shouldfilter%s", "not") # Filtering should work even if log level is modified await hass.services.async_call( "logger", "set_level", {"test.filter": "warning"}, blocking=True, ) assert filter_logger.getEffectiveLevel() == logging.WARNING msg_test( filter_logger, False, "this line containing shouldfilterall should still be filtered", ) # Filtering should be scoped to a service msg_test( filter_logger, True, "this line containing otherfilterer should not be filtered" ) msg_test( logging.getLogger("test.other_filter"), False, "this line containing otherfilterer SHOULD be filtered", ) async def test_setting_level(hass: HomeAssistant) -> None: """Test we set log levels.""" mocks = defaultdict(Mock) with patch("logging.getLogger", mocks.__getitem__): assert await async_setup_component( hass, "logger", { "logger": { "default": "warning", "logs": { "test": "info", "test.child": "debug", "test.child.child": "warning", }, } }, ) await hass.async_block_till_done() assert len(mocks) == 4 assert len(mocks[""].orig_setLevel.mock_calls) == 1 assert mocks[""].orig_setLevel.mock_calls[0][1][0] == LOGSEVERITY["WARNING"] assert len(mocks["test"].orig_setLevel.mock_calls) == 1 assert mocks["test"].orig_setLevel.mock_calls[0][1][0] == LOGSEVERITY["INFO"] assert len(mocks["test.child"].orig_setLevel.mock_calls) == 1 assert mocks["test.child"].orig_setLevel.mock_calls[0][1][0] == LOGSEVERITY["DEBUG"] assert len(mocks["test.child.child"].orig_setLevel.mock_calls) == 1 assert ( mocks["test.child.child"].orig_setLevel.mock_calls[0][1][0] == LOGSEVERITY["WARNING"] ) # Test set default level with patch("logging.getLogger", mocks.__getitem__): await hass.services.async_call( "logger", "set_default_level", {"level": "fatal"}, blocking=True ) assert len(mocks[""].orig_setLevel.mock_calls) == 2 assert mocks[""].orig_setLevel.mock_calls[1][1][0] == LOGSEVERITY["FATAL"] # Test update other loggers with patch("logging.getLogger", mocks.__getitem__): await hass.services.async_call( "logger", "set_level", {"test.child": "info", "new_logger": "notset"}, blocking=True, ) assert len(mocks) == 5 assert len(mocks["test.child"].orig_setLevel.mock_calls) == 2 assert mocks["test.child"].orig_setLevel.mock_calls[1][1][0] == LOGSEVERITY["INFO"] assert len(mocks["new_logger"].orig_setLevel.mock_calls) == 1 assert ( mocks["new_logger"].orig_setLevel.mock_calls[0][1][0] == LOGSEVERITY["NOTSET"] ) async def test_can_set_level_from_yaml(hass: HomeAssistant) -> None: """Test logger propagation.""" assert await async_setup_component( hass, "logger", { "logger": { "logs": { CONFIGED_NS: "warning", f"{CONFIGED_NS}.info": "info", f"{CONFIGED_NS}.debug": "debug", HASS_NS: "warning", COMPONENTS_NS: "info", ZONE_NS: "debug", GROUP_NS: "info", }, } }, ) await _assert_log_levels(hass) _reset_logging() async def test_can_set_level_from_store( hass: HomeAssistant, hass_storage: dict[str, Any] ) -> None: """Test setting up logs from store.""" hass_storage["core.logger"] = { "data": { "logs": { CONFIGED_NS: { "level": "WARNING", "persistence": "once", "type": "module", }, f"{CONFIGED_NS}.info": { "level": "INFO", "persistence": "once", "type": "module", }, f"{CONFIGED_NS}.debug": { "level": "DEBUG", "persistence": "once", "type": "module", }, HASS_NS: {"level": "WARNING", "persistence": "once", "type": "module"}, COMPONENTS_NS: { "level": "INFO", "persistence": "once", "type": "module", }, ZONE_NS: {"level": "DEBUG", "persistence": "once", "type": "module"}, GROUP_NS: {"level": "INFO", "persistence": "once", "type": "module"}, } }, "key": "core.logger", "version": 1, } assert await async_setup_component(hass, "logger", {}) await _assert_log_levels(hass) _reset_logging() async def _assert_log_levels(hass): assert logging.getLogger(UNCONFIG_NS).level == logging.NOTSET assert logging.getLogger(UNCONFIG_NS).isEnabledFor(logging.CRITICAL) is True assert ( logging.getLogger(f"{UNCONFIG_NS}.any").isEnabledFor(logging.CRITICAL) is True ) assert ( logging.getLogger(f"{UNCONFIG_NS}.any.any").isEnabledFor(logging.CRITICAL) is True ) assert logging.getLogger(CONFIGED_NS).isEnabledFor(logging.DEBUG) is False assert logging.getLogger(CONFIGED_NS).isEnabledFor(logging.WARNING) is True assert logging.getLogger(f"{CONFIGED_NS}.any").isEnabledFor(logging.WARNING) is True assert ( logging.getLogger(f"{CONFIGED_NS}.any.any").isEnabledFor(logging.WARNING) is True ) assert logging.getLogger(f"{CONFIGED_NS}.info").isEnabledFor(logging.DEBUG) is False assert logging.getLogger(f"{CONFIGED_NS}.info").isEnabledFor(logging.INFO) is True assert ( logging.getLogger(f"{CONFIGED_NS}.info.any").isEnabledFor(logging.DEBUG) is False ) assert ( logging.getLogger(f"{CONFIGED_NS}.info.any").isEnabledFor(logging.INFO) is True ) assert logging.getLogger(f"{CONFIGED_NS}.debug").isEnabledFor(logging.DEBUG) is True assert ( logging.getLogger(f"{CONFIGED_NS}.debug.any").isEnabledFor(logging.DEBUG) is True ) assert logging.getLogger(HASS_NS).isEnabledFor(logging.DEBUG) is False assert logging.getLogger(HASS_NS).isEnabledFor(logging.WARNING) is True assert logging.getLogger(COMPONENTS_NS).isEnabledFor(logging.DEBUG) is False assert logging.getLogger(COMPONENTS_NS).isEnabledFor(logging.WARNING) is True assert logging.getLogger(COMPONENTS_NS).isEnabledFor(logging.INFO) is True assert logging.getLogger(GROUP_NS).isEnabledFor(logging.DEBUG) is False assert logging.getLogger(GROUP_NS).isEnabledFor(logging.WARNING) is True assert logging.getLogger(GROUP_NS).isEnabledFor(logging.INFO) is True assert logging.getLogger(f"{GROUP_NS}.any").isEnabledFor(logging.DEBUG) is False assert logging.getLogger(f"{GROUP_NS}.any").isEnabledFor(logging.WARNING) is True assert logging.getLogger(f"{GROUP_NS}.any").isEnabledFor(logging.INFO) is True assert logging.getLogger(ZONE_NS).isEnabledFor(logging.DEBUG) is True assert logging.getLogger(f"{ZONE_NS}.any").isEnabledFor(logging.DEBUG) is True await hass.services.async_call( logger.DOMAIN, "set_level", {f"{UNCONFIG_NS}.any": "debug"}, blocking=True ) assert logging.getLogger(UNCONFIG_NS).level == logging.NOTSET assert logging.getLogger(f"{UNCONFIG_NS}.any").level == logging.DEBUG assert logging.getLogger(UNCONFIG_NS).level == logging.NOTSET await hass.services.async_call( logger.DOMAIN, "set_default_level", {"level": "debug"}, blocking=True ) assert logging.getLogger(UNCONFIG_NS).isEnabledFor(logging.DEBUG) is True assert logging.getLogger(f"{UNCONFIG_NS}.any").isEnabledFor(logging.DEBUG) is True assert ( logging.getLogger(f"{UNCONFIG_NS}.any.any").isEnabledFor(logging.DEBUG) is True ) assert logging.getLogger("").isEnabledFor(logging.DEBUG) is True assert logging.getLogger(COMPONENTS_NS).isEnabledFor(logging.DEBUG) is False assert logging.getLogger(GROUP_NS).isEnabledFor(logging.DEBUG) is False logging.getLogger(CONFIGED_NS).setLevel(logging.INFO) assert logging.getLogger(CONFIGED_NS).level == logging.WARNING logging.getLogger("").setLevel(logging.NOTSET) def _reset_logging(): """Reset loggers.""" logging.getLogger(CONFIGED_NS).orig_setLevel(logging.NOTSET) logging.getLogger(f"{CONFIGED_NS}.info").orig_setLevel(logging.NOTSET) logging.getLogger(f"{CONFIGED_NS}.debug").orig_setLevel(logging.NOTSET) logging.getLogger(HASS_NS).orig_setLevel(logging.NOTSET) logging.getLogger(COMPONENTS_NS).orig_setLevel(logging.NOTSET) logging.getLogger(ZONE_NS).orig_setLevel(logging.NOTSET) logging.getLogger(GROUP_NS).orig_setLevel(logging.NOTSET) logging.getLogger(INTEGRATION_NS).orig_setLevel(logging.NOTSET) async def test_can_set_integration_level_from_store( hass: HomeAssistant, hass_storage: dict[str, Any] ) -> None: """Test setting up integration logs from store.""" hass_storage["core.logger"] = { "data": { "logs": { INTEGRATION: { "level": "WARNING", "persistence": "once", "type": "integration", }, } }, "key": "core.logger", "version": 1, } assert await async_setup_component(hass, "logger", {}) assert logging.getLogger(INTEGRATION_NS).isEnabledFor(logging.DEBUG) is False assert logging.getLogger(INTEGRATION_NS).isEnabledFor(logging.WARNING) is True _reset_logging() async def test_chattier_log_level_wins_1( hass: HomeAssistant, hass_storage: dict[str, Any] ) -> None: """Test chattier log level in store takes precedence.""" hass_storage["core.logger"] = { "data": { "logs": { INTEGRATION_NS: { "level": "DEBUG", "persistence": "once", "type": "module", }, } }, "key": "core.logger", "version": 1, } assert await async_setup_component( hass, "logger", { "logger": { "logs": { INTEGRATION_NS: "warning", } } }, ) assert logging.getLogger(INTEGRATION_NS).isEnabledFor(logging.DEBUG) is True assert logging.getLogger(INTEGRATION_NS).isEnabledFor(logging.WARNING) is True _reset_logging() async def test_chattier_log_level_wins_2( hass: HomeAssistant, hass_storage: dict[str, Any] ) -> None: """Test chattier log level in yaml takes precedence.""" hass_storage["core.logger"] = { "data": { "logs": { INTEGRATION_NS: { "level": "WARNING", "persistence": "once", "type": "module", }, } }, "key": "core.logger", "version": 1, } assert await async_setup_component( hass, "logger", {"logger": {"logs": {INTEGRATION_NS: "debug"}}} ) assert logging.getLogger(INTEGRATION_NS).isEnabledFor(logging.DEBUG) is True assert logging.getLogger(INTEGRATION_NS).isEnabledFor(logging.WARNING) is True _reset_logging() async def test_log_once_removed_from_store( hass: HomeAssistant, hass_storage: dict[str, Any] ) -> None: """Test logs with persistence "once" are removed from the store at startup.""" hass_storage["core.logger"] = { "data": { "logs": { ZONE_NS: {"type": "module", "level": "DEBUG", "persistence": "once"} } }, "key": "core.logger", "version": 1, } assert await async_setup_component(hass, "logger", {}) assert hass_storage["core.logger"]["data"] == {"logs": {}}