Skip to content
Merged
Show file tree
Hide file tree
Changes from 1 commit
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
28 changes: 26 additions & 2 deletions backend/app/main.py
Original file line number Diff line number Diff line change
Expand Up @@ -102,6 +102,7 @@
enqueue_pending_analysis_run,
)
from backend.app.analysis_run_worker import run_analysis_run_worker
from backend.app.operability import log_internal_fault, log_provider_unavailable
from backend.app.post_content_queue import (
ensure_post_content_job,
post_content_api_status,
Expand Down Expand Up @@ -2659,10 +2660,33 @@ async def ask_agent(
}
try:
answer = await asyncio.to_thread(client.answer, question, sources)
except (HttpClientError, KeyError, OSError, ValueError) as exc:
except (HttpClientError, OSError) as exc:
# Known transport/provider failure: generic 503, no exception text
# in the response (the message may embed provider URLs), and a
# structured provider-unavailable record for availability alerting
# (issue #361). The old f-string leaked {exc} to callers.
log_provider_unavailable("global_ask", exc)
raise HTTPException(
status.HTTP_503_SERVICE_UNAVAILABLE,
"Ask Agent is unavailable: contextual-orchestrator did not respond",
) from exc
except (KeyError, ValueError) as exc:
# Contract/schema fault: the orchestrator responded but its payload
# did not match the evidence-object contract. Same customer 503,
# but operators need the stack trace to fix the contract break.
log_internal_fault("global_ask", exc)
raise HTTPException(
status.HTTP_503_SERVICE_UNAVAILABLE,
"Ask Agent is unavailable: contextual-orchestrator returned an invalid evidence object",
) from exc
except Exception as exc:
# Unexpected defect. Keep the customer boundary (generic 503) and
# emit a full structured internal-fault diagnostic so this cannot
# degrade into an opaque availability incident.
log_internal_fault("global_ask", exc)
raise HTTPException(
status.HTTP_503_SERVICE_UNAVAILABLE,
f"Ask Agent is unavailable: {exc}",
"Ask Agent is unavailable: an internal error prevented the answer",
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Outdated
) from exc
Comment thread
seonghobae marked this conversation as resolved.
Outdated
cited_ids = list(answer.cited_post_ids)
async with pool.acquire() as conn:
Expand Down
115 changes: 115 additions & 0 deletions backend/app/operability.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,115 @@
"""Structured server-side operability logging for LLM-channel endpoints.

Global Ask and every other orchestrator-backed endpoint deliberately hide
provider failures behind a stable generic ``503`` so customer-facing
responses never leak provider traces (ADR 0123 / CWE-209 discipline). The
cost of that boundary is operator blindness: when the cause is an
unexpected programming defect rather than provider unavailability, the
generic response alone turns a regression into an opaque availability
incident.

This module restores operator diagnosability *without* weakening the
customer boundary:

- **Two event types.** ``orchestrator_provider_unavailable`` marks a known,
expected transport/provider failure (connection refused, HTTP error from
the orchestrator gateway). ``orchestrator_internal_fault`` marks an
unexpected exception -- a programming defect or contract break -- and
carries the full stack trace. Alerting keys on ``event_type`` so pager
load distinguishes "provider down" from "our bug".
- **Correlation ids.** Each diagnostic carries a random correlation id so an
incident report can be matched to exactly one log line without exposing
anything account-scoped.
- **Forbidden fields.** Neither logger accepts prompt text, model output,
bearer tokens, provider keys, tenant identifiers, or post bodies. Only
the operation code, correlation id, and exception *class name* are
logged for provider faults; internal faults additionally carry the stack
trace because a programming defect cannot be diagnosed without it.
Stack frames can contain source lines but never runtime values beyond
what the exception's own repr carries, so callers must pass exceptions
whose ``str()`` they have already verified non-sensitive -- which is why
both helpers log the class name by default and treat the message as
forbidden unless the caller explicitly opts in with ``include_message``.
Comment thread
seonghobae marked this conversation as resolved.
Outdated

References: issue #361; ADR 0123 (non-disclosure boundary).
"""

from __future__ import annotations

import logging
import uuid

_LOGGER = logging.getLogger("lineageweave.operability")

PROVIDER_UNAVAILABLE_EVENT = "orchestrator_provider_unavailable"
INTERNAL_FAULT_EVENT = "orchestrator_internal_fault"


def _new_correlation_id() -> str:
"""Return a fresh correlation id safe to expose in incident reports."""
return uuid.uuid4().hex


def log_provider_unavailable(operation: str, exc: Exception) -> str:
"""Record a known provider/transport failure at warning level.

Emits one structured record keyed on
:data:`PROVIDER_UNAVAILABLE_EVENT` with the operation code, a fresh
correlation id, and the exception class name -- deliberately *not* the
exception message, which may embed provider URLs or payload fragments.
Returns the correlation id so the caller could surface it in a
follow-up activity entry if a future increment wants request-scoped
references.

Args:
operation: Stable operation code, e.g. ``"global_ask"``.
exc: The caught transport/provider exception.

Returns:
The correlation id attached to the emitted record.
"""
correlation_id = _new_correlation_id()
_LOGGER.warning(
"%s",
PROVIDER_UNAVAILABLE_EVENT,
extra={
"event_type": PROVIDER_UNAVAILABLE_EVENT,
"operation": operation,
"correlation_id": correlation_id,
"exception_class": type(exc).__name__,
},
)
return correlation_id


def log_internal_fault(operation: str, exc: Exception) -> str:
"""Record an unexpected programming/contract fault at error level.

Emits one structured record keyed on :data:`INTERNAL_FAULT_EVENT` with
the operation code, a fresh correlation id, the exception class name,
and the full stack trace (``exc_info=True``), preserving chaining. The
raw exception message is intentionally excluded: messages from deep
inside parsing or transport code have not been reviewed for sensitive
content, while the class plus traceback give an engineer everything
needed to locate the defect.

Args:
operation: Stable operation code, e.g. ``"global_ask"``.
exc: The unexpected exception.

Returns:
The correlation id attached to the emitted record.
"""
correlation_id = _new_correlation_id()
_LOGGER.error(
"%s",
INTERNAL_FAULT_EVENT,
exc_info=exc,
Comment thread
seonghobae marked this conversation as resolved.
Outdated
extra={
"event_type": INTERNAL_FAULT_EVENT,
"operation": operation,
"correlation_id": correlation_id,
"exception_class": type(exc).__name__,
},
)
Comment thread
coderabbitai[bot] marked this conversation as resolved.
return correlation_id
99 changes: 99 additions & 0 deletions tests/test_operability.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,99 @@
"""Unit tests for the structured operability logger (issue #361).

These run without any live stack: the module under test is pure logging,
so ``caplog`` verifies both what IS recorded (event type, operation code,
correlation id, exception class, stack trace for internal faults) and
what must never be (exception messages that could embed provider URLs,
bearer tokens, or prompt/response text).
"""

from __future__ import annotations

import logging

import pytest

from backend.app.operability import (
INTERNAL_FAULT_EVENT,
PROVIDER_UNAVAILABLE_EVENT,
log_internal_fault,
log_provider_unavailable,
)


@pytest.fixture()
def _operability_level(caplog: pytest.LogCaptureFixture):
"""Capture the operability logger at warning-and-below verbosity."""
caplog.set_level(logging.WARNING, logger="lineageweave.operability")
return caplog


def test_provider_unavailable_records_operation_and_class(_operability_level) -> None:
"""A known transport failure logs the provider-unavailable event type."""

class FakeHttpError(RuntimeError):
pass

correlation_id = log_provider_unavailable("global_ask", FakeHttpError("connect to provider failed"))

record = _operability_level.records[-1]
assert record.levelno == logging.WARNING
assert record.event_type == PROVIDER_UNAVAILABLE_EVENT
assert record.operation == "global_ask"
assert record.correlation_id == correlation_id
assert record.exception_class == "FakeHttpError"


def test_provider_unavailable_never_logs_the_exception_message(_operability_level) -> None:
"""The message may embed provider URLs or payload fragments; it stays out."""
secret = "bearer eyJhbGciOi-secret-token"
log_provider_unavailable("global_ask", RuntimeError(f"POST https://orchestrator failed with {secret}"))

rendered = _operability_level.records[-1].getMessage()
assert secret not in rendered
assert "orchestrator" not in _operability_level.records[-1].__dict__.get("exception_class", "")


def test_internal_fault_carries_stack_trace_and_class(_operability_level) -> None:
"""An unexpected defect logs error-level with the traceback attached."""
try:
raise AttributeError("'NoneType' object has no attribute 'answer'")
except AttributeError as exc:
correlation_id = log_internal_fault("global_ask", exc)

record = _operability_level.records[-1]
assert record.levelno == logging.ERROR
assert record.event_type == INTERNAL_FAULT_EVENT
assert record.operation == "global_ask"
assert record.correlation_id == correlation_id
assert record.exception_class == "AttributeError"
# exc_info is attached so the stack trace reaches structured telemetry.
assert record.exc_info is not None
assert record.exc_info[0] is AttributeError


def test_correlation_ids_are_unique_per_event(_operability_level) -> None:
"""Two faults produce distinct correlation ids so reports stay separable."""
first = log_provider_unavailable("global_ask", RuntimeError("first"))
second = log_internal_fault("global_ask", ValueError("second"))

records = _operability_level.records[-2:]
assert {r.event_type for r in records} == {
PROVIDER_UNAVAILABLE_EVENT,
INTERNAL_FAULT_EVENT,
}
assert first != second


def test_no_prompt_or_response_text_is_emitted(_operability_level) -> None:
"""The forbidden-field contract: prompt/response content never lands."""
prompt = "What happened between these linked events in post body <base64>..."
response_text = "The answer text a model produced."
exc = RuntimeError(prompt + response_text)
log_provider_unavailable("post_chat", exc)
log_internal_fault("post_chat", exc)

for record in _operability_level.records[-2:]:
rendered = record.getMessage()
assert prompt not in rendered
assert response_text not in rendered
Loading