Suppress repeated Splunk send-failure logs during sustained outages (#181806)

Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>

homeassistant/components/splunk/__init__.py

@@ -143,8 +143,19 @@ async def async_setup_entry(hass: HomeAssistant, entry: ConfigEntry) -> bool:
 
     await event_collector.queue(json.dumps(payload, cls=JSONEncoder), send=False)
 
+    send_failing = False
+
+    def log_send_failure(level: int, message: str, *args: Any) -> None:
+        """Log a send failure, demoting it to debug while an outage is open."""
+        nonlocal send_failing
+
+        _LOGGER.log(logging.DEBUG if send_failing else level, message, *args)
+        send_failing = True
+
     async def splunk_event_listener(event: Event[EventStateChangedData]) -> None:
         """Listen for new messages on the bus and sends them to Splunk."""
+        nonlocal send_failing
+
         state = event.data.get("new_state")
         if state is None or not entity_filter(state.entity_id):
             return
@@ -167,22 +178,47 @@ async def async_setup_entry(hass: HomeAssistant, entry: ConfigEntry) -> bool:
         }
 
         try:
-            await event_collector.queue(json.dumps(payload, cls=JSONEncoder), send=True)
+            sent = await event_collector.queue(
+                json.dumps(payload, cls=JSONEncoder), send=True
+            )
         except SplunkPayloadError as err:
             if err.status == HTTPStatus.UNAUTHORIZED:
-                _LOGGER.error("Splunk token unauthorized: %s", err)
-                # Trigger reauth flow
                 entry.async_start_reauth(hass)
+                log_send_failure(logging.ERROR, "Splunk token unauthorized: %s", err)
             else:
-                _LOGGER.warning("Splunk payload error: %s", err)
+                log_send_failure(logging.WARNING, "Splunk payload error: %s", err)
+            return
         except ClientConnectionError as err:
-            _LOGGER.debug("Connection error sending to Splunk: %s", err)
+            log_send_failure(
+                logging.DEBUG, "Connection error sending to Splunk: %s", err
+            )
+            return
         except TimeoutError:
-            _LOGGER.debug("Timeout sending to Splunk at %s:%s", host, port)
+            log_send_failure(
+                logging.DEBUG, "Timeout sending to Splunk at %s:%s", host, port
+            )
+            return
         except ClientResponseError as err:
-            _LOGGER.warning("Splunk response error: %s", err.message)
+            log_send_failure(logging.WARNING, "Splunk response error: %s", err.message)
+            return
         except Exception:
