From 6479a7ecb0d330f02f5d40d0f8cc6ac308f01a65 Mon Sep 17 00:00:00 2001 From: lcy Date: Sun, 18 Oct 2026 09:50:08 +0800 Subject: [PATCH 1/2] fix(runtime): wait for an HTTP answer before calling local OpenCode ready On many cold starts the agent picker spun for ~2 minutes. `opencode serve` (1.18.5, 1.19.3) starts accepting TCP connections a few hundred ms before it attaches its HTTP request handler; Node emits the request on a connection accepted in that window with no listener and drops it, so the request is never answered while the socket stays open. The launcher took an open port as a ready server, the app's first request (the protocol probe, api/info) landed in that window, and it hung until the 120 s read timeout. Reproduced on the host with plain OpenCode 1.19.3 (a request sent the instant the port opens: 12/12 never answered) and traced on two phones. - the launcher waits until GET /global/health returns any HTTP status line (401 included), each attempt on its own connection with a 1 s read timeout, instead of until a TCP connect succeeds - the two protocol probes get a 5 s call timeout and one retry on a fresh call, so a server caught in that window costs seconds, not 120 s Verified on a phone (M098FE): 12 cold starts at 10-12 s each, no probe timeouts; the readiness check's first attempt landed in the window in 11 of them and the next one succeeded. --- .../core/api/ProtocolDetectingOpenCodeApi.kt | 38 +++++++++++++- .../local/LocalRuntimeProcessLauncher.kt | 50 ++++++++++++++++++- .../core/api/OpenCodeV2ApiClientTest.kt | 20 ++++++++ .../local/LocalRuntimeProcessLauncherTest.kt | 41 +++++++++++++++ 4 files changed, 146 insertions(+), 3 deletions(-) diff --git a/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt b/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt index 435725183..a7ac4c75e 100644 --- a/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt +++ b/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt @@ -23,6 +23,8 @@ import okhttp3.HttpUrl import okhttp3.OkHttpClient import okhttp3.Request import java.io.IOException +import java.io.InterruptedIOException +import java.util.concurrent.TimeUnit /** Which HTTP API a server speaks. V2 servers answer under the `api/` prefix; V1 servers answer the legacy routes. */ enum class OpenCodeProtocol { V1, V2 } @@ -46,6 +48,23 @@ class ProtocolDetectingOpenCodeApi( private val v1: OpenCodeApiClient = OpenCodeApiClient(profile, httpClient, json) private val v2: OpenCodeV2ApiClient = OpenCodeV2ApiClient(profile, httpClient, json) + /** + * The client for the two probe requests (`api/info`, `global/health`): the same connection pool + * and settings as [httpClient], but a short whole-call timeout. + * + * Both answer in milliseconds from any healthy server. `opencode serve` (1.18.5, 1.19.3) accepts + * connections a few hundred milliseconds before it attaches its request handler, and Node drops + * a request that arrives on such a connection without ever answering it. The local launcher now + * waits for a real HTTP answer before reporting Ready (see defaultServerAnswersHttp), but a + * remote or restarted server can still hit that window, and a probe stuck there used to hold the + * agent picker for the shared 120 s read timeout. A probe that has not answered in a few seconds + * is retried on a fresh call instead. + */ + private val probeClient: OkHttpClient = + httpClient.newBuilder() + .callTimeout(PROBE_CALL_TIMEOUT_SECONDS, TimeUnit.SECONDS) + .build() + private val detectedState = MutableStateFlow(null) /** Serialises probes so a slower, older probe cannot overwrite the result of a newer one. */ @@ -367,8 +386,17 @@ class ProtocolDetectingOpenCodeApi( } } .build() - httpClient.newCall(request).execute().use { response -> - return ProbeResponse(response.code, response.body?.string().orEmpty()) + var attempt = 0 + while (true) { + try { + probeClient.newCall(request).execute().use { response -> + return ProbeResponse(response.code, response.body?.string().orEmpty()) + } + } catch (timeout: InterruptedIOException) { + // A call timeout, not a refused or reset connection: try once more on a new call + // before giving up, which surfaces as the usual transient probe failure. + if (++attempt > PROBE_TIMEOUT_RETRIES) throw timeout + } } } @@ -399,6 +427,12 @@ class ProtocolDetectingOpenCodeApi( private companion object { const val UNAUTHORIZED_TAG = "UnauthorizedError" + /** Whole-call limit for one probe request; see [probeClient]. */ + const val PROBE_CALL_TIMEOUT_SECONDS = 5L + + /** Extra attempts after a probe times out, each on a fresh call. */ + const val PROBE_TIMEOUT_RETRIES = 1 + /** Strict parsing, so an HTML page is never accepted as JSON by the lenient default. */ val probeJson: Json = Json { ignoreUnknownKeys = true } } diff --git a/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt b/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt index 4681368ae..453c11d16 100644 --- a/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt +++ b/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt @@ -1,11 +1,20 @@ package com.yugahashimoto.andcode.runtime.local import java.io.File +import java.net.InetSocketAddress +import java.net.Socket import java.util.concurrent.TimeUnit class LocalRuntimeProcessLauncher( private val runtimeDirectory: File, private val portProbe: (Int) -> Boolean, + /** + * Whether a just-started server answers HTTP on the port; startup waits for this, not for + * [portProbe]. `opencode serve` accepts connections a few hundred milliseconds before it can + * serve them, and a request sent on a connection accepted in that window is never answered, so + * an open port is not yet a ready server. See [defaultServerAnswersHttp]. + */ + private val serverReady: (Int) -> Boolean = ::defaultServerAnswersHttp, private val nowMillis: () -> Long = System::currentTimeMillis, private val procRoot: File = File("/proc"), private val processSignal: (Long) -> Unit = { pid -> @@ -206,7 +215,7 @@ class LocalRuntimeProcessLauncher( if (!process.isAlive) { error("Local OpenCode exited during startup: ${tail(logFile)}") } - if (portProbe(port)) return + if (serverReady(port)) return Thread.sleep(250) } process.destroyForcibly() @@ -378,3 +387,42 @@ internal fun localRuntimeEnvironment( private const val AND_CODE_OPENCODE_CONFIG_CONTENT = "{\"instructions\":[\"/root/.config/opencode/and-code-context.md\"," + "\"/root/.config/opencode/and-code-system-prompt.md\"]}" + +/** + * Whether the server on [port] answers an HTTP request, judged by any status line coming back. + * + * `opencode serve` (seen on 1.18.5 and 1.19.3) accepts TCP connections a few hundred milliseconds + * before it prints "listening", and a request sent on a connection accepted in that window is never + * answered - not even after minutes - while the same request on a connection opened moments later + * is served in milliseconds. A plain connect therefore declared the server ready too early, and the + * app's first request (the protocol probe) hung until its 120 s read timeout on many cold starts. + * + * Any status line counts, 401 included: authentication is not the question here. The request is + * sent on its own short-lived connection with a short read timeout, so a connection lost to that + * startup window costs one attempt and the next attempt uses a fresh one. + */ +internal fun defaultServerAnswersHttp(port: Int): Boolean = + runCatching { + Socket().use { socket -> + socket.connect(InetSocketAddress(LOOPBACK, port), READINESS_CONNECT_TIMEOUT_MILLIS) + socket.soTimeout = READINESS_READ_TIMEOUT_MILLIS + socket.getOutputStream().apply { + write("GET /global/health HTTP/1.1\r\nHost: $LOOPBACK\r\nConnection: close\r\n\r\n".toByteArray()) + flush() + } + val head = ByteArray(HTTP_STATUS_PREFIX.length) + var read = 0 + val input = socket.getInputStream() + while (read < head.size) { + val n = input.read(head, read, head.size - read) + if (n < 0) break + read += n + } + read == head.size && String(head, Charsets.US_ASCII) == HTTP_STATUS_PREFIX + } + }.getOrDefault(false) + +private const val LOOPBACK = "127.0.0.1" +private const val HTTP_STATUS_PREFIX = "HTTP/1." +private const val READINESS_CONNECT_TIMEOUT_MILLIS = 1_000 +private const val READINESS_READ_TIMEOUT_MILLIS = 1_000 diff --git a/app/src/test/java/com/yugahashimoto/andcode/core/api/OpenCodeV2ApiClientTest.kt b/app/src/test/java/com/yugahashimoto/andcode/core/api/OpenCodeV2ApiClientTest.kt index af68371f5..6c1b2499c 100644 --- a/app/src/test/java/com/yugahashimoto/andcode/core/api/OpenCodeV2ApiClientTest.kt +++ b/app/src/test/java/com/yugahashimoto/andcode/core/api/OpenCodeV2ApiClientTest.kt @@ -20,6 +20,7 @@ import okhttp3.Credentials import okhttp3.OkHttpClient import okhttp3.mockwebserver.MockResponse import okhttp3.mockwebserver.MockWebServer +import okhttp3.mockwebserver.SocketPolicy import org.junit.After import org.junit.Assert.assertEquals import org.junit.Assert.assertFalse @@ -86,6 +87,25 @@ class OpenCodeV2ApiClientTest { assertEquals(Credentials.basic("opencode", "secret"), request.getHeader("Authorization")) } + @Test + fun `a probe that gets no answer is retried well before the shared read timeout`() = + runBlocking { + // The first api/info sits on a connection that never answers, as seen on a phone right + // after its local server started. The retry on a fresh call gets the real answer. + server.enqueue(MockResponse().setSocketPolicy(SocketPolicy.NO_RESPONSE)) + server.enqueue(json(V2_INFO)) + val detector = ProtocolDetectingOpenCodeApi(profile()) + + val started = System.nanoTime() + val health = detector.health() + val elapsedSeconds = (System.nanoTime() - started) / 1_000_000_000.0 + + assertEquals("2.0.28", health.version) + assertEquals(OpenCodeProtocol.V2, detector.protocol) + assertTrue("probe took ${elapsedSeconds}s", elapsedSeconds < 15.0) + assertEquals(2, server.requestCount) + } + @Test fun `probe treats a V2 401 JSON body as V2 and surfaces a 401`() = runBlocking { diff --git a/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt b/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt index 3e4de7808..a1ded92a4 100644 --- a/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt +++ b/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt @@ -8,6 +8,9 @@ import org.junit.Rule import org.junit.Test import org.junit.rules.TemporaryFolder import java.io.File +import java.net.InetAddress +import java.net.ServerSocket +import java.net.Socket class LocalRuntimeProcessLauncherTest { @get:Rule @@ -523,4 +526,42 @@ class LocalRuntimeProcessLauncherTest { remaining.contains("19$line") || remaining.contains("18$line"), ) } + + @Test + fun `an accepting port that never answers is not a ready server`() { + // What `opencode serve` does for the first few hundred milliseconds: the kernel accepts the + // connection, but nothing ever reads the request or replies. + ServerSocket(0, 1, InetAddress.getLoopbackAddress()).use { listener -> + val accepted = mutableListOf() + val acceptor = Thread { runCatching { while (true) accepted += listener.accept() } }.apply { isDaemon = true } + acceptor.start() + + val started = System.nanoTime() + assertFalse(defaultServerAnswersHttp(listener.localPort)) + assertTrue("readiness check must give up quickly", System.nanoTime() - started < 5_000_000_000L) + accepted.forEach(Socket::close) + } + } + + @Test + fun `any HTTP status line counts as ready, including 401`() { + ServerSocket(0, 1, InetAddress.getLoopbackAddress()).use { listener -> + Thread { + runCatching { + listener.accept().use { client -> + client.getInputStream().read(ByteArray(512)) + client.getOutputStream().write("HTTP/1.1 401 Unauthorized\r\nContent-Length: 0\r\n\r\n".toByteArray()) + } + } + }.apply { isDaemon = true }.start() + + assertTrue(defaultServerAnswersHttp(listener.localPort)) + } + } + + @Test + fun `a closed port is not ready`() { + val port = ServerSocket(0, 1, InetAddress.getLoopbackAddress()).use { it.localPort } + assertFalse(defaultServerAnswersHttp(port)) + } } From d84effe4796b9372e73a9d07c65138038b56ee56 Mon Sep 17 00:00:00 2001 From: lcy Date: Sun, 18 Oct 2026 10:10:16 +0800 Subject: [PATCH 2/2] fix(runtime): keep a live listening server at the readiness deadline, give the probe retry 20 s Per review: - at the 30 s startup deadline, a server that is alive and accepting connections is kept (the old connect-only verdict) instead of being killed, so a loaded device that is slow to answer HTTP does not turn into a failed start - the protocol probe's retry gets a 20 s call timeout, so a remote host that is slow on its first request (tunnel, waking up) still connects - test: thread-safe list for accepted sockets --- .../core/api/ProtocolDetectingOpenCodeApi.kt | 15 ++++++++++++++- .../runtime/local/LocalRuntimeProcessLauncher.kt | 6 ++++++ .../local/LocalRuntimeProcessLauncherTest.kt | 2 +- 3 files changed, 21 insertions(+), 2 deletions(-) diff --git a/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt b/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt index a7ac4c75e..1feec64f4 100644 --- a/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt +++ b/app/src/main/java/com/yugahashimoto/andcode/core/api/ProtocolDetectingOpenCodeApi.kt @@ -65,6 +65,15 @@ class ProtocolDetectingOpenCodeApi( .callTimeout(PROBE_CALL_TIMEOUT_SECONDS, TimeUnit.SECONDS) .build() + /** + * The retry gets longer: a remote host behind a tunnel, or one that is waking up, can be slow to + * answer its first request, and it must not fail where the shared client used to succeed. + */ + private val probeRetryClient: OkHttpClient = + httpClient.newBuilder() + .callTimeout(PROBE_RETRY_CALL_TIMEOUT_SECONDS, TimeUnit.SECONDS) + .build() + private val detectedState = MutableStateFlow(null) /** Serialises probes so a slower, older probe cannot overwrite the result of a newer one. */ @@ -389,7 +398,8 @@ class ProtocolDetectingOpenCodeApi( var attempt = 0 while (true) { try { - probeClient.newCall(request).execute().use { response -> + val client = if (attempt == 0) probeClient else probeRetryClient + client.newCall(request).execute().use { response -> return ProbeResponse(response.code, response.body?.string().orEmpty()) } } catch (timeout: InterruptedIOException) { @@ -430,6 +440,9 @@ class ProtocolDetectingOpenCodeApi( /** Whole-call limit for one probe request; see [probeClient]. */ const val PROBE_CALL_TIMEOUT_SECONDS = 5L + /** Whole-call limit for the retry after a probe timed out; see [probeRetryClient]. */ + const val PROBE_RETRY_CALL_TIMEOUT_SECONDS = 20L + /** Extra attempts after a probe times out, each on a fresh call. */ const val PROBE_TIMEOUT_RETRIES = 1 diff --git a/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt b/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt index 453c11d16..606002d83 100644 --- a/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt +++ b/app/src/main/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncher.kt @@ -211,6 +211,8 @@ class LocalRuntimeProcessLauncher( logFile: File, ) { val deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(30) + // Each attempt can take up to ~2 s (connect + read), so the last one may end slightly after + // the deadline. while (System.nanoTime() < deadline) { if (!process.isAlive) { error("Local OpenCode exited during startup: ${tail(logFile)}") @@ -218,6 +220,10 @@ class LocalRuntimeProcessLauncher( if (serverReady(port)) return Thread.sleep(250) } + // A loaded device can be slow to answer HTTP even once the server is up. Stopping a live, + // listening server here would turn that into a failed start, so it keeps the old, + // connect-only verdict as the last word; the protocol probe's own timeout covers the rest. + if (process.isAlive && portProbe(port)) return process.destroyForcibly() process.waitFor(2, TimeUnit.SECONDS) runCatching { process.outputStream.close() } diff --git a/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt b/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt index a1ded92a4..b95dc1825 100644 --- a/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt +++ b/app/src/test/java/com/yugahashimoto/andcode/runtime/local/LocalRuntimeProcessLauncherTest.kt @@ -532,7 +532,7 @@ class LocalRuntimeProcessLauncherTest { // What `opencode serve` does for the first few hundred milliseconds: the kernel accepts the // connection, but nothing ever reads the request or replies. ServerSocket(0, 1, InetAddress.getLoopbackAddress()).use { listener -> - val accepted = mutableListOf() + val accepted = java.util.concurrent.CopyOnWriteArrayList() val acceptor = Thread { runCatching { while (true) accepted += listener.accept() } }.apply { isDaemon = true } acceptor.start()