Observability#

Logging, request tracing, and usage reporting.

Where logs go#

The app writes structured logs to stdout/stderr. On Azure App Service these are picked up by the App Service log stream and any attached log sink. Locally, they show up in your terminal.

Capture depends on Application Logging (Filesystem) being on for the App Service — this is the application_logs { file_system_level = "Information" } block on azurerm_linux_web_app.backend.logs in infra/app_service.tf. This is a separate setting from http_logs (raw per-request access log) and from the diagnostic setting in infra/observability.tf (which ships both into Log Analytics) — without it, the container’s stdout/stderr is never captured at all, so there’s nothing in the Log stream and nothing for the diagnostic setting to route, regardless of what the app logs or how the diagnostic setting is configured.

The log level is controlled by LOG_LOGLEVEL for application packages (default DEBUG) and LOG_LOGLEVEL_3RDPARTY for third-party libraries (default WARNING). Both accept either a numeric level or a string ("debug", "info", "warning", "error", "critical"). file_system_level above is a second, independent filter on the App Service side — raising it (e.g. to Warning) will silently drop lines even if LOG_LOGLEVEL would have let them through.

Hard prohibitions#

Some things must never appear in logs at any level:

  • Feedback record text / content

  • User-supplied prompt

  • The assembled system or user message sent to the LLM

  • LLM response text

  • API key values (protected by SecretStr)

The constants and helpers in qfa.utils make this easy to honour. When in doubt, log the character count or a hash, not the value.

Two more rules, added with ADR-018:

  • Tracebacks are in scope for data classification. Adapter code translates third-party exceptions (litellm, pydantic, SQLAlchemy) into domain errors with raise ... from exc, kept for debuggability. A log line emitted with exc_info=True or logger.exception therefore still carries the original provider-controlled text through __cause__, even though the log message itself does not. This is a deliberate trade-off, not an oversight — log output must not be exported to third-party log analytics without review.

  • str(exc) may be logged or echoed in a response only when the message was authored in this repo. A log line or exception handler may interpolate str(exc) only for domain errors whose messages are literal constants raised from qfa.services (e.g. AnalysisError). Provider-derived errors (LLMError and subclasses, UsageRepositoryUnavailableError) are logged as content-free scalars instead — type=%s status=%s, never the exception text.

Safe to log#

Everything that’s not in the prohibition list above is fine, especially:

  • request_id (every response carries X-Request-ID)

  • tenant_id from the authenticated key

  • operation (analyze, summarize, …)

  • Record count, estimated tokens

  • Attempt numbers and retry reasons

  • Model name, latency, prompt_tokens, completion_tokens, cost

  • HTTP status codes

  • Azure content-filter category/severity on LLMContentPolicyViolationError (a closed annotation, e.g. violence/high — never the flagged text itself)

Pipeline timing#

Hierarchical analysis (mode=hierarchical) logs where wall-clock time goes, so a slow run can be diagnosed from logs alone — no profiler attach required.

  • Per phase, at INFO — AnalyzeService.analyze_hierarchical logs a starting <phase> line before each potentially slow step (embedding, clustering, map, reduce, then judge) and a <phase> … in <seconds>s line after it, plus a closing one-line breakdown: analyze_hierarchical done in 87.7s (anonymise=… embed=… cluster=… map=… reduce=… judge=…). Reduce runs before the judges (the synthesis is the deliverable and gets slot priority; the judges only feed the confidence), so the two are timed separately. The map line reports the concurrency cap (up to N concurrent LLM call(s)). These lines carry only record/chunk counts and durations.

  • Per chunk and per LLM call, at DEBUG — each map chunk logs a starting map chunk i/N line and a done line; each leaf judge logs a starting/done line with its score (or excluded when the chunk could not be judged). The reduce phase is a recursive tree-reduce rather than a flat fan-out; rather than log every call, it emits a single line each time it has to split (N partial(s) exceed the token budget; tree-reducing in K group(s)), so a multi-level synthesis is visible without one line per group. The per-chunk done lines split their duration into queued=<s> (time waiting for a concurrency slot) and call=<s> (the LLM round-trip after the slot was acquired), so a long chunk caused by queue backlog is distinguishable from a genuinely slow call. Each LLM round-trip also logs model, latency, prompt_tokens, completion_tokens, and cost from the LiteLLMClient adapter, and its per-attempt timeout plus the retry budget. DEBUG (not INFO) because hierarchical mode fans out one call per chunk plus judges and reduces — at INFO this would flood the log. Because map runs concurrently, these per-chunk lines interleave.

