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 43572518..1feec64f 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,32 @@ 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() + + /** + * 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. */ @@ -367,8 +395,18 @@ class ProtocolDetectingOpenCodeApi( } } .build() - httpClient.newCall(request).execute().use { response -> - return ProbeResponse(response.code, response.body?.string().orEmpty()) + var attempt = 0 + while (true) { + try { + 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) { + // 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 +437,15 @@ 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 + + /** 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 + /** 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 4681368a..606002d8 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 -> @@ -202,13 +211,19 @@ 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)}") } - if (portProbe(port)) return + 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() } @@ -378,3 +393,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 af68371f..6c1b2499 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 3e4de780..b95dc182 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 = java.util.concurrent.CopyOnWriteArrayList() + 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)) + } }