diff --git a/packages/kilo-jetbrains/CHANGELOG.md b/packages/kilo-jetbrains/CHANGELOG.md index 5a64b99ab42..7ecd10534fd 100644 --- a/packages/kilo-jetbrains/CHANGELOG.md +++ b/packages/kilo-jetbrains/CHANGELOG.md @@ -4,7 +4,7 @@ ### Fixed -- Surface a clear error when the Kilo backend fails to start instead of hanging on loading, and write the `kilo-dev.log` diagnostic log in release builds. +- Surface a clear error when the Kilo backend fails to start instead of hanging on loading, write the `kilo-dev.log` diagnostic log in release builds, and add CLI install path diagnostics for relocated JetBrains system folders. ## 7.4.2 diff --git a/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/app/KiloBackendAppService.kt b/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/app/KiloBackendAppService.kt index 88cfe1bd64f..5033b312c0c 100644 --- a/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/app/KiloBackendAppService.kt +++ b/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/app/KiloBackendAppService.kt @@ -155,16 +155,32 @@ class KiloBackendAppService private constructor( } suspend fun restart() { + log.info("restart: requested — waiting for lifecycle mutex") mutex.withLock { - clear() - connection.restart() + log.info("restart: acquired lifecycle mutex") + try { + clear() + connection.restart() + log.info("restart: complete") + } catch (e: Exception) { + log.warn("restart: failed", e) + throw e + } } } suspend fun reinstall() { + log.info("reinstall: requested — waiting for lifecycle mutex") mutex.withLock { - clear() - connection.reinstall() + log.info("reinstall: acquired lifecycle mutex") + try { + clear() + connection.reinstall() + log.info("reinstall: complete") + } catch (e: Exception) { + log.warn("reinstall: failed", e) + throw e + } } } diff --git a/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/cli/KiloCliDownloader.kt b/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/cli/KiloCliDownloader.kt index 181d114efc7..e664c97dd88 100644 --- a/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/cli/KiloCliDownloader.kt +++ b/packages/kilo-jetbrains/backend/src/main/kotlin/ai/kilocode/backend/cli/KiloCliDownloader.kt @@ -3,6 +3,7 @@ package ai.kilocode.backend.cli import ai.kilocode.log.KiloLog import com.intellij.openapi.application.PathManager import com.intellij.openapi.util.SystemInfo +import com.intellij.util.EnvironmentUtil import kotlinx.coroutines.Dispatchers import kotlinx.coroutines.withContext import kotlinx.serialization.json.Json @@ -17,6 +18,10 @@ import org.apache.commons.compress.archivers.tar.TarArchiveInputStream import org.apache.commons.compress.compressors.gzip.GzipCompressorInputStream import java.io.File import java.io.RandomAccessFile +import java.nio.channels.FileLock +import java.nio.channels.OverlappingFileLockException +import java.nio.file.Files +import java.nio.file.Path import java.security.MessageDigest import java.time.Instant import java.util.concurrent.ConcurrentHashMap @@ -34,8 +39,11 @@ class KiloCliDownloader( private val root: File = File(PathManager.getSystemPath(), "kilo/cli"), private val baseUrl: String = "https://github.com/Kilo-Org/kilocode/releases/download", private val api: String = "https://api.github.com/repos/Kilo-Org/kilocode/releases/tags", + private val lockTimeoutMs: Long = LOCK_TIMEOUT_MS, ) { companion object { + private const val LOCK_TIMEOUT_MS = 30_000L + private const val LOCK_POLL_MS = 100L private val DIGEST = Regex("^sha256:[a-f0-9]{64}$") private val JSON = Json { ignoreUnknownKeys = true } private val LOCKS = ConcurrentHashMap() @@ -43,6 +51,7 @@ class KiloCliDownloader( suspend fun resolve(version: String, force: Boolean = false, onProgress: (CliDownload) -> Unit = {}): File = withContext(Dispatchers.IO) { + logPaths(version, force) locked { val platform = KiloCliPlatform.current() val dir = File(File(root, version), platform) @@ -50,6 +59,11 @@ class KiloCliDownloader( val done = File(dir, ".complete") val ext = KiloCliPlatform.archive(platform) + log.info( + "Kilo CLI cache target: version=$version platform=$platform exe=${exe.absolutePath} " + + "complete=${done.absolutePath} force=$force" + ) + if (!force) { cached(version, platform, exe, done)?.let { return@locked it } } @@ -66,6 +80,7 @@ class KiloCliDownloader( ) onProgress(CliDownload(0, version, platform)) download(version, platform, ext, archive, onProgress) + log.info("Verifying Kilo CLI archive ${archive.absolutePath}") verify(archive, digest) log.info( "Downloaded Kilo CLI $version for $platform to ${archive.absolutePath} (size=${archive.length()} bytes)" @@ -78,6 +93,7 @@ class KiloCliDownloader( if (archive.exists() && !archive.delete()) { log.warn("Failed to delete extracted Kilo CLI archive ${archive.absolutePath}") } + log.info("Writing Kilo CLI cache completion marker ${complete.absolutePath}") complete.writeText("$digest\n") replace(dir, stage) onProgress(CliDownload(100, version, platform)) @@ -93,7 +109,12 @@ class KiloCliDownloader( private fun cached(version: String, platform: String, exe: File, done: File): File? { val digest = done.takeIf { it.isFile }?.readText()?.trim() - if (!exe.isFile || digest == null || !digest.matches(DIGEST)) return null + val valid = digest != null && digest.matches(DIGEST) + log.info( + "Kilo CLI cache check: version=$version platform=$platform exeExists=${exe.isFile} " + + "completeExists=${done.isFile} digestValid=$valid exe=${exe.absolutePath} complete=${done.absolutePath}" + ) + if (!exe.isFile || !valid) return null log.info("Using cached Kilo CLI $version for $platform at ${exe.absolutePath}") if (!SystemInfo.isWindows) exe.setExecutable(true) prune(version) @@ -101,21 +122,48 @@ class KiloCliDownloader( } private fun locked(block: () -> T): T { + log.info("Ensuring Kilo CLI cache root ${root.absolutePath}") if (!root.isDirectory && !root.mkdirs()) { throw IllegalStateException("Failed to create Kilo CLI cache root ${root.absolutePath}") } val file = File(root, ".lock").canonicalFile + log.info("Kilo CLI cache lock path: ${file.absolutePath}") val mutex = LOCKS.computeIfAbsent(file.absolutePath) { Any() } return synchronized(mutex) { RandomAccessFile(file, "rw").channel.use { channel -> - channel.lock().use { block() } + val start = System.currentTimeMillis() + log.info("Waiting for Kilo CLI cache lock: ${file.absolutePath}") + val lock = acquire(file, channel::tryLock, start) + lock.use { + log.info("Acquired Kilo CLI cache lock after ${System.currentTimeMillis() - start}ms: ${file.absolutePath}") + block() + } } } } + private fun acquire(file: File, attempt: () -> FileLock?, start: Long): FileLock { + while (true) { + val lock = try { + attempt() + } catch (_: OverlappingFileLockException) { + null + } + if (lock != null) return lock + val waited = System.currentTimeMillis() - start + if (waited >= lockTimeoutMs) { + val msg = "Timed out waiting for Kilo CLI cache lock after ${waited}ms: ${file.absolutePath}" + log.warn(msg) + throw IllegalStateException(msg) + } + Thread.sleep(LOCK_POLL_MS.coerceAtMost((lockTimeoutMs - waited).coerceAtLeast(1L))) + } + } + private fun stage(version: String, platform: String): File { val tmp = File(root, ".tmp") val dir = File(tmp, "$version-$platform-${System.nanoTime()}") + log.info("Creating Kilo CLI staging directory ${dir.absolutePath}") if (!dir.isDirectory && !dir.mkdirs()) { throw IllegalStateException("Failed to create Kilo CLI staging directory ${dir.absolutePath}") } @@ -123,6 +171,7 @@ class KiloCliDownloader( } private fun replace(dir: File, stage: File) { + log.info("Installing Kilo CLI cache from ${stage.absolutePath} to ${dir.absolutePath}") val parent = dir.parentFile if (!parent.isDirectory && !parent.mkdirs()) { throw IllegalStateException("Failed to create Kilo CLI cache directory ${parent.absolutePath}") @@ -133,6 +182,7 @@ class KiloCliDownloader( throw IllegalStateException("Failed to move existing Kilo CLI cache ${dir.absolutePath} aside") } if (stage.renameTo(dir)) { + log.info("Installed Kilo CLI cache at ${dir.absolutePath}") if (backup.exists() && !backup.deleteRecursively()) { log.warn("Failed to delete previous Kilo CLI cache ${backup.absolutePath}") } @@ -318,4 +368,41 @@ class KiloCliDownloader( private fun url(version: String, platform: String, ext: String) = "${baseUrl.trimEnd('/')}/v$version/kilo-$platform.$ext" + + private fun logPaths(version: String, force: Boolean) { + val text = buildList { + add("version=$version force=$force") + add("configPath=${safe { PathManager.getConfigPath() }}") + add("systemPath=${safe { PathManager.getSystemPath() }}") + add("pluginsPath=${safe { PathManager.getPluginsPath() }}") + add("logPath=${safe { PathManager.getLogPath() }}") + add("logDir=${safe { PathManager.getLogDir().toString() }}") + add("idea.config.path=${System.getProperty("idea.config.path") ?: ""}") + add("idea.system.path=${System.getProperty("idea.system.path") ?: ""}") + add("idea.plugins.path=${System.getProperty("idea.plugins.path") ?: ""}") + add("idea.log.path=${System.getProperty("idea.log.path") ?: ""}") + add("idea.properties.file=${System.getProperty("idea.properties.file") ?: ""}") + add("user.home=${System.getProperty("user.home") ?: ""}") + add("USERPROFILE=${EnvironmentUtil.getValue("USERPROFILE") ?: ""}") + add("TEMP=${EnvironmentUtil.getValue("TEMP") ?: ""}") + add("TMP=${EnvironmentUtil.getValue("TMP") ?: ""}") + add("cacheRoot=${root.absolutePath}${info(root)}") + }.joinToString(" ") + log.info("Kilo CLI path diagnostics: $text") + } + + private fun info(file: File): String = runCatching { + val path = existing(file.toPath()) + val store = Files.getFileStore(path) + " (canonical=${file.canonicalPath} fs=${store.type().ifBlank { "" }} " + + "name=${store.name().ifBlank { "" }} readOnly=${store.isReadOnly})" + }.getOrElse { " (canonical= fs=)" } + + private fun existing(path: Path): Path { + var current = path + while (!Files.exists(current) && current.parent != null) current = current.parent + return current + } + + private fun safe(value: () -> String): String = runCatching { value() }.getOrElse { "" } } diff --git a/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/app/KiloBackendAppServiceTest.kt b/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/app/KiloBackendAppServiceTest.kt index d99c80fb556..ae9eadc862a 100644 --- a/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/app/KiloBackendAppServiceTest.kt +++ b/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/app/KiloBackendAppServiceTest.kt @@ -629,6 +629,9 @@ class KiloBackendAppServiceTest { assertIs(svc.appState.value) assertFalse(log.messages.any { it.contains("Application start timed out") }) + assertTrue(log.messages.any { it.contains("restart: requested") && it.contains("waiting for lifecycle mutex") }) + assertTrue(log.messages.any { it.contains("restart: acquired lifecycle mutex") }) + assertTrue(log.messages.any { it.contains("restart: complete") }) } finally { gate.countDown() } @@ -654,6 +657,9 @@ class KiloBackendAppServiceTest { assertIs(svc.appState.value) assertFalse(log.messages.any { it.contains("Application start timed out") }) + assertTrue(log.messages.any { it.contains("reinstall: requested") && it.contains("waiting for lifecycle mutex") }) + assertTrue(log.messages.any { it.contains("reinstall: acquired lifecycle mutex") }) + assertTrue(log.messages.any { it.contains("reinstall: complete") }) } finally { gate.countDown() } @@ -790,6 +796,9 @@ class KiloBackendAppServiceTest { assertIs(svc.appState.value) assertNotNull(svc.config) + assertTrue(log.messages.any { it.contains("restart: requested") && it.contains("waiting for lifecycle mutex") }) + assertTrue(log.messages.any { it.contains("restart: acquired lifecycle mutex") }) + assertTrue(log.messages.any { it.contains("restart: complete") }) } @Test diff --git a/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/cli/KiloCliDownloaderTest.kt b/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/cli/KiloCliDownloaderTest.kt index 1c4d3131c0b..12d71855d97 100644 --- a/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/cli/KiloCliDownloaderTest.kt +++ b/packages/kilo-jetbrains/backend/src/test/kotlin/ai/kilocode/backend/cli/KiloCliDownloaderTest.kt @@ -11,6 +11,7 @@ import org.apache.commons.compress.compressors.gzip.GzipCompressorOutputStream import org.junit.jupiter.api.io.TempDir import java.io.ByteArrayOutputStream import java.io.File +import java.io.RandomAccessFile import java.security.MessageDigest import java.util.zip.ZipEntry import java.util.zip.ZipOutputStream @@ -54,6 +55,9 @@ class KiloCliDownloaderTest { it.contains("/.tmp/") } ) + assertTrue(log.messages.any { it.contains("Kilo CLI path diagnostics:") && it.contains("cacheRoot=${dir.absolutePath}") }) + assertTrue(log.messages.any { it.contains("Kilo CLI cache target:") && it.contains("exe=${cli.absolutePath}") }) + assertTrue(log.messages.any { it.contains("Kilo CLI cache lock path:") && it.contains(File(dir, ".lock").canonicalPath) }) val cachedProgress = mutableListOf() val cached = KiloCliDownloader( @@ -269,6 +273,29 @@ class KiloCliDownloaderTest { } } + @Test + fun `cache lock times out clearly when held by another process`() = runBlocking { + assertTrue(dir.mkdirs() || dir.isDirectory) + val file = File(dir, ".lock") + val log = TestLog() + RandomAccessFile(file, "rw").channel.use { channel -> + channel.lock().use { + val ex = assertFailsWith { + KiloCliDownloader( + log = log, + root = dir, + lockTimeoutMs = 50, + ).resolve("1.2.3") + } + + assertContains(ex.message.orEmpty(), "Timed out waiting for Kilo CLI cache lock") + assertContains(ex.message.orEmpty(), file.canonicalPath) + assertTrue(log.messages.any { it.contains("Waiting for Kilo CLI cache lock") && it.contains(file.canonicalPath) }) + assertTrue(log.messages.any { it.contains("Timed out waiting for Kilo CLI cache lock") && it.contains(file.canonicalPath) }) + } + } + } + private fun archive(script: String = "#!/bin/sh\n"): ByteArray { val files = mapOf( "bin/${KiloCliPlatform.exe()}" to script.toByteArray(),