refactor: remove custom access logger

It is fine when application is able to log request, however, normally it
produces a lot noise, which has been handled by adding special logger.
However, nowadays it requires a lot endpoints to be filtered and doesn't
provide any choice.

Instead of it lets disable access logger by default and let users decide
do they need or not to see access log messages
This commit is contained in:
Evgenii Alekseev 2024-01-03 12:18:50 +02:00
parent 768132bb6c
commit 0e6434faad
9 changed files with 7 additions and 277 deletions

View File

@ -4,14 +4,6 @@ ahriman.core.log package
Submodules Submodules
---------- ----------
ahriman.core.log.filtered\_access\_logger module
------------------------------------------------
.. automodule:: ahriman.core.log.filtered_access_logger
:members:
:no-undoc-members:
:show-inheritance:
ahriman.core.log.http\_log\_handler module ahriman.core.log.http\_log\_handler module
------------------------------------------ ------------------------------------------

View File

@ -41,7 +41,7 @@ This package contains everything required for the most of application actions an
* ``ahriman.core.formatters`` package provides ``Printer`` sub-classes for printing data (e.g. package properties) to stdout which are used by some handlers. * ``ahriman.core.formatters`` package provides ``Printer`` sub-classes for printing data (e.g. package properties) to stdout which are used by some handlers.
* ``ahriman.core.gitremote`` is a package with remote PKGBUILD triggers. Should not be called directly. * ``ahriman.core.gitremote`` is a package with remote PKGBUILD triggers. Should not be called directly.
* ``ahriman.core.http`` package provides HTTP clients which can be used later by other classes. * ``ahriman.core.http`` package provides HTTP clients which can be used later by other classes.
* ``ahriman.core.log`` is a log utils package. It includes logger loader class, custom HTTP based logger and access logger for HTTP services with additional filters. * ``ahriman.core.log`` is a log utils package. It includes logger loader class, custom HTTP based logger and some wrappers.
* ``ahriman.core.report`` is a package with reporting triggers. Should not be called directly. * ``ahriman.core.report`` is a package with reporting triggers. Should not be called directly.
* ``ahriman.core.repository`` contains several traits and base repository (``ahriman.core.repository.Repository`` class) implementation. * ``ahriman.core.repository`` contains several traits and base repository (``ahriman.core.repository.Repository`` class) implementation.
* ``ahriman.core.sign`` package provides sign feature (only gpg calls are available). * ``ahriman.core.sign`` package provides sign feature (only gpg calls are available).

View File

@ -111,7 +111,7 @@ Reporting to web service related settings. In most cases there is fallback to we
* ``enabled`` - enable reporting to web service, boolean, optional, default ``yes`` for backward compatibility. * ``enabled`` - enable reporting to web service, boolean, optional, default ``yes`` for backward compatibility.
* ``address`` - remote web service address with protocol, string, optional. In case of websocket, the ``http+unix`` scheme and url encoded address (e.g. ``%2Fvar%2Flib%2Fahriman`` for ``/var/lib/ahriman``) must be used, e.g. ``http+unix://%2Fvar%2Flib%2Fahriman%2Fsocket``. In case if none set, it will be guessed from ``web`` section. * ``address`` - remote web service address with protocol, string, optional. In case of websocket, the ``http+unix`` scheme and url encoded address (e.g. ``%2Fvar%2Flib%2Fahriman`` for ``/var/lib/ahriman``) must be used, e.g. ``http+unix://%2Fvar%2Flib%2Fahriman%2Fsocket``. In case if none set, it will be guessed from ``web`` section.
* ``password`` - password to authorize in web service in order to update service status, string, required in case if authorization enabled. * ``password`` - password to authorize in web service in order to update service status, string, required in case if authorization enabled.
* ``suppress_http_log_errors`` - suppress http log errors, boolean, optional, default ``no``. If set to ``yes``, any http log errors (e.g. if web server is not available, but http logging is enabled) will be suppressed. * ``suppress_http_log_errors`` - suppress HTTP log errors, boolean, optional, default ``no``. If set to ``yes``, any HTTP log errors (e.g. if web server is not available, but HTTP logging is enabled) will be suppressed.
* ``timeout`` - HTTP request timeout in seconds, integer, optional, default is ``30``. * ``timeout`` - HTTP request timeout in seconds, integer, optional, default is ``30``.
* ``username`` - username to authorize in web service in order to update service status, string, required in case if authorization enabled. * ``username`` - username to authorize in web service in order to update service status, string, required in case if authorization enabled.

