Files
FabledScribe/src/fabledassistant/services/logging.py
T
bvandeusen 25d448f896 feat: add generation metrics to logs (think, rounds, tokens)
Log think flag, round count, prompt/output token counts per generation.
Change log category from 'usage' to 'generation' for clean MCP filtering.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
2026-04-02 14:14:41 -04:00

198 lines
6.0 KiB
Python

"""Application logging service for audit, usage, and error events."""
import asyncio
import json
import logging
import traceback as tb_module
from datetime import datetime, timedelta, timezone
from sqlalchemy import delete, func, select, text
from fabledassistant.config import Config
from fabledassistant.models import async_session
from fabledassistant.models.app_log import AppLog
logger = logging.getLogger(__name__)
_retention_task: asyncio.Task | None = None
async def log_audit(
action: str,
user_id: int | None = None,
username: str | None = None,
ip_address: str | None = None,
details: dict | None = None,
) -> None:
async with async_session() as session:
log = AppLog(
category="audit",
user_id=user_id,
username=username,
action=action,
ip_address=ip_address,
details=json.dumps(details) if details else None,
)
session.add(log)
await session.commit()
async def log_usage(
user_id: int | None = None,
username: str | None = None,
endpoint: str | None = None,
method: str | None = None,
status_code: int | None = None,
duration_ms: float | None = None,
) -> None:
async with async_session() as session:
log = AppLog(
category="usage",
user_id=user_id,
username=username,
endpoint=endpoint,
method=method,
status_code=status_code,
duration_ms=duration_ms,
)
session.add(log)
await session.commit()
async def log_generation(
user_id: int,
conv_id: int,
model: str,
timing: dict,
) -> None:
"""Persist per-generation timing breakdown to app_logs for benchmarking."""
async with async_session() as session:
log = AppLog(
category="generation",
user_id=user_id,
action="generation",
endpoint=f"/chat/conversations/{conv_id}",
duration_ms=timing.get("total_ms"),
details=json.dumps({"model": model, "conv_id": conv_id, **timing}),
)
session.add(log)
await session.commit()
async def log_error(
user_id: int | None = None,
username: str | None = None,
endpoint: str | None = None,
method: str | None = None,
error_type: str | None = None,
error_message: str | None = None,
traceback: str | None = None,
) -> None:
details = {}
if error_type:
details["error_type"] = error_type
if error_message:
details["error_message"] = error_message
if traceback:
details["traceback"] = traceback
async with async_session() as session:
log = AppLog(
category="error",
user_id=user_id,
username=username,
endpoint=endpoint,
method=method,
details=json.dumps(details) if details else None,
)
session.add(log)
await session.commit()
async def get_logs(
category: str | None = None,
user_id: int | None = None,
search: str | None = None,
date_from: str | None = None,
date_to: str | None = None,
limit: int = 50,
offset: int = 0,
) -> tuple[list[dict], int]:
async with async_session() as session:
query = select(AppLog)
count_query = select(func.count(AppLog.id))
if category:
query = query.where(AppLog.category == category)
count_query = count_query.where(AppLog.category == category)
if user_id is not None:
query = query.where(AppLog.user_id == user_id)
count_query = count_query.where(AppLog.user_id == user_id)
if search:
pattern = f"%{search}%"
search_filter = (
AppLog.action.ilike(pattern)
| AppLog.endpoint.ilike(pattern)
| AppLog.username.ilike(pattern)
| AppLog.details.ilike(pattern)
)
query = query.where(search_filter)
count_query = count_query.where(search_filter)
if date_from:
query = query.where(AppLog.created_at >= date_from)
count_query = count_query.where(AppLog.created_at >= date_from)
if date_to:
query = query.where(AppLog.created_at <= date_to)
count_query = count_query.where(AppLog.created_at <= date_to)
total = (await session.execute(count_query)).scalar() or 0
query = query.order_by(AppLog.created_at.desc()).limit(limit).offset(offset)
result = await session.execute(query)
logs = [row.to_dict() for row in result.scalars().all()]
return logs, total
async def get_log_stats() -> dict:
async with async_session() as session:
result = await session.execute(
text(
"SELECT category, COUNT(*) as count FROM app_logs GROUP BY category"
)
)
stats = {row.category: row.count for row in result}
return {
"audit": stats.get("audit", 0),
"usage": stats.get("usage", 0),
"error": stats.get("error", 0),
"total": sum(stats.values()),
}
async def delete_old_logs(retention_days: int) -> int:
cutoff = datetime.now(timezone.utc) - timedelta(days=retention_days)
async with async_session() as session:
result = await session.execute(
delete(AppLog).where(AppLog.created_at < cutoff)
)
await session.commit()
return result.rowcount
async def _retention_loop() -> None:
while True:
await asyncio.sleep(3600) # hourly
try:
deleted = await delete_old_logs(Config.LOG_RETENTION_DAYS)
if deleted:
logger.info("Log retention: deleted %d old log entries", deleted)
except Exception:
logger.exception("Error in log retention cleanup")
def start_log_retention_loop() -> None:
global _retention_task
if _retention_task is None or _retention_task.done():
_retention_task = asyncio.create_task(_retention_loop())