From dd0f05b98069cc331b57614bcdab4e7a4b174003 Mon Sep 17 00:00:00 2001 From: "J. Nick Koston" Date: Thu, 23 Mar 2023 09:55:02 -1000 Subject: [PATCH] Avoid calling the http access logging when logging is disabled (#90152) --- homeassistant/components/http/__init__.py | 24 ++++++++- tests/components/http/test_init.py | 60 ++++++++++++++++++++++- 2 files changed, 82 insertions(+), 2 deletions(-) diff --git a/homeassistant/components/http/__init__.py b/homeassistant/components/http/__init__.py index 04b94dc3b81..3106eea05fa 100644 --- a/homeassistant/components/http/__init__.py +++ b/homeassistant/components/http/__init__.py @@ -12,6 +12,7 @@ from typing import Any, Final, TypedDict, cast from aiohttp import web from aiohttp.typedefs import StrOrURL from aiohttp.web_exceptions import HTTPMovedPermanently, HTTPRedirection +from aiohttp.web_log import AccessLogger from cryptography import x509 from cryptography.hazmat.primitives import hashes, serialization from cryptography.hazmat.primitives.asymmetric import rsa @@ -220,6 +221,25 @@ async def async_setup(hass: HomeAssistant, config: ConfigType) -> bool: return True +class HomeAssistantAccessLogger(AccessLogger): + """Access logger for Home Assistant that does not log when disabled.""" + + def log( + self, request: web.BaseRequest, response: web.StreamResponse, time: float + ) -> None: + """Log the request. + + The default implementation logs the request to the logger + with the INFO level and than throws it away if the logger + is not enabled for the INFO level. This implementation + does not log the request if the logger is not enabled for + the INFO level. + """ + if not self.logger.isEnabledFor(logging.INFO): + return + super().log(request, response, time) + + class HomeAssistantHTTP: """HTTP server for Home Assistant.""" @@ -462,7 +482,9 @@ class HomeAssistantHTTP: # pylint: disable-next=protected-access self.app._router.freeze = lambda: None # type: ignore[method-assign] - self.runner = web.AppRunner(self.app) + self.runner = web.AppRunner( + self.app, access_log_class=HomeAssistantAccessLogger + ) await self.runner.setup() self.site = HomeAssistantTCPSite( diff --git a/tests/components/http/test_init.py b/tests/components/http/test_init.py index 578fcc60c7c..0c346ab947c 100644 --- a/tests/components/http/test_init.py +++ b/tests/components/http/test_init.py @@ -1,10 +1,12 @@ """The tests for the Home Assistant HTTP component.""" +import asyncio from datetime import timedelta from http import HTTPStatus from ipaddress import ip_network import logging import pathlib -from unittest.mock import Mock, patch +import time +from unittest.mock import MagicMock, Mock, patch import py import pytest @@ -20,6 +22,7 @@ from homeassistant.util import dt as dt_util from homeassistant.util.ssl import server_context_intermediate, server_context_modern from tests.common import async_fire_time_changed +from tests.test_util.aiohttp import AiohttpClientMockResponse from tests.typing import ClientSessionGenerator @@ -463,3 +466,58 @@ async def test_storing_config( restored["trusted_proxies"][0] = ip_network(restored["trusted_proxies"][0]) assert restored == http.HTTP_SCHEMA(config) + + +async def test_logging( + hass: HomeAssistant, + hass_client: ClientSessionGenerator, + caplog: pytest.LogCaptureFixture, +) -> None: + """Testing the access log works.""" + await asyncio.gather( + *( + async_setup_component(hass, component, {}) + for component in ("http", "logger", "api") + ) + ) + hass.states.async_set("logging.entity", "hello") + await hass.services.async_call( + "logger", + "set_level", + {"aiohttp.access": "info"}, + blocking=True, + ) + client = await hass_client() + response = await client.get("/api/states/logging.entity") + assert response.status == HTTPStatus.OK + + assert "GET /api/states/logging.entity" in caplog.text + caplog.clear() + await hass.services.async_call( + "logger", + "set_level", + {"aiohttp.access": "warning"}, + blocking=True, + ) + response = await client.get("/api/states/logging.entity") + assert response.status == HTTPStatus.OK + assert "GET /api/states/logging.entity" not in caplog.text + + +async def test_hass_access_logger_at_info_level( + hass: HomeAssistant, caplog: pytest.LogCaptureFixture +) -> None: + """Test that logging happens at info level.""" + test_logger = logging.getLogger("test.aiohttp.logger") + logger = http.HomeAssistantAccessLogger(test_logger) + mock_request = MagicMock() + response = AiohttpClientMockResponse( + "POST", "http://127.0.0.1", status=HTTPStatus.OK + ) + setattr(response, "body_length", 42) + logger.log(mock_request, response, time.time()) + assert "42" in caplog.text + caplog.clear() + test_logger.setLevel(logging.WARNING) + logger.log(mock_request, response, time.time()) + assert "42" not in caplog.text