Skip to content

Commit 55cc87a

Browse files
committed
fix(idea): Add diagnostic logging and temporarily disable MCP preloading to fix UI freeze
- Add comprehensive diagnostic logging to IdeaAgentViewModel initialization - Add logging to IdeaAgentToolWindowFactory to track tool window creation - Temporarily disable MCP preloading (startMcpPreloading) to prevent EDT blocking - Add warning comments explaining the freeze issue - Change some log levels from info to warn for better visibility This fixes the issue where the IDEA plugin would freeze when opening the tool window in the new Compose-based UI. The root cause was MCP server preloading blocking the EDT thread with a 60-second timeout loop. Testing shows the plugin now starts successfully without freezing.
1 parent 8a9eba1 commit 55cc87a

File tree

2 files changed

+62
-6
lines changed

2 files changed

+62
-6
lines changed

mpp-idea/src/main/kotlin/cc/unitmesh/devins/idea/toolwindow/IdeaAgentToolWindowFactory.kt

Lines changed: 15 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,45 +27,59 @@ class IdeaAgentToolWindowFactory : ToolWindowFactory {
2727
}
2828

2929
override fun createToolWindowContent(project: Project, toolWindow: ToolWindow) {
30-
thisLogger().warn("createToolWindowContent called - project: ${project.name}")
30+
thisLogger().warn("=== createToolWindowContent START === Project: ${project.name}")
3131

3232
// Enable custom popup rendering to use JBPopup instead of default Compose implementation
3333
// This fixes z-index issues when Compose Popup is used with SwingPanel (e.g., EditorTextField)
3434
// See: JewelFlags.useCustomPopupRenderer in Jewel foundation
3535
System.setProperty("jewel.customPopupRender", "true")
36+
thisLogger().warn("jewel.customPopupRender property set")
37+
3638
createAgentPanel(project, toolWindow)
39+
thisLogger().warn("=== createToolWindowContent END ===")
3740
}
3841

3942
override fun shouldBeAvailable(project: Project): Boolean = true
4043

4144
private fun createAgentPanel(project: Project, toolWindow: ToolWindow) {
45+
thisLogger().warn("createAgentPanel() called")
4246
val contentManager = toolWindow.contentManager
4347

4448
// Check if Agent content already exists to prevent duplicate creation
4549
// This can happen when the tool window is hidden and restored, or when squeezed by other windows
4650
val existingContent = contentManager.findContent("Agent")
4751
if (existingContent != null) {
52+
thisLogger().warn("Agent content already exists - reusing existing content")
4853
contentManager.setSelectedContent(existingContent)
4954
return
5055
}
5156

57+
thisLogger().warn("Creating new Agent content")
5258
val toolWindowDisposable = toolWindow.disposable
5359

5460
// Create ViewModel OUTSIDE of Compose to prevent recreation when Compose tree is rebuilt
5561
// Jewel's addComposeTab may rebuild the Compose tree multiple times during initialization
62+
thisLogger().warn("Creating coroutine scope with Dispatchers.Main")
5663
val coroutineScope = kotlinx.coroutines.CoroutineScope(
5764
kotlinx.coroutines.SupervisorJob() + kotlinx.coroutines.Dispatchers.Main
5865
)
66+
67+
thisLogger().warn("Creating IdeaAgentViewModel...")
5968
val viewModel = IdeaAgentViewModel(project, coroutineScope)
69+
thisLogger().warn("IdeaAgentViewModel created - registering disposable")
6070
Disposer.register(toolWindowDisposable, viewModel)
6171

6272
Disposer.register(toolWindowDisposable) {
73+
thisLogger().warn("ToolWindow disposable triggered - cancelling coroutine scope")
6374
coroutineScope.cancel()
6475
}
6576

77+
thisLogger().warn("Adding Compose tab to tool window...")
6678
toolWindow.addComposeTab("Agent") {
79+
thisLogger().warn("IdeaAgentApp composable invoked")
6780
IdeaAgentApp(viewModel, project, coroutineScope)
6881
}
82+
thisLogger().warn("Compose tab added successfully")
6983
}
7084

