refine package logging

This commit is contained in:
2025-02-06 12:31:05 +02:00
parent 08640d9108
commit 10143ac3ee
32 changed files with 495 additions and 136 deletions

View File

@ -0,0 +1,8 @@
from ahriman.core.database.migrations.m015_logs_process_id import steps
def test_migration_logs_process_id() -> None:
"""
migration must not be empty
"""
assert steps

View File

@ -14,8 +14,12 @@ def test_logs_insert_remove_version(database: SQLite, package_ahriman: Package,
database.logs_insert(LogRecordId(package_python_schedule.base, "1"), 42.0, "message 3")
database.logs_remove(package_ahriman.base, "1")
assert database.logs_get(package_ahriman.base) == [(42.0, "message 1")]
assert database.logs_get(package_python_schedule.base) == [(42.0, "message 3")]
assert database.logs_get(package_ahriman.base) == [
(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1"),
]
assert database.logs_get(package_python_schedule.base) == [
(LogRecordId(package_python_schedule.base, "1"), 42.0, "message 3"),
]
def test_logs_insert_remove_multi(database: SQLite, package_ahriman: Package) -> None:
@ -28,7 +32,7 @@ def test_logs_insert_remove_multi(database: SQLite, package_ahriman: Package) ->
database.logs_remove(package_ahriman.base, None, RepositoryId("i686", database._repository_id.name))
assert not database.logs_get(package_ahriman.base, repository_id=RepositoryId("i686", database._repository_id.name))
assert database.logs_get(package_ahriman.base) == [(42.0, "message 1")]
assert database.logs_get(package_ahriman.base) == [(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1")]
def test_logs_insert_remove_full(database: SQLite, package_ahriman: Package, package_python_schedule: Package) -> None:
@ -41,7 +45,9 @@ def test_logs_insert_remove_full(database: SQLite, package_ahriman: Package, pac
database.logs_remove(package_ahriman.base, None)
assert not database.logs_get(package_ahriman.base)
assert database.logs_get(package_python_schedule.base) == [(42.0, "message 3")]
assert database.logs_get(package_python_schedule.base) == [
(LogRecordId(package_python_schedule.base, "1"), 42.0, "message 3"),
]
def test_logs_insert_get(database: SQLite, package_ahriman: Package) -> None:
@ -50,7 +56,10 @@ def test_logs_insert_get(database: SQLite, package_ahriman: Package) -> None:
"""
database.logs_insert(LogRecordId(package_ahriman.base, "1"), 43.0, "message 2")
database.logs_insert(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1")
assert database.logs_get(package_ahriman.base) == [(42.0, "message 1"), (43.0, "message 2")]
assert database.logs_get(package_ahriman.base) == [
(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1"),
(LogRecordId(package_ahriman.base, "1"), 43.0, "message 2"),
]
def test_logs_insert_get_pagination(database: SQLite, package_ahriman: Package) -> None:
@ -59,7 +68,9 @@ def test_logs_insert_get_pagination(database: SQLite, package_ahriman: Package)
"""
database.logs_insert(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1")
database.logs_insert(LogRecordId(package_ahriman.base, "1"), 43.0, "message 2")
assert database.logs_get(package_ahriman.base, 1, 1) == [(42.0, "message 1")]
assert database.logs_get(package_ahriman.base, 1, 1) == [
(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1"),
]
def test_logs_insert_get_multi(database: SQLite, package_ahriman: Package) -> None:
@ -71,5 +82,40 @@ def test_logs_insert_get_multi(database: SQLite, package_ahriman: Package) -> No
RepositoryId("i686", database._repository_id.name))
assert database.logs_get(package_ahriman.base,
repository_id=RepositoryId("i686", database._repository_id.name)) == [(43.0, "message 2")]
assert database.logs_get(package_ahriman.base) == [(42.0, "message 1")]
repository_id=RepositoryId("i686", database._repository_id.name)) == [
(LogRecordId(package_ahriman.base, "1"), 43.0, "message 2"),
]
assert database.logs_get(package_ahriman.base) == [
(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1"),
]
def test_logs_rotate_remove_all(database: SQLite, package_ahriman: Package) -> None:
"""
must remove all records when rotating with keep_last_records is 0
"""
database.logs_insert(LogRecordId(package_ahriman.base, "1"), 42.0, "message 1")
database.logs_insert(LogRecordId(package_ahriman.base, "1"), 43.0, "message 2")
database.logs_insert(LogRecordId(package_ahriman.base, "2"), 44.0, "message 3")
database.logs_rotate(0)
assert not database.logs_get(package_ahriman.base)
def test_logs_rotate_remove_duplicates(database: SQLite, package_ahriman: Package) -> None:
"""
must remove duplicate records while preserving the most recent one for each package version
"""
database.logs_insert(LogRecordId(package_ahriman.base, "1", "p1"), 42.0, "message 1")
database.logs_insert(LogRecordId(package_ahriman.base, "1", "p2"), 43.0, "message 2")
database.logs_insert(LogRecordId(package_ahriman.base, "1", "p3"), 44.0, "message 3")
database.logs_insert(LogRecordId(package_ahriman.base, "2", "p1"), 45.0, "message 4")
database.logs_rotate(2)
logs = database.logs_get(package_ahriman.base)
assert len(logs) == 2
assert logs == [
(LogRecordId(package_ahriman.base, "1", "p3"), 44.0, "message 3"),
(LogRecordId(package_ahriman.base, "2", "p1"), 45.0, "message 4"),
]

View File

@ -19,12 +19,14 @@ def test_load(configuration: Configuration, mocker: MockerFixture) -> None:
add_mock = mocker.patch("logging.Logger.addHandler")
load_mock = mocker.patch("ahriman.core.status.Client.load")
atexit_mock = mocker.patch("atexit.register")
_, repository_id = configuration.check_loaded()
handler = HttpLogHandler.load(repository_id, configuration, report=False)
assert handler
add_mock.assert_called_once_with(handler)
load_mock.assert_called_once_with(repository_id, configuration, report=False)
atexit_mock.assert_called_once_with(handler.rotate)
def test_load_exist(configuration: Configuration) -> None:
@ -93,3 +95,16 @@ def test_emit_skip(configuration: Configuration, log_record: logging.LogRecord,
handler.emit(log_record)
log_mock.assert_not_called()
def test_rotate(configuration: Configuration, mocker: MockerFixture) -> None:
"""
must rotate logs
"""
rotate_mock = mocker.patch("ahriman.core.status.Client.logs_rotate")
_, repository_id = configuration.check_loaded()
handler = HttpLogHandler(repository_id, configuration, report=False, suppress_errors=False)
handler.rotate()
rotate_mock.assert_called_once_with(handler.keep_last_records)

View File

@ -87,13 +87,3 @@ def test_in_package_context_failed(database: SQLite, package_ahriman: Package, m
raise ValueError()
reset_mock.assert_called_once_with()
def test_suppress_logging(database: SQLite, mocker: MockerFixture) -> None:
"""
must temporary disable log messages
"""
disable_mock = mocker.patch("ahriman.core.log.lazy_logging.logging.disable")
with database.suppress_logging():
pass
disable_mock.assert_has_calls([MockCall(logging.WARNING), MockCall(logging.NOTSET)])

View File

@ -112,6 +112,13 @@ def test_event_get(client: Client) -> None:
client.event_get(None, None)
def test_logs_rotate(client: Client, package_ahriman: Package) -> None:
"""
must do not raise exception on logs rotation call
"""
client.logs_rotate(1)
def test_package_changes_get(client: Client, package_ahriman: Package) -> None:
"""
must raise not implemented on package changes request

View File

@ -34,6 +34,15 @@ def test_event_get(local_client: LocalClient, package_ahriman: Package, mocker:
local_client.repository_id)
def test_logs_rotate(local_client: LocalClient, package_ahriman: Package, mocker: MockerFixture) -> None:
"""
must rotate logs
"""
rotate_mock = mocker.patch("ahriman.core.database.SQLite.logs_rotate")
local_client.logs_rotate(42)
rotate_mock.assert_called_once_with(42, local_client.repository_id)
def test_package_changes_get(local_client: LocalClient, package_ahriman: Package, mocker: MockerFixture) -> None:
"""
must retrieve package changes

View File

@ -5,7 +5,6 @@ from pytest_mock import MockerFixture
from ahriman.core.exceptions import UnknownPackageError
from ahriman.core.status.watcher import Watcher
from ahriman.models.build_status import BuildStatus, BuildStatusEnum
from ahriman.models.log_record_id import LogRecordId
from ahriman.models.package import Package
@ -64,38 +63,6 @@ def test_package_get_failed(watcher: Watcher, package_ahriman: Package) -> None:
watcher.package_get(package_ahriman.base)
def test_package_logs_add_new(watcher: Watcher, package_ahriman: Package, mocker: MockerFixture) -> None:
"""
must create package logs record for new package
"""
delete_mock = mocker.patch("ahriman.core.status.watcher.Watcher.package_logs_remove", create=True)
insert_mock = mocker.patch("ahriman.core.status.local_client.LocalClient.package_logs_add")
log_record_id = LogRecordId(package_ahriman.base, watcher._last_log_record_id.version)
assert watcher._last_log_record_id != log_record_id
watcher.package_logs_add(log_record_id, 42.01, "log record")
delete_mock.assert_called_once_with(package_ahriman.base, log_record_id.version)
insert_mock.assert_called_once_with(log_record_id, 42.01, "log record")
assert watcher._last_log_record_id == log_record_id
def test_package_logs_add_update(watcher: Watcher, package_ahriman: Package, mocker: MockerFixture) -> None:
"""
must create package logs record for current package
"""
delete_mock = mocker.patch("ahriman.core.status.watcher.Watcher.package_logs_remove", create=True)
insert_mock = mocker.patch("ahriman.core.status.local_client.LocalClient.package_logs_add")
log_record_id = LogRecordId(package_ahriman.base, watcher._last_log_record_id.version)
watcher._last_log_record_id = log_record_id
watcher.package_logs_add(log_record_id, 42.01, "log record")
delete_mock.assert_not_called()
insert_mock.assert_called_once_with(log_record_id, 42.01, "log record")
def test_package_remove(watcher: Watcher, package_ahriman: Package, mocker: MockerFixture) -> None:
"""
must remove package base

View File

@ -257,6 +257,57 @@ def test_event_get_failed_http_error_suppress(web_client: WebClient, mocker: Moc
logging_mock.assert_not_called()
def test_logs_rotate(web_client: WebClient, mocker: MockerFixture) -> None:
"""
must rotate logs
"""
requests_mock = mocker.patch("ahriman.core.status.web_client.WebClient.make_request")
web_client.logs_rotate(42)
requests_mock.assert_called_once_with("DELETE", pytest.helpers.anyvar(str, True),
params=web_client.repository_id.query() + [("keep_last_records", "42")])
def test_logs_rotate_failed(web_client: WebClient, mocker: MockerFixture) -> None:
"""
must suppress any exception happened during logs rotation
"""
mocker.patch("requests.Session.request", side_effect=Exception())
web_client.logs_rotate(42)
def test_logs_rotate_failed_http_error(web_client: WebClient, mocker: MockerFixture) -> None:
"""
must suppress HTTP exception happened during logs rotation
"""
mocker.patch("requests.Session.request", side_effect=requests.HTTPError())
web_client.logs_rotate(42)
def test_logs_rotate_failed_suppress(web_client: WebClient, mocker: MockerFixture) -> None:
"""
must suppress any exception happened during logs rotation and don't log
"""
web_client.suppress_errors = True
mocker.patch("requests.Session.request", side_effect=Exception())
logging_mock = mocker.patch("logging.exception")
web_client.logs_rotate(42)
logging_mock.assert_not_called()
def test_logs_rotate_failed_http_error_suppress(web_client: WebClient, mocker: MockerFixture) -> None:
"""
must suppress HTTP exception happened during logs rotation and don't log
"""
web_client.suppress_errors = True
mocker.patch("requests.Session.request", side_effect=requests.HTTPError())
logging_mock = mocker.patch("logging.exception")
web_client.logs_rotate(42)
logging_mock.assert_not_called()
def test_package_changes_get(web_client: WebClient, package_ahriman: Package, mocker: MockerFixture) -> None:
"""
must get changes
@ -551,6 +602,7 @@ def test_package_logs_add(web_client: WebClient, log_record: logging.LogRecord,
payload = {
"created": log_record.created,
"message": log_record.getMessage(),
"process_id": LogRecordId.process_id,
"version": package_ahriman.version,
}
@ -588,7 +640,12 @@ def test_package_logs_get(web_client: WebClient, package_ahriman: Package, mocke
"""
must get logs
"""
message = {"created": 42.0, "message": "log"}
message = {
"created": 42.0,
"message": "log",
"version": package_ahriman.version,
"process_id": LogRecordId.process_id,
}
response_obj = requests.Response()
response_obj._content = json.dumps([message]).encode("utf8")
response_obj.status_code = 200
@ -598,7 +655,9 @@ def test_package_logs_get(web_client: WebClient, package_ahriman: Package, mocke
result = web_client.package_logs_get(package_ahriman.base, 1, 2)
requests_mock.assert_called_once_with("GET", pytest.helpers.anyvar(str, True),
params=web_client.repository_id.query() + [("limit", "1"), ("offset", "2")])
assert result == [(message["created"], message["message"])]
assert result == [
(LogRecordId(package_ahriman.base, package_ahriman.version), message["created"], message["message"]),
]
def test_package_logs_get_failed(web_client: WebClient, package_ahriman: Package, mocker: MockerFixture) -> None:

View File

@ -0,0 +1,77 @@
import pytest
from aiohttp.test_utils import TestClient
from ahriman.models.build_status import BuildStatusEnum
from ahriman.models.package import Package
from ahriman.models.user_access import UserAccess
from ahriman.web.views.v1.service.logs import LogsView
async def test_get_permission() -> None:
"""
must return correct permission for the request
"""
for method in ("DELETE",):
request = pytest.helpers.request("", "", method)
assert await LogsView.get_permission(request) == UserAccess.Full
def test_routes() -> None:
"""
must return correct routes
"""
assert LogsView.ROUTES == ["/api/v1/service/logs"]
async def test_delete(client: TestClient, package_ahriman: Package) -> None:
"""
must delete all logs
"""
await client.post(f"/api/v1/packages/{package_ahriman.base}",
json={"status": BuildStatusEnum.Success.value, "package": package_ahriman.view()})
await client.post(f"/api/v1/packages/{package_ahriman.base}/logs",
json={"created": 42.0, "message": "message 1", "version": "42"})
await client.post(f"/api/v1/packages/{package_ahriman.base}/logs",
json={"created": 43.0, "message": "message 2", "version": "43"})
response = await client.delete("/api/v1/service/logs")
assert response.status == 204
response = await client.get(f"/api/v2/packages/{package_ahriman.base}/logs")
json = await response.json()
assert not json
async def test_delete_partially(client: TestClient, package_ahriman: Package) -> None:
"""
must delete logs based on count input
"""
await client.post(f"/api/v1/packages/{package_ahriman.base}",
json={"status": BuildStatusEnum.Success.value, "package": package_ahriman.view()})
await client.post(f"/api/v1/packages/{package_ahriman.base}/logs",
json={"created": 42.0, "message": "message 1", "version": "42"})
await client.post(f"/api/v1/packages/{package_ahriman.base}/logs",
json={"created": 43.0, "message": "message 2", "version": "43"})
request_schema = pytest.helpers.schema_request(LogsView.delete, location="querystring")
payload = {"keep_last_records": 1}
assert not request_schema.validate(payload)
response = await client.delete("/api/v1/service/logs", params=payload)
assert response.status == 204
response = await client.get(f"/api/v2/packages/{package_ahriman.base}/logs")
json = await response.json()
assert json
async def test_delete_exception(client: TestClient, package_ahriman: Package) -> None:
"""
must raise exception on invalid payload
"""
response_schema = pytest.helpers.schema_response(LogsView.delete, code=400)
response = await client.delete("/api/v1/service/logs", params={"keep_last_records": "string"})
assert response.status == 400
assert not response_schema.validate(await response.json())

View File

@ -3,6 +3,7 @@ import pytest
from aiohttp.test_utils import TestClient
from ahriman.models.build_status import BuildStatusEnum
from ahriman.models.log_record_id import LogRecordId
from ahriman.models.package import Package
from ahriman.models.user_access import UserAccess
from ahriman.web.views.v2.packages.logs import LogsView
@ -48,10 +49,14 @@ async def test_get(client: TestClient, package_ahriman: Package) -> None:
{
"created": 42.0,
"message": "message 1",
"version": "42",
"process_id": LogRecordId.process_id,
},
{
"created": 43.0,
"message": "message 2",
"version": "42",
"process_id": LogRecordId.process_id,
},
]
@ -76,7 +81,7 @@ async def test_get_with_pagination(client: TestClient, package_ahriman: Package)
logs = await response.json()
assert not response_schema.validate(logs)
assert logs == [{"created": 42.0, "message": "message 1"}]
assert logs == [{"created": 42.0, "message": "message 1", "version": "42", "process_id": LogRecordId.process_id}]
async def test_get_bad_request(client: TestClient, package_ahriman: Package) -> None: