mirror of
https://github.com/pchuan98/codex.git
synced 2026-07-01 00:31:56 +08:00
Reduce SQLite contention from OpenTelemetry SDK debug logs (#26396)
## Summary - skip `opentelemetry_sdk` DEBUG and TRACE events before formatting or queueing them for the SQLite log sink - preserve INFO, WARN, and ERROR events from the SDK, along with TRACE events from application targets - add a persistence-level regression test for the target and level policy ## Why OpenTelemetry's batch log processor emits internal `BatchLogProcessor.ExportingDueToTimer` meta-events every second per Codex process. In measured high-fanout `logs_2.sqlite` databases, low-level `opentelemetry_sdk` events accounted for over 30% of retained rows (30-60% on the machines of people I asked to check). Persisting this SDK bookkeeping across many processes adds substantial write volume and contention without representing application activity. ## Validation - `just test -p codex-state` (132/132 tests passed, plus bench smoke) - `just fix -p codex-state` - `just fmt`
This commit is contained in:
committed by
GitHub
Unverified
parent
7da4af622f
commit
d81fcdf8ef
@@ -189,6 +189,17 @@ where
|
||||
|
||||
fn on_event(&self, event: &Event<'_>, ctx: tracing_subscriber::layer::Context<'_, S>) {
|
||||
let metadata = event.metadata();
|
||||
// The SDK emits DEBUG timer meta-events every second per process; these
|
||||
// were over 30% of retained logs in measured high-fanout Codex environments.
|
||||
if metadata.target() == "opentelemetry_sdk"
|
||||
&& matches!(
|
||||
*metadata.level(),
|
||||
tracing::Level::TRACE | tracing::Level::DEBUG
|
||||
)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
let mut visitor = MessageVisitor::default();
|
||||
event.record(&mut visitor);
|
||||
let thread_id = visitor
|
||||
@@ -451,6 +462,10 @@ impl Visit for MessageVisitor {
|
||||
}
|
||||
}
|
||||
|
||||
#[cfg(test)]
|
||||
#[path = "log_db_filter_tests.rs"]
|
||||
mod filter_tests;
|
||||
|
||||
#[cfg(test)]
|
||||
mod tests {
|
||||
use std::io;
|
||||
|
||||
@@ -0,0 +1,53 @@
|
||||
use pretty_assertions::assert_eq;
|
||||
use tracing_subscriber::filter::Targets;
|
||||
use tracing_subscriber::layer::SubscriberExt;
|
||||
use tracing_subscriber::util::SubscriberInitExt;
|
||||
use uuid::Uuid;
|
||||
|
||||
use super::*;
|
||||
|
||||
#[tokio::test]
|
||||
async fn sqlite_sink_drops_low_level_opentelemetry_sdk_logs() {
|
||||
let codex_home =
|
||||
std::env::temp_dir().join(format!("codex-state-log-db-filter-{}", Uuid::new_v4()));
|
||||
let runtime = StateRuntime::init(codex_home.clone(), "test-provider".to_string())
|
||||
.await
|
||||
.expect("initialize runtime");
|
||||
let layer = start(runtime.clone());
|
||||
|
||||
let guard = tracing_subscriber::registry()
|
||||
.with(
|
||||
layer
|
||||
.clone()
|
||||
.with_filter(Targets::new().with_default(tracing::Level::TRACE)),
|
||||
)
|
||||
.set_default();
|
||||
|
||||
tracing::trace!(target: "opentelemetry_sdk", "dropped-trace");
|
||||
tracing::debug!(target: "opentelemetry_sdk", "dropped-debug");
|
||||
tracing::info!(target: "opentelemetry_sdk", "retained-info");
|
||||
tracing::trace!(target: "codex_state", "retained-trace");
|
||||
|
||||
layer.flush().await;
|
||||
drop(guard);
|
||||
|
||||
let logs = runtime
|
||||
.query_logs(&crate::LogQuery::default())
|
||||
.await
|
||||
.expect("query logs after flush");
|
||||
assert_eq!(
|
||||
logs.iter()
|
||||
.map(|row| (
|
||||
row.level.as_str(),
|
||||
row.target.as_str(),
|
||||
row.message.as_deref()
|
||||
))
|
||||
.collect::<Vec<_>>(),
|
||||
vec![
|
||||
("INFO", "opentelemetry_sdk", Some("retained-info")),
|
||||
("TRACE", "codex_state", Some("retained-trace")),
|
||||
]
|
||||
);
|
||||
|
||||
let _ = tokio::fs::remove_dir_all(codex_home).await;
|
||||
}
|
||||
Reference in New Issue
Block a user