View File

@ -36,7 +36,7 @@ level = DEBUG
qualname = root qualname = root
[logger_http] [logger_http]
level = DEBUG level = WARNING
qualname = http qualname = http
propagate = 0 propagate = 0

View File

@ -1,108 +0,0 @@
#
# Copyright (c) 2021-2024 ahriman team.
#
# This file is part of ahriman
# (see https://github.com/arcan1s/ahriman).
#
# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
# the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.
#
# This program is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
#
import re
from aiohttp.web import AccessLogger, BaseRequest, StreamResponse
class FilteredAccessLogger(AccessLogger):
"""
access logger implementation with log filter enabled
Attributes:
DISTRIBUTED_PATH_REGEX(str): (class attribute) regex used for distributed system uri
HEALTH_PATH_REGEX(re.Pattern): (class attribute) regex for health check endpoint
LOG_PATH_REGEX(re.Pattern): (class attribute) regex for logs uri
PROCESS_PATH_REGEX(re.Pattern): (class attribute) regex for process uri
"""
DISTRIBUTED_PATH_REGEX = "/api/v1/distributed"
HEALTH_PATH_REGEX = "/api/v1/info"
LOG_PATH_REGEX = re.compile(r"^/api/v1/packages/[^/]+/logs$")
# technically process id is uuid, but we might change it later
PROCESS_PATH_REGEX = re.compile(r"^/api/v1/service/process/[^/]+$")
@staticmethod
def is_distributed_post(request: BaseRequest) -> bool:
"""
check if the request is for distributed services ping
Args:
request(BaseRequest): http reqeust descriptor
Returns:
bool: True in case if request is distributed service ping endpoint and False otherwise
"""
return request.method == "POST" and FilteredAccessLogger.DISTRIBUTED_PATH_REGEX == request.path
@staticmethod
def is_info_get(request: BaseRequest) -> bool:
"""
check if the request is for health check
Args:
request(BaseRequest): http reqeust descriptor
Returns:
bool: True in case if request is health check and false otherwise
"""
return request.method == "GET" and FilteredAccessLogger.HEALTH_PATH_REGEX == request.path
@staticmethod
def is_logs_post(request: BaseRequest) -> bool:
"""
check if request looks like logs posting
Args:
request(BaseRequest): http reqeust descriptor
Returns:
bool: True in case if request looks like logs positing and False otherwise
"""
return request.method == "POST" and FilteredAccessLogger.LOG_PATH_REGEX.match(request.path) is not None
@staticmethod
def is_process_get(request: BaseRequest) -> bool:
"""
check if request looks like process status request
Args:
request(BaseRequest): http reqeust descriptor
Returns:
bool: True in case if request looks like process status request and False otherwise
"""
return request.method == "GET" and FilteredAccessLogger.PROCESS_PATH_REGEX.match(request.path) is not None
def log(self, request: BaseRequest, response: StreamResponse, time: float) -> None:
"""
access log with enabled filter by request path
Args:
request(BaseRequest): http reqeust descriptor
response(StreamResponse): streaming response object
time(float): log record timestamp
"""
if self.is_distributed_post(request) \
or self.is_info_get(request) \
or self.is_logs_post(request) \
or self.is_process_get(request):
return
AccessLogger.log(self, request, response, time)

View File