All of these are built from the safe-to-log list above; none interpolate feedback text, prompts, or model output. The timing itself comes from qfa.utils.timed, a context manager that measures a block and deliberately does not log — the caller owns the message and keeps it content-free.

Raise the app log level to INFO (LOG_LOGLEVEL=info) to keep the phase breakdown while dropping the per-call/per-chunk noise.

Request tracing#

Every response includes an X-Request-ID header generated by the request-id middleware. The header value is a canonical UUID string and is also the value persisted in llm_calls.call_id for every LLM call the request makes — so the same ID appears in the response header, every log line for that request, the error envelope’s request_id field, and the database. A caller reporting a 502 can hand you that one UUID and you can grep the logs end-to-end and SELECT … FROM llm_calls WHERE call_id = '<uuid>' to recover the cost/duration history for the request.

Usage queries#

Two endpoints expose aggregates over the llm_calls table:

  • GET /v1/usage — stats scoped to the caller’s tenant. Accepts from and to query parameters (ISO 8601, timezone-aware).

  • GET /v1/usage/all — stats across all tenants. Requires is_superuser=true.

Returned shape: counts and token totals per operation, plus simple latency distribution stats. The endpoints are reporting-only — no mutation.

If the database is down, both endpoints return 503 with code=usage_backend_unavailable — a transient condition, so retry with backoff.

Azure Monitor#

App Service logs are shipped to an Azure Log Analytics workspace (qfa-<env>-logs) and surfaced in Application Insights (qfa-<env>-appinsights). Both are created by Terraform in infra/observability.tf. The App Service passes the App Insights connection string to the container as the APPLICATIONINSIGHTS_CONNECTION_STRING app setting (wired in infra/app_service.tf); when that setting is present, the app enables application telemetry at startup — see Application Insights (application telemetry) below.

Architecture at a glance#

New to Azure? Start here. There are two independent signal sources, and they answer different questions — confusing them is the single most common source of “the deployment looks broken when it mostly isn’t”:

  • Application logs — the log lines the app writes. Answers “what did the app do / why did this request fail?”

  • Platform metrics — CPU / memory / disk / HTTP counters the Azure host emits automatically, with zero code. Answers “is the box healthy / saturated?”

Plus a third, app-specific channel that is neither of those: cost/usage tracked in Postgres and exposed via GET /v1/usage.

The critical thing the diagram makes explicit is that Log Analytics and Application Insights are two separate sinks filled by two different pipes — even though workspace-based App Insights physically stores its data inside the same Log Analytics workspace. The diagnostic setting pushes AppService* log tables into Log Analytics with no app involvement; the OpenTelemetry SDK inside the container pushes the App* telemetry tables (AppRequests, AppDependencies, AppExceptions, AppTraces) into Application Insights over the connection string. They fail independently: logs can arrive while App Insights stays empty, or vice-versa.

        flowchart TB
    subgraph app["Your app (container)"]
        py["Application logs → stdout<br/>(request_id, tenant, cost, latency)"]
        otel["Application telemetry<br/>(enabled at startup)<br/>captures requests, outbound calls, exceptions"]
        db[("Postgres: llm_calls<br/>token/cost tracking")]
    end

    subgraph host["Azure App Service (host running your container)"]
        stdout_cap["stdout / stderr capture"]
        stream["Live Log stream<br/>(real-time tail, ephemeral)"]
        metrics["Platform metrics (emitted automatically)<br/>CPU% · Memory% · Disk · Http5xx · HealthCheckStatus"]
    end

    subgraph mon["Azure Monitor"]
        diag["Diagnostic setting<br/>routes console / HTTP / platform logs + AllMetrics"]
        law[("Log Analytics workspace<br/>qfa-env-logs · 30-day retention<br/>AppService* tables · query with KQL")]
        ai["Application Insights (workspace-based)<br/>qfa-env-appinsights<br/>App* tables: AppRequests / AppDependencies /<br/>AppExceptions / AppTraces"]
        alerts["4 metric alert rules<br/>5xx · health · CPU · memory"]
        ag["Action group → Teams webhook"]
    end

    subgraph see["Where YOU look (Azure Portal)"]
        portal_stream["App Service → Log stream<br/>(live tail)"]
        portal_logs["Log Analytics → Logs<br/>(KQL, historical)"]
        portal_metrics["App Service / Plan → Metrics<br/>(CPU / mem / disk / 5xx charts)"]
        portal_ai["App Insights → Live Metrics /<br/>Transaction search / Application Map"]
        portal_alerts["Azure Monitor → Alerts → Teams channel"]
        usage["App API: GET /v1/usage<br/>(cost / token reporting)"]
    end

    py --> stdout_cap
    stdout_cap --> stream
    stdout_cap --> diag
    stream --> portal_stream
    host -.emits.-> metrics
    metrics --> diag
    metrics --> alerts
    metrics --> portal_metrics
    diag --> law
    law --> portal_logs

    otel -->|"exports via connection string"| ai
    ai -.stored in.-> law
    ai --> portal_ai

    alerts --> ag --> portal_alerts
    db --> usage