-            _LOGGER.exception("Unexpected error sending event to Splunk")
+            # Logged in the handler, so the traceback is still available.
+            _LOGGER.log(
+                logging.DEBUG if send_failing else logging.ERROR,
+                "Unexpected error sending event to Splunk",
+                exc_info=not send_failing,
+            )
+            send_failing = True
+            return
+
+        if not sent:
+            # Coalesced into an in-flight send, which says nothing about
+            # whether this event reached Splunk.
+            return
+
+        if send_failing:
+            _LOGGER.info("Sending events to Splunk has recovered")
+            send_failing = False
 
     # Store the event listener cancellation callback
     entry.async_on_unload(

tests/components/splunk/test_init.py

@@ -229,6 +229,11 @@ async def test_event_listener_unauthorized(
             logging.WARNING,
             "Splunk response error: Internal Server Error",
         ),
+        (
+            SplunkPayloadError(0, "Bad request", HTTPStatus.BAD_REQUEST),
+            logging.WARNING,
+            "Splunk payload error: Bad request",
+        ),
     ],
 )
 async def test_event_listener_error_handling(
@@ -262,3 +267,270 @@ async def test_event_listener_error_handling(
         record.levelno == expected_log_level and expected_message in record.message
         for record in caplog.records
     )
+
+
+@pytest.mark.parametrize(
+    ("error", "expected_log_level", "expected_message", "expected_traceback"),
+    [
+        (
+            ClientResponseError(
+                request_info=MagicMock(),
+                history=(),
+                status=500,
+                message="Internal Server Error",
+            ),
+            logging.WARNING,
+            "Splunk response error: Internal Server Error",
+            False,
+        ),
+        (
+            SplunkPayloadError(0, "Unauthorized", HTTPStatus.UNAUTHORIZED),
+            logging.ERROR,
+            "Splunk token unauthorized",
+            False,
+        ),
+        (
+            ValueError("boom"),
+            logging.ERROR,
+            "Unexpected error sending event to Splunk",
+            True,
+        ),
+    ],
+)
+async def test_event_listener_repeated_failures_log_at_debug(
+    hass: HomeAssistant,
+    mock_hass_splunk: AsyncMock,
+    mock_config_entry: MockConfigEntry,
+    caplog: pytest.LogCaptureFixture,
+    error: Exception,
+    expected_log_level: int,
+    expected_message: str,
+    expected_traceback: bool,
+) -> None:
+    """Test the first failure logs at its level and the repeats log at debug."""
+    mock_config_entry.add_to_hass(hass)
+
+    assert await hass.config_entries.async_setup(mock_config_entry.entry_id)
+    await hass.async_block_till_done()
+
+    mock_hass_splunk.queue.side_effect = error
+
+    with caplog.at_level(logging.DEBUG):
+        for i in range(5):
+            hass.states.async_set("sensor.test", str(i))
+            await hass.async_block_till_done()
+
+    matching_records = [
+        record for record in caplog.records if expected_message in record.message
+    ]
+    assert len(matching_records) == 5
+    assert matching_records[0].levelno == expected_log_level
+    # A traceback is worth one record per outage, never one per state change.
+    assert bool(matching_records[0].exc_info) is expected_traceback
+    assert all(record.levelno == logging.DEBUG for record in matching_records[1:])
+    assert not any(record.exc_info for record in matching_records[1:])
+
+
+@pytest.mark.parametrize(
+    ("first_error", "first_message", "first_level", "second_error", "second_message"),
+    [
+        pytest.param(
+            ClientConnectionError("Connection failed"),
+            "Connection error sending to Splunk",
+            logging.DEBUG,
+            SplunkPayloadError(0, "Unauthorized", HTTPStatus.UNAUTHORIZED),
+            "Splunk token unauthorized",
+            id="more_severe_second_failure",
+        ),
+        pytest.param(
+            SplunkPayloadError(0, "Unauthorized", HTTPStatus.UNAUTHORIZED),
+            "Splunk token unauthorized",
+            logging.ERROR,
+            ClientResponseError(
+                request_info=MagicMock(),
+                history=(),
+                status=500,
+                message="Internal Server Error",
+            ),
+            "Splunk response error: Internal Server Error",
+            id="less_severe_second_failure",
+        ),
+    ],
+)
+async def test_event_listener_different_failure_during_outage_logs_at_debug(
+    hass: HomeAssistant,
+    mock_hass_splunk: AsyncMock,
+    mock_config_entry: MockConfigEntry,
+    caplog: pytest.LogCaptureFixture,
+    first_error: Exception,
+    first_message: str,
+    first_level: int,
+    second_error: Exception,
+    second_message: str,
+) -> None:
+    """Test a different failure during an outage logs at debug, whatever its level."""
+    mock_config_entry.add_to_hass(hass)
+
+    assert await hass.config_entries.async_setup(mock_config_entry.entry_id)
+    await hass.async_block_till_done()
+
+    with caplog.at_level(logging.DEBUG):
+        mock_hass_splunk.queue.side_effect = first_error
+        hass.states.async_set("sensor.test", "outage")
+        await hass.async_block_till_done()
+
+        mock_hass_splunk.queue.side_effect = second_error
+        for i in range(2):
+            hass.states.async_set("sensor.test", f"different-{i}")
+            await hass.async_block_till_done()
+
+    first_records = [
+        record for record in caplog.records if first_message in record.message
+    ]
+    assert len(first_records) == 1
+    assert first_records[0].levelno == first_level
+
+    second_records = [
+        record for record in caplog.records if second_message in record.message
+    ]
+    assert len(second_records) == 2
+    assert all(record.levelno == logging.DEBUG for record in second_records)
+
+
+async def test_event_listener_recovery_logs_once_at_info(
+    hass: HomeAssistant,
+    mock_hass_splunk: AsyncMock,
+    mock_config_entry: MockConfigEntry,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Test a recovered outage logs a single info record."""
+    mock_config_entry.add_to_hass(hass)
+
+    assert await hass.config_entries.async_setup(mock_config_entry.entry_id)
+    await hass.async_block_till_done()
+
+    mock_hass_splunk.queue.side_effect = ClientConnectionError("Connection failed")
+
+    with caplog.at_level(logging.DEBUG):
+        for i in range(2):
+            hass.states.async_set("sensor.test", str(i))
+            await hass.async_block_till_done()
+
+        mock_hass_splunk.queue.side_effect = None
+        for i in range(2):
+            hass.states.async_set("sensor.test", f"recovered-{i}")
+            await hass.async_block_till_done()
+
+    recovery_records = [
+        record
+        for record in caplog.records
+        if "Sending events to Splunk has recovered" in record.message
+    ]
+    assert len(recovery_records) == 1
+    assert recovery_records[0].levelno == logging.INFO
+
+
+async def test_event_listener_failure_after_recovery_logs_at_natural_level(
+    hass: HomeAssistant,
+    mock_hass_splunk: AsyncMock,
+    mock_config_entry: MockConfigEntry,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Test a new outage after a recovery logs at its natural level again."""
+    mock_config_entry.add_to_hass(hass)
+
+    assert await hass.config_entries.async_setup(mock_config_entry.entry_id)
+    await hass.async_block_till_done()
+
+    mock_hass_splunk.queue.side_effect = ClientConnectionError("Connection failed")
+
+    with caplog.at_level(logging.DEBUG):
+        hass.states.async_set("sensor.test", "first-outage")
+        await hass.async_block_till_done()
+
+        mock_hass_splunk.queue.side_effect = None
+        hass.states.async_set("sensor.test", "recovered")
+        await hass.async_block_till_done()
+
+        caplog.clear()
+        mock_hass_splunk.queue.side_effect = ClientResponseError(
+            request_info=MagicMock(),
+            history=(),
+            status=500,
+            message="Internal Server Error",
+        )
+        hass.states.async_set("sensor.test", "second-outage")
+        await hass.async_block_till_done()
+
+    assert any(
+        record.levelno == logging.WARNING
+        and "Splunk response error: Internal Server Error" in record.message
+        for record in caplog.records
+    )
+
+
+async def test_event_listener_coalesced_send_is_not_a_recovery(
+    hass: HomeAssistant,
+    mock_hass_splunk: AsyncMock,
+    mock_config_entry: MockConfigEntry,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Test a send coalesced into an in-flight send isn't treated as success.
+
+    hass_splunk.queue() returns False, without raising, when a send is already
+    in flight, which says nothing about whether this event reached Splunk.
+    """
+    mock_config_entry.add_to_hass(hass)
+
+    assert await hass.config_entries.async_setup(mock_config_entry.entry_id)
+    await hass.async_block_till_done()
+
+    error = ClientResponseError(
+        request_info=MagicMock(),
+        history=(),
+        status=500,
+        message="Internal Server Error",
+    )
+    mock_hass_splunk.queue.side_effect = [error, False, error]
+
+    with caplog.at_level(logging.DEBUG):
+        for i in range(3):
+            hass.states.async_set("sensor.test", str(i))
+            await hass.async_block_till_done()
+
+    assert not any(
+        "Sending events to Splunk has recovered" in record.message
+        for record in caplog.records
+    )
+
+    # Still demoted, so the coalesced send did not clear the outage either.
+    failure_records = [
+        record
+        for record in caplog.records
+        if "Splunk response error: Internal Server Error" in record.message
+    ]
+    assert len(failure_records) == 2
+    assert failure_records[0].levelno == logging.WARNING
+    assert failure_records[1].levelno == logging.DEBUG
+
+
+async def test_event_listener_no_recovery_message_without_prior_failure(
+    hass: HomeAssistant,
+    mock_hass_splunk: AsyncMock,
+    mock_config_entry: MockConfigEntry,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    """Test that a successful send without prior failures logs no recovery message."""
+    mock_config_entry.add_to_hass(hass)
+
+    assert await hass.config_entries.async_setup(mock_config_entry.entry_id)
+    await hass.async_block_till_done()
+
+    with caplog.at_level(logging.DEBUG):
+        hass.states.async_set("sensor.test", "123")
+        await hass.async_block_till_done()
+
+    assert not any(
+        "Sending events to Splunk has recovered" in record.message
+        for record in caplog.records
+    )