Skip to content

feat: opt-in structured access-audit logging - #62

Open
alexluft wants to merge 23 commits into
mainfrom
feat/access-audit-log
Open

alexluft wants to merge 23 commits into
mainfrom
feat/access-audit-log

Conversation

@alexluft

@alexluft alexluft commented Aug 17, 2026 •

Copy link
Copy Markdown
Collaborator

What

Adds an opt-in access-audit log: telemetry.audit.enabled, default false. When it is disabled, nothing changes: no layer, no writer thread, and the same log output. The one exception is the ANSI change listed under Also included.

When it is enabled, every HTTP request emits one self-contained JSON line on stdout:

{"audit":"http-access","ts":"2026-08-17T17:16:55Z","user":"user@example.org",
 "subject":"a1b2c3d4-…","source":"192.0.2.10","method":"GET",
 "path":"/aets/PACS/studies/1.2.3.4","aet":"PACS","study":"1.2.3.4",
 "status":200,"duration_ms":4886,"request_id":"0b6f…"}

Motivation. In clinical deployments, "who accessed which study, when" is a legal requirement. Log pipelines (Loki, ELK, …) can select these lines by the audit field and ship them to WORM storage.

Design

  • Identity comes from the authenticating reverse proxy's request headers.
    • Which headers is configurable: user-header and subject-header default to X-Forwarded-Email and X-Forwarded-User.
    • The first version of this PR read X-Auth-Request-*. In oauth2-proxy's reverse-proxy mode those are response headers: they are never set on the upstream request and never stripped from client input. So the identity was empty for real traffic and forgeable by any client.
    • oauth2-proxy (checked in v7.15.3) strips client copies of X-Forwarded-{User,Email,Groups,Preferred-Username,Access-Token} before setting them from the verified session.
    • The docs spell out the preconditions as a product-neutral trust model:
      • the proxy strips client copies of the identity headers;
      • DICOM-RST is reachable only through the proxy.
    • An identity header that is repeated, over-long (more than 320 bytes) or malformed counts as absent. It is never truncated.
  • Optional on-behalf-of for trusted relays, also off by default.
    • A relay application may call DICOM-RST with its own machine identity on behalf of its users, for example because the proxy's authorization is a single role that also gates STOW-RS.
    • Such a relay can name the end user in X-On-Behalf-Of. It is recorded as on_behalf_of only when telemetry.audit.trusted-relays lists the caller's proxy-asserted identity.
    • Anything else is recorded only as on_behalf_of_rejected: "untrusted-caller" | "invalid". The rejected value itself is never logged.
    • With no relays configured, the header is not read at all.
    • This records the relay's claim; it does not authorize anything.
  • request_id comes from X-Request-Id, for correlation with the proxy's access log.
  • Fail-open, off the request path.
    • Records go through a bounded channel (1024) to a dedicated writer thread, so a stalled stdout never ties up a runtime worker.
    • When the buffer is full, the record is dropped and a warning with a running count is logged: the first time, then every 100th.
    • Buffered records are flushed on graceful shutdown, with a bounded wait.
    • Copied values are capped by bytes, the truncation marker included: path 8 KiB, user agent 512 B, source 64 B, each DICOM coordinate 256 B.
  • What is recorded: method, full path and query (QIDO match parameters are part of "which data"), the aet, study, series and instance path parameters, status and duration.
    • Path parameters are read without ever rejecting a request. The first version answered a non-UTF-8 path segment with its own 400.
    • Status and duration are taken when the response head is produced.
    • The layer sits outside the timeout layer, so a timed-out request is audited with its 408.
  • Timestamps use chrono, which is already a transitive dependency via dicom-core. It is declared directly with default-features = false, features = ["clock"].

