[aaltshuler]

Owned server operations can outlive the initiating request, but existing HTTP logs do not provide collector-ready trace context for that work. This adds optional OTLP HTTP/protobuf export and correlated JSON logs. Text logs and disabled export remain the defaults; exporting requires an explicit endpoint.

Request spans record route templates, methods, status and time to response headers. Owned read/write spans preserve request ancestry and bounded outcomes. Export admits only authored telemetry targets; logs retain the existing MCP/Lance payload restrictions. Bodies, credentials, query strings and path parameters are excluded. RUST_LOG controls log events independently of trace export, while warning and error logs retain their enclosing trace IDs when INFO logging is suppressed.

The expanded HTTP/owned-operation regression failed before the filter repair with zero exported spans instead of three. It now passes for INFO, WARN, ERROR and OFF JSON logging and WARN text logging, including parent context, correlation and private-payload canaries. All 222 server library tests and the executable test pass; two subprocess helper tests remain intentionally ignored and are exercised by their parent tests. Existing coverage includes real protobuf export to a loopback collector, malformed context, scoped publication uncertainty and unchanged admission. This revision integrates main at 3602c308, including Tokio 1.53.3, and reports development version 0.14.1.

For review: telemetry is best effort, with a bounded queue and independent exporter timeout. Its background flush does not extend native shutdown deadlines, and buffered spans may be lost at process exit. It is correlation, never durable operation evidence or authority. Storage and authorization contracts remain unchanged. This PR remains a draft.

[ragnorc]

This change gives operators request traces and JSON logs they can join to a caller trace. Text logs stay the default. Export stays off until an OTLP HTTP/protobuf endpoint is set. The binary installs that subscriber from telemetry::init. Export is limited to omnigraph_server::telemetry spans. The batch worker is bounded.

Keep this pull request in draft until the three blocking items are fixed and the branch is rebased onto current main (10f5517c5d41c433005603b0c5a29358ec9560a8). I recommend that change before review leaves draft.

Blocking

1. The log filter also disables trace export

subscriber installs EnvFilter and safe_log_metadata as subscriber-wide layers, then adds the OpenTelemetry layer (crates/omnigraph-server/src/telemetry.rs). A callsite those layers disable is disabled for every layer. RUST_LOG=warn exports no info request span.

The guide treats RUST_LOG as the log control and OTEL_TRACES_SAMPLER as the sample control (docs/user/operations/observability.md). In the code those controls are one switch.

Class: every info span and event on omnigraph_server::telemetry, including http.server and native.operation, whenever the log filter is quieter than info or disables that target.

The formatter owns logs. Put one per-layer filter on the fmt layer. That filter applies EnvFilter and safe_log_metadata together. The OpenTelemetry layer keeps its target allowlist as its own per-layer filter.

A local experiment stacked two .with_filter calls on one layer. The warn-level export test then passed. http_and_owned_operations_preserve_parent_context_without_payloads finished two native.operation spans and omitted the server span. One combined filter on the formatter kept three spans, remote parent b7ad6b7169203331, the warn-level export, and the restricted-target log test.

Liability removed: a quiet log setting deletes traces and reports success. Liability added: the formatter filter and the export filter must stay on different layers. The next signal (metrics, OTLP logs) adds a processor or a layer and leaves this split in place. Five more global filters would make each signal depend on the quietest one.

2. JSON trace correlation is tied to the exporter

init builds a tracer only when an endpoint is set (telemetry.rs). CorrelatedJson reads OtelData from the span. That data exists after a tracer starts the span. With OMNIGRAPH_LOG_FORMAT=json, a valid traceparent, and no endpoint, the completion record has trace_id null. The same record still carries http.route /readyz and the method under span.

The guide says JSON logs include trace_id and span_id. It does not require an endpoint in that sentence.

Class: every JSON log inside a request span while export is off, including the documented completion record. OTEL_SDK_DISABLED=true takes the same path.

Build a SdkTracerProvider with no span processor when export is off. Add the batch exporter only when an endpoint is set. That path does no network I/O. Sampling still follows the SDK config.

init_tracing still reaches telemetry::subscriber with JSON off and no tracer (crates/omnigraph-server/src/lib.rs, server_log_subscriber). The binary calls telemetry::init. An embedder who calls the documented init_tracing gets text logs and no correlation ids. One install function should own this contract. init_tracing should read the same config and return the same guard. If it stays log-only, the guide should say that only telemetry::init installs JSON logs and trace ids. One door is the smaller liability. A second install path will drift on the next signal.

Liability removed: operators can join a JSON line to the caller trace while export is off. Liability added: a tracer and span extensions on each request while export is off. The cost is memory and CPU. There is no I/O. That cost matches the log contract. Correctness comes before the idle-path allocations.

3. Rebase onto current main conflicts, and a bad resolution drops request facts

