diff --git a/codex-rs/core-skills/src/injection.rs b/codex-rs/core-skills/src/injection.rs index 201e7959fb..0d6e0b9c87 100644 --- a/codex-rs/core-skills/src/injection.rs +++ b/codex-rs/core-skills/src/injection.rs @@ -67,6 +67,11 @@ pub async fn build_skill_injections( analytics_client: &AnalyticsEventsClient, tracking: TrackEventsContext, ) -> SkillInjections { + tracing::info!( + mentioned_skill_count = mentioned_skills.len(), + loaded_skills_available = loaded_skills.is_some(), + "building core skill injections" + ); if mentioned_skills.is_empty() { return SkillInjections::default(); } @@ -82,8 +87,23 @@ pub async fn build_skill_injections( .and_then(|outcome| outcome.file_system_for_skill(skill)) .unwrap_or_else(|| Arc::clone(&LOCAL_FS)); let path = PathUri::from_abs_path(&skill.path_to_skills_md); + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + scope = ?skill.scope, + plugin_id = ?skill.plugin_id, + "reading core skill injection file" + ); match fs.read_file_text(&path, /*sandbox*/ None).await { Ok(contents) => { + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + scope = ?skill.scope, + plugin_id = ?skill.plugin_id, + contents_bytes = contents.len(), + "read core skill injection file" + ); emit_skill_injected_metric(otel, skill, "ok"); invocations.push(SkillInvocation { skill_name: skill.name.clone(), @@ -99,6 +119,14 @@ pub async fn build_skill_injections( }); } Err(err) => { + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + scope = ?skill.scope, + plugin_id = ?skill.plugin_id, + error = %err, + "failed to read core skill injection file" + ); emit_skill_injected_metric(otel, skill, "error"); let message = format!( "Failed to load skill {name} at {path}: {err:#}", @@ -111,6 +139,11 @@ pub async fn build_skill_injections( } analytics_client.track_skill_invocations(tracking, invocations); + tracing::info!( + injection_count = result.items.len(), + warning_count = result.warnings.len(), + "built core skill injections" + ); result } @@ -202,6 +235,21 @@ pub fn collect_explicit_skill_mentions( } } + tracing::info!( + input_count = inputs.len(), + available_skill_count = skills.len(), + disabled_skill_count = disabled_paths.len(), + selected_skill_count = selected.len(), + selected_skill_names = ?selected + .iter() + .map(|skill| skill.name.as_str()) + .collect::>(), + selected_skill_paths = ?selected + .iter() + .map(|skill| skill.path_to_skills_md.to_string_lossy().into_owned()) + .collect::>(), + "collected core explicit skill mentions" + ); selected } diff --git a/codex-rs/core-skills/src/model.rs b/codex-rs/core-skills/src/model.rs index 6afbde6cc9..a6c3da5a87 100644 --- a/codex-rs/core-skills/src/model.rs +++ b/codex-rs/core-skills/src/model.rs @@ -154,7 +154,31 @@ impl HostSkillsSnapshot { .file_system_for_skill(skill) .unwrap_or_else(|| Arc::clone(&LOCAL_FS)); let path = PathUri::from_abs_path(&skill.path_to_skills_md); - fs.read_file_text(&path, /*sandbox*/ None).await + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + "reading host skill file text" + ); + let result = fs.read_file_text(&path, /*sandbox*/ None).await; + match &result { + Ok(contents) => { + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + contents_bytes = contents.len(), + "read host skill file text" + ); + } + Err(err) => { + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + error = %err, + "failed to read host skill file text" + ); + } + } + result } } diff --git a/codex-rs/core-skills/src/skill_instructions.rs b/codex-rs/core-skills/src/skill_instructions.rs index b2a002d902..1f36713dbf 100644 --- a/codex-rs/core-skills/src/skill_instructions.rs +++ b/codex-rs/core-skills/src/skill_instructions.rs @@ -33,6 +33,12 @@ impl ContextualUserFragment for SkillInstructions { } fn body(&self) -> String { + tracing::info!( + skill = %self.name, + path = %self.path, + contents_bytes = self.contents.len(), + "rendering core skill instructions fragment" + ); format!( "\n{}\n{}\n{}\n", self.name, self.path, self.contents diff --git a/codex-rs/core/src/session/turn.rs b/codex-rs/core/src/session/turn.rs index 100089723b..bd3182c8b4 100644 --- a/codex-rs/core/src/session/turn.rs +++ b/codex-rs/core/src/session/turn.rs @@ -588,6 +588,16 @@ async fn build_skills_and_plugins( let extension_injection_items = build_extension_turn_input_items(sess, turn_context, &user_input, cancellation_token) .await?; + tracing::info!( + turn_id = %turn_context.sub_id, + user_input_count = user_input.len(), + structured_skill_input_count = user_input + .iter() + .filter(|input| matches!(input, UserInput::Skill { .. })) + .count(), + extension_injection_item_count = extension_injection_items.len(), + "built extension turn input items for skill injection" + ); let skill_name_counts_lower = build_skill_name_counts(&skills_outcome.skills, &skills_outcome.disabled_paths).1; let mentioned_skills = collect_explicit_skill_mentions( @@ -596,6 +606,19 @@ async fn build_skills_and_plugins( &skills_outcome.disabled_paths, &connector_slug_counts, ); + tracing::info!( + turn_id = %turn_context.sub_id, + mentioned_skill_count = mentioned_skills.len(), + mentioned_skill_names = ?mentioned_skills + .iter() + .map(|skill| skill.name.as_str()) + .collect::>(), + mentioned_skill_paths = ?mentioned_skills + .iter() + .map(|skill| skill.path_to_skills_md.to_string_lossy().into_owned()) + .collect::>(), + "collected explicit core skill mentions" + ); maybe_prompt_and_install_mcp_dependencies( sess, turn_context, @@ -619,6 +642,13 @@ async fn build_skills_and_plugins( tracking.clone(), ) .await; + let skill_warning_count = skill_warnings.len(); + tracing::info!( + turn_id = %turn_context.sub_id, + core_skill_injection_count = skill_injections.len(), + core_skill_warning_count = skill_warning_count, + "built core skill injection items" + ); for message in skill_warnings { sess.send_event(turn_context, EventMsg::Warning(WarningEvent { message })) @@ -668,17 +698,34 @@ async fn build_skills_and_plugins( } let mut injection_items: Vec = match injected_host_skill_prompts { - Some(injected_host_skill_prompts) => skill_injections - .iter() - .filter(|skill| !injected_host_skill_prompts.contains_path(&skill.path)) - .map(|skill| { - ContextualUserFragment::into(crate::context::SkillInstructions::from(skill)) - }) - .collect(), + Some(injected_host_skill_prompts) => { + let items = skill_injections + .iter() + .filter(|skill| !injected_host_skill_prompts.contains_path(&skill.path)) + .map(|skill| { + ContextualUserFragment::into(crate::context::SkillInstructions::from(skill)) + }) + .collect::>(); + tracing::info!( + turn_id = %turn_context.sub_id, + core_skill_injection_count = skill_injections.len(), + filtered_core_skill_injection_count = items.len(), + "filtered core skill injections already provided by extension" + ); + items + } None => skill_items, }; + let skill_and_plugin_injection_count = injection_items.len() + plugin_items.len(); injection_items.extend(plugin_items); injection_items.extend(extension_injection_items); + tracing::info!( + turn_id = %turn_context.sub_id, + final_injection_item_count = injection_items.len(), + skill_and_plugin_injection_count, + explicitly_enabled_connector_count = explicitly_enabled_connectors.len(), + "built final turn injection items" + ); Some((injection_items, explicitly_enabled_connectors)) } diff --git a/codex-rs/ext/skills/src/extension.rs b/codex-rs/ext/skills/src/extension.rs index de9facd8c2..6dcd56e7a5 100644 --- a/codex-rs/ext/skills/src/extension.rs +++ b/codex-rs/ext/skills/src/extension.rs @@ -320,7 +320,15 @@ impl SkillsExtension { session_store: &ExtensionData, thread_state: &SkillsThreadState, ) -> Result { - thread_state + tracing::info!( + skill = %entry.name, + authority_kind = %entry.authority.kind, + authority_id = %entry.authority.id, + package = %entry.id.0, + resource = %entry.main_prompt.as_str(), + "reading skill main prompt" + ); + let result = thread_state .read_skill( &self.providers, SkillReadRequest { @@ -331,8 +339,32 @@ impl SkillsExtension { mcp_resources: session_store.get::(), }, ) - .await - .map_err(|err| err.message) + .await; + match &result { + Ok(read_result) => { + tracing::info!( + skill = %entry.name, + authority_kind = %entry.authority.kind, + authority_id = %entry.authority.id, + package = %entry.id.0, + resource = %read_result.resource.as_str(), + contents_bytes = read_result.contents.len(), + "read skill main prompt" + ); + } + Err(err) => { + tracing::info!( + skill = %entry.name, + authority_kind = %entry.authority.kind, + authority_id = %entry.authority.id, + package = %entry.id.0, + resource = %entry.main_prompt.as_str(), + error = %err.message, + "failed to read skill main prompt" + ); + } + } + result.map_err(|err| err.message) } fn emit_warning(&self, turn_id: &str, message: String) { diff --git a/codex-rs/ext/skills/src/fragments.rs b/codex-rs/ext/skills/src/fragments.rs index 0a24b48b5a..b5d2c3124c 100644 --- a/codex-rs/ext/skills/src/fragments.rs +++ b/codex-rs/ext/skills/src/fragments.rs @@ -56,6 +56,12 @@ impl ContextualUserFragment for SkillInstructions { let name = &self.name; let path = &self.path; let contents = &self.contents; + tracing::info!( + skill = %name, + path = %path, + contents_bytes = contents.len(), + "rendering extension skill instructions fragment" + ); format!("\n{name}\n{path}\n{contents}\n") } } diff --git a/codex-rs/ext/skills/src/provider/executor.rs b/codex-rs/ext/skills/src/provider/executor.rs index 75234dfbee..1cfb2cb424 100644 --- a/codex-rs/ext/skills/src/provider/executor.rs +++ b/codex-rs/ext/skills/src/provider/executor.rs @@ -114,6 +114,8 @@ impl SkillProvider for ExecutorSkillProvider { fn read(&self, request: SkillReadRequest) -> SkillProviderFuture<'_, SkillReadResult> { Box::pin(async move { + let package = request.package.0.clone(); + let resource = request.resource.as_str().to_string(); if request.authority.kind != SkillSourceKind::Executor { return Err(SkillProviderError::new(format!( "executor skill provider cannot read {} resources", @@ -135,17 +137,34 @@ impl SkillProvider for ExecutorSkillProvider { "executor skill resource references unavailable environment `{environment_id}`" ))); }; + let resource_path_for_log = resource_path.to_string_lossy().into_owned(); let resource_path = PathUri::from_abs_path(resource_path); + tracing::info!( + authority_id = %request.authority.id, + package = %package, + resource = %resource, + environment_id = %environment_id, + path = %resource_path_for_log, + "reading executor skill resource" + ); let contents = environment .get_filesystem() .read_file_text(&resource_path, /*sandbox*/ None) .await .map_err(|err| { SkillProviderError::new(format!( - "failed to read executor skill resource {}: {err}", - request.resource.as_str() + "failed to read executor skill resource {resource}: {err}" )) })?; + tracing::info!( + authority_id = %request.authority.id, + package = %package, + resource = %resource, + environment_id = %environment_id, + path = %resource_path_for_log, + contents_bytes = contents.len(), + "read executor skill resource" + ); Ok(SkillReadResult { resource: request.resource, diff --git a/codex-rs/ext/skills/src/provider/host.rs b/codex-rs/ext/skills/src/provider/host.rs index 2cee694216..4f634d5ba3 100644 --- a/codex-rs/ext/skills/src/provider/host.rs +++ b/codex-rs/ext/skills/src/provider/host.rs @@ -51,6 +51,13 @@ impl SkillProvider for HostSkillProvider { "host skill provider requires a host skills snapshot", )); }; + tracing::info!( + authority_kind = %request.authority.kind, + authority_id = %request.authority.id, + package = %request.package.0, + resource = %request.resource.as_str(), + "reading host skill resource" + ); let Some(skill) = host_snapshot.outcome().skills.iter().find(|skill| { let skill_path = skill.path_to_skills_md.to_string_lossy(); skill_path == request.resource.as_str() @@ -61,6 +68,12 @@ impl SkillProvider for HostSkillProvider { request.resource.as_str() ))); }; + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + resource = %request.resource.as_str(), + "matched host skill resource" + ); let contents = host_snapshot.read_skill_text(skill).await.map_err(|err| { SkillProviderError::new(format!( @@ -68,6 +81,13 @@ impl SkillProvider for HostSkillProvider { request.resource.as_str() )) })?; + tracing::info!( + skill = %skill.name, + path = %skill.path_to_skills_md.to_string_lossy(), + resource = %request.resource.as_str(), + contents_bytes = contents.len(), + "read host skill resource" + ); Ok(SkillReadResult { resource: request.resource, diff --git a/codex-rs/ext/skills/src/provider/orchestrator.rs b/codex-rs/ext/skills/src/provider/orchestrator.rs index 8d97bf32a1..3c95f80aa7 100644 --- a/codex-rs/ext/skills/src/provider/orchestrator.rs +++ b/codex-rs/ext/skills/src/provider/orchestrator.rs @@ -150,6 +150,8 @@ impl SkillProvider for OrchestratorSkillProvider { fn read(&self, request: SkillReadRequest) -> SkillProviderFuture<'_, SkillReadResult> { Box::pin(async move { + let package = request.package.0.clone(); + let resource = request.resource.as_str().to_string(); if request.authority != SkillAuthority::new(SkillSourceKind::Orchestrator, CODEX_APPS_MCP_SERVER_NAME) { @@ -169,6 +171,12 @@ impl SkillProvider for OrchestratorSkillProvider { "session MCP resource client is not configured", )); }; + tracing::info!( + authority_id = %request.authority.id, + package = %package, + resource = %resource, + "reading orchestrator skill resource" + ); let result = tokio::time::timeout( ORCHESTRATOR_SKILL_READ_TIMEOUT, client.read_resource(CODEX_APPS_MCP_SERVER_NAME, request.resource.as_str()), @@ -206,6 +214,13 @@ impl SkillProvider for OrchestratorSkillProvider { request.resource.as_str() ))); } + tracing::info!( + authority_id = %request.authority.id, + package = %package, + resource = %resource, + contents_bytes = contents.len(), + "read orchestrator skill resource" + ); Ok(SkillReadResult { resource: request.resource, diff --git a/codex-rs/ext/skills/src/selection.rs b/codex-rs/ext/skills/src/selection.rs index a708b18d6c..b81766ceea 100644 --- a/codex-rs/ext/skills/src/selection.rs +++ b/codex-rs/ext/skills/src/selection.rs @@ -72,6 +72,20 @@ pub(crate) fn collect_explicit_skill_mentions( } } + tracing::info!( + input_count = inputs.len(), + catalog_entry_count = catalog.entries.len(), + selected_entry_count = selected.len(), + selected_entry_names = ?selected + .iter() + .map(|entry| entry.name.as_str()) + .collect::>(), + selected_entry_resources = ?selected + .iter() + .map(|entry| entry.main_prompt.as_str()) + .collect::>(), + "collected extension explicit skill mentions" + ); selected } diff --git a/codex-rs/ext/skills/src/state.rs b/codex-rs/ext/skills/src/state.rs index 0b751ebdc2..3cc7577d3d 100644 --- a/codex-rs/ext/skills/src/state.rs +++ b/codex-rs/ext/skills/src/state.rs @@ -89,8 +89,42 @@ impl SkillsThreadState { providers: &SkillProviders, request: SkillReadRequest, ) -> SkillProviderResult { + let authority_kind = request.authority.kind.to_string(); + let authority_id = request.authority.id.clone(); + let package = request.package.0.clone(); + let resource = request.resource.as_str().to_string(); + tracing::info!( + authority_kind = %authority_kind, + authority_id = %authority_id, + package = %package, + resource = %resource, + "dispatching skill read" + ); if request.authority.kind != SkillSourceKind::Orchestrator { - return providers.read(request).await; + let result = providers.read(request).await; + match &result { + Ok(read_result) => { + tracing::info!( + authority_kind = %authority_kind, + authority_id = %authority_id, + package = %package, + resource = %read_result.resource.as_str(), + contents_bytes = read_result.contents.len(), + "completed skill read" + ); + } + Err(err) => { + tracing::info!( + authority_kind = %authority_kind, + authority_id = %authority_id, + package = %package, + resource = %resource, + error = %err.message, + "failed skill read" + ); + } + } + return result; } let cache = self.orchestrator_cache(request.mcp_resources.as_deref()); @@ -101,19 +135,44 @@ impl SkillsThreadState { .unwrap_or_else(std::sync::PoisonError::into_inner) .get(&cache_key) { + tracing::info!( + authority_kind = %authority_kind, + authority_id = %authority_id, + package = %package, + resource = %result.resource.as_str(), + contents_bytes = result.contents.len(), + "served skill read from orchestrator cache" + ); return Ok(result); } let result = providers.read(request).await?; if result.resource != cache_key.resource { + tracing::info!( + authority_kind = %authority_kind, + authority_id = %authority_id, + package = %package, + resource = %result.resource.as_str(), + contents_bytes = result.contents.len(), + "completed uncached skill read" + ); return Ok(result); } - Ok(cache + let result = cache .resources .lock() .unwrap_or_else(std::sync::PoisonError::into_inner) - .insert(cache_key, result)) + .insert(cache_key, result); + tracing::info!( + authority_kind = %authority_kind, + authority_id = %authority_id, + package = %package, + resource = %result.resource.as_str(), + contents_bytes = result.contents.len(), + "completed cached skill read" + ); + Ok(result) } fn orchestrator_cache( diff --git a/justfile b/justfile index 03f87391ac..3c1c4c3e7a 100644 --- a/justfile +++ b/justfile @@ -1,10 +1,12 @@ set working-directory := "codex-rs" -set positional-arguments +set positional-arguments := true + export JUST_SHELL := justfile_directory() / "scripts/just-shell.py" + set shell := ["python3", "-c", 'import os, runpy; runpy.run_path(os.environ["JUST_SHELL"], run_name="__main__")'] set windows-shell := ["python", "-c", 'import os, runpy; runpy.run_path(os.environ["JUST_SHELL"], run_name="__main__")'] -rust_min_stack := "8388608" # 8 MiB +rust_min_stack := "8388608" python := if os_family() == "windows" { "python" } else { "python3" } # Display help @@ -12,7 +14,9 @@ help: just -l # `codex` + alias c := codex + codex *args: cargo run --bin codex -- {args} @@ -72,6 +76,7 @@ install: # # Run `cargo install --locked cargo-nextest` if you don't have it installed. # Prefer this for routine local runs. Workspace crate features are banned, so + # there should be no need to add `--all-features`. [unix] test *args: @@ -82,6 +87,7 @@ test *args: $env:RUST_MIN_STACK = "{{ rust_min_stack }}"; $env:NEXTEST_PROFILE = "local"; cargo nextest run --no-fail-fast @($args | Select-Object -Skip 1) # Run from the repository root so scripts that resolve paths from `cwd` see + # the same layout they use in GitHub Actions. [no-cd] test-github-scripts: @@ -97,6 +103,7 @@ bench-smoke: # Build and run Codex from source using Bazel. # On Unix, use `[no-cd]` and `--run_under="cd $PWD &&"` to ensure Bazel runs + # the command in the current working directory. [no-cd] [unix]