diff --git a/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt b/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt index a978a8f286..ee4577c553 100644 --- a/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt +++ b/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt @@ -108,6 +108,9 @@ internal fun joinChunks(chunks: List): ByteArray { class WebServer( private val config: ServerConfig, + // Seam for the accept-retry tests, which drive thousands of simulated failures and must not + // actually sleep for them. Production always gets Thread.sleep. + internal val sleepMs: (Long) -> Unit = { Thread.sleep(it) }, ) { // Guards serverSocket's creation/bind (in start(), on a background thread) against a // concurrent close (in stop(), typically from the main thread on Activity#onDestroy()). @@ -116,6 +119,16 @@ class WebServer( // socket then binds anyway a moment later, orphaned, and holds the port until the process // dies. The next start() attempt on that port then fails with "Address already in use." private val lifecycleLock = Any() + + // @Volatile: written under lifecycleLock by stop(), but read by the accept loop without it -- + // see acceptLoop, which has to see a stop that happened on another thread. + // + // Never cleared, deliberately: a stop that arrives before the socket is bound has to keep + // start() from binding an orphaned listener, so this is one-way and a stopped instance is + // finished. Restarting means a new WebServer, which is what MainActivity.startWebServer does + // -- it constructs one per start. stop() then start() on the same instance is not a recovery + // path and never was. + @Volatile private var stopRequested = false private lateinit var serverSocket: ServerSocket private lateinit var database: SQLiteDatabase @@ -158,6 +171,24 @@ class WebServer( .create() private val dbContextType = object : TypeToken>() {}.type private var bookshelfTemplateId: Int = -1 + + // Long enough to stop a descriptor-exhaustion spin starving the connections whose closing would + // fix it; short enough to be invisible to a user, and never paid on a successful accept. + private val initialAcceptBackoffMs = 50L + + // Doubling from 50 ms, the interval reaches this in eight failures, so a failure that persists + // costs well under a line a second instead of twenty. That is what bounds the log volume; an + // earlier version capped the retries instead and gave up after twenty, which closed the listener + // and the database and left documentation dead for the rest of the process -- the ADFA-5242 + // symptom, delayed by a second. A listener that cannot accept now keeps trying: the descriptor + // pressure that causes this comes from the rest of the process (Gradle, Termux, the editor) and + // clears on its own timescale, not ours. + private val maxAcceptBackoffMs = 2_000L + + // Retries between heartbeat lines once the interval stops growing: 15 x 2 s is one line every + // 30 seconds while a failure persists. + private val acceptHeartbeatRetries = 15L + private val httpInternalServerError = 500 private val httpNotFound = 404 @@ -358,6 +389,151 @@ class WebServer( } } + /** + * Accepts connections on [socket] until it closes. + * + * Extracted from [start] so ADFA-5242's retry path can be driven by a socket whose accept() + * fails: the rest of start() needs a live Android runtime -- TrafficStats, SQLite -- and this + * loop needs neither. The bug it fixes was invisible precisely because nothing could reach here. + */ + internal fun acceptLoop(socket: ServerSocket) { + // 0 means accept() has been succeeding; any other value is the interval the next retry waits. + var backoffMs = 0L + // Retries spent at the ceiling, so a failure that never clears keeps saying so. Without this + // the escalation log went silent for good once the interval stopped changing. + var retriesAtCeiling = 0L + // Checked in the loop head, not only in the catch: stop() logs and swallows a throwing + // serverSocket.close(), which leaves closed == false, so accept() kept succeeding and the loop + // served on past a requested shutdown, holding the database open (ADFA-5242 review). + while (!shouldStopAccepting(socket)) { + val client = + try { + if (debugEnabled) log.debug("About to call accept() on the server socket, {}.", socket) + socket.accept().also { + // Halved, not zeroed. Zeroing made every failure "the first of a burst", so an + // intermittent one -- a client that RSTs between SYN and accept(), which a WebView + // cancelling a request produces routinely -- logged a full stack trace and stalled + // the listener 50 ms every single time. That is the flood the backoff exists to + // stop. Decaying means a flapping listener keeps most of its interval and a + // genuinely recovered one is back to zero within a few accepts. + backoffMs = if (backoffMs <= initialAcceptBackoffMs) 0L else backoffMs / 2 + // Reset on every success, not only once the interval reaches zero. The counter + // means "consecutive retries at the ceiling", and an accept that succeeds ends + // that run whatever the interval still is. Clearing it only at zero left a stale + // count behind: at the ceiling with 14 retries banked, one success then a return + // to the ceiling fired the heartbeat on the next retry instead of the fifteenth. + retriesAtCeiling = 0L + if (debugEnabled) log.debug("Returned from accept(), clientSocket is {}.", it) + } + } catch (e: IOException) { + // IOException, not SocketException: accept() is declared to throw the wider type, and + // "Too many open files" arrives as a bare IOException. Catching only the subtype let + // that one unwind to start()'s outermost handler, whose finally closes the listening + // socket and the database (ADFA-5242). + if (debugEnabled) log.debug("Caught IOException from accept().", e) + + if (shouldStopAccepting(socket)) { + if (debugEnabled) log.debug("WebServer socket closed, shutting down.") + break + } + + val previous = backoffMs + backoffMs = + if (previous == 0L) { + initialAcceptBackoffMs + } else { + minOf(previous * 2, maxAcceptBackoffMs) + } + // The stack trace goes out once per burst, on the first failure. Repeats say only + // that it is still failing, and only when the interval changes: nineteen identical + // traces told nobody anything the first one had not. They do carry e.toString() + // rather than e.message, so the type is still there -- a burst can change cause + // mid-flight (EMFILE giving way to ECONNABORTED), and message alone is null for + // some IOExceptions, which logged a bare "null". + if (previous == 0L) { + log.error("Accept() failed, retrying in {} ms: {}", backoffMs, e.message, e) + retriesAtCeiling = 0L + } else if (backoffMs != previous) { + log.error("Accept() still failing, backing off to {} ms: {}", backoffMs, e.toString()) + } else { + // At the ceiling the interval stops changing, so neither branch above fires again. + // A heartbeat roughly every 30 s keeps a permanent failure visible without + // returning to a line per retry -- the loop never gives up, so the log must not + // either. + retriesAtCeiling++ + if (retriesAtCeiling % acceptHeartbeatRetries == 0L) { + log.error( + "Accept() still failing after {} retries at {} ms: {}", + retriesAtCeiling, + backoffMs, + e.toString(), + ) + } + } + + if (!pauseAfterFailedAccept(backoffMs)) { + log.info("Accept loop interrupted while backing off; shutting down.") + break + } + continue + } + + // A client cannot be allowed to end the loop: anything escaping here reaches start()'s + // handler, whose finally closes the listener and the database for everyone. + // + // Throwable, not Exception. joinChunks allocates the whole row in one array (1 MB per + // chunk) and Pebble renders recursively, so one large row can raise OutOfMemoryError and a + // pathological template a StackOverflowError -- neither an Exception, both fatal to the + // listener through exactly the path this ticket exists to close. + try { + serveThenClose(client) + } catch (e: Throwable) { + log.error("Serving a client threw past its own handler; the listener stays up: {}", e.message, e) + } + } + } + + /** Serves one connection and closes it, whatever happened. */ + private fun serveThenClose(client: Socket) { + try { + handleClient(client) + } catch (e: Exception) { + reportClientFailure(client, e) + } finally { + // close() is declared to throw, and a client that reset mid-response makes it do so. That + // exception used to leave this function -- from a finally, so it replaced any in-flight one + // -- and unwound past the accept loop into start(), taking the listener and the database + // down with it. "Whatever happened" includes this. + try { + client.close() + } catch (e: IOException) { + if (debugEnabled) log.debug("Cannot close the client socket; it is being discarded anyway.", e) + } + if (debugEnabled) log.debug("clientSocket was {}.", client) + } + } + + /** A client that went wrong: a disconnect is unremarkable, anything else earns a 500 if it can. */ + private fun reportClientFailure( + client: Socket, + e: Exception, + ) { + if (debugEnabled) log.debug("Caught exception while handling a client.", e) + + if (e is java.net.SocketException && e.message?.contains("Closed", ignoreCase = true) == true) { + if (debugEnabled) log.debug("Client disconnected: {}", e.message) + return + } + log.error("Error handling client: {}", e.message, e) + try { + val output = client.outputStream + + sendError(PrintWriter(output, true), output, httpInternalServerError, "Internal Server Error 1") + } catch (e2: Exception) { + log.error("Error sending error response: {}", e2.message, e2) + } + } + fun start() { // Hal Eisen: Required to fix StrictMode.VmPolicy.Builder.detectUntaggedSockets() TrafficStats.setThreadStatsTag(0xC0DE) @@ -394,58 +570,19 @@ class WebServer( } log.info("WebServer started successfully on '{}', port {}.", config.bindName, config.port) - while (true) { - var clientSocket: Socket? = null - try { - try { - if (debugEnabled) log.debug("About to call accept() on the server socket, {}.", serverSocket) - clientSocket = serverSocket.accept() - - if (debugEnabled) log.debug("Returned from socket accept(), clientSocket is {}.", clientSocket) - } catch (e: java.net.SocketException) { - // SLF4J placeholders produce wrong formatting here. --DS, 23-Feb-2026 - if (debugEnabled) log.debug("Caught java.net.SocketException '$e'.") - - if (e.message?.contains("Closed", ignoreCase = true) == true) { - if (debugEnabled) log.debug("WebServer socket closed, shutting down.") - break - } - log.error("Accept() failed: {}", e.message) - continue - } - try { - clientSocket?.let { handleClient(it) } - } catch (e: Exception) { - // SLF4J placeholders produce wrong formatting here. --DS, 23-Feb-2026 - if (debugEnabled) log.debug("Caught exception '$e'.") - - if (e is java.net.SocketException && e.message?.contains("Closed", ignoreCase = true) == true) { - if (debugEnabled) log.debug("Client disconnected: {}", e.message) - } else { - log.error("Error handling client: {}", e.message) - clientSocket?.let { socket -> - try { - val output = socket.outputStream - - sendError(PrintWriter(output, true), output, httpInternalServerError, "Internal Server Error 1") - } catch (e2: Exception) { - log.error("Error sending error response: {}", e2.message) - } - } - } - } - } finally { - clientSocket?.close() - - // CodeRabbit objects to the following line because clientSocket may print out as "null." This is intentional. --DS - if (debugEnabled) log.debug("clientSocket was {}.", clientSocket) - } - } + acceptLoop(serverSocket) } catch (e: Exception) { - log.error("Error: {}", e.message) + log.error("WebServer stopped on an unhandled exception: {}", e.message, e) } finally { if (::serverSocket.isInitialized) { - serverSocket.close() + // Guarded for the same reason serveThenClose guards the client socket: close() is + // declared to throw, and a throw here skipped database.close() and the traffic-stats + // tag below, leaving the SQLite handle open for the life of the process. + try { + serverSocket.close() + } catch (e: IOException) { + log.error("Cannot close the server socket: {}", e.message, e) + } } // database is opened before the stopRequested check that can abort start() // early (and before the accept loop on every other exit path), so it must be @@ -462,6 +599,47 @@ class WebServer( } } + /** + * Whether an accept failure means the server is shutting down rather than having hit something + * transient. `ServerSocket.accept()` is declared to throw `IOException`, of which + * `SocketException` is one subtype, so only the listening socket closing ends the loop -- + * everything else, a `SocketTimeoutException` or a descriptor-exhaustion `IOException` included, + * is retried. Getting this wrong is bad in a different way each way round: treating a transient + * failure as terminal stops serving documentation until the app restarts, and treating the close + * as transient spins the loop against a dead socket. + * + * Decided from state, not from the exception's message, which would spin forever against a + * platform that worded a closed socket differently. [stopRequested] is what carries the decision: + * libcore's [ServerSocket.close] calls `impl.close()` *before* setting its closed flag, so + * accept() can unblock while [ServerSocket.isClosed] is still false, and [stop] sets + * [stopRequested] before closing for exactly that reason. `isClosed` is the belt to that braces + * -- it also covers a close that did not come through [stop] at all. + */ + internal fun shouldStopAccepting(socket: ServerSocket): Boolean = stopRequested || socket.isClosed + + /** + * Waits [delayMs] before the next accept() attempt, so a persistent failure cannot spin this loop + * at full tilt while it clears. Only the failure path ever waits. + * + * "Too many open files" is the realistic cause, and it is not this server's own doing: + * [handleClient] runs inline on this thread, so exactly one client socket is ever open and the + * listener holds two descriptors in total. The pressure comes from the rest of the process -- + * Gradle, Termux, the editor -- and clears on its timescale, which is why the interval escalates + * rather than the retries running out. + * + * Returns false if the wait was interrupted, which the caller must treat as shutdown: re-arming + * the flag and carrying on made every later sleep throw at once, turning the backoff into a hot + * spin -- the opposite of its purpose. + */ + private fun pauseAfterFailedAccept(delayMs: Long): Boolean = + try { + sleepMs(delayMs) + true + } catch (e: InterruptedException) { + Thread.currentThread().interrupt() + false + } + /** * Reads a single line from the stream (bytes until newline). Same stream is used for headers * and body so POST body bytes are not lost to a separate buffered reader. HTTP header lines are ASCII. diff --git a/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptFailureTest.kt b/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptFailureTest.kt new file mode 100644 index 0000000000..bccccfc943 --- /dev/null +++ b/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptFailureTest.kt @@ -0,0 +1,231 @@ +package com.itsaky.androidide.localWebServer + +import com.google.common.truth.Truth.assertThat +import org.junit.After +import org.junit.Test +import java.io.IOException +import java.net.ServerSocket +import java.net.Socket +import java.net.SocketException + +/** + * ADFA-5242: one failed accept() must not take documentation down for the rest of the session. + * + * `ServerSocket.accept()` is declared to throw `IOException`; `SocketException` is one subtype. The + * loop used to catch only that subtype, and the enclosing try had a finally but no catch, so any + * other `IOException` -- a descriptor-exhaustion "Too many open files", say -- unwound to + * `start()`'s outermost handler, whose finally closes the listening socket *and* the database. Every + * later request then failed until the app restarted, with one log line as the only trace. + * + * These drive the real loop through a socket whose accept() fails on demand. Stopping is decided + * from socket state rather than the exception's message, so the scripted socket closes itself when it + * means "stop" -- which is what a real `ServerSocket` does before accept() unblocks. + */ +class AcceptFailureTest { + // The interrupt test sets the thread's interrupt flag; clearing it only via that test's own + // assertion means a failure earlier in the test leaks the flag onto the JUnit worker, where the + // next test that blocks fails for reasons that have nothing to do with it. + @After + fun clearInterrupt() { + Thread.interrupted() + } + + // Every path is given explicitly: ServerConfig's defaults reach for external storage, which a + // JVM test has no stub for. + // Every delay the loop asked for, in order. Recording instead of sleeping keeps a test that drives + // hundreds of failures instant, and makes the backoff itself assertable. + private val delays = mutableListOf() + + private fun server(onSleep: (Long) -> Unit = {}) = + WebServer( + sleepMs = { + delays += it + onSleep(it) + }, + config = + ServerConfig( + port = 0, + databasePath = "/nonexistent/test.db", + fileDirPath = "/tmp", + debugDatabasePath = "/nonexistent/debug.db", + debugEnablePath = "/nonexistent/debug-flag", + experimentsEnablePath = "/nonexistent/exp-flag", + clearCacheEnablePath = "/nonexistent/cs0-flag", + projectDatabasePath = "/nonexistent/recent-projects.db", + ), + ) + + @Test + fun `a closed socket is what stops accepting`() { + val server = server() + ServerSocket().use { open -> + assertThat(server.shouldStopAccepting(open)).isFalse() + open.close() + assertThat(server.shouldStopAccepting(open)).isTrue() + } + } + + // stop() can arrive before start() has bound anything, so it records the intent and the loop has + // to honour it even while the socket it was handed is still open. + @Test + fun `a requested stop is honoured before the socket closes`() { + val server = server() + server.stop() + + ServerSocket().use { open -> + assertThat(server.shouldStopAccepting(open)).isTrue() + } + } + + @Test + fun `a closed socket ends the accept loop at once`() { + val socket = ScriptedServerSocket(failures = 0) + socket.use { server().acceptLoop(it) } + + assertThat(socket.acceptCalls).isEqualTo(1) + } + + @Test + fun `a retryable failure does not end the accept loop`() { + val socket = ScriptedServerSocket(failures = 2) + socket.use { server().acceptLoop(it) } + + // Three: two failures retried, then the close that ends it. One would mean the first failure + // escaped the loop -- the ADFA-5242 bug. + assertThat(socket.acceptCalls).isEqualTo(3) + } + + // A message is not evidence. An exception *saying* the socket closed, from a socket that is still + // open, is some other fault and gets retried like any other. + @Test + fun `a closed-sounding message from a live socket is retried`() { + val socket = ScriptedServerSocket(failures = 30, error = { SocketException("Socket closed") }) + socket.use { server().acceptLoop(it) } + + assertThat(socket.acceptCalls).isEqualTo(31) + } + + // Every IOException subtype is retried, not just the ones named in the original bug report: a + // SocketTimeoutException reaching start()'s handler would have killed the server just as surely. + @Test + fun `a transient failure is retried whatever its type`() { + val socket = + ScriptedServerSocket(failures = 5, error = { java.net.SocketTimeoutException("Accept timed out") }) + socket.use { server().acceptLoop(it) } + + assertThat(socket.acceptCalls).isEqualTo(6) + } + + // The loop used to give up after twenty consecutive failures, which returned to start(), whose + // finally closes the listening socket *and* the database -- documentation dead for the rest of the + // process. That is the ADFA-5242 symptom the retry exists to prevent, so there is no giving up: + // only the socket closing ends the loop. + @Test + fun `a persistent failure is retried past any cap, until the socket closes`() { + val socket = ScriptedServerSocket(failures = 500) + socket.use { server().acceptLoop(it) } + + assertThat(socket.acceptCalls).isEqualTo(501) + } + + // What bounds the cost of a persistent failure is the interval, not a cap on attempts. + @Test + fun `the retry interval doubles from 50 ms and stops at 2 seconds`() { + val socket = ScriptedServerSocket(failures = 20) + socket.use { server().acceptLoop(it) } + + assertThat(delays.take(7)).containsExactly(50L, 100L, 200L, 400L, 800L, 1600L, 2000L).inOrder() + assertThat(delays.distinct().max()).isEqualTo(2000L) + } + + // A success halves the interval rather than zeroing it. + // + // This asserted a reset to 50 ms until the review pointed out what that costs: a listener that + // fails intermittently -- a client RSTing between SYN and accept(), which a WebView cancelling a + // documentation request produces routinely -- was treated as "first failure of a burst" every + // time, so every occurrence logged a full stack trace and stalled the listener 50 ms. Decay keeps + // most of the interval while a listener is flapping, and still returns to zero within a few clean + // accepts once it has genuinely recovered. + @Test + fun `a success decays the retry interval instead of clearing it`() { + val socket = ScriptedServerSocket(failures = 12, succeedAt = setOf(5)) + socket.use { server().acceptLoop(it) } + + // Four failures walk 50..400; the success halves 400 to 200, so the next failure doubles to 400. + assertThat(delays.take(4)).containsExactly(50L, 100L, 200L, 400L).inOrder() + assertThat(delays[4]).isEqualTo(400L) + } + + // Recovery still gets all the way back to zero, so a later isolated failure starts cheap. + @Test + fun `enough clean accepts return the interval to its starting point`() { + val socket = ScriptedServerSocket(failures = 20, succeedAt = setOf(2, 3, 4, 5)) + socket.use { server().acceptLoop(it) } + + // One failure (50), then four successes decay 50 -> 0, so the next failure starts at 50 again. + assertThat(delays.take(1)).containsExactly(50L) + assertThat(delays[1]).isEqualTo(50L) + } + + // Re-arming the interrupt flag and carrying on made every later sleep throw immediately, so the + // backoff became a hot spin -- the opposite of its purpose. An interrupt ends the loop. + @Test + fun `an interrupt ends the accept loop instead of spinning`() { + val socket = ScriptedServerSocket(failures = 500) + socket.use { server(onSleep = { throw InterruptedException("shutting down") }).acceptLoop(it) } + + assertThat(socket.acceptCalls).isEqualTo(1) + assertThat(Thread.interrupted()).isTrue() + } + + // Socket.close() is declared to throw and a reset client makes it do so. It ran in a finally, so + // the exception replaced whatever was in flight and unwound past this loop into start(), whose + // own finally closes the listener and the database -- one bad client killing documentation for + // the session, by the same route as the accept failure this ticket is about. + @Test + fun `a client whose close fails does not end the accept loop`() { + val socket = + ScriptedServerSocket( + failures = 1, + succeedAt = setOf(1), + client = { + object : Socket() { + override fun close() = throw IOException("Broken pipe") + } + }, + ) + socket.use { server().acceptLoop(it) } + + // Two: the client whose close() threw, then the close that ends the loop. One would mean the + // throw escaped. + assertThat(socket.acceptCalls).isEqualTo(2) + } + + /** + * Fails accept() [failures] times, then closes itself and reports it. + * + * Closing before throwing is what makes [WebServer.shouldStopAccepting]'s `isClosed` arm fire + * here. A real libcore [ServerSocket.close] is the other way round -- `impl.close()` runs before + * the closed flag is set, so accept() can unblock while `isClosed()` is still false -- which is + * why the production path leans on `stopRequested`, set by [WebServer.stop] before it closes. + */ + private class ScriptedServerSocket( + private val failures: Int, + private val succeedAt: Set = emptySet(), + private val error: () -> IOException = { IOException("Too many open files") }, + private val client: () -> Socket = { Socket() }, + ) : ServerSocket() { + var acceptCalls = 0 + private set + + override fun accept(): Socket { + acceptCalls++ + // A returned socket would send the loop into handleClient, which needs a database; the + // loop only needs one to hand on, so an unconnected one counts as a success. + if (acceptCalls in succeedAt) return client() + if (acceptCalls <= failures) throw error() + close() + throw SocketException("Socket closed") + } + } +}