@ -29,7 +29,6 @@ from ahriman.core.configuration import Configuration
from ahriman.core.database import SQLite from ahriman.core.database import SQLite
from ahriman.core.distributed import WorkersCache from ahriman.core.distributed import WorkersCache
from ahriman.core.exceptions import InitializeError from ahriman.core.exceptions import InitializeError
from ahriman.core.log.filtered_access_logger import FilteredAccessLogger
from ahriman.core.spawn import Spawn from ahriman.core.spawn import Spawn
from ahriman.core.status.watcher import Watcher from ahriman.core.status.watcher import Watcher
from ahriman.models.repository_id import RepositoryId from ahriman.models.repository_id import RepositoryId
@ -122,7 +121,7 @@ def run_server(application: Application) -> None:
unix_socket = _create_socket(configuration, application) unix_socket = _create_socket(configuration, application)
run_app(application, host=host, port=port, sock=unix_socket, handle_signals=True, run_app(application, host=host, port=port, sock=unix_socket, handle_signals=True,
access_log=logging.getLogger("http"), access_log_class=FilteredAccessLogger) access_log=logging.getLogger("http"))
def setup_server(configuration: Configuration, spawner: Spawn, repositories: list[RepositoryId]) -> Application: def setup_server(configuration: Configuration, spawner: Spawn, repositories: list[RepositoryId]) -> Application:

View File

@ -1,16 +0,0 @@
import logging
import pytest
from ahriman.core.log.filtered_access_logger import FilteredAccessLogger
@pytest.fixture
def filtered_access_logger() -> FilteredAccessLogger:
"""
fixture for custom access logger
Returns:
FilteredAccessLogger: custom access logger test instance
"""
logger = logging.getLogger()
return FilteredAccessLogger(logger)

View File

@ -1,136 +0,0 @@
from pytest_mock import MockerFixture
from unittest.mock import MagicMock
from ahriman.core.log.filtered_access_logger import FilteredAccessLogger
def test_is_distributed_post() -> None:
"""
must correctly define distributed services ping request
"""
request = MagicMock()
request.method = "POST"
request.path = "/api/v1/distributed"
assert FilteredAccessLogger.is_distributed_post(request)
request.method = "GET"
request.path = "/api/v1/distributed"
assert not FilteredAccessLogger.is_distributed_post(request)
request.method = "POST"
request.path = "/api/v1/distributed/path"
assert not FilteredAccessLogger.is_distributed_post(request)
def test_is_info_get() -> None:
"""
must correctly define health check request
"""
request = MagicMock()
request.method = "GET"
request.path = "/api/v1/info"
assert FilteredAccessLogger.is_info_get(request)
request.method = "POST"
request.path = "/api/v1/info"
assert not FilteredAccessLogger.is_info_get(request)
request.method = "GET"
request.path = "/api/v1/infos"
assert not FilteredAccessLogger.is_info_get(request)
def test_is_logs_post() -> None:
"""
must correctly define if request belongs to logs posting
"""
request = MagicMock()
request.method = "POST"
request.path = "/api/v1/packages/ahriman/logs"
assert FilteredAccessLogger.is_logs_post(request)
request.method = "POST"
request.path = "/api/v1/packages/linux-headers/logs"
assert FilteredAccessLogger.is_logs_post(request)
request.method = "POST"
request.path = "/api/v1/packages/memtest86+/logs"
assert FilteredAccessLogger.is_logs_post(request)
request.method = "POST"
request.path = "/api/v1/packages/memtest86%2B/logs"
assert FilteredAccessLogger.is_logs_post(request)
request.method = "POST"
request.path = "/api/v1/packages/python2.7/logs"
assert FilteredAccessLogger.is_logs_post(request)
request.method = "GET"
request.path = "/api/v1/packages/ahriman/logs"
assert not FilteredAccessLogger.is_logs_post(request)
request.method = "POST"
request.path = "/api/v1/packages/ahriman"
assert not FilteredAccessLogger.is_logs_post(request)
request.method = "POST"
request.path = "/api/v1/packages/ahriman/logs/random/path/after"
assert not FilteredAccessLogger.is_logs_post(request)
def test_is_process_get() -> None:
"""
must correctly define if request belongs to process get
"""
request = MagicMock()
request.method = "GET"
request.path = "/api/v1/service/process/e7d67119-264a-48f4-b7e4-07bc96a7de00"
assert FilteredAccessLogger.is_process_get(request)
request.method = "POST"
request.path = "/api/v1/service/process/e7d67119-264a-48f4-b7e4-07bc96a7de00"
assert not FilteredAccessLogger.is_process_get(request)
request.method = "GET"
request.path = "/api/v1/service/process/e7d67119-264a-48f4-b7e4-07bc96a7de00/some/random/path"
assert not FilteredAccessLogger.is_process_get(request)
request.method = "GET"
request.path = "/api/v1/service/process"
assert not FilteredAccessLogger.is_process_get(request)
request.method = "GET"
request.path = "/api/v1/service/process/"
assert not FilteredAccessLogger.is_process_get(request)
def test_log(filtered_access_logger: FilteredAccessLogger, mocker: MockerFixture) -> None:
"""
must emit log record
"""
request_mock = MagicMock()
response_mock = MagicMock()
is_log_path_mock = mocker.patch("ahriman.core.log.filtered_access_logger.FilteredAccessLogger.is_logs_post",
return_value=False)
log_mock = mocker.patch("aiohttp.web_log.AccessLogger.log")
filtered_access_logger.log(request_mock, response_mock, 0.001)
is_log_path_mock.assert_called_once_with(request_mock)
log_mock.assert_called_once_with(filtered_access_logger, request_mock, response_mock, 0.001)
def test_log_filter_logs(filtered_access_logger: FilteredAccessLogger, mocker: MockerFixture) -> None:
"""
must skip log record in case if it is from logs posting
"""
request_mock = MagicMock()
response_mock = MagicMock()
mocker.patch("ahriman.core.log.filtered_access_logger.FilteredAccessLogger.is_logs_post", return_value=True)
log_mock = mocker.patch("aiohttp.web_log.AccessLogger.log")
filtered_access_logger.log(request_mock, response_mock, 0.001)
log_mock.assert_not_called()

