Skip to content
Closed
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 10 additions & 8 deletions codex-rs/exec-server/src/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1310,6 +1310,7 @@ mod tests {
}

#[tokio::test(flavor = "current_thread")]
#[serial_test::serial(exec_server_tracing)]
async fn process_start_propagates_caller_trace_context_across_background_task() {
let (client_stdin, server_reader) = duplex(1 << 20);
let (mut server_writer, client_stdout) = duplex(1 << 20);
Expand Down Expand Up @@ -1360,6 +1361,15 @@ mod tests {
trace
});

let tracer_provider = SdkTracerProvider::builder().build();
let tracer = tracer_provider.tracer("exec-server-test");
let subscriber = tracing_subscriber::registry().with(
tracing_opentelemetry::layer()
.with_tracer(tracer)
.with_filter(filter_fn(codex_otel::OtelProvider::trace_export_filter)),
);
let _subscriber_guard = tracing::subscriber::set_default(subscriber);

let client = ExecServerClient::connect(
JsonRpcConnection::from_stdio(
client_stdout,
Expand All @@ -1371,14 +1381,6 @@ mod tests {
.await
.expect("client should connect");

let tracer_provider = SdkTracerProvider::builder().build();
let tracer = tracer_provider.tracer("exec-server-test");
let subscriber = tracing_subscriber::registry().with(
tracing_opentelemetry::layer()
.with_tracer(tracer)
.with_filter(filter_fn(codex_otel::OtelProvider::trace_export_filter)),
);
let _subscriber_guard = tracing::subscriber::set_default(subscriber);
tracing::callsite::rebuild_interest_cache();
let parent_span = tracing::info_span!("process-start-parent");
let expected_trace = codex_otel::span_w3c_trace_context(&parent_span)
Expand Down
1 change: 1 addition & 0 deletions codex-rs/exec-server/src/remote.rs
Original file line number Diff line number Diff line change
Expand Up @@ -711,6 +711,7 @@ mod tests {
}

#[tokio::test(flavor = "current_thread")]
#[serial_test::serial(exec_server_tracing)]
async fn register_environment_posts_with_auth_provider_headers() {
let provider = SdkTracerProvider::builder().build();
let tracer = provider.tracer("exec-server-test");
Expand Down
58 changes: 33 additions & 25 deletions codex-rs/exec-server/src/rpc.rs
Original file line number Diff line number Diff line change
Expand Up @@ -363,23 +363,19 @@ impl RpcClient {
})
}

#[tracing::instrument(
name = "codex.exec_server.request",
level = "info",
skip_all,
fields(
otel.kind = "client",
otel.name = method,
method,
)
)]
fn allocate_request_id(&self) -> RequestId {
RequestId::Integer(self.next_request_id.fetch_add(1, Ordering::SeqCst))
}

pub(crate) async fn call<P, T>(&self, method: &str, params: &P) -> Result<T, RpcCallError>
where
P: Serialize,
T: DeserializeOwned,
{
let _call_slot = self.acquire_regular_call_slot()?;
self.call_inner(method, params, RpcCallTimeout::None).await
let request_id = self.allocate_request_id();
self.call_inner(request_id, method, params, RpcCallTimeout::None)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this drops telemetry for the two early admission failures: regular calls can return PendingRequestLimitExceeded before call_inner, and cleanup overflow closes the transport before reaching it too...
Both were inside the outer request spans before this change, so saturation is now exactly when this telemetry disappears

.await
}

pub(crate) async fn call_with_timeout<P, T>(
Expand All @@ -393,20 +389,16 @@ impl RpcClient {
T: DeserializeOwned,
{
let _call_slot = self.acquire_regular_call_slot()?;
self.call_inner(method, params, RpcCallTimeout::After(call_timeout))
.await
}

#[tracing::instrument(
name = "codex.exec_server.request",
level = "info",
skip_all,
fields(
otel.kind = "client",
otel.name = method,
let request_id = self.allocate_request_id();
Comment thread
anp-oai marked this conversation as resolved.
self.call_inner(
request_id,
method,
params,
RpcCallTimeout::After(call_timeout),
)
)]
.await
}

pub(crate) async fn call_for_cleanup<P, T>(
&self,
method: &str,
Expand All @@ -426,11 +418,27 @@ impl RpcClient {
}
},
};
self.call_inner(method, params, RpcCallTimeout::None).await
let request_id = self.allocate_request_id();
self.call_inner(request_id, method, params, RpcCallTimeout::None)
.await
}

