Prevent recursive Tokio tracing in telemetry and SQLite logs (#51775)

## Why

Tokio runtime tracing can cause SQLite log writes to enqueue more writes and exporter activity to generate further OTLP exports.

## What changed

- Exclude `tokio` and `runtime` spans from OTLP export alongside `h2` spans.
- Limit `tokio::` and `runtime::` targets to `INFO` in the default log filter, and reject their `TRACE` events directly in the SQLite sink even without an outer filter.
- Box and pin the session-loop future before spawning it.
- Reorder tracing and Tokio test attributes, restrict the skills concurrency test's subscriber to the catalog-refresh span, and use the default log filter in the SQLite formatter comparison test.

GitOrigin-RevId: f545013a2469088d7f9890c1f46bb93eb5446d2d
This commit is contained in:
zbarsky-openai
2026-10-07 17:28:32 +00:00
committed by copyberry
parent bd5564fec4
commit 9dd798805f
8 changed files with 31 additions and 20 deletions
+2 -2
View File
@@ -969,14 +969,14 @@ impl Session {
.as_ref()
.and_then(|startup| startup.session_teardown(thread_id));
let session_for_loop = Arc::clone(&session);
let session_loop_handle = tokio::spawn(storage_originator.scope(async move {
let session_loop_handle = tokio::spawn(Box::pin(storage_originator.scope(async move {
submission_loop(session_for_loop, configured_config, rx_sub)
.instrument(info_span!("session_loop", thread_id = %thread_id))
.await;
if let Some(tree_teardown) = tree_teardown {
tree_teardown.complete();
}
}));
})));
let io = SessionIo {
tx_sub,
rx_event,
+1 -1
View File
@@ -10065,8 +10065,8 @@ async fn capability_roots_require_turn_environment_selection() {
);
}
#[tokio::test]
#[tracing_test::traced_test]
#[tokio::test]
async fn conflicting_ready_environment_root_ids_keep_first_location() {
let (session, turn_context) = make_session_and_context().await;
let selected_root =
@@ -1509,10 +1509,15 @@ async fn overlapping_executor_catalogs_render_their_own_roots() -> TestResult {
// the refresh callsite as globally disabled before this subscriber reaches it.
let _interest_cache_guard =
tracing::Dispatch::new(tracing::subscriber::NoSubscriber::default());
let subscriber = tracing_subscriber::registry().with(PauseAfterRefresh {
entered: Mutex::new(Some(entered)),
resume: Mutex::new(resume),
});
let subscriber = tracing_subscriber::registry().with(
PauseAfterRefresh {
entered: Mutex::new(Some(entered)),
resume: Mutex::new(resume),
}
.with_filter(tracing_subscriber::filter::filter_fn(|metadata| {
metadata.name() == "skills.executor.refresh_executor_catalog"
})),
);
let a = tokio::spawn(render(root_a).with_subscriber(subscriber));
tokio::time::timeout(std::time::Duration::from_secs(/*secs*/ 10), paused).await??;
let b = render(root_b).await;
+3 -3
View File
@@ -341,9 +341,9 @@ impl OtelProvider {
pub fn trace_export_filter(meta: &tracing::Metadata<'_>) -> bool {
let target = meta.target();
if meta.is_span() {
// h2 creates explicit-root spans that escape the SDK's telemetry suppression.
// Exporting them would make OTLP transport generate more OTLP exports.
target != "h2" && !target.starts_with("h2::")
// The exporter uses h2 and Tokio. Their root spans escape the
// SDK's suppression and would generate further OTLP exports.
!matches!(target.split("::").next(), Some("h2" | "tokio" | "runtime"))
} else {
is_trace_safe_target(target)
}
@@ -132,8 +132,8 @@ async fn callback(authorization_url: &str, issuer: &str, provider_error: bool) -
Ok(())
}
#[tokio::test]
#[traced_test]
#[tokio::test]
async fn enterprise_callback_errors_and_sdk_logs_exclude_credentials() -> Result<()> {
if isolated_process(
"enterprise_oauth_login::tests::enterprise_callback_errors_and_sdk_logs_exclude_credentials",
@@ -227,8 +227,8 @@ fn enterprise_callback_requires_loopback() -> Result<()> {
Ok(())
}
#[tokio::test]
#[traced_test]
#[tokio::test]
async fn enterprise_public_api_storage_and_privacy() -> Result<()> {
if isolated_process("enterprise_oauth_login::tests::enterprise_public_api_storage_and_privacy")
.await?
@@ -278,8 +278,8 @@ async fn keyring_failure_does_not_reuse_the_pinned_refresh_token() -> Result<()>
Ok(())
}
#[tokio::test]
#[traced_test]
#[tokio::test]
async fn enterprise_credential_errors_and_keyring_traces_hide_account_key() -> Result<()> {
let home = TempCodexHome::new();
let sentinel = "private-workspace-sentinel";
@@ -59,8 +59,8 @@ impl InProcessTransportFactory for ElicitationTestTransport {
}
}
#[tokio::test]
#[traced_test]
#[tokio::test]
async fn recovered_connections_accept_elicitations_with_previously_cancelled_ids()
-> anyhow::Result<()> {
for params in [
+12 -6
View File
@@ -74,6 +74,8 @@ pub fn default_filter() -> Targets {
.with_target("codex_otel.log_only", LevelFilter::OFF)
.with_target("codex_otel.trace_safe", LevelFilter::OFF)
.with_target("rmcp", LevelFilter::INFO)
.with_target("tokio::", LevelFilter::INFO)
.with_target("runtime::", LevelFilter::INFO)
.with_target("tokio_graceful::guard", LevelFilter::DEBUG)
.with_target("tokio_graceful::trigger", LevelFilter::DEBUG)
.with_target("codex_api::responses_websocket_timing", LevelFilter::OFF)
@@ -286,6 +288,14 @@ where
return;
}
// Channel sends and timer polls from this sink must not enqueue more
// SQLite writes when Tokio runtime tracing is enabled.
if *metadata.level() == tracing::Level::TRACE
&& matches!(target.split("::").next(), Some("tokio" | "runtime"))
{
return;
}
// `tracing-log` checks filters with the original log target before
// dispatching an event whose tracing target is `log`, so the outer
// target filter cannot reliably reject these bridged events.
@@ -738,13 +748,9 @@ mod tests {
.with_writer(writer.clone())
.with_ansi(false)
.with_target(false)
.with_filter(Targets::new().with_default(tracing::Level::TRACE)),
.with_filter(default_filter()),
)
.with(
layer
.clone()
.with_filter(Targets::new().with_default(tracing::Level::TRACE)),
);
.with(layer.clone().with_filter(default_filter()));
let guard = subscriber.set_default();
tracing::trace!("threadless-before");