diff --git a/homeassistant/util/logging.py b/homeassistant/util/logging.py index abadb613168..18bd1a4e3ca 100644 --- a/homeassistant/util/logging.py +++ b/homeassistant/util/logging.py @@ -124,27 +124,29 @@ class AsyncHandler: self.handler.set_name(name) # type: ignore +def log_exception(format_err: Callable[..., Any], *args: Any) -> None: + """Log an exception with additional context.""" + module = inspect.getmodule(inspect.stack()[1][0]) + if module is not None: + module_name = module.__name__ + else: + # If Python is unable to access the sources files, the call stack frame + # will be missing information, so let's guard. + # https://github.com/home-assistant/home-assistant/issues/24982 + module_name = __name__ + + # Do not print the wrapper in the traceback + frames = len(inspect.trace()) - 1 + exc_msg = traceback.format_exc(-frames) + friendly_msg = format_err(*args) + logging.getLogger(module_name).error("%s\n%s", friendly_msg, exc_msg) + + def catch_log_exception( func: Callable[..., Any], format_err: Callable[..., Any], *args: Any ) -> Callable[[], None]: """Decorate a callback to catch and log exceptions.""" - def log_exception(*args: Any) -> None: - module = inspect.getmodule(inspect.stack()[1][0]) - if module is not None: - module_name = module.__name__ - else: - # If Python is unable to access the sources files, the call stack frame - # will be missing information, so let's guard. - # https://github.com/home-assistant/home-assistant/issues/24982 - module_name = __name__ - - # Do not print the wrapper in the traceback - frames = len(inspect.trace()) - 1 - exc_msg = traceback.format_exc(-frames) - friendly_msg = format_err(*args) - logging.getLogger(module_name).error("%s\n%s", friendly_msg, exc_msg) - # Check for partials to properly determine if coroutine function check_func = func while isinstance(check_func, partial): @@ -159,7 +161,7 @@ def catch_log_exception( try: await func(*args) except Exception: # pylint: disable=broad-except - log_exception(*args) + log_exception(format_err, *args) wrapper_func = async_wrapper else: @@ -170,7 +172,7 @@ def catch_log_exception( try: func(*args) except Exception: # pylint: disable=broad-except - log_exception(*args) + log_exception(format_err, *args) wrapper_func = wrapper return wrapper_func @@ -186,20 +188,7 @@ def catch_log_coro_exception( try: return await target except Exception: # pylint: disable=broad-except - module = inspect.getmodule(inspect.stack()[1][0]) - if module is not None: - module_name = module.__name__ - else: - # If Python is unable to access the sources files, the frame - # will be missing information, so let's guard. - # https://github.com/home-assistant/home-assistant/issues/24982 - module_name = __name__ - - # Do not print the wrapper in the traceback - frames = len(inspect.trace()) - 1 - exc_msg = traceback.format_exc(-frames) - friendly_msg = format_err(*args) - logging.getLogger(module_name).error("%s\n%s", friendly_msg, exc_msg) + log_exception(format_err, *args) return None return coro_wrapper() diff --git a/tests/components/mqtt/test_alarm_control_panel.py b/tests/components/mqtt/test_alarm_control_panel.py index 254449cc129..6677122cf10 100644 --- a/tests/components/mqtt/test_alarm_control_panel.py +++ b/tests/components/mqtt/test_alarm_control_panel.py @@ -2,6 +2,8 @@ import copy import json +import pytest + from homeassistant.components import alarm_control_panel from homeassistant.const import ( STATE_ALARM_ARMED_AWAY, @@ -551,6 +553,7 @@ async def test_discovery_update_alarm(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' diff --git a/tests/components/mqtt/test_binary_sensor.py b/tests/components/mqtt/test_binary_sensor.py index 7c07abb8d35..31acf187ad5 100644 --- a/tests/components/mqtt/test_binary_sensor.py +++ b/tests/components/mqtt/test_binary_sensor.py @@ -3,6 +3,8 @@ import copy from datetime import datetime, timedelta import json +import pytest + from homeassistant.components import binary_sensor, mqtt from homeassistant.components.mqtt.discovery import async_start from homeassistant.const import ( @@ -184,6 +186,43 @@ async def test_setting_sensor_value_via_mqtt_message(hass, mqtt_mock): assert state.state == STATE_OFF +async def test_invalid_sensor_value_via_mqtt_message(hass, mqtt_mock, caplog): + """Test the setting of the value via MQTT.""" + assert await async_setup_component( + hass, + binary_sensor.DOMAIN, + { + binary_sensor.DOMAIN: { + "platform": "mqtt", + "name": "test", + "state_topic": "test-topic", + "payload_on": "ON", + "payload_off": "OFF", + } + }, + ) + + state = hass.states.get("binary_sensor.test") + + assert state.state == STATE_OFF + + async_fire_mqtt_message(hass, "test-topic", "0N") + state = hass.states.get("binary_sensor.test") + assert state.state == STATE_OFF + assert "No matching payload found for entity" in caplog.text + caplog.clear() + assert "No matching payload found for entity" not in caplog.text + + async_fire_mqtt_message(hass, "test-topic", "ON") + state = hass.states.get("binary_sensor.test") + assert state.state == STATE_ON + + async_fire_mqtt_message(hass, "test-topic", "0FF") + state = hass.states.get("binary_sensor.test") + assert state.state == STATE_ON + assert "No matching payload found for entity" in caplog.text + + async def test_setting_sensor_value_via_mqtt_message_and_template(hass, mqtt_mock): """Test the setting of the value via MQTT.""" assert await async_setup_component( @@ -548,6 +587,7 @@ async def test_expiration_on_discovery_and_discovery_update_of_binary_sensor( assert state.state == STATE_UNAVAILABLE +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer",' ' "off_delay": -1 }' diff --git a/tests/components/mqtt/test_camera.py b/tests/components/mqtt/test_camera.py index cefeda04097..5747d876b57 100644 --- a/tests/components/mqtt/test_camera.py +++ b/tests/components/mqtt/test_camera.py @@ -1,6 +1,8 @@ """The tests for mqtt camera component.""" import json +import pytest + from homeassistant.components import camera, mqtt from homeassistant.components.mqtt.discovery import async_start from homeassistant.setup import async_setup_component @@ -155,6 +157,7 @@ async def test_discovery_update_camera(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" entry = MockConfigEntry(domain=mqtt.DOMAIN) diff --git a/tests/components/mqtt/test_climate.py b/tests/components/mqtt/test_climate.py index 9ae13a426b9..8c3bfebed20 100644 --- a/tests/components/mqtt/test_climate.py +++ b/tests/components/mqtt/test_climate.py @@ -868,6 +868,7 @@ async def test_discovery_update_climate(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer",' ' "power_command_topic": "test_topic#" }' diff --git a/tests/components/mqtt/test_common.py b/tests/components/mqtt/test_common.py index 4bc3bc1a937..bfd478a712e 100644 --- a/tests/components/mqtt/test_common.py +++ b/tests/components/mqtt/test_common.py @@ -252,7 +252,6 @@ async def help_test_unique_id(hass, domain, config): """Test unique id option only creates one entity per unique_id.""" await async_mock_mqtt_component(hass) assert await async_setup_component(hass, domain, config,) - async_fire_mqtt_message(hass, "test-topic", "payload") assert len(hass.states.async_entity_ids(domain)) == 1 diff --git a/tests/components/mqtt/test_cover.py b/tests/components/mqtt/test_cover.py index 6de462b9020..201bb17c7a8 100644 --- a/tests/components/mqtt/test_cover.py +++ b/tests/components/mqtt/test_cover.py @@ -1,4 +1,6 @@ """The tests for the MQTT cover platform.""" +import pytest + from homeassistant.components import cover from homeassistant.components.cover import ( ATTR_CURRENT_POSITION, @@ -1831,6 +1833,7 @@ async def test_discovery_update_cover(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer",' ' "command_topic": "test_topic#" }' diff --git a/tests/components/mqtt/test_device_trigger.py b/tests/components/mqtt/test_device_trigger.py index 7274badbed9..f77ccca57ef 100644 --- a/tests/components/mqtt/test_device_trigger.py +++ b/tests/components/mqtt/test_device_trigger.py @@ -134,6 +134,7 @@ async def test_get_non_existing_triggers(hass, device_reg, entity_reg, mqtt_mock assert_lists_same(triggers, []) +@pytest.mark.no_fail_on_log_exception async def test_discover_bad_triggers(hass, device_reg, entity_reg, mqtt_mock): """Test bad discovery message.""" config_entry = MockConfigEntry(domain=DOMAIN, data={}) diff --git a/tests/components/mqtt/test_fan.py b/tests/components/mqtt/test_fan.py index 6ef1c0aab86..d8b6ce00ee6 100644 --- a/tests/components/mqtt/test_fan.py +++ b/tests/components/mqtt/test_fan.py @@ -1,4 +1,6 @@ """Test MQTT fans.""" +import pytest + from homeassistant.components import fan from homeassistant.const import ( ATTR_ASSUMED_STATE, @@ -681,6 +683,7 @@ async def test_discovery_update_fan(hass, mqtt_mock, caplog): await help_test_discovery_update(hass, mqtt_mock, caplog, fan.DOMAIN, data1, data2) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' diff --git a/tests/components/mqtt/test_init.py b/tests/components/mqtt/test_init.py index 28cca6a856a..9ec5e09f276 100644 --- a/tests/components/mqtt/test_init.py +++ b/tests/components/mqtt/test_init.py @@ -821,6 +821,7 @@ async def test_setup_fails_without_config(hass): assert not await async_setup_component(hass, mqtt.DOMAIN, {}) +@pytest.mark.no_fail_on_log_exception async def test_message_callback_exception_gets_logged(hass, caplog): """Test exception raised by message handler.""" await async_mock_mqtt_component(hass) diff --git a/tests/components/mqtt/test_legacy_vacuum.py b/tests/components/mqtt/test_legacy_vacuum.py index 9e774bfdf1e..b402c23e299 100644 --- a/tests/components/mqtt/test_legacy_vacuum.py +++ b/tests/components/mqtt/test_legacy_vacuum.py @@ -2,6 +2,8 @@ from copy import deepcopy import json +import pytest + from homeassistant.components import vacuum from homeassistant.components.mqtt import CONF_COMMAND_TOPIC from homeassistant.components.mqtt.vacuum import schema_legacy as mqttvacuum @@ -612,6 +614,7 @@ async def test_discovery_update_vacuum(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer",' ' "command_topic": "test_topic#" }' diff --git a/tests/components/mqtt/test_light.py b/tests/components/mqtt/test_light.py index 3019b6b6ebd..9f5e65bd987 100644 --- a/tests/components/mqtt/test_light.py +++ b/tests/components/mqtt/test_light.py @@ -153,6 +153,8 @@ light: payload_off: "off" """ +import pytest + from homeassistant.components import light, mqtt from homeassistant.components.mqtt.discovery import async_start from homeassistant.const import ATTR_ASSUMED_STATE, STATE_OFF, STATE_ON @@ -1420,6 +1422,7 @@ async def test_discovery_update_light(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' diff --git a/tests/components/mqtt/test_light_json.py b/tests/components/mqtt/test_light_json.py index f640d287a1b..23c83dabde7 100644 --- a/tests/components/mqtt/test_light_json.py +++ b/tests/components/mqtt/test_light_json.py @@ -89,6 +89,8 @@ light: """ import json +import pytest + from homeassistant.components import light from homeassistant.const import ( ATTR_ASSUMED_STATE, @@ -1155,6 +1157,7 @@ async def test_discovery_update_light(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' @@ -1214,5 +1217,5 @@ async def test_entity_id_update_discovery_update(hass, mqtt_mock): async def test_entity_debug_info_message(hass, mqtt_mock): """Test MQTT debug info.""" await help_test_entity_debug_info_message( - hass, mqtt_mock, light.DOMAIN, DEFAULT_CONFIG + hass, mqtt_mock, light.DOMAIN, DEFAULT_CONFIG, payload='{"state":"ON"}' ) diff --git a/tests/components/mqtt/test_light_template.py b/tests/components/mqtt/test_light_template.py index 29adc555bc5..611ba07c3d6 100644 --- a/tests/components/mqtt/test_light_template.py +++ b/tests/components/mqtt/test_light_template.py @@ -26,6 +26,8 @@ If your light doesn't support white value feature, omit `white_value_template`. If your light doesn't support RGB feature, omit `(red|green|blue)_template`. """ +import pytest + from homeassistant.components import light from homeassistant.const import ( ATTR_ASSUMED_STATE, @@ -901,6 +903,7 @@ async def test_discovery_update_light(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' @@ -961,6 +964,15 @@ async def test_entity_id_update_discovery_update(hass, mqtt_mock): async def test_entity_debug_info_message(hass, mqtt_mock): """Test MQTT debug info.""" - await help_test_entity_debug_info_message( - hass, mqtt_mock, light.DOMAIN, DEFAULT_CONFIG - ) + config = { + light.DOMAIN: { + "platform": "mqtt", + "schema": "template", + "name": "test", + "command_topic": "test-topic", + "command_on_template": "on,{{ transition }}", + "command_off_template": "off,{{ transition|d }}", + "state_template": '{{ value.split(",")[0] }}', + } + } + await help_test_entity_debug_info_message(hass, mqtt_mock, light.DOMAIN, config) diff --git a/tests/components/mqtt/test_lock.py b/tests/components/mqtt/test_lock.py index a6e01102152..80ecbde3c4d 100644 --- a/tests/components/mqtt/test_lock.py +++ b/tests/components/mqtt/test_lock.py @@ -1,4 +1,6 @@ """The tests for the MQTT lock platform.""" +import pytest + from homeassistant.components.lock import ( DOMAIN as LOCK_DOMAIN, SERVICE_LOCK, @@ -366,6 +368,7 @@ async def test_discovery_update_lock(hass, mqtt_mock, caplog): await help_test_discovery_update(hass, mqtt_mock, caplog, LOCK_DOMAIN, data1, data2) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' diff --git a/tests/components/mqtt/test_sensor.py b/tests/components/mqtt/test_sensor.py index 1acc7656a8b..58c98f02484 100644 --- a/tests/components/mqtt/test_sensor.py +++ b/tests/components/mqtt/test_sensor.py @@ -2,6 +2,8 @@ from datetime import datetime, timedelta import json +import pytest + from homeassistant.components import mqtt from homeassistant.components.mqtt.discovery import async_start import homeassistant.components.sensor as sensor @@ -361,6 +363,7 @@ async def test_discovery_update_sensor(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer",' ' "state_topic": "test_topic#" }' diff --git a/tests/components/mqtt/test_state_vacuum.py b/tests/components/mqtt/test_state_vacuum.py index 367b9ceda8a..15429e6bc57 100644 --- a/tests/components/mqtt/test_state_vacuum.py +++ b/tests/components/mqtt/test_state_vacuum.py @@ -2,6 +2,8 @@ from copy import deepcopy import json +import pytest + from homeassistant.components import vacuum from homeassistant.components.mqtt import CONF_COMMAND_TOPIC, CONF_STATE_TOPIC from homeassistant.components.mqtt.vacuum import CONF_SCHEMA, schema_state as mqttvacuum @@ -298,6 +300,7 @@ async def test_no_fan_vacuum(hass, mqtt_mock): assert state.attributes.get(ATTR_BATTERY_LEVEL) == 61 +@pytest.mark.no_fail_on_log_exception async def test_status_invalid_json(hass, mqtt_mock): """Test to make sure nothing breaks if the vacuum sends bad JSON.""" config = deepcopy(DEFAULT_CONFIG) @@ -406,6 +409,7 @@ async def test_discovery_update_vacuum(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "schema": "state", "name": "Beer",' ' "command_topic": "test_topic#"}' @@ -460,5 +464,5 @@ async def test_entity_id_update_discovery_update(hass, mqtt_mock): async def test_entity_debug_info_message(hass, mqtt_mock): """Test MQTT debug info.""" await help_test_entity_debug_info_message( - hass, mqtt_mock, vacuum.DOMAIN, DEFAULT_CONFIG_2 + hass, mqtt_mock, vacuum.DOMAIN, DEFAULT_CONFIG_2, payload="{}" ) diff --git a/tests/components/mqtt/test_switch.py b/tests/components/mqtt/test_switch.py index c34d32a3c9d..b51812d2fa3 100644 --- a/tests/components/mqtt/test_switch.py +++ b/tests/components/mqtt/test_switch.py @@ -314,6 +314,7 @@ async def test_discovery_update_switch(hass, mqtt_mock, caplog): ) +@pytest.mark.no_fail_on_log_exception async def test_discovery_broken(hass, mqtt_mock, caplog): """Test handling of bad discovery message.""" data1 = '{ "name": "Beer" }' diff --git a/tests/conftest.py b/tests/conftest.py index c7885c6125e..efaf1ff7dff 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -19,6 +19,7 @@ from homeassistant.setup import async_setup_component from homeassistant.util import location from tests.async_mock import patch +from tests.ignore_uncaught_exceptions import IGNORE_UNCAUGHT_EXCEPTIONS pytest.register_assert_rewrite("tests.common") @@ -36,6 +37,13 @@ logging.basicConfig(level=logging.DEBUG) logging.getLogger("sqlalchemy.engine").setLevel(logging.INFO) +def pytest_configure(config): + """Register marker for tests that log exceptions.""" + config.addinivalue_line( + "markers", "no_fail_on_log_exception: mark test to not fail on logged exception" + ) + + def check_real(func): """Force a function to require a keyword _test_real to be passed in.""" @@ -95,6 +103,11 @@ def hass(loop, hass_storage, request): loop.run_until_complete(hass.async_stop(force=True)) for ex in exceptions: + if ( + request.module.__name__, + request.function.__name__, + ) in IGNORE_UNCAUGHT_EXCEPTIONS: + continue if isinstance(ex, ServiceNotFound): continue raise ex @@ -242,3 +255,15 @@ def hass_ws_client(aiohttp_client, hass_access_token, hass): return websocket return create_client + + +@pytest.fixture(autouse=True) +def fail_on_log_exception(request, monkeypatch): + """Fixture to fail if a callback wrapped by catch_log_exception or coroutine wrapped by async_create_catching_coro throws.""" + if "no_fail_on_log_exception" in request.keywords: + return + + def log_exception(format_err, *args): + raise + + monkeypatch.setattr("homeassistant.util.logging.log_exception", log_exception) diff --git a/tests/helpers/test_dispatcher.py b/tests/helpers/test_dispatcher.py index d2aa939043c..09c7942d08f 100644 --- a/tests/helpers/test_dispatcher.py +++ b/tests/helpers/test_dispatcher.py @@ -1,6 +1,8 @@ """Test dispatcher helpers.""" from functools import partial +import pytest + from homeassistant.core import callback from homeassistant.helpers.dispatcher import ( async_dispatcher_connect, @@ -128,6 +130,7 @@ async def test_simple_function_multiargs(hass): assert calls == [3, 2, "bla"] +@pytest.mark.no_fail_on_log_exception async def test_callback_exception_gets_logged(hass, caplog): """Test exception raised by signal handler.""" diff --git a/tests/ignore_uncaught_exceptions.py b/tests/ignore_uncaught_exceptions.py new file mode 100644 index 00000000000..1325d76791c --- /dev/null +++ b/tests/ignore_uncaught_exceptions.py @@ -0,0 +1,12 @@ +"""List of tests that have uncaught exceptions today. Will be shrunk over time.""" +IGNORE_UNCAUGHT_EXCEPTIONS = [ + ("test_homeassistant_bridge", "test_homeassistant_bridge_fan_setup",), + ( + "tests.components.owntracks.test_device_tracker", + "test_mobile_multiple_async_enter_exit", + ), + ( + "tests.components.smartthings.test_init", + "test_event_handler_dispatches_updated_devices", + ), +] diff --git a/tests/util/test_logging.py b/tests/util/test_logging.py index c2c9d4803f9..2d05157e26f 100644 --- a/tests/util/test_logging.py +++ b/tests/util/test_logging.py @@ -3,6 +3,8 @@ import asyncio import logging import threading +import pytest + import homeassistant.util.logging as logging_util @@ -65,6 +67,7 @@ async def test_async_handler_thread_log(loop): assert queue.empty() +@pytest.mark.no_fail_on_log_exception async def test_async_create_catching_coro(hass, caplog): """Test exception logging of wrapped coroutine."""