diff --git a/app/api/routers/admin_dbops.py b/app/api/routers/admin_dbops.py index 8230ab9..57498c1 100644 --- a/app/api/routers/admin_dbops.py +++ b/app/api/routers/admin_dbops.py @@ -232,7 +232,7 @@ async def requeue_pdf_lookup( message="Publication not found.", ) status, message = _requeue_response_state(queued=result.queued) - structured_log(logger, "info", "api.admin.db.pdf_queue_requeue_requested", admin_user_id=int(admin_user.id), publication_id=int(publication_id), queued=bool(result.queued)) + structured_log(logger, "info", "api.admin.db.pdf_requeued", admin_user_id=int(admin_user.id), publication_id=int(publication_id), queued=bool(result.queued)) return success_payload( request, data={ @@ -340,7 +340,7 @@ async def trigger_publication_near_duplicate_repair( code="invalid_near_duplicate_repair_request", message=str(exc), ) from exc - structured_log(logger, "info", "api.admin.db.publication_near_duplicate_repair_triggered", admin_user_id=int(admin_user.id), dry_run=bool(payload.dry_run), selected_cluster_count=len(payload.selected_cluster_keys), job_id=int(result["job_id"]), status=result["status"]) + structured_log(logger, "info", "api.admin.db.dedup_repair_triggered", admin_user_id=int(admin_user.id), dry_run=bool(payload.dry_run), selected_cluster_count=len(payload.selected_cluster_keys), job_id=int(result["job_id"]), status=result["status"]) return success_payload(request, data=result) diff --git a/app/api/routers/scholars.py b/app/api/routers/scholars.py index f0784fe..c0a281b 100644 --- a/app/api/routers/scholars.py +++ b/app/api/routers/scholars.py @@ -575,7 +575,7 @@ async def clear_scholar_image_customization( profile=profile, upload_dir=settings.scholar_image_upload_dir, ) - structured_log(logger, "info", "api.scholars.image_customization_cleared", user_id=current_user.id, scholar_profile_id=updated.id) + structured_log(logger, "info", "api.scholars.image_cleared", user_id=current_user.id, scholar_profile_id=updated.id) return success_payload( request, data=_serialize_scholar(updated), diff --git a/app/logging_config.py b/app/logging_config.py index 22907be..559a400 100644 --- a/app/logging_config.py +++ b/app/logging_config.py @@ -108,6 +108,14 @@ class JsonLogFormatter(logging.Formatter): return value +_CONSOLE_SHORT_KEYS = { + "user_id": "user", + "scholar_id": "scholar", + "crawl_run_id": "run", + "run_id": "run", +} + + class ConsoleLogFormatter(logging.Formatter): def __init__(self, *, redact_fields: set[str]) -> None: super().__init__() @@ -140,7 +148,8 @@ class ConsoleLogFormatter(logging.Formatter): for key in sorted(payload.keys()): if key in {"timestamp", "level", "logger", "event", "exception"}: continue - parts.append(f"{key}={payload[key]}") + display_key = _CONSOLE_SHORT_KEYS.get(key, key) + parts.append(f"{display_key}={payload[key]}") if "exception" in payload: parts.append(f"exception={payload['exception']}") diff --git a/app/services/domains/ingestion/application.py b/app/services/domains/ingestion/application.py index da37c88..4b619d7 100644 --- a/app/services/domains/ingestion/application.py +++ b/app/services/domains/ingestion/application.py @@ -153,7 +153,7 @@ class ScholarIngestionService: await db_session.commit() await db_session.refresh(user_settings) structured_log( - logger, "info", "ingestion.safety_cooldown_cleared", + logger, "info", "ingestion.cooldown_cleared", user_id=user_id, reason=previous.get("cooldown_reason"), cooldown_until=previous.get("cooldown_until"), @@ -962,7 +962,7 @@ class ScholarIngestionService: ) elif pre_apply_state.get("cooldown_active") and not safety_state.get("cooldown_active"): structured_log( - logger, "info", "ingestion.safety_cooldown_cleared", + logger, "info", "ingestion.cooldown_cleared", user_id=user_id, crawl_run_id=int(run.id), reason=pre_apply_state.get("cooldown_reason"), @@ -1319,7 +1319,7 @@ class ScholarIngestionService: effective_delay = self._effective_request_delay_seconds(request_delay_seconds) if effective_delay != _int_or_default(request_delay_seconds, effective_delay): structured_log( - logger, "warning", "ingestion.request_delay_coerced_to_policy_floor", + logger, "warning", "ingestion.delay_coerced", user_id=user_id, requested_request_delay_seconds=_int_or_default(request_delay_seconds, 0), effective_request_delay_seconds=effective_delay, @@ -2596,13 +2596,6 @@ class ScholarIngestionService: db_session.add(link) discovered_count += 1 - structured_log( - logger, "debug", "ingestion.publication_discovered", - scholar_profile_id=scholar.id, - publication_id=publication.id, - crawl_run_id=run.id, - ) - await self._commit_discovered_publication( db_session, run=run, @@ -2720,11 +2713,6 @@ class ScholarIngestionService: ) db_session.add(publication) await db_session.flush() - structured_log( - logger, "debug", "ingestion.publication_created", - publication_id=publication.id, - cluster_id=publication.cluster_id, - ) return publication @staticmethod diff --git a/app/services/domains/publications/pdf_queue.py b/app/services/domains/publications/pdf_queue.py index 83c9031..0313f11 100644 --- a/app/services/domains/publications/pdf_queue.py +++ b/app/services/domains/publications/pdf_queue.py @@ -514,9 +514,9 @@ async def _run_resolution_task( ) if arxiv_rate_limited and arxiv_lookup_allowed: arxiv_lookup_allowed = False - structured_log(logger, "warning", "publications.pdf_queue.arxiv_batch_disabled", detail="arXiv temporarily disabled for remaining batch after rate limit") + structured_log(logger, "warning", "pdf_queue.arxiv_batch_disabled", detail="arXiv temporarily disabled for remaining batch after rate limit") except OpenAlexBudgetExhaustedError: - structured_log(logger, "warning", "publications.pdf_queue.budget_exhausted", detail="Stopping PDF resolution batch — OpenAlex daily budget exhausted") + structured_log(logger, "warning", "pdf_queue.budget_exhausted", detail="Stopping PDF resolution batch — OpenAlex daily budget exhausted") break diff --git a/app/services/domains/publications/pdf_resolution_pipeline.py b/app/services/domains/publications/pdf_resolution_pipeline.py index f17d65b..37efa6b 100644 --- a/app/services/domains/publications/pdf_resolution_pipeline.py +++ b/app/services/domains/publications/pdf_resolution_pipeline.py @@ -45,7 +45,7 @@ async def resolve_publication_pdf_outcome_for_row( except ArxivRateLimitError: arxiv_rate_limited = True arxiv_outcome = None - structured_log(logger, "warning", "publications.pdf_resolution.arxiv_rate_limited", publication_id=int(row.publication_id)) + structured_log(logger, "warning", "pdf_resolution.arxiv_rate_limited", publication_id=int(row.publication_id)) if arxiv_outcome and arxiv_outcome.pdf_url: return PipelineOutcome(arxiv_outcome, None, arxiv_rate_limited=arxiv_rate_limited) @@ -94,7 +94,7 @@ async def _openalex_outcome( # Re-raise so the caller's batch loop can stop hitting the API. raise except Exception as exc: - structured_log(logger, "warning", "publications.pdf_resolution.openalex_failed", error=str(exc)) + structured_log(logger, "warning", "pdf_resolution.openalex_failed", error=str(exc)) return None @@ -107,12 +107,12 @@ async def _arxiv_outcome( from app.services.domains.arxiv.application import discover_arxiv_id_for_publication if not allow_lookup: - structured_log(logger, "info", "publications.pdf_resolution.arxiv_skipped", publication_id=int(row.publication_id), skip_reason="batch_arxiv_cooldown_active") + structured_log(logger, "info", "pdf_resolution.arxiv_skipped", publication_id=int(row.publication_id), skip_reason="batch_arxiv_cooldown_active") return None skip_reason = arxiv_skip_reason_for_item(item=row) if skip_reason is not None: - structured_log(logger, "info", "publications.pdf_resolution.arxiv_skipped", publication_id=int(row.publication_id), skip_reason=skip_reason) + structured_log(logger, "info", "pdf_resolution.arxiv_skipped", publication_id=int(row.publication_id), skip_reason=skip_reason) return None try: @@ -130,7 +130,7 @@ async def _arxiv_outcome( except ArxivRateLimitError: raise # propagate so orchestration can switch to non-arXiv fallback except Exception as exc: - structured_log(logger, "warning", "publications.pdf_resolution.arxiv_failed", error=str(exc)) + structured_log(logger, "warning", "pdf_resolution.arxiv_failed", error=str(exc)) return None diff --git a/app/services/domains/scholar/source.py b/app/services/domains/scholar/source.py index 50d27ca..7e34f01 100644 --- a/app/services/domains/scholar/source.py +++ b/app/services/domains/scholar/source.py @@ -101,13 +101,6 @@ class LiveScholarSource: cstart=cstart, pagesize=pagesize, ) - structured_log( - logger, "debug", "scholar_source.fetch_started", - scholar_id=scholar_id, - requested_url=requested_url, - cstart=cstart, - pagesize=pagesize, - ) return await self._fetch_with_global_throttle(requested_url) async def fetch_author_search_html( @@ -120,19 +113,9 @@ class LiveScholarSource: query=query, start=start, ) - structured_log( - logger, "debug", "scholar_source.search_fetch_started", - query=query, - requested_url=requested_url, - start=start, - ) return await self._fetch_with_global_throttle(requested_url) async def fetch_publication_html(self, publication_url: str) -> FetchResult: - structured_log( - logger, "debug", "scholar_source.publication_fetch_started", - requested_url=publication_url, - ) return await self._fetch_with_global_throttle(publication_url) async def _fetch_with_global_throttle(self, requested_url: str) -> FetchResult: diff --git a/tests/unit/test_logging.py b/tests/unit/test_logging.py index 2a08d4c..696cb2a 100644 --- a/tests/unit/test_logging.py +++ b/tests/unit/test_logging.py @@ -82,7 +82,7 @@ def test_structured_log_console_formatter(caplog) -> None: output = formatter.format(record) assert "export.failed" in output - assert "scholar_id=7" in output + assert "scholar=7" in output def test_structured_log_strips_metric_fields(caplog) -> None: