From 0afe8074f0885d8315bceaa54c5595c76c45ad67 Mon Sep 17 00:00:00 2001 From: David Schachter Date: Mon, 17 Aug 2026 21:56:45 -0700 Subject: [PATCH 1/3] ADFA-5172: Instrument the accept loop to locate the periodic 1 s stall The local WebServer stalls ~1.02 s about every 2 s under sustained load, and a client-side measurement cannot say whether the loop was waiting in accept() or busy elsewhere -- the ticket's first diagnostic. Time each accept-loop iteration in two parts, parked in accept() versus busy outside it, and time the per-request stat of the sdcard debug database, which is FUSE-backed emulated storage and is the leading suspect for a slow iteration delaying the next accept. One warn line is logged per iteration that crosses ServerConfig.stallThresholdMs (200 ms by default), carrying the previous iteration's split so a stall can be attributed to the loop or exonerated. Kept independent of the webserver.debug sentinel on purpose: its ~10 log lines per request perturb the timing being measured, and the ticket's next step is to re-run with the sentinel removed. A long park in accept() is normal on an idle server, so it is reported only when the previous park was short -- i.e. during the sustained load where the stall lives, not when a user simply stopped browsing. --- .../androidide/localWebServer/WebServer.kt | 65 +++++++++++++++++++ 1 file changed, 65 insertions(+) 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 0b76b64d2d..503d632898 100644 --- a/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt +++ b/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt @@ -52,6 +52,8 @@ data class ServerConfig( "/Download/CodeOnTheGo.webserver.cs0", // Yes, this is hack code. val projectDatabasePath: String = "/data/data/com.itsaky.androidide/databases/RecentProject_database", + // ADFA-5172: accept-loop iterations slower than this get one diagnostic log line. + val stallThresholdMs: Long = 200, ) data class JavaExecutionResult( @@ -100,6 +102,12 @@ class WebServer( private val contentChunkSize = 1024 * 1024 + private val stallThresholdNanos = TimeUnit.MILLISECONDS.toNanos(config.stallThresholdMs) + + // How long handleClient()'s last stat of config.debugDatabasePath took. A plain var is safe: + // the accept loop is serial and single-threaded, and it is the only reader. + private var debugDbStatNanos = 0L + // function to obtain the last modified date of a documentation.db database // this is used to see if there is a newer version of the database on the sdcard fun getDatabaseTimestamp( @@ -187,12 +195,23 @@ class WebServer( } log.info("WebServer started successfully on '{}', port {}.", config.bindName, config.port) + // ADFA-5172: carried across iterations so a stall report can say whether the loop was + // even in accept() when the connection arrived. + var previousAcceptWaitNanos = 0L + var previousBusyNanos = 0L + while (true) { var clientSocket: Socket? = null + var acceptWaitNanos = 0L + var busyStartNanos = 0L + debugDbStatNanos = 0L try { try { if (debugEnabled) log.debug("About to call accept() on the server socket, {}.", serverSocket) + val acceptStartNanos = System.nanoTime() clientSocket = serverSocket.accept() + busyStartNanos = System.nanoTime() + acceptWaitNanos = busyStartNanos - acceptStartNanos if (debugEnabled) log.debug("Returned from socket accept(), clientSocket is {}.", clientSocket) } catch (e: java.net.SocketException) { @@ -232,6 +251,14 @@ class WebServer( // CodeRabbit objects to the following line because clientSocket may print out as "null." This is intentional. --DS if (debugEnabled) log.debug("clientSocket was {}.", clientSocket) + + // Zero when accept() threw, which leaves nothing to time. + if (busyStartNanos != 0L) { + val busyNanos = System.nanoTime() - busyStartNanos + reportStall(acceptWaitNanos, busyNanos, previousAcceptWaitNanos, previousBusyNanos) + previousAcceptWaitNanos = acceptWaitNanos + previousBusyNanos = busyNanos + } } } } catch (e: Exception) { @@ -255,6 +282,41 @@ class WebServer( } } + /** + * Logs one line per accept-loop iteration that crosses [ServerConfig.stallThresholdMs], for + * ADFA-5172's periodic ~1 s stall. Splits "parked in accept()" from "busy outside it" because + * that is what separates a stall the loop caused -- a slow iteration delays the next accept, + * so an arriving SYN can be dropped and retried ~1 s later -- from one it merely suffered. + * Deliberately independent of [debugEnabled], whose ~10 log lines per request perturb the + * timing being measured. + */ + private fun reportStall( + acceptWaitNanos: Long, + busyNanos: Long, + previousAcceptWaitNanos: Long, + previousBusyNanos: Long, + ) { + // A long wait in accept() is just an idle server, so report only the first one after a busy + // stretch: that is the periodic stall, not a user who stopped browsing the documentation. + val stalledBeforeAccept = + acceptWaitNanos >= stallThresholdNanos && previousAcceptWaitNanos < stallThresholdNanos + val stalledWhileBusy = busyNanos >= stallThresholdNanos || debugDbStatNanos >= stallThresholdNanos + if (!stalledBeforeAccept && !stalledWhileBusy) return + + log.warn( + "Accept-loop stall: {} ms parked in accept(), then {} ms busy outside it, of which {} ms " + + "stat'ing '{}'. Previous iteration: {} ms parked, {} ms busy.", + millis(acceptWaitNanos), + millis(busyNanos), + millis(debugDbStatNanos), + config.debugDatabasePath, + millis(previousAcceptWaitNanos), + millis(previousBusyNanos), + ) + } + + private fun millis(nanos: Long): Long = TimeUnit.NANOSECONDS.toMillis(nanos) + /** * 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. @@ -331,7 +393,10 @@ class WebServer( // check to see if there is a newer version of the documentation.db database on the sdcard // if there is use that for our responses + // Timed for ADFA-5172: this stats FUSE-backed emulated storage on every request. + val statStartNanos = System.nanoTime() val debugDatabaseTimestamp = getDatabaseTimestamp(config.debugDatabasePath, true) + debugDbStatNanos = System.nanoTime() - statStartNanos if (debugDatabaseTimestamp > databaseTimestamp) { bookshelfTemplateId = -1 database.close() From 3968a4ba0dd074068090658b7194121c654caa8d Mon Sep 17 00:00:00 2001 From: David Schachter Date: Tue, 18 Aug 2026 05:11:17 -0700 Subject: [PATCH 2/3] ADFA-5172: Stop reporting an idle wait in accept() as a stall Review found two false positives in the accept-wait half of the report, and both were real: the carried previous-wait started at zero, which reads as an iteration that was served instantly, so the first request after startup was always reported -- on the device it logged "74552 ms parked in accept()" for exactly that reason -- and a long wait after any genuine pause looked the same. The wait now has to look like what ADFA-5172 is about: at least the threshold, no more than 10 s (Linux retransmits a SYN at 1 s, 3 s and 7 s, so past that it is nobody browsing), and preceded by an iteration that was served promptly. A sentinel distinguishes "no iteration has finished yet" from one that waited 0 ms. The decision moved into shouldReportAcceptWait() so it is testable, and it now has tests: the stall itself, each false positive that prompted this, the retransmission ladder, an ordinary wait, and the degenerate threshold. A negative stallThresholdMs is clamped to zero rather than reported as an error -- it is a diagnostic knob, and a nonsense value should not throw. Zero has a quirk worth knowing, so it is documented and tested rather than engineered around: it reports every iteration's serving time, but silences the accept-wait half, whose "the last iteration was served promptly" test cannot hold when the threshold is zero. --- .../androidide/localWebServer/WebServer.kt | 37 +++++++-- .../localWebServer/AcceptWaitReportingTest.kt | 78 +++++++++++++++++++ 2 files changed, 108 insertions(+), 7 deletions(-) create mode 100644 app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt 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 503d632898..2a3d3325f5 100644 --- a/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt +++ b/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt @@ -52,7 +52,9 @@ data class ServerConfig( "/Download/CodeOnTheGo.webserver.cs0", // Yes, this is hack code. val projectDatabasePath: String = "/data/data/com.itsaky.androidide/databases/RecentProject_database", - // ADFA-5172: accept-loop iterations slower than this get one diagnostic log line. + // ADFA-5172: accept-loop iterations slower than this get one diagnostic log line. Zero reports + // every iteration's serving time (and silences the accept-wait half, whose "the last iteration + // was served promptly" test cannot hold at zero); a negative value is clamped to zero. val stallThresholdMs: Long = 200, ) @@ -102,7 +104,14 @@ class WebServer( private val contentChunkSize = 1024 * 1024 - private val stallThresholdNanos = TimeUnit.MILLISECONDS.toNanos(config.stallThresholdMs) + // Sentinel for "no iteration has finished yet", distinct from an iteration that waited 0 ms. + private val noPreviousIteration = -1L + + private val stallThresholdNanos = TimeUnit.MILLISECONDS.toNanos(config.stallThresholdMs.coerceAtLeast(0)) + + // A park longer than this is an idle server, not a lost handshake: Linux's SYN retransmission + // ladder is 1 s, 3 s, 7 s, so anything past it is nobody browsing rather than ADFA-5172. + private val maxReportedAcceptWaitNanos = TimeUnit.SECONDS.toNanos(10) // How long handleClient()'s last stat of config.debugDatabasePath took. A plain var is safe: // the accept loop is serial and single-threaded, and it is the only reader. @@ -197,7 +206,7 @@ class WebServer( // ADFA-5172: carried across iterations so a stall report can say whether the loop was // even in accept() when the connection arrived. - var previousAcceptWaitNanos = 0L + var previousAcceptWaitNanos = noPreviousIteration var previousBusyNanos = 0L while (true) { @@ -296,10 +305,7 @@ class WebServer( previousAcceptWaitNanos: Long, previousBusyNanos: Long, ) { - // A long wait in accept() is just an idle server, so report only the first one after a busy - // stretch: that is the periodic stall, not a user who stopped browsing the documentation. - val stalledBeforeAccept = - acceptWaitNanos >= stallThresholdNanos && previousAcceptWaitNanos < stallThresholdNanos + val stalledBeforeAccept = shouldReportAcceptWait(acceptWaitNanos, previousAcceptWaitNanos) val stalledWhileBusy = busyNanos >= stallThresholdNanos || debugDbStatNanos >= stallThresholdNanos if (!stalledBeforeAccept && !stalledWhileBusy) return @@ -315,6 +321,23 @@ class WebServer( ) } + /** + * Whether a wait in accept() is worth a line. Waiting is normal, so this reports only a wait + * that looks like ADFA-5172's stall: long enough to be a retransmitted handshake, short enough + * not to be an idle server, and preceded by an iteration that was served promptly -- meaning + * requests were arriving steadily right up to the stall. + * + * [previousAcceptWaitNanos] is [noPreviousIteration] until one iteration has completed, so the + * very first request after startup is never reported. + */ + internal fun shouldReportAcceptWait( + acceptWaitNanos: Long, + previousAcceptWaitNanos: Long, + ): Boolean { + val loadWasSteady = previousAcceptWaitNanos in 0 until stallThresholdNanos + return loadWasSteady && acceptWaitNanos >= stallThresholdNanos && acceptWaitNanos <= maxReportedAcceptWaitNanos + } + private fun millis(nanos: Long): Long = TimeUnit.NANOSECONDS.toMillis(nanos) /** diff --git a/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt b/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt new file mode 100644 index 0000000000..13cadd0582 --- /dev/null +++ b/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt @@ -0,0 +1,78 @@ +package com.itsaky.androidide.localWebServer + +import com.google.common.truth.Truth.assertThat +import org.junit.Test +import java.util.concurrent.TimeUnit + +/** + * Covers when a wait in accept() is worth a log line (ADFA-5172). Waiting is the normal state of a + * server with nothing to do, so the interesting case is narrow: long enough to be a retransmitted + * handshake, short enough not to be an idle server, and arriving in the middle of steady traffic. + */ +class AcceptWaitReportingTest { + private val thresholdMs = 200L + + // Every path is given explicitly: ServerConfig's defaults reach for external storage, which a + // JVM test has no stub for. + private fun server(stallThresholdMs: Long = thresholdMs) = + WebServer( + 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", + stallThresholdMs = stallThresholdMs, + ), + ) + + private fun millis(value: Long) = TimeUnit.MILLISECONDS.toNanos(value) + + private val noPreviousIteration = -1L + + @Test + fun `a one second wait between promptly served requests is the stall being hunted`() { + assertThat(server().shouldReportAcceptWait(millis(1_020), previousAcceptWaitNanos = millis(0))).isTrue() + } + + @Test + fun `the first request after startup is never reported, however long the wait`() { + assertThat(server().shouldReportAcceptWait(millis(74_000), noPreviousIteration)).isFalse() + assertThat(server().shouldReportAcceptWait(millis(1_020), noPreviousIteration)).isFalse() + } + + @Test + fun `a wait after an already long wait is an idle server, not a stall`() { + assertThat(server().shouldReportAcceptWait(millis(1_020), previousAcceptWaitNanos = millis(30_000))).isFalse() + } + + @Test + fun `a wait far past the retransmission ladder is nobody browsing`() { + assertThat(server().shouldReportAcceptWait(millis(60_000), previousAcceptWaitNanos = millis(5))).isFalse() + } + + @Test + fun `a wait within the retransmission ladder is still reported`() { + // 1 s, 3 s and 7 s are Linux's first three SYN retransmissions. + assertThat(server().shouldReportAcceptWait(millis(3_100), previousAcceptWaitNanos = millis(5))).isTrue() + assertThat(server().shouldReportAcceptWait(millis(7_200), previousAcceptWaitNanos = millis(5))).isTrue() + } + + @Test + fun `an ordinary wait below the threshold is not reported`() { + assertThat(server().shouldReportAcceptWait(millis(30), previousAcceptWaitNanos = millis(5))).isFalse() + } + + @Test + fun `a zero or negative threshold silences the accept-wait report instead of flooding it`() { + // "The previous iteration waited less than the threshold" cannot hold when the threshold is + // zero, so this branch goes quiet rather than reporting every wait. A negative threshold is + // clamped to zero and behaves the same. The busy-phase report, which has no such + // precondition, does fire for every iteration at these settings. + assertThat(server(stallThresholdMs = 0).shouldReportAcceptWait(millis(1_020), previousAcceptWaitNanos = 0)).isFalse() + assertThat(server(stallThresholdMs = -5).shouldReportAcceptWait(millis(1_020), previousAcceptWaitNanos = 0)).isFalse() + } +} From df93f25adafe7fc105d72383b583632f02785819 Mon Sep 17 00:00:00 2001 From: David Schachter Date: Tue, 18 Aug 2026 08:35:15 -0700 Subject: [PATCH 3/3] ADFA-5172: Flatten the accept loop, and pin the report's boundaries Review asked for both. The loop was a try inside a try inside a while, with two catch blocks each nesting conditionals two deep, and a finally doing three unrelated jobs. It is now eight lines: accept, serve, close. The pieces became functions that each do one thing -- acceptNextClient() returns null only when the listening socket closed and retries any other accept failure, serveClient() serves one connection and answers a 500 if handling fails partway, sendInternalServerError(), closeQuietly(), and isSocketClosed() for the string test that a closed socket forces on us. Two side effects worth noting. The socket can no longer be null inside the loop, so the old comment defending a log line that could print "null" is gone with the line it defended; the replacement logs the socket it actually served. And the timings the loop carried in locals are now fields, which is honest about what they always were: state belonging to the single accept thread, not to one iteration. The report's filtering contract now has boundary tests, both ends inclusive: one millisecond under the threshold, exactly on it, one over; 9,999 / 10,000 / 10,001 ms against the ceiling; and the previous wait counting as steady load right up to the threshold. Round values well inside each range said nothing about whether the comparisons were inclusive, which is exactly what a later edit flips silently. --- .../androidide/localWebServer/WebServer.kt | 149 ++++++++++-------- .../localWebServer/AcceptWaitReportingTest.kt | 26 +++ 2 files changed, 112 insertions(+), 63 deletions(-) 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 2a3d3325f5..7dfa15d4d5 100644 --- a/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt +++ b/app/src/main/java/com/itsaky/androidide/localWebServer/WebServer.kt @@ -113,9 +113,13 @@ class WebServer( // ladder is 1 s, 3 s, 7 s, so anything past it is nobody browsing rather than ADFA-5172. private val maxReportedAcceptWaitNanos = TimeUnit.SECONDS.toNanos(10) - // How long handleClient()'s last stat of config.debugDatabasePath took. A plain var is safe: - // the accept loop is serial and single-threaded, and it is the only reader. + // How long handleClient()'s last stat of config.debugDatabasePath took, and how long the last + // accept() waited. Plain vars are safe: the accept loop is serial and single-threaded, and it is + // the only reader and writer. private var debugDbStatNanos = 0L + private var acceptWaitNanos = 0L + private var previousAcceptWaitNanos = noPreviousIteration + private var previousBusyNanos = 0L // function to obtain the last modified date of a documentation.db database // this is used to see if there is a newer version of the database on the sdcard @@ -204,70 +208,14 @@ class WebServer( } log.info("WebServer started successfully on '{}', port {}.", config.bindName, config.port) - // ADFA-5172: carried across iterations so a stall report can say whether the loop was - // even in accept() when the connection arrived. - var previousAcceptWaitNanos = noPreviousIteration - var previousBusyNanos = 0L - while (true) { - var clientSocket: Socket? = null - var acceptWaitNanos = 0L - var busyStartNanos = 0L - debugDbStatNanos = 0L - try { - try { - if (debugEnabled) log.debug("About to call accept() on the server socket, {}.", serverSocket) - val acceptStartNanos = System.nanoTime() - clientSocket = serverSocket.accept() - busyStartNanos = System.nanoTime() - acceptWaitNanos = busyStartNanos - acceptStartNanos - - 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'.") + val clientSocket = acceptNextClient() ?: break - 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) - } - } - } - } + try { + serveClient(clientSocket) } 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) - - // Zero when accept() threw, which leaves nothing to time. - if (busyStartNanos != 0L) { - val busyNanos = System.nanoTime() - busyStartNanos - reportStall(acceptWaitNanos, busyNanos, previousAcceptWaitNanos, previousBusyNanos) - previousAcceptWaitNanos = acceptWaitNanos - previousBusyNanos = busyNanos - } + closeQuietly(clientSocket) + if (debugEnabled) log.debug("Served and closed clientSocket {}.", clientSocket) } } } catch (e: Exception) { @@ -291,6 +239,81 @@ class WebServer( } } + /** + * Waits for the next connection. Null means the listening socket closed and the loop is done; + * an accept that failed for any other reason is logged and retried, since one bad accept is not + * a reason to stop serving. + */ + private fun acceptNextClient(): Socket? { + while (true) { + try { + if (debugEnabled) log.debug("About to call accept() on the server socket, {}.", serverSocket) + + val acceptStartNanos = System.nanoTime() + val clientSocket = serverSocket.accept() + acceptWaitNanos = System.nanoTime() - acceptStartNanos + + if (debugEnabled) log.debug("Returned from socket accept(), clientSocket is {}.", clientSocket) + return 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 (isSocketClosed(e)) { + if (debugEnabled) log.debug("WebServer socket closed, shutting down.") + return null + } + log.error("Accept() failed: {}", e.message) + } + } + } + + /** Serves one connection, answering with a 500 if handling it fails partway. */ + private fun serveClient(clientSocket: Socket) { + val busyStartNanos = System.nanoTime() + debugDbStatNanos = 0L + + try { + handleClient(clientSocket) + } 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 && isSocketClosed(e)) { + if (debugEnabled) log.debug("Client disconnected: {}", e.message) + } else { + log.error("Error handling client: {}", e.message) + sendInternalServerError(clientSocket) + } + } finally { + val busyNanos = System.nanoTime() - busyStartNanos + reportStall(acceptWaitNanos, busyNanos, previousAcceptWaitNanos, previousBusyNanos) + previousAcceptWaitNanos = acceptWaitNanos + previousBusyNanos = busyNanos + } + } + + private fun sendInternalServerError(clientSocket: Socket) { + try { + val output = clientSocket.outputStream + + sendError(PrintWriter(output, true), output, httpInternalServerError, "Internal Server Error 1") + } catch (e: Exception) { + log.error("Error sending error response: {}", e.message) + } + } + + private fun closeQuietly(clientSocket: Socket) { + try { + clientSocket.close() + } catch (e: Exception) { + log.error("Cannot close client socket: {}", e.message) + } + } + + /** A closed socket reports itself only in the exception's message, hence the string test. */ + private fun isSocketClosed(e: java.net.SocketException): Boolean = e.message?.contains("Closed", ignoreCase = true) == true + /** * Logs one line per accept-loop iteration that crosses [ServerConfig.stallThresholdMs], for * ADFA-5172's periodic ~1 s stall. Splits "parked in accept()" from "busy outside it" because diff --git a/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt b/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt index 13cadd0582..ab2cfadc72 100644 --- a/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt +++ b/app/src/test/java/com/itsaky/androidide/localWebServer/AcceptWaitReportingTest.kt @@ -66,6 +66,32 @@ class AcceptWaitReportingTest { assertThat(server().shouldReportAcceptWait(millis(30), previousAcceptWaitNanos = millis(5))).isFalse() } + @Test + fun `the threshold itself is inclusive, and one millisecond under it is not reported`() { + val server = server() + + assertThat(server.shouldReportAcceptWait(millis(thresholdMs - 1), previousAcceptWaitNanos = millis(5))).isFalse() + assertThat(server.shouldReportAcceptWait(millis(thresholdMs), previousAcceptWaitNanos = millis(5))).isTrue() + assertThat(server.shouldReportAcceptWait(millis(thresholdMs + 1), previousAcceptWaitNanos = millis(5))).isTrue() + } + + @Test + fun `the ten second ceiling is inclusive, and one millisecond over it is an idle server`() { + val server = server() + + assertThat(server.shouldReportAcceptWait(millis(9_999), previousAcceptWaitNanos = millis(5))).isTrue() + assertThat(server.shouldReportAcceptWait(millis(10_000), previousAcceptWaitNanos = millis(5))).isTrue() + assertThat(server.shouldReportAcceptWait(millis(10_001), previousAcceptWaitNanos = millis(5))).isFalse() + } + + @Test + fun `the previous wait counts as steady load right up to the threshold`() { + val server = server() + + assertThat(server.shouldReportAcceptWait(millis(1_020), previousAcceptWaitNanos = millis(thresholdMs - 1))).isTrue() + assertThat(server.shouldReportAcceptWait(millis(1_020), previousAcceptWaitNanos = millis(thresholdMs))).isFalse() + } + @Test fun `a zero or negative threshold silences the accept-wait report instead of flooding it`() { // "The previous iteration waited less than the threshold" cannot hold when the threshold is