Create log files in an executor thread (#120912)

This commit is contained in:
Erik Montnemery 2024-07-02 15:48:35 +02:00 committed by GitHub
parent faf43ed4c7
commit b8b7c23258
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
2 changed files with 47 additions and 40 deletions

View file

@ -8,7 +8,7 @@ import contextlib
from functools import partial from functools import partial
from itertools import chain from itertools import chain
import logging import logging
import logging.handlers from logging.handlers import RotatingFileHandler, TimedRotatingFileHandler
import mimetypes import mimetypes
from operator import contains, itemgetter from operator import contains, itemgetter
import os import os
@ -257,12 +257,12 @@ async def async_setup_hass(
) -> core.HomeAssistant | None: ) -> core.HomeAssistant | None:
"""Set up Home Assistant.""" """Set up Home Assistant."""
def create_hass() -> core.HomeAssistant: async def create_hass() -> core.HomeAssistant:
"""Create the hass object and do basic setup.""" """Create the hass object and do basic setup."""
hass = core.HomeAssistant(runtime_config.config_dir) hass = core.HomeAssistant(runtime_config.config_dir)
loader.async_setup(hass) loader.async_setup(hass)
async_enable_logging( await async_enable_logging(
hass, hass,
runtime_config.verbose, runtime_config.verbose,
runtime_config.log_rotate_days, runtime_config.log_rotate_days,
@ -287,7 +287,7 @@ async def async_setup_hass(
async with hass.timeout.async_timeout(10): async with hass.timeout.async_timeout(10):
await hass.async_stop() await hass.async_stop()
hass = create_hass() hass = await create_hass()
if runtime_config.skip_pip or runtime_config.skip_pip_packages: if runtime_config.skip_pip or runtime_config.skip_pip_packages:
_LOGGER.warning( _LOGGER.warning(
@ -326,13 +326,13 @@ async def async_setup_hass(
if config_dict is None: if config_dict is None:
recovery_mode = True recovery_mode = True
await stop_hass(hass) await stop_hass(hass)
hass = create_hass() hass = await create_hass()
elif not basic_setup_success: elif not basic_setup_success:
_LOGGER.warning("Unable to set up core integrations. Activating recovery mode") _LOGGER.warning("Unable to set up core integrations. Activating recovery mode")
recovery_mode = True recovery_mode = True
await stop_hass(hass) await stop_hass(hass)
hass = create_hass() hass = await create_hass()
elif any(domain not in hass.config.components for domain in CRITICAL_INTEGRATIONS): elif any(domain not in hass.config.components for domain in CRITICAL_INTEGRATIONS):
_LOGGER.warning( _LOGGER.warning(
@ -345,7 +345,7 @@ async def async_setup_hass(
recovery_mode = True recovery_mode = True
await stop_hass(hass) await stop_hass(hass)
hass = create_hass() hass = await create_hass()
if old_logging: if old_logging:
hass.data[DATA_LOGGING] = old_logging hass.data[DATA_LOGGING] = old_logging
@ -523,8 +523,7 @@ async def async_from_config_dict(
return hass return hass
@core.callback async def async_enable_logging(
def async_enable_logging(
hass: core.HomeAssistant, hass: core.HomeAssistant,
verbose: bool = False, verbose: bool = False,
log_rotate_days: int | None = None, log_rotate_days: int | None = None,
@ -607,23 +606,9 @@ def async_enable_logging(
if (err_path_exists and os.access(err_log_path, os.W_OK)) or ( if (err_path_exists and os.access(err_log_path, os.W_OK)) or (
not err_path_exists and os.access(err_dir, os.W_OK) not err_path_exists and os.access(err_dir, os.W_OK)
): ):
err_handler: ( err_handler = await hass.async_add_executor_job(
logging.handlers.RotatingFileHandler _create_log_file, err_log_path, log_rotate_days
| logging.handlers.TimedRotatingFileHandler
) )
if log_rotate_days:
err_handler = logging.handlers.TimedRotatingFileHandler(
err_log_path, when="midnight", backupCount=log_rotate_days
)
else:
err_handler = _RotatingFileHandlerWithoutShouldRollOver(
err_log_path, backupCount=1
)
try:
err_handler.doRollover()
except OSError as err:
_LOGGER.error("Error rolling over log file: %s", err)
err_handler.setLevel(logging.INFO if verbose else logging.WARNING) err_handler.setLevel(logging.INFO if verbose else logging.WARNING)
err_handler.setFormatter(logging.Formatter(fmt, datefmt=FORMAT_DATETIME)) err_handler.setFormatter(logging.Formatter(fmt, datefmt=FORMAT_DATETIME))
@ -640,7 +625,29 @@ def async_enable_logging(
async_activate_log_queue_handler(hass) async_activate_log_queue_handler(hass)
class _RotatingFileHandlerWithoutShouldRollOver(logging.handlers.RotatingFileHandler): def _create_log_file(
err_log_path: str, log_rotate_days: int | None
) -> RotatingFileHandler | TimedRotatingFileHandler:
"""Create log file and do roll over."""
err_handler: RotatingFileHandler | TimedRotatingFileHandler
if log_rotate_days:
err_handler = TimedRotatingFileHandler(
err_log_path, when="midnight", backupCount=log_rotate_days
)
else:
err_handler = _RotatingFileHandlerWithoutShouldRollOver(
err_log_path, backupCount=1
)
try:
err_handler.doRollover()
except OSError as err:
_LOGGER.error("Error rolling over log file: %s", err)
return err_handler
class _RotatingFileHandlerWithoutShouldRollOver(RotatingFileHandler):
"""RotatingFileHandler that does not check if it should roll over on every log.""" """RotatingFileHandler that does not check if it should roll over on every log."""
def shouldRollover(self, record: logging.LogRecord) -> bool: def shouldRollover(self, record: logging.LogRecord) -> bool:

View file

@ -69,7 +69,7 @@ def mock_http_start_stop() -> Generator[None]:
yield yield
@patch("homeassistant.bootstrap.async_enable_logging", Mock()) @patch("homeassistant.bootstrap.async_enable_logging", AsyncMock())
async def test_home_assistant_core_config_validation(hass: HomeAssistant) -> None: async def test_home_assistant_core_config_validation(hass: HomeAssistant) -> None:
"""Test if we pass in wrong information for HA conf.""" """Test if we pass in wrong information for HA conf."""
# Extensive HA conf validation testing is done # Extensive HA conf validation testing is done
@ -93,10 +93,10 @@ async def test_async_enable_logging(
side_effect=OSError, side_effect=OSError,
), ),
): ):
bootstrap.async_enable_logging(hass) await bootstrap.async_enable_logging(hass)
mock_async_activate_log_queue_handler.assert_called_once() mock_async_activate_log_queue_handler.assert_called_once()
mock_async_activate_log_queue_handler.reset_mock() mock_async_activate_log_queue_handler.reset_mock()
bootstrap.async_enable_logging( await bootstrap.async_enable_logging(
hass, hass,
log_rotate_days=5, log_rotate_days=5,
log_file="test.log", log_file="test.log",
@ -140,7 +140,7 @@ async def test_config_does_not_turn_off_debug(hass: HomeAssistant) -> None:
@pytest.mark.parametrize("hass_config", [{"frontend": {}}]) @pytest.mark.parametrize("hass_config", [{"frontend": {}}])
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_asyncio_debug_on_turns_hass_debug_on( async def test_asyncio_debug_on_turns_hass_debug_on(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -597,7 +597,7 @@ def mock_is_virtual_env() -> Generator[Mock]:
@pytest.fixture @pytest.fixture
def mock_enable_logging() -> Generator[Mock]: def mock_enable_logging() -> Generator[AsyncMock]:
"""Mock enable logging.""" """Mock enable logging."""
with patch("homeassistant.bootstrap.async_enable_logging") as enable_logging: with patch("homeassistant.bootstrap.async_enable_logging") as enable_logging:
yield enable_logging yield enable_logging
@ -633,7 +633,7 @@ def mock_ensure_config_exists() -> Generator[AsyncMock]:
@pytest.mark.parametrize("hass_config", [{"browser": {}, "frontend": {}}]) @pytest.mark.parametrize("hass_config", [{"browser": {}, "frontend": {}}])
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_setup_hass( async def test_setup_hass(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -686,7 +686,7 @@ async def test_setup_hass(
@pytest.mark.parametrize("hass_config", [{"browser": {}, "frontend": {}}]) @pytest.mark.parametrize("hass_config", [{"browser": {}, "frontend": {}}])
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_setup_hass_takes_longer_than_log_slow_startup( async def test_setup_hass_takes_longer_than_log_slow_startup(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -727,7 +727,7 @@ async def test_setup_hass_takes_longer_than_log_slow_startup(
async def test_setup_hass_invalid_yaml( async def test_setup_hass_invalid_yaml(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -754,7 +754,7 @@ async def test_setup_hass_invalid_yaml(
async def test_setup_hass_config_dir_nonexistent( async def test_setup_hass_config_dir_nonexistent(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -780,7 +780,7 @@ async def test_setup_hass_config_dir_nonexistent(
async def test_setup_hass_recovery_mode( async def test_setup_hass_recovery_mode(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -816,7 +816,7 @@ async def test_setup_hass_recovery_mode(
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_setup_hass_safe_mode( async def test_setup_hass_safe_mode(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -851,7 +851,7 @@ async def test_setup_hass_safe_mode(
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_setup_hass_recovery_mode_and_safe_mode( async def test_setup_hass_recovery_mode_and_safe_mode(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -887,7 +887,7 @@ async def test_setup_hass_recovery_mode_and_safe_mode(
@pytest.mark.parametrize("hass_config", [{"homeassistant": {"non-existing": 1}}]) @pytest.mark.parametrize("hass_config", [{"homeassistant": {"non-existing": 1}}])
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_setup_hass_invalid_core_config( async def test_setup_hass_invalid_core_config(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,
@ -926,7 +926,7 @@ async def test_setup_hass_invalid_core_config(
) )
@pytest.mark.usefixtures("mock_hass_config") @pytest.mark.usefixtures("mock_hass_config")
async def test_setup_recovery_mode_if_no_frontend( async def test_setup_recovery_mode_if_no_frontend(
mock_enable_logging: Mock, mock_enable_logging: AsyncMock,
mock_is_virtual_env: Mock, mock_is_virtual_env: Mock,
mock_mount_local_lib_path: AsyncMock, mock_mount_local_lib_path: AsyncMock,
mock_ensure_config_exists: AsyncMock, mock_ensure_config_exists: AsyncMock,