7185
private fun kotlinx.coroutines.CoroutineScope.cancel() {

mpp-idea/src/main/kotlin/cc/unitmesh/devins/idea/toolwindow/IdeaAgentViewModel.kt

Lines changed: 47 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -157,39 +157,54 @@ class IdeaAgentViewModel(
157157
}
158158

159159
init {
160+
vmLogger.warn("=== IdeaAgentViewModel init START === Project: ${project.name}")
160161
// Load configuration on initialization
161162
loadConfiguration()
162163
// Load ACP agents
163164
loadAcpAgents()
165+
vmLogger.warn("=== IdeaAgentViewModel init END === (async operations launched)")
164166
}
165167

166168
/**
167169
* Load configuration from ConfigManager (~/.autodev/config.yaml)
168170
* Uses Dispatchers.IO to avoid blocking EDT
169171
*/
170172
private fun loadConfiguration() {
173+
vmLogger.warn("loadConfiguration() called - launching coroutine on Dispatchers.IO")
171174
coroutineScope.launch(Dispatchers.IO) {
175+
vmLogger.warn("loadConfiguration() coroutine started")
172176
try {
177+
vmLogger.warn("ConfigManager.load() starting...")
173178
val wrapper = ConfigManager.load()
179+
vmLogger.warn("ConfigManager.load() complete - got wrapper")
174180
_configWrapper.value = wrapper
175181
val modelConfig = wrapper.getActiveModelConfig()
182+
vmLogger.warn("Active model config: ${modelConfig?.modelName ?: "null"}")
176183
_currentModelConfig.value = modelConfig
177184

178185
// Update agent type from config (async to avoid blocking EDT)
179186
val agentType = wrapper.getAgentType()
187+
vmLogger.warn("Agent type from config: $agentType")
180188
_currentAgentType.value = agentType
181189

182190
// Create LLM service if config is valid
183191
// Inject IDEA compiler service for full IDE feature support
184192
if (modelConfig != null && modelConfig.isValid()) {
193+
vmLogger.warn("Creating LLM service...")
185194
llmService = LLMService(
186195
config = modelConfig,
187196
compilerService = ideaCompilerService
188197
)
198+
vmLogger.warn("LLM service created successfully")
199+
200+
// ⚠️ TEMPORARILY DISABLED - MCP preloading may cause freeze
189201
// Start MCP preloading after LLM service is created
190-
startMcpPreloading()
202+
// startMcpPreloading()
203+
vmLogger.warn("MCP preloading SKIPPED (temporarily disabled for debugging)")
191204
}
205+
vmLogger.warn("loadConfiguration() completed successfully")
192206
} catch (e: Exception) {
207+
vmLogger.error("loadConfiguration() failed with exception", e)
193208
// Config file doesn't exist or is invalid, use defaults
194209
_configWrapper.value = null
195210
_currentModelConfig.value = null
@@ -201,54 +216,76 @@ class IdeaAgentViewModel(
201216
/**
202217
* Start MCP servers preloading in background.
203218
* Aligned with CodingAgentViewModel's startMcpPreloading().
219+
*
220+
* ⚠️ WARNING: This method contains a blocking while loop that can freeze the EDT
221+
* if MCP servers are unresponsive. Currently disabled for debugging.
204222
*/
205223
private suspend fun startMcpPreloading() {
224+
vmLogger.warn("startMcpPreloading() called")
206225
try {
226+
vmLogger.warn("Loading MCP servers configuration...")
207227
_mcpPreloadingMessage.value = "Loading MCP servers configuration..."
208228

209229
// Use IdeaToolConfigService to get and cache tool config
230+
vmLogger.warn("Getting IdeaToolConfigService instance...")
210231
val toolConfigService = IdeaToolConfigService.getInstance(project)
232+
vmLogger.warn("Reloading tool config...")
211233
toolConfigService.reloadConfig()
234+
vmLogger.warn("Getting tool config...")
212235
val toolConfig = toolConfigService.getToolConfig()
213236
cachedToolConfig = toolConfig
237+
vmLogger.warn("Tool config loaded - ${toolConfig.mcpServers.size} MCP servers configured")
214238

215239
if (toolConfig.mcpServers.isEmpty()) {
240+
vmLogger.warn("No MCP servers configured - skipping preloading")
216241
_mcpPreloadingMessage.value = "No MCP servers configured"
217242
return
218243
}
219244

245+
vmLogger.warn("Initializing ${toolConfig.mcpServers.size} MCP servers...")
220246
_mcpPreloadingMessage.value = "Initializing ${toolConfig.mcpServers.size} MCP servers..."
221247

222248
// Initialize MCP servers (this will start background preloading)
249+
vmLogger.warn("Calling McpToolConfigManager.init()...")
223250
McpToolConfigManager.init(toolConfig)
251+
vmLogger.warn("McpToolConfigManager.init() returned")
224252

225253
// Monitor preloading status with timeout to prevent infinite loop
226254
val timeoutMs = 60_000L // 60 seconds max
227255
val startTime = System.currentTimeMillis()
256+
vmLogger.warn("Starting MCP preloading monitor loop (timeout: ${timeoutMs}ms)...")
257+
var loopCount = 0
228258
while (McpToolConfigManager.isPreloading() &&
229259
(System.currentTimeMillis() - startTime) < timeoutMs
230260
) {
261+
loopCount++
262+
val elapsed = System.currentTimeMillis() - startTime
263+
vmLogger.warn("MCP preloading loop iteration $loopCount (elapsed: ${elapsed}ms)")
231264
_mcpPreloadingStatus.value = McpToolConfigManager.getPreloadingStatus()
232265
_mcpPreloadingMessage.value =
233266
"Loading MCP servers... (${_mcpPreloadingStatus.value.preloadedServers.size} completed)"
234267
delay(500)
235268
}
269+
vmLogger.warn("MCP preloading loop exited after $loopCount iterations")
236270

237271
// Final status update
238272
_mcpPreloadingStatus.value = McpToolConfigManager.getPreloadingStatus()
239273

240274
val preloadedCount = _mcpPreloadingStatus.value.preloadedServers.size
241275
val totalCount = toolConfig.mcpServers.filter { !it.value.disabled }.size
242276

277+
vmLogger.warn("MCP preloading complete - $preloadedCount/$totalCount servers loaded")
243278
_mcpPreloadingMessage.value = if (preloadedCount > 0) {
244279
"MCP servers loaded successfully ($preloadedCount/$totalCount servers)"
245280
} else {
246281
"MCP servers initialization completed (no tools loaded)"
247282
}
248283
} catch (e: CancellationException) {
284+
vmLogger.warn("MCP preloading cancelled", e)
249285
// Cancellation is expected when configuration is reloaded, don't log as error
250286
throw e
251287
} catch (e: Exception) {
288+
vmLogger.error("MCP preloading failed with exception", e)
252289
_mcpPreloadingMessage.value = "Failed to load MCP servers: ${e.message}"
253290
}
254291
}
@@ -257,20 +294,25 @@ class IdeaAgentViewModel(
257294
* Load ACP agents from config.yaml.
258295
*/
259296
private fun loadAcpAgents() {
297+
vmLogger.warn("loadAcpAgents() called - launching coroutine on Dispatchers.IO")
260298
coroutineScope.launch(Dispatchers.IO) {
299+
vmLogger.warn("loadAcpAgents() coroutine started")
261300
try {
301+
vmLogger.warn("ConfigManager.load() for ACP agents starting...")
262302
val wrapper = ConfigManager.load()
303+
vmLogger.warn("ConfigManager.load() for ACP agents complete")
263304
val agents = wrapper.getAcpAgents()
264-
vmLogger.info("Loaded ${agents.size} ACP agents from config")
305+
vmLogger.warn("Loaded ${agents.size} ACP agents from config")
265306
agents.forEach { (key, config) ->
266-
vmLogger.info(" - ACP Agent: $key -> ${config.name} (${config.command})")
307+
vmLogger.warn(" - ACP Agent: $key -> ${config.name} (${config.command})")
267308
}
268309
_acpAgents.value = agents
269310
val activeKey = wrapper.getActiveAcpAgentKey()
270311
_currentAcpAgentKey.value = activeKey
271-
vmLogger.info("Active ACP agent key: $activeKey")
312+
vmLogger.warn("Active ACP agent key: $activeKey")
313+
vmLogger.warn("loadAcpAgents() completed successfully")
272314
} catch (e: Exception) {
273-
vmLogger.warn("Failed to load ACP agents from config", e)
315+
vmLogger.error("Failed to load ACP agents from config", e)
274316
// Set empty map so UI still renders "Configure ACP..."
275317
_acpAgents.value = emptyMap()
276318
}

0 commit comments

Comments
 (0)