Also included

  • movescu: logs the Study Instance UID on C-MOVE completion, only when auditing is enabled, Debug-escaped.
  • Regular log, only while auditing is enabled: line breaks inside a log event are escaped (\n, \r).
    • Why: audit records share stdout with the text log, and tracing-subscriber escapes ANSI sequences but not line breaks. A log message that carries request data could otherwise start a line of its own that looks like an audit record. One example is the S3 prefix log, which is built from percent-decoded path segments.
    • The formatter hands each event to the writer with one write_all, and a test pins that.
    • With auditing disabled, the default writer is used and the output is unchanged.
    • Residual: panic messages go to stderr unescaped. A collector that merges stderr into the same stream as stdout should keep the stream distinction.
  • ANSI colours: with_ansi(is_terminal() && NO_COLOR unset) on the fmt layer. Container logs lose the escape codes, TTY output keeps colours, and NO_COLOR is still honoured. This is the one default-on change. It is listed under Changed in the CHANGELOG. Please say if you would rather have it as a separate PR.
  • Docs: docs/topics/configuration.md documents every key, the trust model and the record's limits. CHANGELOG entries are under Unreleased.

Relation to native OIDC

This agrees with @feliwir's point above: native OIDC, with the subject taken from a verified JWT, is the better end state. Until DICOM-RST has it, an authenticating proxy is the only way to run it in an SSO environment, and this PR makes the audit correct and hard to forge in that setup.

When native OIDC lands, the identity could come from the verified token instead of headers. Relays could then forward their users' own tokens, which would replace the on-behalf-of mechanism.

Open question for maintainers

source is still the leftmost X-Forwarded-For entry, as in the first version. It is documented as client-asserted, because proxies usually append to a client's XFF. Recording the peer address, or a configurable number of trusted hops, would be stricter. That is left to you.

Testing

  • cargo check, cargo test and cargo test --all-features pass: 53 unit, 2 end-to-end audit tests through the real binary (enabled and disabled), and 4 existing integration tests.
  • cargo fmt --check passes. cargo clippy --all-targets -- -D warnings is clean. CI's --all-features clippy shows only the 11 warnings already on main.
  • MSRV: cargo +1.91 check and test pass.
  • Each commit builds and passes the tests on its own.
  • Every new test was checked by deliberately breaking the code it covers.

Please squash-merge. The branch carries 23 commits of review iterations.


🤖 Generated with Claude Code

https://claude.ai/code/session_01Q9PMSu4fFsV5dSNojTTQaG
https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k

@feliwir

feliwir commented Aug 17, 2026

Copy link
Copy Markdown
Contributor

I think it would make sense to integrate OIDC authorization first. So we could track the subject from the JWT.

Reading the user & mail from some HTTP header fields is some special case when deployed behind a reverse proxy that is not really the default setup.

@MaxOremek

Copy link
Copy Markdown

We have in Bonn developed a RUST based LDAP Audit Microservices with JWT with Access Logging to a PostGres. Would you be interested in recycling this?

@alexluft

Copy link
Copy Markdown
Collaborator Author

I'd absolutely upvote a native oidc support 👍
Until then, using oauth2 proxy is the only way to get dicom-rst integrated into sso environments.
Running web services behind reverse proxies with- or without an authentication layer is pretty common and best practice. Passing sub and more information from the reverse proxy for audit log (which is required legally) is a low hanging fruit.

