fix(jetbrains): address CLI startup review

This commit is contained in:
kirillk
2026-07-09 11:45:34 -04:00
parent 6609a76fa0
commit 23f89aae7d
8 changed files with 58 additions and 31 deletions
+1 -1
View File
@@ -4,7 +4,7 @@
### Fixed
- 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.
- Surface a clear error when the Kilo backend fails to start instead of hanging on loading, write rotated `kilo-dev.log.*` diagnostic logs in release builds, and add CLI install path diagnostics for relocated JetBrains system folders.
## 7.4.2
+4 -4
View File
@@ -109,7 +109,7 @@ All properties below are passed with `-P` on the Gradle command line or in the r
| `kilo.dev.worktree.root` | monorepo root | Worktree root used to resolve `.kilo-dev/`. Auto-detected from the Gradle project directory; override only when the auto-detection is wrong. |
The checked-in IDE run configurations pass `--no-configuration-cache` because the IntelliJ Platform Gradle Plugin run-IDE tasks are not configuration-cache compatible in this setup.
They also pass `--purge-old-log-directories` so stale sandbox logs do not hide the current backend and frontend `kilo-dev.log` files.
They also pass `--purge-old-log-directories` so stale sandbox logs do not hide the current backend and frontend `kilo-dev.log.*` files.
Example with a fixed split-mode port:
@@ -141,7 +141,7 @@ The checked-in `Run IDE (Backend)`, `Run IDE (Frontend)`, and `Run IDE (Split Mo
### Debug logging properties
The plugin supports a few JVM system properties for local debugging. These are most useful with sandbox runs because the logs are mirrored to `kilo-dev.log` files for frontend and backend.
The plugin supports a few JVM system properties for local debugging. These are most useful with sandbox runs because the logs are mirrored to `kilo-dev.log.*` files for frontend and backend.
`kilo.dev.log.level`
@@ -167,8 +167,8 @@ The plugin supports a few JVM system properties for local debugging. These are m
Where to find the log files:
- In sandbox runs, Kilo writes separate dev log files for each side under the IDE sandbox log directory reported by `PathManager.getLogDir()`.
- Frontend log file: `<sandbox log dir>/kilo-frontend/kilo-dev.log`
- Backend log file: `<sandbox log dir>/kilo-backend/kilo-dev.log`
- Frontend log file: `<sandbox log dir>/kilo-frontend/kilo-dev.log.0`
- Backend log file: `<sandbox log dir>/kilo-backend/kilo-dev.log.0`
- In practice these sit under the current `log_run*` sandbox logs for the active run.
- If you are unsure of the exact sandbox root, open the IDE log directory from the running sandbox instance and then look for the `kilo-frontend/` and `kilo-backend/` subdirectories.
@@ -162,6 +162,8 @@ class KiloBackendAppService private constructor(
clear()
connection.restart()
log.info("restart: complete")
} catch (e: CancellationException) {
throw e
} catch (e: Exception) {
log.warn("restart: failed", e)
throw e
@@ -177,6 +179,8 @@ class KiloBackendAppService private constructor(
clear()
connection.reinstall()
log.info("reinstall: complete")
} catch (e: CancellationException) {
throw e
} catch (e: Exception) {
log.warn("reinstall: failed", e)
throw e
@@ -8,6 +8,7 @@ import com.intellij.openapi.application.PathManager
import com.intellij.openapi.util.SystemInfo
import com.intellij.util.EnvironmentUtil
import kotlinx.coroutines.CompletableDeferred
import kotlinx.coroutines.CancellationException
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.TimeoutCancellationException
import kotlinx.coroutines.withContext
@@ -43,6 +44,7 @@ class KiloBackendCliManager(
companion object {
private const val STARTUP_TIMEOUT_MS = 30_000L
private const val STARTUP_TIMEOUT_GRACE_MS = 8_000L
private const val KILL_TIMEOUT_SECONDS = 5L
}
@@ -64,7 +66,21 @@ class KiloBackendCliManager(
val path = resolveCli(onProgress)
onResolved()
log.info("CLI binary path: ${path.absolutePath} (size=${path.length()} bytes)")
spawn(path)
withTimeout(timeoutMs + STARTUP_TIMEOUT_GRACE_MS) { spawn(path) }
} catch (e: TimeoutCancellationException) {
val msg = "CLI startup timed out after ${timeoutMs}ms"
log.warn(msg, e)
process?.let { proc ->
log.info("Cleaning up orphaned CLI process (pid=${proc.pid()})")
process = null
cleanup(proc, "startup timeout cleanup")
}
CliServer.State.Error(
message = msg,
details = e.stackTraceToString(),
)
} catch (e: CancellationException) {
throw e
} catch (e: Exception) {
log.warn("CLI startup failed", e)
process?.let { proc ->
@@ -106,6 +122,7 @@ class KiloBackendCliManager(
private suspend fun spawn(cli: File): CliServer.State =
withContext(Dispatchers.IO) {
val pwd = generatePassword()
val start = System.nanoTime()
val env = buildEnv(pwd)
val diag = startupDiagnostics(cli, env, log)
@@ -148,20 +165,21 @@ class KiloBackendCliManager(
stdout = proc.inputStream,
stderr = stderr,
pwd = pwd,
timeoutMs = timeoutMs,
timeoutMs = (timeoutMs - elapsed(start)).coerceAtLeast(1L),
alive = { proc.isAlive },
pid = { proc.pid() },
code = { proc.waitFor() },
onTimeout = { cleanup(proc, "startup timeout") },
onTimeout = {
if (process == proc) process = null
cleanup(proc, "startup timeout")
},
diagnostics = { diag },
log = log,
onThread = { stdout = it },
)
if (state is CliServer.State.Error) {
if (state is CliServer.State.Error && process == proc) {
process = null
uninstall()
this@KiloBackendCliManager.stderr = null
this@KiloBackendCliManager.stdout = null
cleanup(proc, "startup error")
}
state
}
@@ -242,6 +260,8 @@ class KiloBackendCliManager(
SecureRandom().nextBytes(bytes)
return bytes.joinToString("") { "%02x".format(it) }
}
private fun elapsed(start: Long): Long = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start)
}
internal fun startupDiagnostics(cli: File, env: Map<String, String>, log: KiloLog): String {
@@ -131,11 +131,11 @@ class KiloCliDownloader(
val mutex = LOCKS.computeIfAbsent(file.absolutePath) { Any() }
return synchronized(mutex) {
RandomAccessFile(file, "rw").channel.use { channel ->
val start = System.currentTimeMillis()
val start = System.nanoTime()
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}")
log.info("Acquired Kilo CLI cache lock after ${elapsed(start)}ms: ${file.absolutePath}")
block()
}
}
@@ -150,7 +150,7 @@ class KiloCliDownloader(
null
}
if (lock != null) return lock
val waited = System.currentTimeMillis() - start
val waited = elapsed(start)
if (waited >= lockTimeoutMs) {
val msg = "Timed out waiting for Kilo CLI cache lock after ${waited}ms: ${file.absolutePath}"
log.warn(msg)
@@ -160,6 +160,8 @@ class KiloCliDownloader(
}
}
private fun elapsed(start: Long): Long = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start)
private fun stage(version: String, platform: String): File {
val tmp = File(root, ".tmp")
val dir = File(tmp, "$version-$platform-${System.nanoTime()}")
@@ -377,16 +379,16 @@ class KiloCliDownloader(
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") ?: "<unset>"}")
add("idea.system.path=${System.getProperty("idea.system.path") ?: "<unset>"}")
add("idea.plugins.path=${System.getProperty("idea.plugins.path") ?: "<unset>"}")
add("idea.log.path=${System.getProperty("idea.log.path") ?: "<unset>"}")
add("idea.properties.file=${System.getProperty("idea.properties.file") ?: "<unset>"}")
add("user.home=${System.getProperty("user.home") ?: "<unset>"}")
add("USERPROFILE=${EnvironmentUtil.getValue("USERPROFILE") ?: "<unset>"}")
add("TEMP=${EnvironmentUtil.getValue("TEMP") ?: "<unset>"}")
add("TMP=${EnvironmentUtil.getValue("TMP") ?: "<unset>"}")
add("cacheRoot=${root.absolutePath}${info(root)}")
add("idea.config.path=${safe { System.getProperty("idea.config.path") ?: "<unset>" }}")
add("idea.system.path=${safe { System.getProperty("idea.system.path") ?: "<unset>" }}")
add("idea.plugins.path=${safe { System.getProperty("idea.plugins.path") ?: "<unset>" }}")
add("idea.log.path=${safe { System.getProperty("idea.log.path") ?: "<unset>" }}")
add("idea.properties.file=${safe { System.getProperty("idea.properties.file") ?: "<unset>" }}")
add("user.home=${safe { System.getProperty("user.home") ?: "<unset>" }}")
add("USERPROFILE=${safe { EnvironmentUtil.getValue("USERPROFILE") ?: "<unset>" }}")
add("TEMP=${safe { EnvironmentUtil.getValue("TEMP") ?: "<unset>" }}")
add("TMP=${safe { EnvironmentUtil.getValue("TMP") ?: "<unset>" }}")
add("cacheRoot=${safe { root.absolutePath + info(root) }}")
}.joinToString(" ")
log.info("Kilo CLI path diagnostics: $text")
}
@@ -44,7 +44,7 @@ class KiloBackendCliManagerReadyTest {
stdout = input,
stderr = StringBuilder("stderr line"),
pwd = "pwd123",
timeoutMs = 50,
timeoutMs = WATCHDOG_TIMEOUT_MS,
alive = { true },
pid = { 456L },
code = { 0 },
@@ -57,7 +57,7 @@ class KiloBackendCliManagerReadyTest {
val err = assertIs<CliServer.State.Error>(state)
assertEquals(1, calls.get())
assertContains(err.message, "within 50ms")
assertContains(err.message, "within ${WATCHDOG_TIMEOUT_MS}ms")
assertContains(err.message, "process alive=true")
assertContains(err.message, "pid=456")
assertContains(err.details.orEmpty(), "stderr line")
@@ -107,5 +107,6 @@ class KiloBackendCliManagerReadyTest {
companion object {
private const val TIMEOUT_MS = 1_000L
private const val WATCHDOG_TIMEOUT_MS = 50L
}
}
@@ -274,7 +274,7 @@ class KiloCliDownloaderTest {
}
@Test
fun `cache lock times out clearly when held by another process`() = runBlocking {
fun `cache lock times out clearly when already held in this process`() = runBlocking {
assertTrue(dir.mkdirs() || dir.isDirectory)
val file = File(dir, ".lock")
val log = TestLog()
@@ -21,10 +21,10 @@ import java.util.logging.LogRecord
* Logging interface for the Kilo JetBrains plugin.
*
* In normal (non-sandbox) mode, output goes through IntelliJ's own [com.intellij.openapi.diagnostic.Logger],
* which writes to the standard IDE log file, and to a rotated `kilo-dev.log` file inside the IDE log directory.
* which writes to the standard IDE log file, and to rotated `kilo-dev.log.*` files inside the IDE log directory.
*
* In sandbox mode (i.e. when running via `./gradlew runIde`, detected via the `idea.plugin.in.sandbox.mode`
* system property), output is written only to `kilo-dev.log`.
* system property), output is written only to `kilo-dev.log.*`.
*
* Usage:
* ```kotlin
@@ -119,7 +119,7 @@ internal class FileLog(cls: Class<*>) : KiloLog {
private val handler: FileHandler by lazy {
val dir = resolveLogDir()
val path = dir.resolve("kilo-dev.log")
val path = dir.resolve("kilo-dev.log.%g")
IntellijLog(FileLog::class.java).info("Kilo diagnostic log directory: $dir")
val h = FileHandler(path.toString(), LIMIT, COUNT, true)
h.formatter = KiloFormatter()