Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 8 additions & 5 deletions src/youtube_extension/backend/services/logging_service.py
Original file line number Diff line number Diff line change
Expand Up @@ -372,19 +372,22 @@ async def _flush_buffer(self) -> None:
async def _write_to_files(self, logs: list[StructuredLogEntry]) -> None:
"""Write logs to file outputs"""
try:
# Write structured logs
# Write structured logs.
# aiofiles dispatches every write() to the thread-pool executor, so a
# per-entry loop costs one executor round-trip per log line. Serialise
# the whole batch first and issue a single write instead.
structured_path = self.config['log_directory'] / 'structured_logs.jsonl'
structured_payload = ''.join(f'{log.json()}\n' for log in logs)
async with aiofiles.open(structured_path, 'a') as f:
for log in logs:
await f.write(log.json() + '\n')
await f.write(structured_payload)

# Write error logs separately
error_logs = [log for log in logs if log.level in ['ERROR', 'CRITICAL']]
if error_logs:
error_path = self.config['log_directory'] / 'error_logs.jsonl'
error_payload = ''.join(f'{log.json()}\n' for log in error_logs)
async with aiofiles.open(error_path, 'a') as f:
for log in error_logs:
await f.write(log.json() + '\n')
await f.write(error_payload)

except Exception as e:
self.logger.error(f"Failed to write logs to files: {e}")
Expand Down
117 changes: 117 additions & 0 deletions tests/unit/test_logging_service.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,9 +2,11 @@

from __future__ import annotations

import json
import sys
import time
from pathlib import Path
from unittest.mock import patch

import pytest

Expand All @@ -16,6 +18,8 @@
StructuredLogEntry,
)

MODULE_PATH = "youtube_extension.backend.services.logging_service"

# ===========================================================================
# LogLevel constants
# ===========================================================================
Expand Down Expand Up @@ -386,3 +390,116 @@ async def test_has_uptime(self, service):
status = service.get_health_status()
assert "uptime_seconds" in status
assert status["uptime_seconds"] >= 0


# ===========================================================================
# LoggingService._write_to_files — batching
# ===========================================================================


class TestLoggingServiceWriteToFiles:
"""Tests for _write_to_files().

aiofiles delegates every ``write()`` to the thread-pool executor, so the
number of ``write()`` calls -- not the number of bytes -- is what costs.
These tests pin the batch to a single write per file.
"""

@pytest.fixture
async def service(self, tmp_path):
return LoggingService(
config={"log_directory": tmp_path / "logs", "enable_remote_logging": False}
)

@staticmethod
def _entries(n: int, level: str = "INFO") -> list[StructuredLogEntry]:
return [
StructuredLogEntry(
timestamp=f"2026-01-01T00:00:{i:02d}Z",
level=level,
logger_name="test",
message=f"msg-{i}",
)
for i in range(n)
]

async def test_batches_structured_logs_into_one_write(self, service, tmp_path):
writes: list[str] = []

class _FakeFile:
async def write(self, data):
writes.append(data)

async def __aenter__(self):
return self

async def __aexit__(self, *exc):
return False

with patch(f"{MODULE_PATH}.aiofiles.open", return_value=_FakeFile()):
await service._write_to_files(self._entries(25))

assert len(writes) == 1, (
f"_write_to_files issued {len(writes)} write() calls for 25 log entries; "
"each aiofiles write is a separate thread-pool round-trip, so the batch "
"must be serialised into a single write"
)
assert writes[0].count("\n") == 25

async def test_batches_error_logs_into_one_write(self, service, tmp_path):
writes: list[str] = []

class _FakeFile:
async def write(self, data):
writes.append(data)

async def __aenter__(self):
return self

async def __aexit__(self, *exc):
return False

with patch(f"{MODULE_PATH}.aiofiles.open", return_value=_FakeFile()):
await service._write_to_files(self._entries(12, level="ERROR"))

# One write for structured_logs.jsonl, one for error_logs.jsonl.
assert len(writes) == 2, (
f"_write_to_files issued {len(writes)} write() calls for 12 ERROR entries; "
"expected exactly one batched write per file"
)
assert all(payload.count("\n") == 12 for payload in writes)

async def test_writes_every_entry_exactly_once(self, service, tmp_path):
await service._write_to_files(self._entries(5))

path = tmp_path / "logs" / "structured_logs.jsonl"
lines = [ln for ln in path.read_text().splitlines() if ln.strip()]
assert len(lines) == 5
assert [json.loads(ln)["message"] for ln in lines] == [f"msg-{i}" for i in range(5)]

async def test_appends_rather_than_truncating(self, service, tmp_path):
await service._write_to_files(self._entries(3))
await service._write_to_files(self._entries(2))

path = tmp_path / "logs" / "structured_logs.jsonl"
lines = [ln for ln in path.read_text().splitlines() if ln.strip()]
assert len(lines) == 5

async def test_error_logs_routed_to_separate_file(self, service, tmp_path):
mixed = self._entries(2, level="INFO") + self._entries(3, level="CRITICAL")
await service._write_to_files(mixed)

structured = tmp_path / "logs" / "structured_logs.jsonl"
errors = tmp_path / "logs" / "error_logs.jsonl"
assert len([ln for ln in structured.read_text().splitlines() if ln.strip()]) == 5
assert len([ln for ln in errors.read_text().splitlines() if ln.strip()]) == 3

async def test_no_error_content_written_when_no_error_logs(self, service, tmp_path):
await service._write_to_files(self._entries(4, level="INFO"))
errors = tmp_path / "logs" / "error_logs.jsonl"
# The service pre-creates its log files at init, so assert on content.
existing = errors.read_text() if errors.exists() else ""
assert [ln for ln in existing.splitlines() if ln.strip()] == []

async def test_empty_batch_does_not_raise(self, service):
await service._write_to_files([])
Loading