Comment thread src/audit.rs Outdated
@alexluft
alexluft requested review from feliwir and nickamzol and removed request for feliwir August 18, 2026 12:09
Alex Luft and others added 21 commits September 26, 2026 06:05
Adds telemetry.audit.enabled (default: false). When enabled, every HTTP
request emits one JSON line on stdout recording who accessed what:
identity from the X-Auth-Request-Email/-User headers an authenticating
reverse proxy injects (DICOM-RST itself has no auth, see #15/#42),
source from X-Forwarded-For, plus method, full path+query, extracted
aet/study/series/instance path parameters, status and duration.

Delivery is fail-open by design: records flow through a bounded channel
to a stdout writer task; a full buffer drops the record and logs a
rate-limited warning instead of ever blocking request handling.

Also: log the Study Instance UID on C-MOVE completion so DIMSE-side
retrievals are attributable too, and disable ANSI colors when stdout is
not a terminal so container logs stay machine-parseable.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Q9PMSu4fFsV5dSNojTTQaG
chrono is already in the dependency graph via dicom-core (with the
clock feature enabled), so the hand-rolled RFC 3339 formatter bought
nothing. Declared directly (default-features = false, clock only)
rather than leaning on the transitive edge. Output format unchanged:
2026-08-17T17:16:55Z.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Q9PMSu4fFsV5dSNojTTQaG
The example record now uses a documentation IP (RFC 5737), an example.org
identity, a placeholder AET and a placeholder UID.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
X-Auth-Request-User/-Email are response headers in oauth2-proxy's
reverse-proxy mode: they are never set on the upstream request and never
stripped from it, so for real traffic they are empty while any client can
forge them. Read the identity from X-Forwarded-Email / X-Forwarded-User
instead, which oauth2-proxy (pass_user_headers, the default) removes from
the incoming request and re-sets from the verified session.

Both header names are configurable (telemetry.audit.user-header,
telemetry.audit.subject-header) for other proxies. They are parsed into
HeaderName when the configuration is loaded, so an invalid name fails at
startup with the offending key instead of at request time. A header that
occurs more than once is ambiguous and treated as absent.

Adds middleware-level tests driving an axum Router with a test sink that
exposes its receiver.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
The middleware took RawPathParams as an extractor argument. That extractor
rejects when a path parameter is not valid percent-encoded UTF-8, so the
audit layer answered such requests with its own 400 instead of passing them
to the application, and did not record them. The layer was also installed
when auditing was disabled, which applied the same rejection to every
deployment.

Read the path parameters without a rejecting extractor, so an undecodable
request passes through unchanged and is still audited, and install the
layer only when telemetry.audit.enabled is set, so a disabled audit leaves
the middleware stack exactly as it was.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
A service that calls DICOM-RST for a signed-in user authenticates as
itself, so the audit record names the service, not the person whose data
is accessed. Let explicitly trusted callers name that person:

- telemetry.audit.trusted-relays (default: empty) lists identities, as
  they appear in the user header, that may assert an end user.
- telemetry.audit.on-behalf-of-header (default: X-On-Behalf-Of) is the
  request header carrying the assertion.

The assertion is recorded as on_behalf_of only when the verified caller
is a trusted relay (ASCII case-insensitive), the header occurs exactly
once, and the value is 1..=320 bytes of UTF-8 without whitespace or
control characters. Otherwise on_behalf_of_rejected records why
("untrusted-caller" or "invalid") and the asserted value is not logged.
With no trusted relays configured the header is not read at all, so the
record is exactly what it was before.

Relays are trimmed, checked non-empty and normalised when the
configuration is loaded; an on-behalf-of header that collides with the
user or subject header is a load error.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Adds request_id to the audit record when the request carries exactly one
X-Request-Id of 1..=128 visible ASCII characters, so an audit line can be
joined with the access log of the proxy or ingress that assigned the id.
Malformed or repeated ids are omitted.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
The study_uid field on the C-MOVE completion line changed the default
INFO output for every deployment. Pass telemetry.audit.enabled down to
the MOVE-SCU and add the field only then; with auditing disabled the
completion line is the same as before and the identifier is not read.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Documents every telemetry.audit key, the record fields, the trust model
(the proxy must replace client-supplied identity headers and be the only
way to reach the HTTP port; relays are trusted by the identity the proxy
verified for them) and a generic oauth2-proxy example. Adds the audit
log, trusted relays, request id and the ANSI color change to the
changelog.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
A trusted relay's value is recorded verbatim, so pin that quotes and
backslashes in it stay data inside the one JSON line: they can neither
close the field nor forge another key.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Forcing with_ansi(stdout().is_terminal()) overrode tracing-subscriber's
default, which disables colors when NO_COLOR is set to a non-empty value.
Colors are now used only on a terminal and without NO_COLOR.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Identity headers were read with HeaderValue::to_str, which only accepts
visible ASCII, so an identity with non-ASCII characters was dropped. The
user and subject headers now accept 1..=320 bytes of UTF-8 without
control characters. Anything else, including an over-long value, is
recorded as absent and never truncated: a shortened identity could equal
someone else's.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Configuring Authorization, Proxy-Authorization or Cookie as the user,
subject or on-behalf-of header would copy secrets into the audit log.
Such a configuration is now a load error naming the key.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
path, user_agent and source were copied into the record without a limit,
so a single oversized request produced an equally oversized audit line.
They are now capped at 8 KiB, 512 bytes and 64 bytes respectively, cut
at a character boundary and marked with a trailing "…".

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
The writer ran as a Tokio task doing blocking stdout writes, so a stalled
stdout consumer could tie up a runtime worker. Records are now written by
a dedicated std::thread that receives with blocking_recv.

The thread is started before the runtime and joined after it has shut
down: once the server stops gracefully, every sink is dropped, the writer
drains the buffer and exits, and main waits up to 5 seconds for it.
Without a graceful shutdown, buffered records are lost; this is
documented.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
The Study Instance UID comes from the percent-decoded request path, so a
request could put a newline or other control character into the human
log line. Record it with Debug formatting, which escapes them.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
- a trusted relay is matched through a configured user header, and the
  same name in the default header does not count;
- a trusted relay that sends no on-behalf-of header produces neither
  on_behalf_of nor on_behalf_of_rejected;
- a request that times out in a TimeoutLayer inside the audit layer is
  recorded with its 408.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Two integration tests start the server binary with and without
telemetry.audit.enabled, send one request and inspect stdout: enabled
produces exactly one "http-access" JSON line with the forwarded identity,
disabled produces none while the request itself is still logged. They
need no PACS or container.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
The trust model is now stated for any proxy first: the proxy replaces
client copies of the user and subject headers but must leave the
on-behalf-of header alone, because relays are proxy clients themselves;
each relay sets that header from its own verified session and never
forwards a client's copy; DICOM-RST is reachable only through the proxy.
The oauth2-proxy behaviour follows as verified for v7.15.3, with advice
to check the version in use; the module docs no longer assert it and
point to the configuration page instead.

Also documents that on_behalf_of is a recorded claim, never
authorization; that source and request_id are client-asserted unless
overwritten upstream; when status and duration are taken and when no
record is written; why records without a user deserve an alert; the
request-id charset, the periodic drop warning and the effect of an
undecodable path parameter.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
The `…` marker was appended after cutting to the cap, so a cut value
was up to three bytes over it; it now counts against the cap. The
`aet`/`study`/`series`/`instance` fields were copied verbatim, so one
long path segment still produced an oversized record; each is now
capped at 256 bytes, far above any valid AE title or UID.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
oauth2-proxy sets it to the session's access token; pointing an identity
header at it would write the token into every audit record. The list
stays a best-effort guard and the docs now say so.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
@alexluft
alexluft force-pushed the feat/access-audit-log branch from b13ed6f to cd93b04 Compare September 26, 2026 07:46
alexluft and others added 2 commits September 26, 2026 08:04
Audit records and the regular log share stdout, and tracing-subscriber's
text formatter escapes ANSI sequences but not line breaks. A message that
carries request data (e.g. a percent-decoded path segment in the S3
prefix log line) could therefore start a line of its own that looks like
an audit record. While auditing is enabled, the regular log is written
through a writer that escapes line breaks inside each formatted event and
keeps only its final one. With auditing disabled the default writer is
used and the output is unchanged.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
Pin that tracing-subscriber hands the writer one whole event, including
when a newline ends a format argument or a field, so a future version
that streamed events in pieces fails the suite instead of silently
reopening the forged-line path. `bounded` now honours caps smaller than
the marker (no marker then), tested from 0. Docs: the one-line
guarantee is about \n and \r, not Unicode line separators; drop a stale
doc comment on the credential-header list.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcyZjaNmg7eB5uC1jeXV3k
@alexluft

Copy link
Copy Markdown
Collaborator Author

@feliwir this is ready for review. It adds an opt-in access-audit log: it is off by default, and nothing changes unless telemetry.audit.enabled is set. Identity comes from the authenticating proxy's forwarded request headers, and on-behalf-of is recorded only for explicitly configured trusted relays; everything is documented in docs/topics/configuration.md and the CHANGELOG. Given the review iterations on the branch, I'd suggest a squash-merge. Thanks!

@nickamzol

Copy link
Copy Markdown
Member

The motivation states that access auditing is a legal requirement, but the design is fail-open: records are dropped under pressure and lost on write errors. Is that intended?

I'm also not comfortable with the on-behalf-of / trusted-relay mechanism. It adds a fair amount of security-sensitive configuration and logic to work around missing OIDC support, and it records a claim that DICOM-RST can't verify. I'd rather drop it from this PR and implement native OIDC instead.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants