From 91c66024c7784f8de2d8c8355bcccad40ab3c44d Mon Sep 17 00:00:00 2001 From: willwang-openai Date: Fri, 28 Aug 2026 00:04:15 +0000 Subject: [PATCH] Instrument the loaded plugin cache (#41231) ## What changed - Count loaded-plugin cache requests by `hit`, `hit_after_wait`, or `load` outcome. - Record time spent waiting for the load semaphore and loading plugins. - Count cache clears and capacity evictions. - Remove the unused force-reload path from `PluginsManager::plugins_for_config`. GitOrigin-RevId: db7829e7bd9b1414a263d9a7100c05dfdd832777 --- codex-rs/core-plugins/src/lib.rs | 1 + .../core-plugins/src/loaded_cache_metrics.rs | 49 +++++++++++++++ codex-rs/core-plugins/src/manager.rs | 63 ++++++++++++------- 3 files changed, 91 insertions(+), 22 deletions(-) create mode 100644 codex-rs/core-plugins/src/loaded_cache_metrics.rs diff --git a/codex-rs/core-plugins/src/lib.rs b/codex-rs/core-plugins/src/lib.rs index 913d1d4c8a..cde35626bc 100644 --- a/codex-rs/core-plugins/src/lib.rs +++ b/codex-rs/core-plugins/src/lib.rs @@ -7,6 +7,7 @@ mod executor_hooks; mod git_policy; mod http_client_selector; pub mod installed_marketplaces; +mod loaded_cache_metrics; pub mod loader; mod manager; pub mod manifest; diff --git a/codex-rs/core-plugins/src/loaded_cache_metrics.rs b/codex-rs/core-plugins/src/loaded_cache_metrics.rs new file mode 100644 index 0000000000..7ae5c93140 --- /dev/null +++ b/codex-rs/core-plugins/src/loaded_cache_metrics.rs @@ -0,0 +1,49 @@ +//! Request counts exclude disabled plugins, account-switch discards, and cancellations. +//! Auth retries keep the furthest request outcome reached; each completed wait/load is timed. +//! Skill-snapshot lookups are not requests. Clear events include already-empty caches. +//! Tags never contain configuration data. + +use std::time::Duration; + +pub(crate) const LOAD_DURATION: &str = "codex.plugins.loaded_cache.load.duration_ms"; +pub(crate) const WAIT_DURATION: &str = "codex.plugins.loaded_cache.wait.duration_ms"; + +pub(crate) enum RequestOutcome { + Hit, + HitAfterWait, + Load, +} + +impl RequestOutcome { + pub(crate) fn record(self) { + let Some(metrics) = codex_otel::global() else { + return; + }; + let outcome = match self { + Self::Hit => "hit", + Self::HitAfterWait => "hit_after_wait", + Self::Load => "load", + }; + let _ = metrics.counter( + "codex.plugins.loaded_cache.request", + /*inc*/ 1, + &[("outcome", outcome)], + ); + } +} + +pub(crate) fn record_duration(name: &'static str, duration: Duration) { + if let Some(metrics) = codex_otel::global() { + let _ = metrics.record_duration(name, duration, &[]); + } +} + +pub(crate) fn record_event(event: &'static str) { + if let Some(metrics) = codex_otel::global() { + let _ = metrics.counter( + "codex.plugins.loaded_cache.event", + /*inc*/ 1, + &[("event", event)], + ); + } +} diff --git a/codex-rs/core-plugins/src/manager.rs b/codex-rs/core-plugins/src/manager.rs index a47f6f50bc..724acb265c 100644 --- a/codex-rs/core-plugins/src/manager.rs +++ b/codex-rs/core-plugins/src/manager.rs @@ -9,6 +9,8 @@ use crate::PluginGitMode; use crate::app_mcp_routing::apply_app_mcp_routing_policy; use crate::installed_marketplaces::installed_marketplace_roots_from_layer_stack; use crate::is_openai_curated_marketplace_name; +use crate::loaded_cache_metrics; +use crate::loaded_cache_metrics::RequestOutcome; use crate::loader::PluginHookLoadOutcome; use crate::loader::TargetCuratedMarketplace; use crate::loader::configured_curated_plugin_ids_from_codex_home; @@ -699,11 +701,6 @@ impl PluginsManager { } } - pub async fn plugins_for_config(&self, config: &PluginsConfigInput) -> PluginLoadOutcome { - self.plugins_for_config_with_force_reload(config, /*force_reload*/ false) - .await - } - /// Returns skill snapshots parsed while loading the matching plugin cache entry. pub fn plugin_skill_snapshots_for_config( &self, @@ -732,15 +729,10 @@ impl PluginsManager { skip_all, fields( otel.name = "plugins_for_config", - force_reload, plugins_enabled = config.plugins_enabled ) )] - pub(crate) async fn plugins_for_config_with_force_reload( - &self, - config: &PluginsConfigInput, - force_reload: bool, - ) -> PluginLoadOutcome { + pub async fn plugins_for_config(&self, config: &PluginsConfigInput) -> PluginLoadOutcome { if !config.plugins_enabled { return PluginLoadOutcome::default(); } @@ -750,6 +742,7 @@ impl PluginsManager { // same-account revisions also cover ordinary token refreshes, where returning no plugins // is wrong, so retry those instead. let auth_change_receiver = self.auth_manager.auth_change_receiver(); + let mut cache_outcome = RequestOutcome::Hit; loop { let auth_revision = *auth_change_receiver.borrow(); @@ -763,9 +756,10 @@ impl PluginsManager { remote_global_catalog_active, auth_identity.clone(), ); - if !force_reload && let Some(plugins) = self.cached_loaded_plugins(&cache_key) { + if let Some(plugins) = self.cached_loaded_plugins(&cache_key) { let outcome = self.resolve_loaded_plugins_for_auth(plugins, auth_mode); if *auth_change_receiver.borrow() == auth_revision { + cache_outcome.record(); return outcome; } if !self.remote_installed_plugins_auth_is_current(&auth_identity) { @@ -774,7 +768,16 @@ impl PluginsManager { continue; } - let Ok(_load_permit) = self.loaded_plugins_load_semaphore.acquire().await else { + if matches!(cache_outcome, RequestOutcome::Hit) { + cache_outcome = RequestOutcome::HitAfterWait; + } + let wait_started = Instant::now(); + let load_permit = self.loaded_plugins_load_semaphore.acquire().await; + loaded_cache_metrics::record_duration( + loaded_cache_metrics::WAIT_DURATION, + wait_started.elapsed(), + ); + let Ok(_load_permit) = load_permit else { warn!("plugin load semaphore closed"); return PluginLoadOutcome::default(); }; @@ -784,9 +787,10 @@ impl PluginsManager { } continue; } - if !force_reload && let Some(plugins) = self.cached_loaded_plugins(&cache_key) { + if let Some(plugins) = self.cached_loaded_plugins(&cache_key) { let outcome = self.resolve_loaded_plugins_for_auth(plugins, auth_mode); if *auth_change_receiver.borrow() == auth_revision { + cache_outcome.record(); return outcome; } if !self.remote_installed_plugins_auth_is_current(&auth_identity) { @@ -796,6 +800,8 @@ impl PluginsManager { } let cache_generation = self.loaded_plugins_cache_generation(); let plugin_skill_snapshots = new_plugin_skill_snapshots(); + cache_outcome = RequestOutcome::Load; + let load_started = Instant::now(); let plugins = load_plugins_from_layer_stack( &config.config_layer_stack, self.remote_installed_plugins_snapshot(), @@ -806,6 +812,10 @@ impl PluginsManager { self.skill_root_loader.as_ref(), ) .await; + loaded_cache_metrics::record_duration( + loaded_cache_metrics::LOAD_DURATION, + load_started.elapsed(), + ); if *auth_change_receiver.borrow() != auth_revision { if !self.remote_installed_plugins_auth_is_current(&auth_identity) { return PluginLoadOutcome::default(); @@ -821,6 +831,7 @@ impl PluginsManager { ); let outcome = self.resolve_loaded_plugins_for_auth(plugins, auth_mode); if *auth_change_receiver.borrow() == auth_revision { + cache_outcome.record(); return outcome; } if !self.remote_installed_plugins_auth_is_current(&auth_identity) { @@ -883,6 +894,8 @@ impl PluginsManager { }; cache.generation = cache.generation.wrapping_add(1); cache.entries.clear(); + drop(cache); + loaded_cache_metrics::record_event("clear"); } fn clear_caches_after_marketplace_source_refresh( @@ -946,14 +959,20 @@ impl PluginsManager { Ok(cache) => cache, Err(err) => err.into_inner(), }; - if cache.generation == generation { - cache.entries.retain(|entry| entry.key != key); - cache.entries.push_front(LoadedPluginsCacheEntry { - key, - plugins, - plugin_skill_snapshots, - }); - cache.entries.truncate(LOADED_PLUGINS_CACHE_CAPACITY); + if cache.generation != generation { + return; + } + cache.entries.retain(|entry| entry.key != key); + cache.entries.push_front(LoadedPluginsCacheEntry { + key, + plugins, + plugin_skill_snapshots, + }); + let evicted = cache.entries.len() > LOADED_PLUGINS_CACHE_CAPACITY; + cache.entries.truncate(LOADED_PLUGINS_CACHE_CAPACITY); + drop(cache); + if evicted { + loaded_cache_metrics::record_event("capacity_eviction"); } }