View File

@ -7,7 +7,6 @@ from unittest.mock import call as MockCall
from ahriman.core.configuration import Configuration from ahriman.core.configuration import Configuration
from ahriman.core.exceptions import InitializeError from ahriman.core.exceptions import InitializeError
from ahriman.core.log.filtered_access_logger import FilteredAccessLogger
from ahriman.core.spawn import Spawn from ahriman.core.spawn import Spawn
from ahriman.core.status.watcher import Watcher from ahriman.core.status.watcher import Watcher
from ahriman.web.keys import ConfigurationKey from ahriman.web.keys import ConfigurationKey
@ -104,7 +103,7 @@ def test_run(application: Application, mocker: MockerFixture) -> None:
run_server(application) run_server(application)
run_application_mock.assert_called_once_with( run_application_mock.assert_called_once_with(
application, host="127.0.0.1", port=port, sock=None, handle_signals=True, application, host="127.0.0.1", port=port, sock=None, handle_signals=True,
access_log=pytest.helpers.anyvar(int), access_log_class=FilteredAccessLogger access_log=pytest.helpers.anyvar(int),
) )
@ -119,7 +118,7 @@ def test_run_with_auth(application_with_auth: Application, mocker: MockerFixture
run_server(application_with_auth) run_server(application_with_auth)
run_application_mock.assert_called_once_with( run_application_mock.assert_called_once_with(
application_with_auth, host="127.0.0.1", port=port, sock=None, handle_signals=True, application_with_auth, host="127.0.0.1", port=port, sock=None, handle_signals=True,
access_log=pytest.helpers.anyvar(int), access_log_class=FilteredAccessLogger access_log=pytest.helpers.anyvar(int),
) )
@ -136,7 +135,7 @@ def test_run_with_socket(application: Application, mocker: MockerFixture) -> Non
socket_mock.assert_called_once_with(application[ConfigurationKey], application) socket_mock.assert_called_once_with(application[ConfigurationKey], application)
run_application_mock.assert_called_once_with( run_application_mock.assert_called_once_with(
application, host="127.0.0.1", port=port, sock=42, handle_signals=True, application, host="127.0.0.1", port=port, sock=42, handle_signals=True,
access_log=pytest.helpers.anyvar(int), access_log_class=FilteredAccessLogger access_log=pytest.helpers.anyvar(int),
) )