Skip to content

Commit c39833a

Browse files
committed
fix(audit): address OTLP payload review feedback
Signed-off-by: Yuting Wu (DLAlgo) <yutwu@nvidia.com>
1 parent 7d8ed18 commit c39833a

8 files changed

Lines changed: 252 additions & 42 deletions

File tree

lib/llm/src/audit/config.rs

Lines changed: 32 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,9 @@
44
use std::sync::OnceLock;
55
use std::sync::atomic::{AtomicU8, Ordering};
66

7+
#[cfg(test)]
8+
use std::sync::Mutex;
9+
710
use dynamo_runtime::config::environment_names::llm::audit as env_audit;
811

912
use crate::telemetry::parse_sink_names;
@@ -35,6 +38,9 @@ pub struct AuditPolicy {
3538
static POLICY: OnceLock<AuditPolicy> = OnceLock::new();
3639
static CAPTURE_STATE: AtomicU8 = AtomicU8::new(CAPTURE_UNINITIALIZED);
3740

41+
#[cfg(test)]
42+
static TEST_POLICY_OVERRIDE: Mutex<Option<&'static AuditPolicy>> = Mutex::new(None);
43+
3844
/// Audit is enabled if we have at least one sink
3945
fn load_from_env() -> AuditPolicy {
4046
let sinks = std::env::var(env_audit::DYN_AUDIT_SINKS)
@@ -91,9 +97,33 @@ fn load_from_env() -> AuditPolicy {
9197
}
9298

9399
pub fn policy() -> &'static AuditPolicy {
100+
#[cfg(test)]
101+
if let Some(policy) = *TEST_POLICY_OVERRIDE
102+
.lock()
103+
.expect("test policy lock poisoned")
104+
{
105+
return policy;
106+
}
107+
94108
POLICY.get_or_init(load_from_env)
95109
}
96110

111+
#[cfg(test)]
112+
pub(crate) fn override_policy_from_env_for_test() {
113+
let policy = Box::leak(Box::new(load_from_env()));
114+
*TEST_POLICY_OVERRIDE
115+
.lock()
116+
.expect("test policy lock poisoned") = Some(policy);
117+
}
118+
119+
#[cfg(test)]
120+
pub(crate) fn clear_policy_override_for_test() {
121+
*TEST_POLICY_OVERRIDE
122+
.lock()
123+
.expect("test policy lock poisoned") = None;
124+
mark_capture_inactive();
125+
}
126+
97127
pub(crate) fn mark_capture_active() {
98128
CAPTURE_STATE.store(CAPTURE_ACTIVE, Ordering::Release);
99129
}
@@ -102,7 +132,7 @@ pub(crate) fn mark_capture_inactive() {
102132
CAPTURE_STATE.store(CAPTURE_INACTIVE, Ordering::Release);
103133
}
104134

105-
pub fn capture_enabled() -> bool {
135+
pub(crate) fn capture_enabled() -> bool {
106136
// Require the explicit ACTIVE transition so that publishes happening before
107137
// `init_from_env_with_shutdown` finishes — i.e. while the bus is still
108138
// uninitialized — are skipped at the `create_handle` gate rather than
@@ -114,7 +144,7 @@ pub fn capture_enabled() -> bool {
114144
policy.enabled && CAPTURE_STATE.load(Ordering::Acquire) == CAPTURE_ACTIVE
115145
}
116146

117-
pub fn otel_sink_capture_enabled() -> bool {
147+
pub(crate) fn otel_sink_capture_enabled() -> bool {
118148
let policy = policy();
119149
policy.enabled
120150
&& CAPTURE_STATE.load(Ordering::Acquire) == CAPTURE_ACTIVE

lib/llm/src/audit/handle.rs

Lines changed: 18 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -31,9 +31,9 @@ impl AuditHttpRequestHeaders {
3131
/// Distinguishes the two record types emitted per chat completion.
3232
///
3333
/// Request and response are published as separate `AuditRecord`s sharing the same
34-
/// `request_id`. Downstream consumers correlate by `request_id`; the request record
35-
/// is emitted before the worker dispatches, the response record is emitted after the
36-
/// response stream completes successfully. On client cancel mid-stream (or
34+
/// `request_id`. Downstream consumers correlate by `request_id`; the request emit
35+
/// is scheduled before the worker dispatches, the response record is emitted after
36+
/// the response stream completes successfully. On client cancel mid-stream (or
3737
/// aggregation failure) only the request record is emitted.
3838
#[derive(Serialize, Deserialize, Clone, Copy, Debug, Eq, PartialEq)]
3939
#[serde(rename_all = "lowercase")]
@@ -74,9 +74,10 @@ impl AuditHandle {
7474
&self.request_id
7575
}
7676

77-
/// Publish a `Request` event record on the audit bus. Call once, as soon as the
78-
/// request is captured and before worker dispatch — this lets downstream
79-
/// observers see hung / canceled requests that never produce a response record.
77+
/// Publish a `Request` event record on the audit bus. Call once after the
78+
/// request is captured. The preprocessor schedules this before worker
79+
/// dispatch so downstream observers can see hung / canceled requests that
80+
/// never produce a response record.
8081
pub fn emit_request(&self, request: Arc<NvCreateChatCompletionRequest>) {
8182
let rec = AuditRecord {
8283
schema_version: 1,
@@ -183,20 +184,28 @@ mod tests {
183184
serde_json::from_value(json).expect("Failed to create test response")
184185
}
185186

187+
struct AuditPolicyResetGuard;
188+
189+
impl Drop for AuditPolicyResetGuard {
190+
fn drop(&mut self) {
191+
crate::audit::config::clear_policy_override_for_test();
192+
}
193+
}
194+
186195
/// Test that DYN_AUDIT_FORCE_LOGGING=true bypasses store=false
187196
/// When force logging is enabled, audit handle should be created even when store=false
188197
#[test]
198+
#[serial_test::serial]
189199
fn test_force_logging_bypasses_store() {
190200
with_vars(
191201
[
192202
("DYN_AUDIT_SINKS", Some("stderr")),
193203
("DYN_AUDIT_FORCE_LOGGING", Some("true")),
194204
],
195205
|| {
196-
// `capture_enabled()` now requires `CAPTURE_ACTIVE`; mimic the
197-
// audit init lifecycle (`init_from_env_with_shutdown`) instead of
198-
// relying on the old "uninitialized counts as enabled" semantics.
206+
crate::audit::config::override_policy_from_env_for_test();
199207
crate::audit::config::mark_capture_active();
208+
let _reset_guard = AuditPolicyResetGuard;
200209

201210
let request = create_test_request("test-model", false);
202211
let handle = create_handle(&request, "test-id", None);

lib/llm/src/audit/otel_sink.rs

Lines changed: 95 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,9 @@
55
//!
66
//! Emits exactly one OTLP `LogRecord` per `AuditRecord`. The exporter is
77
//! constructed once at sink init (not per emit). Network I/O happens on the
8-
//! SDK's internal batch processor; `emit()` is non-blocking enqueue.
8+
//! SDK's internal batch processor; `emit()` is non-blocking enqueue. The audit
9+
//! worker calls `force_flush()` after draining on shutdown, but abrupt process
10+
//! teardown can still lose buffered OTLP records.
911
//!
1012
//! Transport follows `OTEL_EXPORTER_OTLP_LOGS_PROTOCOL` with
1113
//! `OTEL_EXPORTER_OTLP_PROTOCOL` as fallback. Supported values are
@@ -22,6 +24,7 @@ use axum::http::HeaderValue;
2224
use dynamo_runtime::config::environment_names::{
2325
llm::audit as env_audit, logging::otlp as env_otlp,
2426
};
27+
use opentelemetry::Context;
2528
use opentelemetry::logs::{AnyValue, LogRecord, Logger, LoggerProvider, Severity};
2629
use opentelemetry_otlp::{Protocol, WithExportConfig};
2730
use opentelemetry_sdk::Resource;
@@ -79,11 +82,8 @@ const AUDIT_INSTRUMENTATION_SCOPE: &str = "dynamo.payload";
7982
const DEFAULT_SERVICE_NAME: &str = "dynamo";
8083

8184
pub struct OtelSink {
82-
/// Held so the SDK's batch processor flushes when the sink is dropped on
83-
/// audit-bus shutdown. The field is never read directly — its job is to
84-
/// keep the provider alive for the sink's lifetime. TODO(phase D): wire
85-
/// an explicit `force_flush` hook on the worker cancellation path so
86-
/// records aren't lost if the runtime is torn down before Drop runs.
85+
/// Held so the SDK's batch processor stays alive for the sink's lifetime
86+
/// and can be force-flushed when the audit worker shuts down.
8787
#[allow(dead_code)]
8888
provider: SdkLoggerProvider,
8989
logger: SdkLogger,
@@ -175,6 +175,24 @@ impl OtlpLogsProtocol {
175175
}
176176
}
177177

178+
fn logs_endpoint_from_env(protocol: OtlpLogsProtocol) -> String {
179+
if let Ok(endpoint) = std::env::var(env_otlp::OTEL_EXPORTER_OTLP_LOGS_ENDPOINT) {
180+
return endpoint;
181+
}
182+
183+
if let Ok(endpoint) = std::env::var(env_otlp::OTEL_EXPORTER_OTLP_ENDPOINT) {
184+
return match protocol {
185+
OtlpLogsProtocol::HttpProtobuf => {
186+
let trimmed = endpoint.trim_end_matches('/');
187+
format!("{trimmed}/v1/logs")
188+
}
189+
OtlpLogsProtocol::Grpc => endpoint,
190+
};
191+
}
192+
193+
protocol.default_endpoint().to_string()
194+
}
195+
178196
fn render_header_value(name: &str, value: &HeaderValue, policy: &OtelHeaderPolicy) -> String {
179197
if policy.should_redact(name) {
180198
return REDACTED_HEADER_VALUE.to_string();
@@ -267,9 +285,7 @@ impl OtelSink {
267285

268286
pub async fn from_policy(policy: &AuditPolicy) -> Result<Self> {
269287
let protocol = OtlpLogsProtocol::from_env();
270-
let endpoint = std::env::var(env_otlp::OTEL_EXPORTER_OTLP_LOGS_ENDPOINT)
271-
.or_else(|_| std::env::var(env_otlp::OTEL_EXPORTER_OTLP_TRACES_ENDPOINT))
272-
.unwrap_or_else(|_| protocol.default_endpoint().to_string());
288+
let endpoint = logs_endpoint_from_env(protocol);
273289

274290
let exporter = match protocol {
275291
OtlpLogsProtocol::HttpProtobuf => opentelemetry_otlp::LogExporter::builder()
@@ -468,8 +484,23 @@ impl AuditSink for OtelSink {
468484
record.add_attribute("audit_drop_reason", AnyValue::String(reason.into()));
469485
}
470486
record.add_attribute("payload", AnyValue::String(payload.into()));
487+
488+
// Audit OTLP export is an explicit sink, not telemetry generated while
489+
// exporting telemetry. Use a fresh context so a globally suppressed
490+
// tracing bridge cannot cause the direct LogRecord emit to be skipped.
491+
let _guard = Context::new().attach();
471492
self.logger.emit(record);
472493
}
494+
495+
async fn shutdown(&self) {
496+
if let Err(err) = self.provider.force_flush() {
497+
tracing::warn!(
498+
target: "dynamo_llm::audit",
499+
error = %err,
500+
"audit otel: force_flush failed during shutdown"
501+
);
502+
}
503+
}
473504
}
474505

475506
#[cfg(test)]
@@ -815,4 +846,59 @@ mod tests {
815846
|| assert_eq!(OtlpLogsProtocol::from_env(), OtlpLogsProtocol::Grpc),
816847
);
817848
}
849+
850+
#[test]
851+
#[serial]
852+
fn logs_endpoint_uses_signal_specific_endpoint_first() {
853+
temp_env::with_vars(
854+
[
855+
(
856+
env_otlp::OTEL_EXPORTER_OTLP_LOGS_ENDPOINT,
857+
Some("http://collector:9999/custom/logs"),
858+
),
859+
(
860+
env_otlp::OTEL_EXPORTER_OTLP_ENDPOINT,
861+
Some("http://collector:4318"),
862+
),
863+
(
864+
env_otlp::OTEL_EXPORTER_OTLP_TRACES_ENDPOINT,
865+
Some("http://collector:4317/v1/traces"),
866+
),
867+
],
868+
|| {
869+
assert_eq!(
870+
logs_endpoint_from_env(OtlpLogsProtocol::HttpProtobuf),
871+
"http://collector:9999/custom/logs"
872+
);
873+
},
874+
);
875+
}
876+
877+
#[test]
878+
#[serial]
879+
fn logs_endpoint_falls_back_to_generic_endpoint_not_traces_endpoint() {
880+
temp_env::with_vars(
881+
[
882+
(env_otlp::OTEL_EXPORTER_OTLP_LOGS_ENDPOINT, None::<&str>),
883+
(
884+
env_otlp::OTEL_EXPORTER_OTLP_ENDPOINT,
885+
Some("http://collector:4318"),
886+
),
887+
(
888+
env_otlp::OTEL_EXPORTER_OTLP_TRACES_ENDPOINT,
889+
Some("http://collector:4317/v1/traces"),
890+
),
891+
],
892+
|| {
893+
assert_eq!(
894+
logs_endpoint_from_env(OtlpLogsProtocol::HttpProtobuf),
895+
"http://collector:4318/v1/logs"
896+
);
897+
assert_eq!(
898+
logs_endpoint_from_env(OtlpLogsProtocol::Grpc),
899+
"http://collector:4318"
900+
);
901+
},
902+
);
903+
}
818904
}

lib/llm/src/audit/sink.rs

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
// SPDX-FileCopyrightText: Copyright (c) 2024-2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
22
// SPDX-License-Identifier: Apache-2.0
33

4+
use std::io::Write as _;
45
use std::sync::Arc;
56
use std::time::Duration;
67

@@ -26,6 +27,7 @@ use super::{
2627
pub trait AuditSink: Send + Sync {
2728
fn name(&self) -> &'static str;
2829
async fn emit(&self, rec: &AuditRecord);
30+
async fn shutdown(&self) {}
2931
}
3032

3133
pub struct StderrSink;
@@ -37,7 +39,9 @@ impl AuditSink for StderrSink {
3739
async fn emit(&self, rec: &AuditRecord) {
3840
match serde_json::to_string(rec) {
3941
Ok(js) => {
40-
tracing::info!(target="dynamo_llm::audit", log_type="audit", record=%js, "audit")
42+
if let Err(e) = writeln!(std::io::stderr(), "{js}") {
43+
tracing::warn!("audit: stderr write failed: {e}");
44+
}
4145
}
4246
Err(e) => tracing::warn!("audit: serialize failed: {e}"),
4347
}
@@ -236,6 +240,7 @@ pub async fn spawn_workers_from_env(shutdown: CancellationToken) -> anyhow::Resu
236240
) => break,
237241
}
238242
}
243+
sink.shutdown().await;
239244
return;
240245
}
241246
msg = rx.recv() => {
@@ -251,6 +256,7 @@ pub async fn spawn_workers_from_env(shutdown: CancellationToken) -> anyhow::Resu
251256
}
252257
}
253258
}
259+
sink.shutdown().await;
254260
});
255261
}
256262
tracing::info!(sinks = sink_count, "Audit sinks ready");

0 commit comments

Comments
 (0)