The one-line mental model: host signals (stdout logs, CPU%, memory%) do not need the OTel SDK and already have homes — Log stream / Log Analytics for logs, the Metrics blade for CPU/memory. Application telemetry (per-request traces in the App Insights App* tables) is what the OTel SDK lights up. Wiring OTel is required for App Insights; it is not required for logs or host metrics.

Running these queries in the portal#

  1. Azure Portal → search for qfa-<env>-logs (or Resource group → qfa-<env>-logs) and open the Log Analytics workspace.

  2. In the workspace’s left-hand menu, open Logs. Dismiss the sample-queries dialog if it appears — you want the empty editor.

  3. Paste a query into the editor and set the time range with the picker above it. If the query already contains a TimeGenerated filter, the picker shows Set in query and defers to it — don’t set both.

  4. Click Run (or press Shift+Enter). Click any result row to expand its full set of columns.

Two gotchas: Run executes the whole editor unless you first select a single query, and a “failed to resolve table” error means nothing has been ingested into that table yet — it is not a syntax error. Ingestion also lags the live log stream by a few minutes (see below), so re-run after a short wait if a fresh event is missing.

The Application Insights App* tables (populated by the OpenTelemetry SDK — delivery pending verification, see below):

// All requests in the last hour
AppRequests
| where TimeGenerated > ago(1h)
| project TimeGenerated, Name, ResultCode, DurationMs

// Exceptions
AppExceptions
| where TimeGenerated > ago(1h)
| project TimeGenerated, ProblemId, OuterMessage

App Service log tables#

The queries above target the Application Insights App* tables, which the app’s telemetry populates (see Application Insights (application telemetry) below — delivery is currently pending verification). Independently of that, the App Service diagnostic setting in infra/observability.tf ships three log categories straight to the same workspace, so these tables are populated as soon as the container runs — they are the authoritative log source today:

  • AppServiceConsoleLogs — the container’s stdout/stderr: the application’s own log lines plus web-server output. The message text is in the ResultDescription column.

  • AppServicePlatformLogs — App Service platform lifecycle events: container start/stop, warm-up probe results, and startup failures such as ContainerTimeout. The message text is in the Message column — a different column name from the console table, which is easy to trip over in a joint query.

  • AppServiceHTTPLogs — one row per HTTP request (method, path, status, latency), written by the front end regardless of whether the app logs.

For “what API calls have been made and what did they return” specifically, skip hand-writing KQL: infra/observability.tf provisions a saved query, qfa-<env>-api-calls-overview (category qfa-monitoring), against AppServiceHTTPLogs. Find it in the Log Analytics workspace under Logs → Queries → Saved Queries, or run it directly:

AppServiceHTTPLogs
| project TimeGenerated, CsMethod, CsUriStem, ScStatus, TimeTaken
| order by TimeGenerated desc

Container (console) logs — the application’s own output:

AppServiceConsoleLogs
| where TimeGenerated > ago(1h)
| project TimeGenerated, ResultDescription
| order by TimeGenerated desc

Platform logs — container lifecycle and startup failures (note Message, not ResultDescription):

AppServicePlatformLogs
| where TimeGenerated > ago(1h)
| project TimeGenerated, Level, Message
| order by TimeGenerated desc

Joint view — console and platform logs merged into one time-ordered stream (the Log Analytics equivalent of az webapp log tail). The two tables name their message column differently, so coalesce picks whichever is populated per row, and Type records which table each row came from:

