Debugging extension loading timing and fallbacks

Richard Feldman created

Change summary

crates/agent/src/agent.rs                                  |  2 
crates/agent_ui/src/agent_configuration.rs                 | 14 
crates/agent_ui/src/agent_ui.rs                            |  3 
crates/agent_ui/src/language_model_selector.rs             | 15 
crates/ai_onboarding/src/agent_api_keys_onboarding.rs      |  5 
crates/ai_onboarding/src/agent_panel_onboarding_content.rs |  5 
crates/extension/src/extension_host_proxy.rs               |  8 
crates/extension_host/src/extension_host.rs                | 97 -------
crates/extension_host/src/wasm_host/llm_provider.rs        | 35 ++
crates/gpui/src/elements/svg.rs                            | 21 -
crates/language_model/src/registry.rs                      | 23 -
crates/language_models/src/extension.rs                    |  8 
12 files changed, 51 insertions(+), 185 deletions(-)

Detailed changes

crates/agent/src/agent.rs 🔗

@@ -105,7 +105,7 @@ impl LanguageModels {
     fn refresh_list(&mut self, cx: &App) {
         let providers = LanguageModelRegistry::global(cx)
             .read(cx)
-            .providers()
+            .visible_providers()
             .into_iter()
             .filter(|provider| provider.is_authenticated(cx))
             .collect::<Vec<_>>();

crates/agent_ui/src/agent_configuration.rs 🔗

@@ -117,7 +117,7 @@ impl AgentConfiguration {
     }
 
     fn build_provider_configuration_views(&mut self, window: &mut Window, cx: &mut Context<Self>) {
-        let providers = LanguageModelRegistry::read_global(cx).providers();
+        let providers = LanguageModelRegistry::read_global(cx).visible_providers();
         for provider in providers {
             self.add_provider_configuration_view(&provider, window, cx);
         }
@@ -261,20 +261,10 @@ impl AgentConfiguration {
                                     .w_full()
                                     .gap_1p5()
                                     .child(if let Some(icon_path) = provider.icon_path() {
-                                        log::info!(
-                                            "Rendering LLM provider icon with from_external_svg: provider={}, path={}",
-                                            provider.id(),
-                                            icon_path
-                                        );
                                         Icon::from_external_svg(icon_path)
                                             .size(IconSize::Small)
                                             .color(Color::Muted)
                                     } else {
-                                        log::info!(
-                                            "Rendering LLM provider icon with Icon::new: provider={}, icon={:?}",
-                                            provider.id(),
-                                            provider.icon()
-                                        );
                                         Icon::new(provider.icon())
                                             .size(IconSize::Small)
                                             .color(Color::Muted)
@@ -430,7 +420,7 @@ impl AgentConfiguration {
         &mut self,
         cx: &mut Context<Self>,
     ) -> impl IntoElement {
-        let providers = LanguageModelRegistry::read_global(cx).providers();
+        let providers = LanguageModelRegistry::read_global(cx).visible_providers();
 
         let popover_menu = PopoverMenu::new("add-provider-popover")
             .trigger(

crates/agent_ui/src/agent_ui.rs 🔗

@@ -348,7 +348,8 @@ fn init_language_model_settings(cx: &mut App) {
         |_, event: &language_model::Event, cx| match event {
             language_model::Event::ProviderStateChanged(_)
             | language_model::Event::AddedProvider(_)
-            | language_model::Event::RemovedProvider(_) => {
+            | language_model::Event::RemovedProvider(_)
+            | language_model::Event::ProvidersChanged => {
                 update_active_language_model_from_settings(cx);
             }
             _ => {}

crates/agent_ui/src/language_model_selector.rs 🔗

@@ -149,6 +149,9 @@ impl LanguageModelPickerDelegate {
                     language_model::Event::RemovedProvider(_) => {
                         refresh_tx.unbounded_send(()).ok();
                     }
+                    language_model::Event::ProvidersChanged => {
+                        refresh_tx.unbounded_send(()).ok();
+                    }
                     _ => {}
                 })
                 .detach();
@@ -425,7 +428,7 @@ impl PickerDelegate for LanguageModelPickerDelegate {
 
         let configured_providers = language_model_registry
             .read(cx)
-            .providers()
+            .visible_providers()
             .into_iter()
             .filter(|provider| provider.is_authenticated(cx))
             .collect::<Vec<_>>();
@@ -538,14 +541,10 @@ impl PickerDelegate for LanguageModelPickerDelegate {
                                 .w_full()
                                 .gap_1p5()
                                 .child(match &model_info.icon {
-                                    ProviderIcon::Name(icon_name) => {
-                                        log::info!("ICON_DEBUG model_selector using Icon::new for {:?}", icon_name);
-                                        Icon::new(*icon_name)
-                                            .color(model_icon_color)
-                                            .size(IconSize::Small)
-                                    }
+                                    ProviderIcon::Name(icon_name) => Icon::new(*icon_name)
+                                        .color(model_icon_color)
+                                        .size(IconSize::Small),
                                     ProviderIcon::Path(icon_path) => {
-                                        log::info!("ICON_DEBUG model_selector using from_external_svg path={}", icon_path);
                                         Icon::from_external_svg(icon_path.clone())
                                             .color(model_icon_color)
                                             .size(IconSize::Small)

crates/ai_onboarding/src/agent_api_keys_onboarding.rs 🔗

@@ -29,7 +29,8 @@ impl ApiKeysWithProviders {
             |this: &mut Self, _registry, event: &language_model::Event, cx| match event {
                 language_model::Event::ProviderStateChanged(_)
                 | language_model::Event::AddedProvider(_)
-                | language_model::Event::RemovedProvider(_) => {
+                | language_model::Event::RemovedProvider(_)
+                | language_model::Event::ProvidersChanged => {
                     this.configured_providers = Self::compute_configured_providers(cx)
                 }
                 _ => {}
@@ -44,7 +45,7 @@ impl ApiKeysWithProviders {
 
     fn compute_configured_providers(cx: &App) -> Vec<(ProviderIcon, SharedString)> {
         LanguageModelRegistry::read_global(cx)
-            .providers()
+            .visible_providers()
             .iter()
             .filter(|provider| {
                 provider.is_authenticated(cx) && provider.id() != ZED_CLOUD_PROVIDER_ID

crates/ai_onboarding/src/agent_panel_onboarding_content.rs 🔗

@@ -27,7 +27,8 @@ impl AgentPanelOnboarding {
             |this: &mut Self, _registry, event: &language_model::Event, cx| match event {
                 language_model::Event::ProviderStateChanged(_)
                 | language_model::Event::AddedProvider(_)
-                | language_model::Event::RemovedProvider(_) => {
+                | language_model::Event::RemovedProvider(_)
+                | language_model::Event::ProvidersChanged => {
                     this.has_configured_providers = Self::has_configured_providers(cx)
                 }
                 _ => {}
@@ -45,7 +46,7 @@ impl AgentPanelOnboarding {
 
     fn has_configured_providers(cx: &App) -> bool {
         LanguageModelRegistry::read_global(cx)
-            .providers()
+            .visible_providers()
             .iter()
             .any(|provider| provider.is_authenticated(cx) && provider.id() != ZED_CLOUD_PROVIDER_ID)
     }

crates/extension/src/extension_host_proxy.rs 🔗

@@ -414,17 +414,9 @@ impl ExtensionLanguageModelProviderProxy for ExtensionHostProxy {
         cx: &mut App,
     ) {
         let Some(proxy) = self.language_model_provider_proxy.read().clone() else {
-            log::warn!(
-                "ExtensionHostProxy::register_language_model_provider: no proxy set for provider {}",
-                provider_id
-            );
             return;
         };
 
-        log::info!(
-            "ExtensionHostProxy::register_language_model_provider: delegating to proxy for {}",
-            provider_id
-        );
         proxy.register_language_model_provider(provider_id, register_fn, cx)
     }
 

crates/extension_host/src/extension_host.rs 🔗

@@ -101,17 +101,8 @@ const LEGACY_LLM_EXTENSION_IDS: &[&str] = &[
 /// This migration only runs once per provider - we track which providers have been
 /// migrated in `migrated_llm_providers` to avoid overriding user preferences.
 fn migrate_legacy_llm_provider_env_var(manifest: &ExtensionManifest, cx: &mut App) {
-    log::info!(
-        "migrate_legacy_llm_provider_env_var called for extension: {}",
-        manifest.id
-    );
-
     // Only apply migration to known legacy LLM extensions
     if !LEGACY_LLM_EXTENSION_IDS.contains(&manifest.id.as_ref()) {
-        log::info!(
-            "  skipping - not a legacy LLM extension (known: {:?})",
-            LEGACY_LLM_EXTENSION_IDS
-        );
         return;
     }
 
@@ -131,15 +122,7 @@ fn migrate_legacy_llm_provider_env_var(manifest: &ExtensionManifest, cx: &mut Ap
             .migrated_llm_providers
             .contains(full_provider_id.as_ref());
 
-        log::info!(
-            "  provider {}: env_var={}, already_migrated={}",
-            full_provider_id,
-            env_var_name,
-            already_migrated
-        );
-
         if already_migrated {
-            log::info!("  skipping - already migrated");
             continue;
         }
 
@@ -148,8 +131,6 @@ fn migrate_legacy_llm_provider_env_var(manifest: &ExtensionManifest, cx: &mut Ap
             .map(|v| !v.is_empty())
             .unwrap_or(false);
 
-        log::info!("  env_var_is_set: {}", env_var_is_set);
-
         // Mark as migrated regardless of whether we enable env var reading
         let should_enable_env_var = env_var_is_set;
         settings::update_settings_file(<dyn fs::Fs>::global(cx), cx, {
@@ -184,14 +165,6 @@ fn migrate_legacy_llm_provider_env_var(manifest: &ExtensionManifest, cx: &mut Ap
                 }
             }
         });
-
-        if env_var_is_set {
-            log::info!(
-                "Migrating legacy LLM provider {}: auto-enabling {} env var reading",
-                full_provider_id,
-                env_var_name
-            );
-        }
     }
 }
 
@@ -716,54 +689,27 @@ impl ExtensionStore {
     /// This can be used to make certain functionality provided by extensions
     /// available out-of-the-box.
     pub fn auto_install_extensions(&mut self, cx: &mut Context<Self>) {
-        log::info!("auto_install_extensions called");
-
         if cfg!(test) {
-            log::info!("auto_install_extensions: skipping because cfg!(test)");
             return;
         }
 
         let extension_settings = ExtensionSettings::get_global(cx);
 
-        log::info!(
-            "auto_install_extensions: settings has {} extensions: {:?}",
-            extension_settings.auto_install_extensions.len(),
-            extension_settings
-                .auto_install_extensions
-                .keys()
-                .collect::<Vec<_>>()
-        );
-
         let extensions_to_install = extension_settings
             .auto_install_extensions
             .keys()
-            .filter(|extension_id| {
-                let should = extension_settings.should_auto_install(extension_id);
-                log::info!("  {} should_auto_install: {}", extension_id, should);
-                should
-            })
+            .filter(|extension_id| extension_settings.should_auto_install(extension_id))
             .filter(|extension_id| {
                 let is_already_installed = self
                     .extension_index
                     .extensions
                     .contains_key(extension_id.as_ref());
                 let dominated = SUPPRESSED_EXTENSIONS.contains(&extension_id.as_ref());
-                log::info!(
-                    "  {} is_already_installed: {}, suppressed: {}",
-                    extension_id,
-                    is_already_installed,
-                    dominated
-                );
                 !is_already_installed && !dominated
             })
             .cloned()
             .collect::<Vec<_>>();
 
-        log::info!(
-            "auto_install_extensions: will install {:?}",
-            extensions_to_install
-        );
-
         cx.spawn(async move |this, cx| {
             for extension_id in extensions_to_install {
                 // HACK: In debug builds, check if extension exists locally in repo's extensions/ dir
@@ -780,12 +726,6 @@ impl ExtensionStore {
                         .join(extension_id.as_ref());
 
                     if local_extension_path.exists() {
-                        log::info!(
-                            "Auto-installing local dev extension: {} from {:?}",
-                            extension_id,
-                            local_extension_path
-                        );
-
                         // Force-remove existing extension directory if it exists and isn't a symlink
                         // This handles the case where the extension was previously installed from the registry
                         if let Some(installed_dir) = this
@@ -797,10 +737,6 @@ impl ExtensionStore {
                                 let metadata = std::fs::symlink_metadata(&existing_path);
                                 let is_symlink = metadata.map(|m| m.is_symlink()).unwrap_or(false);
                                 if !is_symlink {
-                                    log::info!(
-                                        "Removing existing non-dev extension directory: {:?}",
-                                        existing_path
-                                    );
                                     if let Err(e) = std::fs::remove_dir_all(&existing_path) {
                                         log::error!(
                                             "Failed to remove existing extension directory {:?}: {}",
@@ -1014,8 +950,6 @@ impl ExtensionStore {
     }
 
     pub fn install_latest_extension(&mut self, extension_id: Arc<str>, cx: &mut Context<Self>) {
-        log::info!("installing extension {extension_id} latest version");
-
         let schema_versions = schema_version_range();
         let wasm_api_versions = wasm_api_version_range(ReleaseChannel::global(cx));
 
@@ -1063,7 +997,6 @@ impl ExtensionStore {
         operation: ExtensionOperation,
         cx: &mut Context<Self>,
     ) -> Task<Result<()>> {
-        log::info!("installing extension {extension_id} {version}");
         let Some(url) = self
             .http_client
             .build_zed_api_url(
@@ -1370,13 +1303,6 @@ impl ExtensionStore {
             .filter(|id| extensions_to_load.contains(id))
             .count();
 
-        log::info!(
-            "extensions updated. loading {}, reloading {}, unloading {}",
-            extensions_to_load.len() - reload_count,
-            reload_count,
-            extensions_to_unload.len() - reload_count
-        );
-
         let extension_ids = extensions_to_load
             .iter()
             .filter_map(|id| {
@@ -1806,19 +1732,9 @@ impl ExtensionStore {
                     }
 
                     // Register LLM providers
-                    log::info!(
-                        "Extension {} has {} LLM providers to register",
-                        manifest.id,
-                        llm_providers_with_models.len()
-                    );
                     for llm_provider in llm_providers_with_models {
                         let provider_id: Arc<str> =
                             format!("{}:{}", manifest.id, llm_provider.provider_info.id).into();
-                        log::info!(
-                            "Registering LLM provider {} with {} models",
-                            provider_id,
-                            llm_provider.models.len()
-                        );
                         let wasm_ext = extension.as_ref().clone();
                         let pinfo = llm_provider.provider_info.clone();
                         let mods = llm_provider.models.clone();
@@ -1908,7 +1824,6 @@ impl ExtensionStore {
                     .log_err();
             }
 
-            log::info!("rebuilt extension index in {:?}", start_time.elapsed());
             index
         })
     }
@@ -2182,11 +2097,6 @@ impl ExtensionStore {
                     })?,
                 path_style,
             );
-            log::info!(
-                "Uploading extension {} to {:?}",
-                missing_extension.clone().id,
-                dest_dir
-            );
 
             client
                 .update(cx, |client, cx| {
@@ -2194,11 +2104,6 @@ impl ExtensionStore {
                 })?
                 .await?;
 
-            log::info!(
-                "Finished uploading extension {}",
-                missing_extension.clone().id
-            );
-
             let result = client
                 .update(cx, |client, _cx| {
                     client.proto_client().request(proto::InstallExtension {

crates/extension_host/src/wasm_host/llm_provider.rs 🔗

@@ -115,7 +115,7 @@ impl LanguageModelProvider for ExtensionLanguageModelProvider {
     }
 
     fn name(&self) -> LanguageModelProviderName {
-        LanguageModelProviderName::from(self.provider_info.name.clone())
+        LanguageModelProviderName::from(format!("(Extension) {}", self.provider_info.name))
     }
 
     fn icon(&self) -> ui::IconName {
@@ -123,13 +123,7 @@ impl LanguageModelProvider for ExtensionLanguageModelProvider {
     }
 
     fn icon_path(&self) -> Option<SharedString> {
-        let path = self.icon_path.clone();
-        log::info!(
-            "LLM provider {} icon_path() returning: {:?}",
-            self.provider_info.id,
-            path
-        );
-        path
+        self.icon_path.clone()
     }
 
     fn default_model(&self, cx: &App) -> Option<Arc<dyn LanguageModel>> {
@@ -185,7 +179,30 @@ impl LanguageModelProvider for ExtensionLanguageModelProvider {
     }
 
     fn is_authenticated(&self, cx: &App) -> bool {
-        self.state.read(cx).is_authenticated
+        // First check cached state
+        if self.state.read(cx).is_authenticated {
+            return true;
+        }
+
+        // Also check env var dynamically (in case migration happened after provider creation)
+        if let Some(ref auth_config) = self.auth_config {
+            if let Some(ref env_var_name) = auth_config.env_var {
+                let provider_id_string = self.provider_id_string();
+                let env_var_allowed = ExtensionSettings::get_global(cx)
+                    .allowed_env_var_providers
+                    .contains(provider_id_string.as_str());
+
+                if env_var_allowed {
+                    if let Ok(value) = std::env::var(env_var_name) {
+                        if !value.is_empty() {
+                            return true;
+                        }
+                    }
+                }
+            }
+        }
+
+        false
     }
 
     fn authenticate(&self, cx: &mut App) -> Task<Result<(), AuthenticateError>> {

crates/gpui/src/elements/svg.rs 🔗

@@ -132,25 +132,12 @@ impl Element for Svg {
                 } else if let Some((path, color)) =
                     self.external_path.as_ref().zip(style.text.color)
                 {
-                    log::info!(
-                        "ICON_DEBUG svg.rs external_path={}, color={:?}",
-                        path,
-                        color
-                    );
-                    let Some(bytes) = window.use_asset::<SvgAsset>(path, cx).and_then(|asset| {
-                        if let Err(ref e) = asset {
-                            log::error!("ICON_DEBUG svg.rs FAILED path={}: {:?}", path, e);
-                        }
-                        asset.log_err()
-                    }) else {
-                        log::warn!("ICON_DEBUG svg.rs NO_BYTES path={}", path);
+                    let Some(bytes) = window
+                        .use_asset::<SvgAsset>(path, cx)
+                        .and_then(|asset| asset.log_err())
+                    else {
                         return;
                     };
-                    log::info!(
-                        "ICON_DEBUG svg.rs loaded {} bytes path={}",
-                        bytes.len(),
-                        path
-                    );
 
                     let transformation = self
                         .transformation

crates/language_model/src/registry.rs 🔗

@@ -157,11 +157,6 @@ impl LanguageModelRegistry {
         cx: &mut Context<Self>,
     ) {
         let id = provider.id();
-        log::info!(
-            "LanguageModelRegistry::register_provider: {} (name: {})",
-            id,
-            provider.name()
-        );
 
         let subscription = provider.subscribe(cx, {
             let id = id.clone();
@@ -201,22 +196,8 @@ impl LanguageModelRegistry {
 
     /// Returns providers, filtering out hidden built-in providers.
     pub fn visible_providers(&self) -> Vec<Arc<dyn LanguageModelProvider>> {
-        let all = self.providers();
-        log::info!(
-            "ICON_DEBUG visible_providers: all_providers={}, installed_llm_extension_ids={:?}",
-            all.len(),
-            self.installed_llm_extension_ids
-        );
-        for p in &all {
-            let hidden = self.should_hide_provider(&p.id());
-            log::info!(
-                "ICON_DEBUG   provider {} (id: {}): hidden={}",
-                p.name(),
-                p.id(),
-                hidden
-            );
-        }
-        all.into_iter()
+        self.providers()
+            .into_iter()
             .filter(|p| !self.should_hide_provider(&p.id()))
             .collect()
     }

crates/language_models/src/extension.rs 🔗

@@ -42,11 +42,6 @@ impl ExtensionLanguageModelProviderProxy for LanguageModelProviderRegistryProxy
         register_fn: LanguageModelProviderRegistration,
         cx: &mut App,
     ) {
-        log::info!(
-            "LanguageModelProviderRegistryProxy::register_language_model_provider called for: {}",
-            provider_id
-        );
-        // The register_fn closure will call registry.register_provider internally
         register_fn(cx);
     }
 
@@ -63,9 +58,6 @@ impl ExtensionLanguageModelProviderProxy for LanguageModelProviderRegistryProxy
 pub fn init_proxy(cx: &mut App) {
     let proxy = ExtensionHostProxy::default_global(cx);
     let registry = LanguageModelRegistry::global(cx);
-    log::info!(
-        "language_models::extension::init_proxy: registering LanguageModelProviderRegistryProxy"
-    );
 
     // Set the function that determines which built-in providers should be hidden
     registry.update(cx, |registry, _cx| {