#[tracing::instrument(
name = "codex.exec_server.request",
level = "info",
skip_all,
fields(
otel.kind = "client",
otel.name = method,
rpc.system = "jsonrpc",
rpc.method = method,
rpc.request_id = %request_id,
method,
)
)]
async fn call_inner<P, T>(
&self,
request_id: RequestId,
method: &str,
params: &P,
call_timeout: RpcCallTimeout,
Expand All @@ -439,7 +447,6 @@ impl RpcClient {
P: Serialize,
T: DeserializeOwned,
{
let request_id = RequestId::Integer(self.next_request_id.fetch_add(1, Ordering::SeqCst));
let (response_tx, response_rx) = oneshot::channel();
{
let mut pending = self.pending.lock().await;
Expand Down Expand Up @@ -967,6 +974,7 @@ mod tests {
}

#[tokio::test(flavor = "current_thread")]
#[serial_test::serial(exec_server_tracing)]
async fn rpc_client_propagates_current_trace_context() {
let span_exporter = InMemorySpanExporter::default();
let tracer_provider = SdkTracerProvider::builder()
Expand Down
1 change: 1 addition & 0 deletions codex-rs/exec-server/src/server.rs
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ mod tests {
use crate::ExecServerTelemetry;

#[tokio::test]
#[serial_test::serial(exec_server_tracing)]
async fn telemetry_entrypoint_emits_root_span() {
let exporter = InMemorySpanExporter::default();
let provider = SdkTracerProvider::builder()
Expand Down
16 changes: 13 additions & 3 deletions codex-rs/exec-server/src/server/processor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -129,7 +129,7 @@ async fn run_connection(
codex_exec_server_protocol::JSONRPCMessage::Request(request) => {
let request_started_at = Instant::now();
if let Some((method, route)) = router.request_route(request.method.as_str()) {
let request_span = request_span(method, &request);
let request_span = request_span(method, &request, transport);
let message = tokio::select! {
message = route(Arc::clone(&handler), request).instrument(request_span.clone()) => message,
_ = disconnected_rx.changed() => {
Expand Down Expand Up @@ -160,7 +160,7 @@ async fn run_connection(
drop(request_span);
} else {
let method = "unknown";
let request_span = request_span(method, &request);
let request_span = request_span(method, &request, transport);
if outgoing_tx
.send(RpcServerOutboundMessage::Error {
request_id: request.id,
Expand Down Expand Up @@ -244,12 +244,17 @@ async fn run_connection(
fn request_span(
span_name: &str,
request: &codex_exec_server_protocol::JSONRPCRequest,
transport: ConnectionTransport,
) -> tracing::Span {
let method = request.method.as_str();
let span = tracing::info_span!(
"codex.exec_server.request",
otel.kind = "server",
otel.name = span_name,
rpc.system = "jsonrpc",
rpc.method = method,

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NIT: should rpc.method use the bounded routed span_name here?

rpc.transport = transport.metric_tag(),
rpc.request_id = %request.id,
method,
result = tracing::field::Empty,
);
Expand Down Expand Up @@ -324,6 +329,7 @@ mod tests {
use crate::server::session_registry::SessionRegistry;

#[test]
#[serial_test::serial(exec_server_tracing)]
fn request_span_uses_bounded_name_wire_method_and_inbound_trace_parent() {
let span_exporter = InMemorySpanExporter::default();
let tracer_provider = SdkTracerProvider::builder()
Expand Down Expand Up @@ -351,7 +357,11 @@ mod tests {
params: None,
trace: Some(trace),
};
let request_span = request_span("unknown", &request);
let request_span = request_span(
"unknown",
&request,
crate::telemetry::ConnectionTransport::Stdio,
);
request_span.in_scope(|| {});
drop(request_span);
});
Expand Down
2 changes: 1 addition & 1 deletion codex-rs/exec-server/src/telemetry.rs
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ pub(crate) enum ConnectionTransport {
}

impl ConnectionTransport {
fn metric_tag(self) -> &'static str {
pub(crate) fn metric_tag(self) -> &'static str {
match self {
Self::Relay => "relay",
Self::Stdio => "stdio",
Expand Down
1 change: 1 addition & 0 deletions codex-rs/exec-server/src/trace_context_tests.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ use tracing_subscriber::prelude::*;
use super::current_trace_context_headers;

#[test]
#[serial_test::serial(exec_server_tracing)]
fn creates_traceparent_header_from_current_span() {
let provider = SdkTracerProvider::builder().build();
let tracer = provider.tracer("exec-server-test");
Expand Down
Loading