union AppServiceConsoleLogs, AppServicePlatformLogs
| where TimeGenerated > ago(1h)
| extend Msg = coalesce(ResultDescription, Message)
| project TimeGenerated, Type, Msg
| order by TimeGenerated desc

Log Analytics ingestion lags the live App Service → Log stream (and az webapp log tail) by roughly 2–5 minutes. Use the log stream for real-time debugging and these queries for historical search, filtering, and alerting.

Alerting#

Four metric alert rules are provisioned in infra/observability.tf, all routed through the qfa-<env>-alerts action group, which POSTs to the Microsoft Teams incoming webhook configured via var.teams_webhook_url (see Set up a new environment):

Alert

Metric

Threshold

Severity

HTTP 5xx

Http5xx

>5 in 5 min

2

Health check

HealthCheckStatus

<1 (i.e. /v1/health failing)

1

High CPU

CpuPercentage

>85% for 5 min

2

High memory

MemoryPercentage

>85% for 5 min

2

Thresholds are identical across environments, but the hardware under them is not: prd runs 1 vCPU (P0v3) against dev/staging’s 2 (B2), so the startup CPU spike from loading the embedding model sits closer to the 85% line on prd. Sustained firing of high_cpu or high_memory on prd is the trigger to move prd to P1v3 (ADR-019), not to raise the threshold further.

The health-check alert (severity 1) fires when the App Service platform’s built-in health probe of /v1/health fails — this is the most direct signal that the container is down or crashed.

Posting to teams channel.#

If one of the alerts, as described above, is triggered, a webhook is triggered. This webhook is stored as a git secret with the variable name TEAMS_ALERTS_WEBHOOK_URL. For now we use the same channel for dev/stg/prd alerts, so this one variable is used for all of the environments.

The webhook is linked to a workflow. This workflow posts the alert as an adaptive card in the teams channel QFA Monitor (in 510 - Community Engagement & Accountability). To see this workflow you need to press on the three dots on the QFA Monitor channel and then press Workflows. From there you will see the workflow.

The workflow does three things:m receive the alert, parse the json and post it as adaptive card in the teams channel.

Application Insights (application telemetry)#

Application Insights holds application telemetry — one record per request (AppRequests), per outbound call (AppDependencies), per exception (AppExceptions), plus the app’s log lines (AppTraces). This is a separate signal from the AppService* log tables above: those arrive via the diagnostic setting and do not depend on the app, whereas the App* tables are emitted by the app itself.

Telemetry turns on automatically when the APPLICATIONINSIGHTS_CONNECTION_STRING app setting is present — i.e. in deployed environments, where Terraform wires it. Local dev leaves the setting unset and emits nothing, so an empty App Insights locally is expected.

Look at the qfa-<env>-appinsights resource, not the App Service tab. Open that Application Insights resource directly. Do not use qfa-<env>-backend → Application Insights — that App Service tab controls Azure’s codeless auto-instrumentation, a different mechanism this app does not use, so it always shows “Enable Application Insights…” even though telemetry is already wired. Don’t click Enable there — it would attach an injected agent on top of the app’s own telemetry and duplicate every record.

Verification pending. Telemetry is wired but end-to-end delivery has not yet been confirmed against a deployed environment. Until it is, treat the App Service log stream and the AppService* tables as the authoritative log source, and verify the App* tables populate after the next deploy.

Validating that App Insights receives telemetry (fastest → slowest):

  1. Live Metrics (qfa-<env>-appinsights → Live Metrics). Near-real-time (~1 s) and it bypasses the 2–5 min ingestion lag that affects the KQL tables. Open it, then send a handful of requests (curl https://<app>/v1/health). If the server shows as connected and the request rate ticks up, telemetry is flowing. If it stays “not connected”, the app isn’t emitting — check the connection string reached the container and that the app isn’t crash-looping (telemetry is batched, so a container killed during a crash-loop can lose it before it is sent).

  2. Transaction search — inspect a single request end-to-end (request + dependencies + exceptions), correlated by OperationId.

  3. Logs (KQL), after ingestion: AppRequests | where TimeGenerated > ago(15m) | project TimeGenerated, Name, ResultCode, DurationMs.

  4. Application Map — appears once AppDependencies has rows; draws app → Postgres → OpenAI.

Once telemetry is confirmed, your application log lines appear in both AppServiceConsoleLogs (via the diagnostic setting) and AppTraces (via App Insights) — the same lines in two tables, reaching them by two independent paths.