git merge-tree --name-only origin/main 31c9f294 against 10f5517c5d41c433005603b0c5a29358ec9560a8 (fix(server): log the status an error response sends, #1117, now on main) conflicts in:

• Cargo.lock
• crates/omnigraph-server/src/lib.rs
• crates/omnigraph-server/src/operations.rs
• docs/user/index.md

The same four files conflicted with 235cd3b9. 13ecdc8b is behind that history. I inspected the conflict bodies with git merge-file on the three blobs.

Owned write. Current main runs the future under SUBMITTED_WRITE.scope, destructures OwnedResult, calls ApiError::after_owned_write, then logs owned write ended without a definite outcome with status = %error.status(). after_owned_write is what makes status() the status the response sends. The PR side inserts operation_finished("write", result.result.is_ok(), result.uncertain) at that spot. Pasting that call into the rebased function fails to compile: result is already the inner Result. Taking the PR side and dropping after_owned_write lets an uncertain write be judged as a write with no effects, and the status log can disagree with the response.

Keep SUBMITTED_WRITE.scope, after_owned_write, and the status log. Call operation_finished("write", result.is_ok(), uncertain) on the inner result, before after_owned_write. operation_outcome records succeeded, failed, or uncertain. The HTTP status stays in the existing log.

Owned read. Current main runs the read inside scope_request and maps errors with ApiError::with_request_facts. The PR side replaces that body with operation_finished. Taking the PR side drops the task-local record that this request submitted a write. An owned read, including an MCP tool call, can then report that the request had no effects when a write was submitted.

Keep scope_request and with_request_facts. Call operation_finished inside that scope, so the completion event stays on the operation span.

lib.rs: keep pub mod telemetry and use extract::{ApiJson, ApiPath, ApiQuery}.

docs/user/index.md: keep the storage-failures link and the server logs and traces link.

Cargo.lock: regenerate it with the locked build. A hand merge of that conflict will drift.

The .instrument(operation_span(...)) lines merged on their own. Keep them.

Optional

main calls shutdown_in_background and then returns (crates/omnigraph-server/src/main.rs). That method spawns a thread and returns. Process exit ends the thread before shutdown_with_timeout (five seconds) can finish. The guide says a best-effort flush starts with a five-second bound, and that process exit can lose spans. The loss sentence matches the binary. Say that the five-second timeout applies when an embedder calls TelemetryGuard::shutdown. The loopback test calls shutdown() on the test thread, so it covers the embedder path. Joining after run returns would wait up to five seconds after native shutdown. The guide says the flush does not delay process exit. Make one of those sentences the contract, and make the binary match it.

The HTTP exporter reads OTEL_EXPORTER_OTLP_TRACES_HEADERS, then OTEL_EXPORTER_OTLP_HEADERS (opentelemetry-otlp 0.31.1, exporter/http/mod.rs). The guide says "Normal authentication configuration still applies." Name those two variables. The server bearer token is a separate control. Endpoint userinfo stays rejected.

The HTTP span stays open until owned child spans close. The registry holds a parent reference for the child. response_headers_ms is the time until headers. Span duration includes detached owned work. One guide sentence will keep operators from reading span duration as time-to-headers.

CorrelatedJson builds a JSON string and parses it on every event. That cost is acceptable at the current log rate. Keep it on the formatter.

http-proto enables opentelemetry-proto feature gen-tonic-messages, which depends on tonic and tonic-prost. The HTTP exporter links the gRPC stack. Worth a follow-up if binary size or the crate graph matters. Behavior is unchanged. deny.toml already allows the licenses.

An unrecognized OTEL_TRACES_SAMPLER warns and falls back to parent-based always-on (opentelemetry_sdk 0.31.0, trace/config.rs). internal-logs is enabled, so the warning can surface. Startup still succeeds. Fail closed here only if a bad sampler must stop the process.

OTEL_BSP_* and OTEL_EXPORTER_OTLP_TRACES_TIMEOUT do not change the hardcoded queue (2048), batch (256), delay (5s), or HTTP timeout (3s). The guide states those bounds. Add that the SDK variables do not override them.

This change does not install a Lance metrics recorder. Lance observability on the current guide is a metrics facade. A later metrics change should use that recorder and LANCE_OBJECT_STORE_METRICS_LABEL. A second exporter pipeline would split signals the same way the log filter and the tracer are split today.

Tradeoff

The design is small: one subscriber, one optional batch processor, one JSON formatter. That shape is right. The liability is that three contracts share switches: log level with export, correlation with the endpoint, and init_tracing with telemetry::init. Five more changes of this kind add another environment variable, another global filter, and another install path. The durable shape is one subscriber builder. The formatter owns the log gate. The tracer always exists. Export is a processor on that tracer.

The privacy bounds in this change should stay on that builder: the target allowlist, the traceparent length cap, rejection of baggage and userinfo, and the restricted rmcp / Lance targets.

Checked, and left as-is

JSON completion records include the route template and method under span while export is off. The missing field is trace_id.

set_parent after info_span! adopts the caller. The existing test sees parent b7ad6b7169203331 and trace 0af7651916cd43dd8448eb211c80319c.

Dropping the handler span leaves the request span in the child scope. The registry parent reference keeps it. The owned-operation parent test passed.

service.name filtering matches the SDK value unknown_service. OTEL_SERVICE_NAME and a later service.name resource attribute override it.

Malformed traceparent and the privacy canaries stay out of logs and span debug text. The restricted-target log test passed for text and JSON.

Tests to add

A .gqt case sees rows, counts, column types, and errors. This contract is the subscriber and the exporter. The owner is the omnigraph-server library tests. Please add these two beside the existing telemetry tests:

1. EnvFilter warn, in-memory exporter, GET /readyz. Expect one finished span named GET /readyz.
2. OMNIGRAPH_LOG_FORMAT=json, no endpoint, traceparent 00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01. Expect completion trace_id 0af7651916cd43dd8448eb211c80319c.

On 31c9f294, with those tests and the current subscriber, (1) failed with 0 spans and (2) failed because trace_id was null. After a temporary formatter-only log gate and a no-processor provider, the same tests passed, and the existing parent-context, redaction, OTLP loopback, and restricted-target tests passed. I removed the temporary tests. They are not on the branch.

Validation

Head reviewed: 31c9f294c43f151f6e83208cfa994f6a99f74f3f. Isolated checkout. No push.

Failure, current subscriber, tests added locally:

CARGO_TARGET_DIR=/workspace/target cargo test -p omnigraph-server --lib --locked -- telemetry::tests::warn_log_filter_still_exports_the_request_span telemetry::tests::json_logs_carry_the_caller_trace_when_export_is_off telemetry::tests::http_and_owned_operations_preserve_parent_context_without_payloads telemetry::tests::malformed_context_and_unknown_routes_never_echo_request_input operations::tests::disconnected_owned_operation_keeps_the_request_span_open operations::tests::disconnected_owned_operation_keeps_its_request_span log_filter_tests::restricted_dependency_logs_remain_filtered_under_specific_directives -- --test-threads=8

Result: 5 passed, 2 failed, 206 filtered out. warn_log_filter_still_exports_the_request_span: 0 spans, expected 1 (quiet logs must not drop traces: []). json_logs_carry_the_caller_trace_when_export_is_off: trace_id null, with /readyz present under span.http.route. The parent-context, malformed-context, both owned-operation span tests, and the restricted-target test passed.

Success, temporary fix only, then restored. Same package and flags, plus telemetry::tests::exporter_requires_an_explicit_endpoint_and_valid_safe_configuration and telemetry::tests::bounded_worker_exports_real_otlp_protobuf_and_flushes_before_shutdown, and without the extra parent-lifetime test:

Result: 8 passed, 0 failed, 205 filtered out. omnigraph-server test compile 15.38s. Tests 0.01s.

Limitations

I did not rerun the workspace CI graph. I did not re-check the PR body's CI claim. I did not run the full omnigraph-server suite. The flush-on-exit note comes from main returning after an unjoined spawn, and from process exit ending that thread. I did not run a process-exit test. Lance's observability guide is a metrics facade. This PR does not install that recorder. The temporary edits are gone from the isolated checkout.

Inline comments that could not be attached

crates/omnigraph-server/src/telemetry.rs:202 — EnvFilter here is a subscriber-wide layer. RUST_LOG=warn disables info callsites before the OpenTelemetry layer sees them. A local test exported 0 request spans (quiet logs must not drop traces: []). Move this filter, together with safe_log_metadata, onto the fmt layer as one per-layer filter. Leave the target allowlist on the OpenTelemetry layer. Two stacked .with_filter calls kept the two native.operation spans and dropped the server span. One combined formatter filter kept all three spans.

crates/omnigraph-server/src/telemetry.rs:73 — This builds a tracer only when an endpoint is set. With JSON logs, a valid traceparent, and no endpoint, the completion record has trace_id null. The route is still present under span. Build a SdkTracerProvider with no span processor when export is off, and add the batch exporter only for an endpoint. That path does no network I/O.

crates/omnigraph-server/src/lib.rs:2410 — init_tracing reaches this call with JSON off and no tracer. The binary uses telemetry::init. One install path should read OMNIGRAPH_LOG_FORMAT and the endpoint and install the same subscriber. Otherwise an embedder who follows init_tracing gets neither JSON logs nor correlation ids.

crates/omnigraph-server/src/operations.rs:258 — On rebase onto 10f5517c, this call lands where ApiError::after_owned_write is. Keep SUBMITTED_WRITE.scope, after_owned_write, and the status = %error.status() log (owned write ended without a definite outcome). Call operation_finished("write", result.is_ok(), uncertain) on the inner Result, before after_owned_write. result.result does not compile after main's destructure. Dropping after_owned_write lets an uncertain write be judged as having no effects, and the status log can disagree with the response (#1117).

crates/omnigraph-server/src/operations.rs:436 — On rebase, keep scope_request and ApiError::with_request_facts. Call operation_finished inside that scope. Replacing the body drops the task-local submitted-write fact. An owned read, including an MCP tool call, can then report that the request had no effects when a write was submitted.

docs/user/operations/observability.md:29 — This sentence holds when a tracer is installed. With JSON logs and no endpoint, the completion record omits trace_id and span_id. Route and method are already under span. A provider with no processor (no export I/O) makes the sentence true.