mirror of
https://github.com/openai/codex.git
synced 2026-10-18 17:18:52 +00:00
Keep submission logs useful without exposing payloads (#51467)
## Why Submission diagnostics need approval and turn metadata without logging user input, tool responses, commands, paths, or instruction payloads. ## What changed - Log thread and submission IDs, operation kind, and parent/root turn IDs as explicit fields. - Give `Op` and `ThreadSettingsOverrides` selective `Debug` output that retains identifiers, approval decisions, and policy categories while omitting payloads. - Preserve Guardian review identifiers and status when logging approval of a denied-action retry. ## Testing Add an app-server integration test that verifies command approval, Guardian review, and turn policy metadata reach SQLite-backed diagnostic logs with `RUST_LOG=off`. GitOrigin-RevId: 308acb7b70e4849cf31514b11e4d9b46eaf6a09b
This commit is contained in:
@@ -4,18 +4,24 @@ use app_test_support::ChatGptIdTokenClaims;
|
||||
use app_test_support::MockResponsesConfig;
|
||||
use app_test_support::TestAppServer;
|
||||
use app_test_support::app_server_json_shutdown_event;
|
||||
use app_test_support::create_escalated_command_execution_sse_response;
|
||||
use app_test_support::create_exec_command_sse_response;
|
||||
use app_test_support::create_final_assistant_message_sse_response;
|
||||
use app_test_support::create_mock_responses_server_sequence;
|
||||
use app_test_support::encode_id_token;
|
||||
use app_test_support::write_models_cache;
|
||||
use codex_app_server_protocol::ApprovalsReviewer;
|
||||
use codex_app_server_protocol::AskForApproval;
|
||||
use codex_app_server_protocol::ClientInfo;
|
||||
use codex_app_server_protocol::ClientRequest;
|
||||
use codex_app_server_protocol::InitializeCapabilities;
|
||||
use codex_app_server_protocol::JSONRPCMessage;
|
||||
use codex_app_server_protocol::LoginAccountResponse;
|
||||
use codex_app_server_protocol::RequestId;
|
||||
use codex_app_server_protocol::SandboxPolicy;
|
||||
use codex_app_server_protocol::ServerRequest;
|
||||
use codex_app_server_protocol::ThreadApproveGuardianDeniedActionParams;
|
||||
use codex_app_server_protocol::ThreadApproveGuardianDeniedActionResponse;
|
||||
use codex_app_server_protocol::ThreadStartParams;
|
||||
use codex_app_server_protocol::TurnStartParams;
|
||||
use codex_app_server_protocol::TurnStartResponse;
|
||||
@@ -27,6 +33,7 @@ use codex_state::StateRuntime;
|
||||
use codex_utils_absolute_path::test_support::PathExt;
|
||||
use core_test_support::responses;
|
||||
use core_test_support::skip_if_no_network;
|
||||
use core_test_support::skip_if_wine_exec;
|
||||
use pretty_assertions::assert_eq;
|
||||
use serde_json::Value;
|
||||
use serde_json::json;
|
||||
@@ -48,6 +55,155 @@ use wiremock::matchers::path;
|
||||
|
||||
const READ_TIMEOUT: Duration = Duration::from_secs(10);
|
||||
|
||||
#[tokio::test]
|
||||
async fn submission_metadata_reaches_persisted_and_feedback_logs() -> Result<()> {
|
||||
skip_if_wine_exec!(
|
||||
Ok(()),
|
||||
"command approval routing requires a host-native cwd under Wine-exec"
|
||||
);
|
||||
skip_if_no_network!(Ok(()));
|
||||
|
||||
let server = create_mock_responses_server_sequence(vec![
|
||||
create_escalated_command_execution_sse_response(
|
||||
vec!["echo".into(), "hello".into()],
|
||||
/*workdir*/ None,
|
||||
/*timeout_ms*/ Some(5000),
|
||||
"call-approval",
|
||||
)?,
|
||||
create_final_assistant_message_sse_response("done")?,
|
||||
])
|
||||
.await;
|
||||
let codex_home = TempDir::new()?;
|
||||
MockResponsesConfig::new(&server.uri())
|
||||
.with_approval_policy("on-request")
|
||||
.with_provider_config("supports_websockets = false")
|
||||
.write(codex_home.path())?;
|
||||
let mut app_server = TestAppServer::builder()
|
||||
.with_codex_home(codex_home.path())
|
||||
// SQLite and feedback diagnostics must remain safe independently of stderr.
|
||||
.with_env_overrides(&[("RUST_LOG", Some("off"))])
|
||||
.build()
|
||||
.await?;
|
||||
app_server.initialize().await?;
|
||||
let thread = app_server
|
||||
.start_thread(ThreadStartParams::default())
|
||||
.await?
|
||||
.thread;
|
||||
let _: ThreadApproveGuardianDeniedActionResponse = app_server
|
||||
.request(
|
||||
|request_id| ClientRequest::ThreadApproveGuardianDeniedAction {
|
||||
request_id,
|
||||
params: ThreadApproveGuardianDeniedActionParams {
|
||||
thread_id: thread.id.clone(),
|
||||
event: json!({
|
||||
"id": "guardian-review",
|
||||
"target_item_id": "guardian-item",
|
||||
"turn_id": "guardian-turn",
|
||||
"status": "denied",
|
||||
"action": {
|
||||
"type": "mcp_tool_call",
|
||||
"server": "example",
|
||||
"tool_name": "write",
|
||||
},
|
||||
}),
|
||||
},
|
||||
},
|
||||
)
|
||||
.await?;
|
||||
let _: TurnStartResponse = app_server
|
||||
.request(|request_id| ClientRequest::TurnStart {
|
||||
request_id,
|
||||
params: TurnStartParams {
|
||||
thread_id: thread.id.clone(),
|
||||
input: vec![UserInput::Text {
|
||||
text: "run echo".into(),
|
||||
text_elements: Vec::new(),
|
||||
}],
|
||||
approval_policy: Some(AskForApproval::OnRequest),
|
||||
approvals_reviewer: Some(ApprovalsReviewer::User),
|
||||
sandbox_policy: Some(SandboxPolicy::ReadOnly {
|
||||
network_access: false,
|
||||
}),
|
||||
..Default::default()
|
||||
},
|
||||
})
|
||||
.await?;
|
||||
let server_request =
|
||||
timeout(READ_TIMEOUT, app_server.read_stream_until_request_message()).await??;
|
||||
let ServerRequest::CommandExecutionRequestApproval { request_id, params } = server_request
|
||||
else {
|
||||
anyhow::bail!("expected command approval request");
|
||||
};
|
||||
let approval_id = params.approval_id.unwrap_or(params.item_id);
|
||||
app_server
|
||||
.send_response(request_id, json!({ "decision": "decline" }))
|
||||
.await?;
|
||||
timeout(
|
||||
READ_TIMEOUT,
|
||||
app_server.read_stream_until_notification_message("turn/completed"),
|
||||
)
|
||||
.await??;
|
||||
|
||||
let state = StateRuntime::init(
|
||||
SqliteConfig::new_for_testing(codex_home.path().abs()),
|
||||
"mock_provider".into(),
|
||||
)
|
||||
.await?;
|
||||
// Feedback is read from SQLite, so this also verifies persistence.
|
||||
let feedback = timeout(Duration::from_secs(/*secs*/ 60), async {
|
||||
loop {
|
||||
let logs =
|
||||
String::from_utf8(state.query_feedback_logs_for_threads(&[&thread.id]).await?)?;
|
||||
if logs
|
||||
.lines()
|
||||
.any(|line| line.contains("Submission") && line.contains("exec_approval"))
|
||||
{
|
||||
break Ok::<_, anyhow::Error>(logs);
|
||||
}
|
||||
tokio::time::sleep(Duration::from_millis(/*millis*/ 50)).await;
|
||||
}
|
||||
})
|
||||
.await??;
|
||||
state.close().await;
|
||||
for (operation, fields) in [
|
||||
(
|
||||
"exec_approval",
|
||||
vec![
|
||||
format!("thread_id={}", thread.id),
|
||||
format!("id: \"{approval_id}\""),
|
||||
format!("turn_id: Some(\"{}\")", params.turn_id),
|
||||
"decision: denied".into(),
|
||||
],
|
||||
),
|
||||
(
|
||||
"approve_guardian_denied_action",
|
||||
vec![
|
||||
"review_id: \"guardian-review\"".into(),
|
||||
"target_item_id: Some(\"guardian-item\")".into(),
|
||||
"turn_id: \"guardian-turn\"".into(),
|
||||
"status: Denied".into(),
|
||||
],
|
||||
),
|
||||
(
|
||||
"turn_input",
|
||||
vec![
|
||||
"approval_policy: Some(OnRequest)".into(),
|
||||
"approvals_reviewer: Some(User)".into(),
|
||||
"sandbox_policy: Some(read-only)".into(),
|
||||
],
|
||||
),
|
||||
] {
|
||||
let line = feedback
|
||||
.lines()
|
||||
.find(|line| line.contains("Submission") && line.contains(operation))
|
||||
.with_context(|| format!("missing {operation} submission"))?;
|
||||
for field in fields {
|
||||
anyhow::ensure!(line.contains(&field), "missing {field}: {line}");
|
||||
}
|
||||
}
|
||||
Ok(())
|
||||
}
|
||||
|
||||
#[tokio::test]
|
||||
async fn credentials_stay_out_of_persisted_and_feedback_logs() -> Result<()> {
|
||||
skip_if_no_network!(Ok(()));
|
||||
|
||||
@@ -461,11 +461,15 @@ pub(super) async fn submission_loop(
|
||||
continue;
|
||||
}
|
||||
};
|
||||
if matches!(sub.op, Op::ResolveElicitation { .. }) {
|
||||
debug!(submission_id = %sub.id, operation = sub.op.kind(), "Submission");
|
||||
} else {
|
||||
debug!(?sub, "Submission");
|
||||
}
|
||||
debug!(
|
||||
thread_id = %sess.thread_id(),
|
||||
submission_id = %sub.id,
|
||||
operation = sub.op.kind(),
|
||||
parent_turn_id = ?sub.parent_turn_id,
|
||||
root_turn_id = ?sub.root_turn_id,
|
||||
op = ?sub.op,
|
||||
"Submission"
|
||||
);
|
||||
let dispatch_span = submission_dispatch_span(&sub);
|
||||
let should_exit = async {
|
||||
match sub.op {
|
||||
|
||||
@@ -6,7 +6,6 @@ use codex_protocol::protocol::W3cTraceContext;
|
||||
use tokio::sync::OwnedRwLockReadGuard;
|
||||
|
||||
#[derive(Debug)]
|
||||
#[expect(dead_code, reason = "Turn ancestry is retained in Debug diagnostics.")]
|
||||
pub(crate) struct Submission {
|
||||
pub id: String,
|
||||
pub op: Op,
|
||||
|
||||
@@ -483,7 +483,17 @@ pub enum TurnSettingsUpdateOutcome {
|
||||
|
||||
/// Thread-settings overrides that can be applied before user input or on their
|
||||
/// own. Standalone updates change the settings inherited by future turns.
|
||||
#[derive(Debug, Clone, Default, PartialEq)]
|
||||
// Diagnostics retain requested policy categories, never paths or instruction payloads.
|
||||
#[derive(derive_more::Debug, Clone, Default, PartialEq)]
|
||||
#[debug(
|
||||
"ThreadSettingsOverrides {{ approval_policy: {approval_policy:?}, approvals_reviewer: {approvals_reviewer:?}, sandbox_policy: {:?}, permission_profile: {:?} }}",
|
||||
sandbox_policy.as_ref().map(tracing::field::display),
|
||||
permission_profile.as_ref().map(|profile| match profile {
|
||||
PermissionProfile::Managed { .. } => "managed",
|
||||
PermissionProfile::Disabled => "disabled",
|
||||
PermissionProfile::External { .. } => "external",
|
||||
}),
|
||||
)]
|
||||
pub struct ThreadSettingsOverrides {
|
||||
/// Updated fallback `cwd` and environments supplied together as a complete pair.
|
||||
pub environments: Option<TurnEnvironmentRequests>,
|
||||
@@ -560,7 +570,8 @@ pub struct AdditionalContextEntry {
|
||||
}
|
||||
|
||||
/// Submission operation
|
||||
#[derive(Debug)]
|
||||
// Keep diagnostic fields explicit so new payload fields do not enter logs by default.
|
||||
#[derive(derive_more::Debug)]
|
||||
#[allow(clippy::large_enum_variant)]
|
||||
#[non_exhaustive]
|
||||
pub enum Op {
|
||||
@@ -570,6 +581,7 @@ pub enum Op {
|
||||
|
||||
/// Interrupt the named turn only if no input is queued for it.
|
||||
/// The decision is acknowledged before cancellation finishes.
|
||||
#[debug("InterruptIfNoPendingInput {{ turn_id: {turn_id:?} }}")]
|
||||
InterruptIfNoPendingInput {
|
||||
turn_id: String,
|
||||
reply: oneshot::Sender<bool>,
|
||||
@@ -580,15 +592,19 @@ pub enum Op {
|
||||
CleanBackgroundTerminals,
|
||||
|
||||
/// Start a realtime conversation stream.
|
||||
#[debug("RealtimeConversationStart {{ session_id: {:?}, version: {:?}, output_modality: {:?} }}", _0.realtime_session_id, _0.version, _0.output_modality)]
|
||||
RealtimeConversationStart(ConversationStartParams),
|
||||
|
||||
/// Send audio input to the running realtime conversation stream.
|
||||
#[debug("RealtimeConversationAudio {{ item_id: {:?}, sample_rate: {}, num_channels: {}, samples_per_channel: {:?} }}", _0.frame.item_id, _0.frame.sample_rate, _0.frame.num_channels, _0.frame.samples_per_channel)]
|
||||
RealtimeConversationAudio(ConversationAudioParams),
|
||||
|
||||
/// Send text input to the running realtime conversation stream.
|
||||
#[debug("RealtimeConversationText {{ role: {:?} }}", _0.role)]
|
||||
RealtimeConversationText(ConversationTextParams),
|
||||
|
||||
/// Append speakable text to the running realtime conversation stream.
|
||||
#[debug("RealtimeConversationSpeech")]
|
||||
RealtimeConversationSpeech(ConversationSpeechParams),
|
||||
|
||||
/// Close the running realtime conversation stream.
|
||||
@@ -598,6 +614,7 @@ pub enum Op {
|
||||
RealtimeConversationListVoices,
|
||||
|
||||
/// Submit turn input using the requested routing behavior.
|
||||
#[debug("TurnInput {{ requested_settings: {:?} }}", request.thread_settings)]
|
||||
TurnInput {
|
||||
request: Box<TurnInputRequest>,
|
||||
mode: TurnInputMode,
|
||||
@@ -605,6 +622,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Resume an interrupted regular turn.
|
||||
#[debug("RecoverTurn {{ requested_settings: {thread_settings:?} }}")]
|
||||
RecoverTurn {
|
||||
thread_settings: ThreadSettingsOverrides,
|
||||
start_options: TurnStartOptions,
|
||||
@@ -612,6 +630,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Stop the active root turn without recording a terminal turn event.
|
||||
#[debug("SuspendTurnAndShutdown")]
|
||||
SuspendTurnAndShutdown {
|
||||
reply: oneshot::Sender<CodexResult<SuspendTurnOutcome>>,
|
||||
},
|
||||
@@ -620,6 +639,7 @@ pub enum Op {
|
||||
///
|
||||
/// This uses the same submission queue as turn starts so app-server can
|
||||
/// preserve caller order between both kinds of mutation.
|
||||
#[debug("ThreadSettings {{ requested_settings: {thread_settings:?} }}")]
|
||||
ThreadSettings {
|
||||
/// Sparse thread-settings overrides to apply.
|
||||
thread_settings: ThreadSettingsOverrides,
|
||||
@@ -630,6 +650,7 @@ pub enum Op {
|
||||
|
||||
/// Update only the named running turn, without changing future settings.
|
||||
/// The reply reports the actual publication or why it did not occur.
|
||||
#[debug("TurnSettings {{ turn_id: {turn_id:?}, requested_approvals_reviewer: {:?} }}", update.approvals_reviewer)]
|
||||
TurnSettings {
|
||||
turn_id: String,
|
||||
update: TurnSettingsUpdate,
|
||||
@@ -638,12 +659,14 @@ pub enum Op {
|
||||
|
||||
/// Inter-agent communication that should be recorded as agent-message history
|
||||
/// while still using the normal thread submission lifecycle.
|
||||
#[debug("InterAgentCommunication {{ id: {:?}, author: {:?}, recipient: {:?}, trigger_turn: {} }}", communication.id, communication.author, communication.recipient, communication.trigger_turn)]
|
||||
InterAgentCommunication {
|
||||
communication: InterAgentCommunication,
|
||||
start_options: TurnStartOptions,
|
||||
},
|
||||
|
||||
/// Approve a command execution
|
||||
#[debug("ExecApproval {{ id: {id:?}, turn_id: {turn_id:?}, decision: {} }}", decision.to_opaque_string())]
|
||||
ExecApproval {
|
||||
/// The id of the submission we are approving
|
||||
id: String,
|
||||
@@ -654,6 +677,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Approve a code patch
|
||||
#[debug("PatchApproval {{ id: {id:?}, decision: {} }}", decision.to_opaque_string())]
|
||||
PatchApproval {
|
||||
/// The id of the submission we are approving
|
||||
id: String,
|
||||
@@ -662,6 +686,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Resolve an MCP elicitation request.
|
||||
#[debug("ResolveElicitation {{ request_id: {request_id:?}, decision: {decision:?} }}")]
|
||||
ResolveElicitation {
|
||||
/// Name of the MCP server that issued the request.
|
||||
server_name: String,
|
||||
@@ -676,6 +701,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Resolve a request_user_input tool call.
|
||||
#[debug("UserInputAnswer {{ id: {id:?} }}")]
|
||||
UserInputAnswer {
|
||||
/// Turn id for the in-flight request.
|
||||
id: String,
|
||||
@@ -684,6 +710,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Resolve a request_permissions tool call.
|
||||
#[debug("RequestPermissionsResponse {{ id: {id:?}, scope: {:?}, strict_auto_review: {} }}", response.scope, response.strict_auto_review)]
|
||||
RequestPermissionsResponse {
|
||||
/// Call id for the in-flight request.
|
||||
id: String,
|
||||
@@ -692,6 +719,7 @@ pub enum Op {
|
||||
},
|
||||
|
||||
/// Resolve a dynamic tool call request.
|
||||
#[debug("DynamicToolResponse {{ id: {id:?}, success: {} }}", response.success)]
|
||||
DynamicToolResponse {
|
||||
/// Call id for the in-flight request.
|
||||
id: String,
|
||||
@@ -717,12 +745,24 @@ pub enum Op {
|
||||
///
|
||||
/// This persists thread-level memory mode metadata without involving the
|
||||
/// model.
|
||||
#[debug("SetThreadMemoryMode {{ mode: {mode:?} }}")]
|
||||
SetThreadMemoryMode { mode: ThreadMemoryMode },
|
||||
|
||||
/// Request a code review from the agent.
|
||||
#[debug(
|
||||
"Review {{ target: {} }}",
|
||||
match &review_request.target {
|
||||
ReviewTarget::UncommittedChanges => "uncommitted_changes",
|
||||
ReviewTarget::BaseBranch { .. } => "base_branch",
|
||||
ReviewTarget::Commit { .. } => "commit",
|
||||
ReviewTarget::Custom { .. } => "custom",
|
||||
},
|
||||
)]
|
||||
Review { review_request: ReviewRequest },
|
||||
|
||||
/// Record that the user approved one retry of a concrete Guardian-denied action.
|
||||
// Assessment events are transient; retain the review identity when approving a retry.
|
||||
#[debug("ApproveGuardianDeniedAction {{ review_id: {:?}, target_item_id: {:?}, turn_id: {:?}, status: {:?} }}", event.id, event.target_item_id, event.turn_id, event.status)]
|
||||
ApproveGuardianDeniedAction { event: GuardianAssessmentEvent },
|
||||
|
||||
/// Request to shut down codex instance.
|
||||
@@ -733,6 +773,7 @@ pub enum Op {
|
||||
/// The command string is executed using the user's default shell and may
|
||||
/// include shell syntax (pipes, redirects, etc.). Output is streamed via
|
||||
/// `ExecCommand*` events and the UI regains control upon `TurnComplete`.
|
||||
#[debug("RunUserShellCommand {{ timeout_ms: {timeout_ms:?} }}")]
|
||||
RunUserShellCommand {
|
||||
/// The raw command string after '!'
|
||||
command: String,
|
||||
|
||||
Reference in New Issue
Block a user