iT邦幫忙

2026 iThome 鐵人賽

0
Software Development

Kotlin Ktor 實戰 101系列 第 34 篇

Kotlin Ktor 實戰 101 Day 34 真的起一台 server 的 end to end 測試

  • 分享至 

  • xImage
  •  

https://ithelp.ithome.com.tw/upload/images/20260909/20121948LfQo3aVCtG.jpg

day 33 把 todo-api 打包成 fat jar 跟 Docker image,加了 2 條健康檢查,也量了關機要多久,那篇文末記了 8 筆部署債,其中一筆寫著「沒有 graceful drain,SIGTERM 之後 Ktor 有沒有把手上的請求處理完才關,這一輪只量了關機總時間,沒有量還在飛的請求會怎樣」

這篇來還那一筆,而要量「還在飛的請求」,前提是得先有一條真的連線,這件事這個系列到目前為止一次都沒做過

這篇要完成什麼

  • 確認一件不太舒服的事,前面 34 篇的測試沒有一個走過真的 socket
  • 把 end to end 分成 2 層,同一個 process 裡起真的 Netty,以及從外面打打包好的 image
  • 用 EngineMain.createServer 把正式那條啟動路徑走一遍
  • 用 Netty 那條 4096 個 byte 的界線,示範 testApplication 結構上看不到什麼
  • 順手驗掉 day 24 從原始碼推出來、但沒有真的跑過的那句話
  • 確認 keep-alive 真的在同一條連線上服務 2 個請求
  • 量 stop(grace, timeout) 到底保護了誰,答案跟名字不太一樣
  • 用 Testcontainers 起 day 33 那個 image 加一個 PostgreSQL,從容器外面走完一趟完整的旅程
  • 補完 day 33 那個「503 花了 5 秒」的完整形狀
  • 分開測「完全不給憑證」跟「給空字串」,擋下來的不是同一道關卡
  • 把 day 33 手動量到的退出碼 143 變成一個斷言,順便多驗一個 137
  • 量這套東西讓 ./gradlew test 貴了多少,該怎麼分開跑,以及這種慢測試值不值得寫
  • 順手發現 day 33 建出來的 image 是 amd64,在 arm64 機器上是模擬跑的
  • 跟 Relix 的對照,2 個系列在這件事上停在同一個地方
  • 這篇加的測試,以及留下的債

沒有一個測試走過真的 socket

先確認現況,在專案根目錄跑

grep -rn "embeddedServer\|Netty\|CIO\|resolvedConnectors\|port = 0" src/test/

0 命中,29 個測試 class、278 個測試,全部都是 testApplication

這不是說那些測試沒用,day 03 就講過,testApplication 跑的是跟正式環境同一套 routing 和 plugin,不是簡化過的模擬版,day 24 把它拆開之後,答案更精確一點,下面這段是 ktor-server-test-host 的 TestApplication.kt,不是專案裡的程式碼

internal val embeddedServer by lazy {
    EmbeddedServer(properties, TestEngine, engineConfig)
}

正式跑的是 Netty,測試跑的是 TestEngine,day 24 當時的結論是「module、plugin 與 routing 可以共用,但 engine 的啟動方式、網路邊界與外部資源仍要另外驗證」

那句「仍要另外驗證」,一路到 day 33 都沒有人去驗,所以下面這些東西,這個系列從來沒有測過

  • Netty 這一層,連線怎麼建、HTTP 怎麼解、超過限制的請求會怎樣
  • EngineMain 配 application.yaml 這條正式啟動路徑,day 17 換上去之後,測試一直是繞過它的
  • 真的 client 走真的 TCP 拿到的回應
  • 關機的時候還在飛的請求會怎樣
  • day 33 打包出來的那個 image,那篇手動 docker run 再 curl 過,但沒有任何一個自動化測試打過它

兩層 end to end

「end to end」這個詞不精確,要看兩端各是哪裡,這篇分成 2 層做

第 1 層是同一個 process 裡起真的 Netty,綁一個真的 port,用真的 HttpClient 從外面打進去,這層便宜,一個測試幾百毫秒,抓得到 engine 這一層的行為

第 2 層是黑箱打打包好的 image,用 Testcontainers 把 day 33 那個 jib image 跟一個 PostgreSQL 接在同一個網路上,從容器外面用真的 HTTP 打,這層貴,但它測的是真的要上線的那個東西,包括環境變數怎麼傳、非 root 跑得起來嗎、docker stop 之後會怎樣

第 1 層的測試放在新檔案 src/test/kotlin/com/cashwu/todo/EndToEndTest.kt,第 2 層放在 src/test/kotlin/com/cashwu/todo/BlackBoxTest.kt,2 個檔案各是一個 class EndToEndTest 跟 class BlackBoxTest,下面每一段 @Test 開頭的程式碼都是完整的測試方法,放在對應那個 class 裡面,不是 @Test 開頭的另外標出來,有的是 class 外面的 top level helper,有的是 Ktor 自己的原始碼

第一層,把正式那條啟動路徑走一遍

EngineMain.main(args) 是 src/main/kotlin/com/cashwu/todo/Application.kt 裡 main() 唯一那一行,下面這段是它的實作,出處是 ktor-server-netty 的 EngineMain.kt,主要只是拿來看的,不要貼進專案裡

public object EngineMain {
    @JvmStatic
    public fun main(args: Array<String>) {
        val server = createServer(args)
        server.start(true)
    }

    public fun createServer(
        args: Array<String>
    ): EmbeddedServer<NettyApplicationEngine, NettyApplicationEngine.Configuration> {
        val config = CommandLineConfig(args)
        return EmbeddedServer(config.rootConfig, Netty) {
            takeFrom(config.engineConfig)
            loadConfiguration(config.rootConfig.environment.config)
        }
    }
}

public object EngineMain 那一層要留著,@JvmStatic 只能標在 named object 或 companion object 的成員上,把裡面那個 main 單獨抓出來放到自己的檔案,編譯器會直接擋下來

Only members in named objects and companion objects can be annotated with '@JvmStatic'.

關鍵是 createServer 是 public 的,測試因此可以拿到跟正式環境完全同一條路建出來的 server,只是不傳 start(true) 那個會擋住的參數

createServer 走的是 CommandLineConfig(args),它會載入 application.yaml、吃 -port= 覆蓋 port、吃 -P:key=value 覆蓋任何一個設定值,所以測試要做的事只有 2 件,port 給 0 讓作業系統挑一個沒人用的,資料庫指向 H2

第 1 個測試,寫在 EndToEndTest.kt

@Test
fun `the yaml modules list boots the app on a real port`() {
    val server = EngineMain.createServer(
        arrayOf(
            "-port=0",
            "-P:todo.database.url=jdbc:h2:mem:e2e",
            "-P:todo.database.driver=org.h2.Driver",
            "-P:todo.database.user=sa",
            "-P:todo.database.password=",
        )
    )
    server.start(wait = false)
    try {
        val port = runBlocking { server.engine.resolvedConnectors() }.single().port
        assertTrue(port > 0, "port 0 應該被換成真的 port")
        Socket("127.0.0.1", port).use { assertTrue(it.isConnected) }

        HttpClient(CIO).use { client ->
            runBlocking {
                val root = client.get("http://127.0.0.1:$port/")
                assertEquals(HttpStatusCode.OK, root.status)
                assertEquals("Hello, Ktor!", root.bodyAsText())

                assertEquals(HttpStatusCode.OK, client.get("http://127.0.0.1:$port/health/live").status)

                val todos = client.get("http://127.0.0.1:$port/todos") { bearerAuth(TEST_TOKEN) }
                assertEquals(HttpStatusCode.OK, todos.status)
                assertTrue(todos.bodyAsText().contains("買牛奶"))
            }
        }
    } finally {
        server.stop(0, 0)
    }
}

resolvedConnectors() 是這裡的重點,給 0 之後真正綁到哪個 port 只有 engine 知道,這個函式回的是綁定之後的結果,這一輪拿到的是上面 log 那個 54411,下一輪會是別的數字,day 24 提過 TestApplicationEngine 的同名函式回的是寫死的 localhost:80 跟 localhost:443,因為它根本沒有 socket

TEST_TOKEN 是 day 17 建立的 TestApp.kt 裡那個,day 27 之後它是 testIssuer.accessToken(TEST_USER) 簽出來的 JWT,這裡直接沿用,因為簽章用的祕密來自同一份 application.yaml

HttpClient(CIO) 是 day 31 加進來的相依,那篇拿它打外部的待辦服務,這裡拿它打自己,走的是真的 TCP,不是 testApplication 那個接在 TestEngine 上的 client

跑起來的 log

14:28:23.963 INFO  [no-call-id] o.f.c.i.c.DbMigrate -- Current version of schema "PUBLIC": << Empty Schema >>
14:28:23.967 INFO  [no-call-id] o.f.c.i.c.DbMigrate -- Migrating schema "PUBLIC" to version "1 - create todos"
14:28:23.975 INFO  [no-call-id] o.f.c.i.c.DbMigrate -- Successfully applied 1 migration to schema "PUBLIC", now at version v1 (execution time 00:00.002s)
14:28:23.990 DEBUG [no-call-id] Exposed -- Loaded TransactionsHolder class ThreadLocalTransactionsStack to manage instances (priority 0)
14:28:24.019 DEBUG [no-call-id] Exposed -- SELECT TODOS.ID, TODOS.TITLE, TODOS.DONE, TODOS.CREATED_AT FROM TODOS LIMIT 1
14:28:24.027 DEBUG [no-call-id] Exposed -- INSERT INTO TODOS (TITLE, DONE, CREATED_AT) VALUES ('買牛奶', TRUE, '2026-08-27T08:00:00Z')
14:28:24.028 DEBUG [no-call-id] Exposed -- INSERT INTO TODOS (TITLE, DONE, CREATED_AT) VALUES ('繳電費', FALSE, '2026-08-28T09:30:00Z')
14:28:24.029 DEBUG [no-call-id] Exposed -- INSERT INTO TODOS (TITLE, DONE, CREATED_AT) VALUES ('寫 day 05 的文章', FALSE, '2026-08-29T21:15:00Z')
14:28:24.041 INFO  [no-call-id] Application -- Application started in 0.83 seconds.
14:28:24.121 INFO  [no-call-id] Application -- Responding at http://0.0.0.0:54411
14:28:24.211 INFO  [45m01c=jrvn3] Application -- 200 GET / 9ms
14:28:24.234 INFO  [8slpr+ug8vo8] Application -- 200 GET /health/live 8ms
14:28:24.277 DEBUG [n9oo+mpa9hqy] Exposed -- SELECT TODOS.ID, TODOS.TITLE, TODOS.DONE, TODOS.CREATED_AT FROM TODOS ORDER BY TODOS.ID ASC
14:28:24.281 INFO  [n9oo+mpa9hqy] Application -- 200 GET /todos 18ms
14:28:24.284 INFO  [no-call-id] c.z.h.HikariDataSource -- todo-pool - Shutdown initiated...
14:28:24.285 INFO  [no-call-id] c.z.h.HikariDataSource -- todo-pool - Shutdown completed.
EndToEndTest > the yaml modules list boots the app on a real port() PASSED

Responding at http://0.0.0.0:54411 那一行就是 -port=0 的結果,作業系統挑了 54411,下一輪會是別的數字

前面幾行是 day 23 的 Flyway 在 H2 上建表,再把 day 20 那 3 筆 seed 寫進去,GET /todos 那一筆前面的 SELECT ... ORDER BY TODOS.ID ASC 是 day 21 的 repository 發的,同一條 call id 接著就是 200 GET /todos

log 不印 body,body 是測試自己斷言的,/ 是 Hello, Ktor!,/todos 那串 JSON 跟 testApplication 裡拿到的長得一樣,這正是重點,routing、序列化、認證本來就該一樣,會不一樣的在底下那層

4096 個 byte 那條線,testApplication 看不到

day 24 拆 TestEngine 的時候點出一件事,TestApplicationEngine 傳給 BaseApplicationEngine 的第 4 個參數是一個空白的 EnginePipeline(developmentMode),而 Netty 拿的是 defaultEnginePipeline,那篇處理的是這個差別在例外上的後果,還有一個更前面的差別那篇沒有提,TestEngine 連 HTTP decoder 都沒有

Netty 有,它的 HttpServerCodec 對請求的起始行有長度上限,預設 4096 個 byte,同一個路由,2 種模式各打一次,這個測試放在 EndToEndTest.kt

@Test
fun `netty rejects an over long request line before routing`() {
    val reached = AtomicInteger()
    withNetty({ routing { get("/echo") { reached.incrementAndGet(); call.respondText("ok") } } }) { client, port ->
        assertEquals(HttpStatusCode.OK, client.get("http://127.0.0.1:$port/echo?q=" + "a".repeat(4000)).status)
        assertEquals(1, reached.get())

        val rejected = client.get("http://127.0.0.1:$port/echo?q=" + "a".repeat(4100))

        assertEquals(HttpStatusCode.BadRequest, rejected.status)
        assertEquals("An HTTP line is larger than 4096 bytes.", rejected.bodyAsText())
        assertEquals(1, reached.get(), "handler 不該被呼叫第二次")
    }
}

那個 reached 計數器是關鍵,4000 個字元的時候 handler 被呼叫一次,4100 的時候計數器還是 1,也就是 routing 完全沒有被叫到,請求在解析階段就被打回去了

/echo?q= + 3000 個 a  -> 200 OK  body=[ok]   handler 被呼叫 1 次
/echo?q= + 4000 個 a  -> 200 OK  body=[ok]   handler 被呼叫 1 次
/echo?q= + 4100 個 a  -> 400 Bad Request  body=[An HTTP line is larger than 4096 bytes.]  handler 被呼叫 0 次
/echo?q= + 8000 個 a  -> 400 Bad Request  body=[An HTTP line is larger than 4096 bytes.]  handler 被呼叫 0 次

同一個路由放進 testApplication,行為完全不同,這個測試也放在 class EndToEndTest 裡面,跟上面那個並排才看得出差別

@Test
fun `testApplication lets the same request line straight through`() = testApplication {
    val reached = AtomicInteger()
    serverConfig { developmentMode = false }
    routing { get("/echo") { reached.incrementAndGet(); call.respondText("ok") } }

    val response = client.get("/echo?q=" + "a".repeat(100_000))

    assertEquals(HttpStatusCode.OK, response.status)
    assertEquals(1, reached.get())
}

100000 個字元照樣 200,照樣進到 handler,沒有 decoder 就沒有上限

這個差別在什麼時候會有問題 ? 一條吃很長 query string 的路由,在 testApplication 裡怎麼測都過,上線之後超過 4096 就變成 400,而且那個 400 不會經過 day 15 的 StatusPages,body 是 Netty 給的英文句子,不是這個專案統一的錯誤 JSON

順便驗掉 day 24 沒驗的那句話

day 24 講例外那一節的結尾寫著「那個 HTML 例外頁在正式環境是看不到的,因為 Netty 走的是另一條路」,那篇沒有真的起 Netty,所以那句話當時是從原始碼推出來的,既然這篇手上有真的 Netty,順手驗一下,測試一樣放在 class EndToEndTest 裡面

@Test
fun `the development mode exception page never shows up under netty`() {
    for (dev in listOf(false, true)) {
        withNetty({ routing { get("/boom") { throw IllegalStateException("炸了") } } }, dev) { client, port ->
            val response = client.get("http://127.0.0.1:$port/boom")

            assertEquals(HttpStatusCode.InternalServerError, response.status)
            assertEquals("炸了", response.bodyAsText(), "developmentMode = $dev 不該換成 HTML 例外頁")
        }
    }
}

2 種模式跑出來都是

500 Internal Server Error  body=[炸了]

2 個字元的純文字,對照 day 24 在 testApplication 的預設 development mode 底下量到的

<html><body><h1>Internal Server Error</h1><h2>Request Information:</h2><pre>Method: GET

day 24 的說法成立,而且比那篇當時能講的更強一點,它不只是「正式環境看不到」,是 developmentMode 就算開著,Netty 這條路也生不出那個 HTML 頁,那頁是 setupFallbackResponse 在 EnginePipeline.Before 產的,而 Netty 的 defaultEnginePipeline 在 EnginePipeline.Call 就把例外接完了,根本走不到外面那一層

同一條連線送兩個請求

keep-alive 是 testApplication 結構上碰不到的東西,它沒有連線這個概念,用 java.net.Socket 手寫 2 個請求就看得到,這個測試也在 class EndToEndTest 裡面

@Test
fun `keep alive serves two requests on one socket`() {
    withNetty({ routing { get("/fast") { call.respondText("fast") } } }) { _, port ->
        Socket("127.0.0.1", port).use { socket ->
            socket.soTimeout = 10_000
            val out = socket.getOutputStream()
            val reader = BufferedReader(socket.getInputStream().reader())
            repeat(2) {
                out.write("GET /fast HTTP/1.1\r\nHost: 127.0.0.1\r\nConnection: keep-alive\r\n\r\n".toByteArray())
                out.flush()
                assertEquals("HTTP/1.1 200 OK", reader.readLine())
                var length = -1
                while (true) {
                    val line = reader.readLine() ?: break
                    if (line.startsWith("Content-Length:", true)) length = line.substringAfter(":").trim().toInt()
                    if (line.isEmpty()) break
                }
                assertEquals("fast", CharArray(length).also { reader.read(it) }.concatToString())
            }
            assertTrue(!socket.isClosed, "兩個請求走的是同一條連線")
        }
    }
}

withNetty 是 EndToEndTest.kt 最下面的 top level helper,在 class EndToEndTest 的大括號外面,起一個 embeddedServer(Netty) 綁 port 0,跑完關掉

private fun withNetty(
    module: Application.() -> Unit,
    developmentMode: Boolean = false,
    block: suspend (HttpClient, Int) -> Unit,
) {
    val server: EmbeddedServer<*, *> = embeddedServer(
        Netty,
        serverConfig(applicationEnvironment()) {
            this.developmentMode = developmentMode
            module(body = module)
        },
        configure = { connector { port = 0 } },
    )
    server.start(wait = false)
    try {
        val port = runBlocking { server.engine.resolvedConnectors() }.single().port
        HttpClient(CIO).use { client -> runBlocking { block(client, port) } }
    } finally {
        server.stop(0, 0)
    }
}

2 次都拿到 HTTP/1.1 200 OK,body 都是 fast,socket 沒有被關掉,這個測試本身沒有揭露什麼意外,它的用處在下一節,要證明連線被關掉,得先有東西證明連線正常時不會被關掉

stop 的 grace period 保護不到連線

stop(gracePeriodMillis, timeoutMillis) 這個簽名很容易讓人以為它做的是 graceful drain,也就是不收新請求、把手上的做完、再關門,量一下就知道不是

測試的做法是用 raw socket 送一個會跑 800 毫秒的請求,200 毫秒後呼叫 stop,然後同時盯 3 件事,handler 有沒有跑完、respondText 有沒有丟例外、client 那一側讀到什麼,這個測試也在 class EndToEndTest 裡面,它沒有用 withNetty,因為要在 server 還活著的時候自己挑時間點呼叫 stop

@Test
fun `stop finishes the handler but the connection is already gone`() {
    val handlerFinished = AtomicInteger()
    val respondFailed = AtomicReference("沒有丟例外")
    val clientSaw = AtomicReference("什麼都沒讀到")
    val sent = CountDownLatch(1)

    val server = embeddedServer(
        Netty,
        serverConfig(applicationEnvironment()) {
            developmentMode = false
            module {
                routing {
                    get("/slow") {
                        delay(800)
                        handlerFinished.incrementAndGet()
                        try {
                            call.respondText("done")
                        } catch (e: Throwable) {
                            respondFailed.set(e::class.simpleName ?: "未知例外")
                        }
                    }
                }
            }
        },
        configure = { connector { port = 0 } },
    )
    server.start(wait = false)
    val port = runBlocking { server.engine.resolvedConnectors() }.single().port

    val reader = Thread {
        Socket("127.0.0.1", port).use { socket ->
            socket.soTimeout = 15_000
            val out = socket.getOutputStream()
            out.write("GET /slow HTTP/1.1\r\nHost: 127.0.0.1\r\n\r\n".toByteArray())
            out.flush()
            sent.countDown()
            clientSaw.set(socket.getInputStream().bufferedReader().readLine() ?: "EOF")
        }
    }
    reader.start()

    sent.await()
    Thread.sleep(200)
    server.stop(gracePeriodMillis = 2000, timeoutMillis = 5000)
    reader.join(15_000)

    assertEquals(1, handlerFinished.get(), "handler 有跑完")
    assertEquals("沒有丟例外", respondFailed.get(), "respondText 不會告訴你送不出去")
    assertEquals("EOF", clientSaw.get(), "連線在 stop 的第一時間就斷了,回應沒送到")
}

3 個 Atomic 變數是給另一條執行緒寫的,handlerFinished 由 handler 加一,respondFailed 只有在 respondText 丟例外的時候才會被換掉,clientSaw 由 reader 那條執行緒寫,readLine() 回 null 就代表對方把連線關了,記成 EOF

sent 這個 latch 是為了讓時間點可信,主執行緒要等請求真的送出去才開始數那 200 毫秒,不然 stop 有機會跑在請求之前

用 raw socket 而不是 HttpClient 是刻意的,這樣讀到的東西是 socket 本身給的,不會被 client 的重試或錯誤包裝混淆

探索這個行為的時候,handler 拉長到 1500 毫秒、grace 給 5000,server.stop() 跟 server.engine.stop() 各跑 3 次,這一輪的數字是

server.stop 第1次  stop 209→6620 (6411ms) | handler 進入 4 完成 1506 respond 成功 1506 | client 於 210ms 讀到 EOF
server.stop 第2次  stop 205→6618 (6413ms) | handler 進入 6 完成 1510 respond 成功 1511 | client 於 206ms 讀到 EOF
server.stop 第3次  stop 209→6620 (6411ms) | handler 進入 6 完成 1510 respond 成功 1510 | client 於 209ms 讀到 EOF
engine.stop 第1次  stop 210→6652 (6442ms) | handler 進入 7 完成 1511 respond 成功 1511 | client 於 211ms 讀到 EOF
engine.stop 第2次  stop 207→6663 (6456ms) | handler 進入 3 完成 1504 respond 成功 1505 | client 於 209ms 讀到 EOF
engine.stop 第3次  stop 210→6624 (6414ms) | handler 進入 6 完成 1511 respond 成功 1511 | client 於 211ms 讀到 EOF

6 次一致,3 個事實

連線在 stop 開始後 1 到 2 毫秒就被關掉,第 2 次 stop 從 205 毫秒開始,client 在 206 毫秒讀到 EOF

handler 照樣被跑完,同一次 handler 在 1510 毫秒完成,比 stop 開始晚了 1.3 秒

call.respondText 不會丟例外,回應寫進一條已經關掉的連線,靜靜地掉了,應用程式這一側完全看不出來有東西沒送到

第三點是最麻煩的,如果 respondText 會丟例外,至少 log 上會留下痕跡,可以接 day 15 的 StatusPages 或 day 16 的 CallLogging 去觀察,現在的情況是 access log 會記一筆成功的回應,而 client 那邊什麼都沒收到

那 grace period 到底在等什麼 ? 把請求拿掉,讓一台完全閒置的 server 關機,這一輪 3 次的數字是

第1次 stop 5→5111 (5106ms)  閒置連線於 5ms 得到 EOF   stop 後新連線 ConnectException: Connection refused
第2次 stop 4→5101 (5097ms)  閒置連線於 5ms 得到 EOF   stop 後新連線 ConnectException: Connection refused
第3次 stop 4→5099 (5095ms)  閒置連線於 5ms 得到 EOF   stop 後新連線 ConnectException: Connection refused

沒有任何請求在飛,grace 給 5000,還是等了 5095 到 5106 毫秒,而且閒置的 keep-alive 連線也一樣在第一時間被關掉

反過來把 grace 調小,handler 就跑不完了

grace=100  timeout=8000  stop 219→349 (130ms)  handler 沒完成  client 讀到 EOF
grace=0    timeout=0     stop 207→217 (10ms)   handler 沒完成  client 讀到 EOF

所以 grace period 保護的是 handler 有沒有機會跑完,不是回應送不送得到,這 2 件事在名字上看起來是同一件

機制的線索在 ktor-server-netty 的 NettyApplicationEngine.stop 裡,原始碼自己有一段註解承認語意落差,下面這段跟再下面那段 EmbeddedServer.stop 一樣,都是函式庫的原始碼,不是要貼進專案的

// Quiet period in Ktor Server and Netty EventLoopGroup are different.
// Ktor Server waits for all requests to finish without accepting new ones.
// Netty's EventLoopGroup accepts new tasks during the gracePeriod
// and always waits at least gracePeriod, even if there are no tasks to complete.
val noQuietPeriod = 0L

最後那句 always waits at least gracePeriod, even if there are no tasks to complete 就是閒置關機也要等滿 5 秒的原因,同一個函式的順序是先關掉 listening channel,再依序 connectionEventGroup、workerEventGroup、callEventGroup 各自 shutdownGracefully,3 個 group 拿到的 quiet period 不一樣 (最後那個包在 if (!configuration.shareWorkGroup) 裡面,預設設定下會跑到)

至於是哪一個動作關掉了已經建立的連線,這一次沒有追到那個程度,所以這裡只寫觀察到的行為,能排除的是 application 被取消這個解釋,EmbeddedServer.stop 的順序是先跑完 engine.stop(...) 才 destroyApplication(),原始碼如下

public fun stop(shutdownGracePeriod: Long, shutdownTimeout: Long, timeUnit: TimeUnit) {
    try {
        engine.stop(timeUnit.toMillis(shutdownGracePeriod), timeUnit.toMillis(shutdownTimeout))
    } catch (e: Exception) {
        environment.log.warn("Exception occurred during engine shutdown", e)
    }
    applicationInstanceLock.write {
        destroyApplication()
    }

這裡量的是直接呼叫 stop(),而 SIGTERM 走的是同一條路,EmbeddedServer.start() 第 1 行就是 addShutdownHook { stop() },容器收到 SIGTERM 之後跑的就是上面這個函式,只是參數換成 shutdownGracePeriod 跟 shutdownTimeout 的預設值

day 33 那筆債的答案因此是負面的,這個服務沒有 graceful drain,換到 Kubernetes 上,pod 收到 SIGTERM 的那一刻,手上那些請求的客戶端會拿到連線中斷,而 app 自己的 log 會說那幾筆都成功了

day 33 其實預留了這個問題,那篇量到退出碼 143 之後接著寫「這個數字不能證明當時還在飛的請求都有處理完,graceful drain 要用一個尚未完成的請求另外測」,這一節就是那個「另外測」,而答案是沒有處理完

第二層,打包好的 image 才是要上線的東西

day 33 用 jib 建了一個 todo-api:slim,246MB,alpine base,user = "1000:1000",那篇驗證它的方式是手動 docker run 再 curl,這一節把那件事自動化

BlackBoxTest.kt 最下面 2 個 helper 負責起這一組容器,跟 withNetty 一樣是 top level 的,在 class BlackBoxTest 外面

private fun todoPostgresContainer(network: Network): PostgreSQLContainer =
    PostgreSQLContainer("postgres:18-alpine")
        .withNetwork(network)
        .withNetworkAliases("db")
        .withDatabaseName("todo")
        .withUsername("todo")
        .withPassword("todo")

private fun todoAppContainer(network: Network, secret: String? = "black-box-secret-32-bytes-minimum"): GenericContainer<*> =
    GenericContainer(TODO_IMAGE)
        .withNetwork(network)
        .withExposedPorts(8080)
        .withEnv("DB_URL", "jdbc:postgresql://db:5432/todo")
        .withEnv("DB_USER", "todo")
        .withEnv("DB_PASSWORD", "todo")
        .withEnv("ALICE_PASSWORD", ALICE_PASSWORD)
        .withEnv("BOB_PASSWORD", "black-box-bob")
        .apply { if (secret != null) withEnv("JWT_SECRET", secret) }

TODO_IMAGE 是同一個檔案上面的 private const val TODO_IMAGE = "todo-api:slim",也就是 day 33 jibDockerBuild 出來的那個 tag

跟 day 25 那個 PostgreSQL 容器比,這裡多了 2 件事,一個是 Network,2 個容器要接在同一個網路上,app 才能用 db 這個名字連到資料庫,另一個是 withEnv,設定不再是 -P: 或 MapApplicationConfig,而是真的環境變數,走的是 application.yaml 裡 $DB_URL、$JWT_SECRET 那套語法

等待的條件也不一樣,把這 2 個容器兜成一組的是同一個檔案的 TodoStack,也是 top level

private class TodoStack : AutoCloseable {
    val network: Network = Network.newNetwork()
    val db: PostgreSQLContainer = todoPostgresContainer(network)
    val app: GenericContainer<*> = todoAppContainer(network)
        .waitingFor(Wait.forHttp("/health/ready").forPort(8080).forStatusCode(200))
        .withStartupTimeout(Duration.ofSeconds(60))
    val client: HttpClient = HttpClient(CIO)

    val baseUrl: String get() = "http://${app.host}:${app.getMappedPort(8080)}"

    fun start(): TodoStack {
        val asked = System.nanoTime()
        db.start()
        app.start()
        println("整組起到 readiness 回 200 花了 ${(System.nanoTime() - asked) / 1_000_000}ms")
        return this
    }

    override fun close() {
        client.close()
        runCatching { app.stop() }
        runCatching { db.stop() }
        runCatching { network.close() }
    }
}

private fun <T> withStack(block: (TodoStack) -> T): T = TodoStack().start().use(block)

baseUrl 用的是 app.host 加 getMappedPort(8080),不是寫死的 localhost:8080,容器裡是 8080,對映到外面是 Docker 隨機挑的,這跟第 1 層 port = 0 再問 resolvedConnectors() 是同一個道理,port 只有一個地方知道

close() 裡每個 stop() 都包 runCatching,因為 readiness 那個測試會自己先把 db 停掉,收尾再停一次不該讓測試爆掉

Wait.forHttp 打的就是 day 33 那條 readiness,這是健康檢查第 1 次被拿來做它本來該做的事,判斷「現在該不該把流量送進來」,整組起到 readiness 回 200,這一輪 4 個測試各量一次,是 9791、8056、8942、8272 毫秒

不過這個數字有雜質,Testcontainers 起容器的時候每次都印一行警告

The architecture 'amd64' for image 'todo-api:slim' (ID sha256:8cc16e33ed58...) does not match the Docker server architecture 'arm64'. This will cause the container to execute much more slowly due to emulation and may lead to timeout failures.

day 33 那個 jib 設定沒有指定平台,建出來的是 amd64,而這台機器是 arm64,所以底下 8 秒有一部分是模擬的成本,postgres:18-alpine 也吃到同一件事,這一輪沒有去建一個 arm64 的 image 重量一次,文末記一筆

一趟完整的旅程

第 1 個黑箱測試從外面走完一遍,這裡所有的請求都是從容器外面發的,走的是 Docker 對映出來的 port

這一節到〈把 143 從一次手動量測變成一個斷言〉為止的每個測試都在 class BlackBoxTest 裡面,stack 是同一個檔案的 helper,把 Network、PostgreSQL 容器、app 容器跟一個對外的 HttpClient 包成一組,withStack { } 負責起這一組、跑完關掉,stack.db、stack.app、stack.client、stack.baseUrl 都是從它拿的

@Test
fun `the whole journey runs from outside the containers`() = withStack { stack ->
    runBlocking {
        val live = stack.client.get("${stack.baseUrl}/health/live")
        assertEquals(HttpStatusCode.OK, live.status)
        println("GET  /health/live      -> ${live.status} ${live.bodyAsText()}")

        val ready = stack.client.get("${stack.baseUrl}/health/ready")
        assertEquals(HttpStatusCode.OK, ready.status)
        println("GET  /health/ready     -> ${ready.status} ${ready.bodyAsText()}")

        val anonymous = stack.client.get("${stack.baseUrl}/todos")
        assertEquals(HttpStatusCode.Unauthorized, anonymous.status)
        println("GET  /todos 不帶 token -> ${anonymous.status} ${anonymous.bodyAsText()}")

        val login = stack.client.post("${stack.baseUrl}/login") {
            contentType(ContentType.Application.Json)
            setBody("""{"name":"alice","password":"$ALICE_PASSWORD"}""")
        }
        assertEquals(HttpStatusCode.OK, login.status)
        val token = blackBoxJson.decodeFromString<TokenResponse>(login.bodyAsText()).accessToken
        println("POST /login            -> ${login.status}")

        val created = stack.client.post("${stack.baseUrl}/todos") {
            bearerAuth(token)
            contentType(ContentType.Application.Json)
            setBody("""{"title":"黑箱測試買的牛奶","done":false}""")
        }
        assertEquals(HttpStatusCode.Created, created.status)
        val id = blackBoxJson.decodeFromString<Todo>(created.bodyAsText()).id
        println("POST /todos            -> ${created.status} ${created.bodyAsText()}")

        val psql = stack.db.execInContainer("psql", "-U", "todo", "-d", "todo", "-tAc", "select id, title from todos")
        assertContains(psql.stdout, "$id|黑箱測試買的牛奶")
        println("psql\n${psql.stdout.trim()}")

        val deleted = stack.client.delete("${stack.baseUrl}/todos/$id") { bearerAuth(token) }
        assertEquals(HttpStatusCode.NoContent, deleted.status)
        println("DELETE /todos/$id        -> ${deleted.status}")
    }
}

那些 println 是為了把回應留下來,斷言只看得到過或不過,看不到 body 長什麼樣,這一輪印出來的

GET  /health/live      -> 200 OK {"status":"up","database":null}
GET  /health/ready     -> 200 OK {"status":"up","database":"up"}
GET  /todos 不帶 token -> 401 Unauthorized {"status":401,"message":"請帶著有效的 token 再來","details":[]}
POST /login            -> 200 OK
POST /todos            -> 201 Created {"id":4,"title":"黑箱測試買的牛奶","done":false,"created_at":"2026-09-05T07:13:18.151838Z"}
DELETE /todos/4        -> 204 No Content

那個 401 的 body 是 day 26 定的固定 JSON,走的是 ErrorHandling.kt 的 respondFixedJson 而不是 ContentNegotiation,它在容器裡長得跟測試裡一模一樣,這是好事,代表那條路徑沒有相依於任何只有測試環境才有的東西

比較有意思的是中間那一步,execInContainer 那一行從資料庫容器那一側確認資料真的寫進去了,不是再問一次 API,那樣只會證明 API 跟自己講的一樣,psql 印出來的是

1|買牛奶
2|繳電費
3|寫 day 05 的文章
4|黑箱測試買的牛奶

前 3 筆是 day 20 那份 seed,第 4 筆是這個測試從 HTTP 那一端建的,整條路徑因此被確認了一次,HTTP 進來、day 21 的 Exposed 交易、day 23 的 Flyway 建的表、真的 PostgreSQL,中間沒有任何一段是替身

還有一個測試只做一件事,確認 image 不是用 root 跑的

@Test
fun `the image does not run as root`() = withStack { stack ->
    val id = stack.app.execInContainer("id").stdout.trim()

    assertContains(id, "uid=1000")
    println("id -> $id")
}

輸出是 uid=1000 gid=1000 groups=1000,day 33 的 jib { container { user = "1000:1000" } } 那一行,現在有測試驗證了

那個五秒的 503,完整的形狀是這樣

day 33 有一節叫〈那個 503 花了 5 秒〉,量到的是

01:48:32.740 INFO  [dw3z6sziqi2p] Application -- 503 GET /health/ready 5028ms

解釋是連線池的 connectionTimeout: "$DB_CONNECTION_TIMEOUT:5000",這次真的把資料庫容器停掉,從外面連打 6 次,發現第 1 次跟後面 5 次不一樣

@Test
fun `every readiness probe after the first waits for the connection timeout`() = withStack { stack ->
    stack.db.stop()
    runBlocking {
        val waits = (1..6).map {
            val asked = System.nanoTime()
            val ready = stack.client.get("${stack.baseUrl}/health/ready")
            val took = (System.nanoTime() - asked) / 1_000_000
            assertEquals(HttpStatusCode.ServiceUnavailable, ready.status)
            assertEquals("""{"status":"down","database":"down"}""", ready.bodyAsText())
            took
        }

        assertTrue(waits.first() < 1000, "第一次拿到的是池子裡那條已經死掉的連線")
        assertTrue(waits.drop(1).all { it > 4000 }, "之後每一次都要等滿 connectionTimeout")
        println("readiness $waits ms")

        val live = stack.client.get("${stack.baseUrl}/health/live")
        assertEquals(HttpStatusCode.OK, live.status)
        println("/health/live 在資料庫掛掉之後 -> ${live.status} ${live.bodyAsText()}")
    }
    println("app log\n" + stack.app.logs.lines().filter { it.contains("/health/ready") }.joinToString("\n"))
}

第 1 行的 stack.db.stop() 是整個測試的前提,app 容器還活著,資料庫沒了,這一輪 6 個數字是

[28, 5056, 5026, 5027, 5030, 5018] ms

app 容器自己的 log,看得更清楚

07:13:54.947 INFO  [oa2b480barjm] Application -- 200 GET /health/ready 55ms
07:13:55.105 INFO  [6vky1-/a34j8] Application -- 503 GET /health/ready 21ms
07:14:00.158 INFO  [vcdu+kbappiq] Application -- 503 GET /health/ready 5045ms
07:14:05.178 INFO  [uer/2c90baek] Application -- 503 GET /health/ready 5009ms
07:14:10.215 INFO  [7rcx9a/++5c0] Application -- 503 GET /health/ready 5021ms
07:14:15.244 INFO  [/h3jeoqjdnfa] Application -- 503 GET /health/ready 5022ms
07:14:20.265 INFO  [k+rjxxznpy3/] Application -- 503 GET /health/ready 5013ms

第 1 次只花 28 毫秒,是因為 HikariCP 手上還有一條連線可以給,isValid(1) 拿到一條已經斷掉的 socket,立刻回 false,之後池子空了,每一次都要重新開一條連線,而資料庫已經不在,於是等滿 5000 毫秒的 connectionTimeout

day 33 那個 5028 沒有寫錯,它量到的是穩定之後的狀態,要補的是前面那一下,也就是資料庫剛倒下去的第 1 秒,探測會很快回 503,之後才變成每次 5 秒,day 33 那節的結論不受影響,Kubernetes probe 的 timeoutSeconds 預設一秒,照這份設定探測仍會在 app 回 503 之前先 timeout,只是「之前」是從第 2 次探測才開始

/health/live 在整個過程中都是 200 {"status":"up","database":null},day 33 那個「資料庫掛掉不該重新啟動 app」的判斷從外面看也成立

憑證的兩道關卡不是同一道

day 33 還有一節叫〈憑證不給就起不來〉,這句話是對的,但在容器裡把 2 種情況分開測之後,會發現擋下來的是 2 道不同的關卡

完全不給 JWT_SECRET,容器 log 的第 1 行就是

Exception in thread "main" io.ktor.server.config.ApplicationConfigurationException: Required environment variable "JWT_SECRET" not found and no default value is present
	at io.ktor.server.config.yaml.YamlConfigKt.resolveReference(YamlConfig.kt:233)
	at io.ktor.server.config.yaml.YamlConfigKt.resolveReferences(YamlConfig.kt:196)
	at io.ktor.server.config.yaml.YamlConfigKt.swapEnvironmentVariables$replace(YamlConfig.kt:176)

這是設定那一層擋的,module() 根本沒有開始跑,這正是 day 27 定下「憑證不給版控預設值」那條規矩想要的效果

改成給一個空字串,設定那一關就過去了,空字串是一個合法的值,$JWT_SECRET 只要求那個變數存在

07:13:36.588 INFO  [no-call-id] Application -- Autoreload is disabled because the development mode is off.
Exception in thread "main" java.lang.IllegalArgumentException: Empty key
	at java.base/javax.crypto.spec.SecretKeySpec.<init>(Unknown Source)
	at io.ktor.server.sessions.SessionTransportTransformerMessageAuthentication.<init>(SessionTransportTransformerMessageAuthentication.kt:29)
	at io.ktor.server.sessions.SessionTransportTransformerMessageAuthentication.<init>(SessionTransportTransformerMessageAuthentication.kt:28)
	at com.cashwu.todo.ApplicationKt.module$lambda$14$0(Application.kt:114)
	at io.ktor.server.sessions.SessionsBuilderKt.cookie(SessionsBuilder.kt:242)
	at com.cashwu.todo.ApplicationKt.module$lambda$14(Application.kt:493)

Autoreload is disabled 那一行代表 application 已經開始啟動了,真正擋下來的是 install(Sessions) 裡那個 SessionTransportTransformerMessageAuthentication,也就是 day 32 加 cookie session 的時候放的 HMAC 金鑰,SecretKeySpec 不收空的 key

測試把 2 種情況擺在一起,bootWithSecret 是同一個檔案的 helper,餵一個 JWT_SECRET 進去起容器,回傳容器的 log 跟它有沒有起得來,傳 null 就是完全不設那個環境變數

@Test
fun `an empty jwt secret gets past the config layer but sessions still stop it`() {
    val (missingLog, missingBooted) = bootWithSecret(null)

    assertEquals(false, missingBooted)
    assertContains(missingLog, "ApplicationConfigurationException")
    println("不給 JWT_SECRET\n" + missingLog.lines().filter { it.isNotBlank() }.take(4).joinToString("\n"))

    val (emptyLog, emptyBooted) = bootWithSecret("")

    assertEquals(false, emptyBooted)
    assertEquals(false, emptyLog.contains("ApplicationConfigurationException"), "空字串過得了設定那一關")
    assertContains(emptyLog, "java.lang.IllegalArgumentException: Empty key")
    assertContains(emptyLog, "SessionTransportTransformerMessageAuthentication")
    println("給空字串\n" + emptyLog.lines().filter { it.isNotBlank() }.take(6).joinToString("\n"))
}

bootWithSecret 這裡有一個坑,容器啟動失敗之後 container.logs 拿到的是空字串,要在建容器的時候掛一個 ToStringConsumer,log 才收得到

private fun bootWithSecret(secret: String?): Pair<String, Boolean> {
    val network = Network.newNetwork()
    val db = todoPostgresContainer(network)
    db.start()
    val collected = ToStringConsumer()
    val app = todoAppContainer(network, secret)
        .withLogConsumer(collected)
        .withStartupCheckStrategy(OneShotStartupCheckStrategy().withTimeout(Duration.ofSeconds(60)))
    try {
        val booted = runCatching { app.start() }.isSuccess
        return collected.toUtf8String() to booted
    } finally {
        runCatching { app.stop() }
        runCatching { db.stop() }
        runCatching { network.close() }
    }
}

OneShotStartupCheckStrategy 是關鍵,預設的策略會等容器「起來並且維持著」,而這裡要的正好相反,是等它自己死掉再看死因

要注意的是,擋下空字串的是 day 32 才加進來的東西,JWT 那一側沒有對祕密長度做任何檢查,如果 day 32 沒有加 cookie session,一個空字串的 JWT_SECRET 會讓服務正常啟動,然後用空金鑰簽 token,這一筆記進文末的債

把 143 從一次手動量測變成一個斷言

退出碼 143 不是新發現,day 33 就量到了,也解釋過「143 是 128 加 15,代表容器收到 SIGTERM,並且在 Docker 改送 SIGKILL 前退出」,這一節做的是把那次手動量測變成每次都會跑的斷言

@Test
fun `docker stop makes the container exit with 143`() = withStack { stack ->
    val asked = System.nanoTime()
    stack.app.dockerClient.stopContainerCmd(stack.app.containerId).withTimeout(30).exec()
    val took = (System.nanoTime() - asked) / 1_000_000
    val state = stack.app.dockerClient.inspectContainerCmd(stack.app.containerId).exec().state

    assertEquals(143L, state.exitCodeLong)
    assertEquals(false, state.oomKilled)
    assertContains(stack.app.logs, "todo-pool - Shutdown completed.")
    println("stopContainer 花了 ${took}ms 退出碼 ${state.exitCodeLong} oomKilled=${state.oomKilled}")
    println("關機最後兩行\n" + stack.app.logs.lines().filter { it.contains("HikariDataSource") }.takeLast(2).joinToString("\n"))
}

stack.app.dockerClient 是 Testcontainers 開出來的 docker-java client,GenericContainer 自己沒有「送 SIGTERM 然後看退出碼」這種 API,stop() 是清理用的,會把容器一起移掉,退出碼就查不到了,所以這裡繞過它直接下 stopContainerCmd

多斷言 oomKilled 是因為 143 跟 137 只差一點,137 是 128 加 9 的 SIGKILL,代表容器沒有在寬限時間內自己結束、被強制砍掉,而記憶體不足被砍拿到的也是 137,2 個一起斷言,這條路才不會有一天悄悄從 143 掉到 137 而沒人發現

這一輪量到的是 1235 毫秒,退出碼 143,oomKilled 是 false

那個 1.2 秒有出處,ApplicationEngine.Configuration 的 shutdownGracePeriod 預設是 1000 毫秒,而 start() 註冊的 shutdown hook 呼叫的是不帶參數的 stop(),也就是吃這個預設值,前面那一節量到 grace period 是無條件等滿的,1.2 秒正好是那一秒加上收尾

day 33 量到的 STOP_SECONDS=0.21 比這個預設 grace 還短,2 次的量法不一樣,那次是 docker stop 這個 CLI 指令本身的耗時,這次是 Testcontainers 的 stopContainerCmd 呼叫到回傳,而且這一輪沒有把 day 33 那個情境重跑一次,所以 2 個數字不放在一起比

關機時 log 的最後 2 行

07:13:27.903 INFO  [no-call-id] c.z.h.HikariDataSource -- todo-pool - Shutdown initiated...
07:13:27.913 INFO  [no-call-id] c.z.h.HikariDataSource -- todo-pool - Shutdown completed.

day 18 那個「相依是 AutoCloseable 的話,application 停止時容器會自己關掉」的機制,在真的 SIGTERM 底下也成立,那 2 行是從容器裡撈出來的,不是測試環境模擬的

這套東西有多貴

./gradlew test --rerun-tasks 連跑 3 次

real 96.27
real 97.64
real 97.70

再把這 2 個新檔案暫時搬走,同一個指令再跑 3 次,當作對照組

real 22.19
real 22.26
real 21.99

所以這篇加的東西讓整套測試多花大約 74 秒

時間花在哪裡很清楚,耗時前幾名的 class

BlackBoxTest               5 個  72.455s
PostgresBehaviourTest      5 個   3.823s
TodoSocketTest            10 個   3.432s
EndToEndTest               6 個   3.316s
TransactionTest            8 個   2.014s
ExposedTodoRepositoryTest  3 個   1.594s

多出來的 70 幾秒裡,超過 72 秒是 BlackBoxTest,原因有幾個,5 個測試各自起一組容器,每組起到 readiness 回 200 要 8、9 秒,加起來就 35 秒,那個 readiness 測試自己還要等 5 次連線池逾時,又是 25 秒,憑證那個測試不只起一組,它為了分開測「不給」跟「空字串」起了 2 組,剩下的是每一組容器停掉、網路收回這些固定成本,這一輪沒有逐項拆開量

第 1 層便宜得多,EndToEndTest 6 個測試 3.316 秒,跟 TodoSocketTest 差不多,放進日常的 ./gradlew test 沒有問題

第 2 層不該每次都跑,day 25 那篇〈CI 那一關〉已經講過一次同樣的問題,當時是 Docker 的硬性相依,結論是「要分開的話可以用 JUnit tag 把容器測試標出來另外跑」,那個建議在這裡更成立,因為代價從幾秒變成一分多鐘,合理的分法是本機跟 pull request 跑前面那些,BlackBoxTest 留給 image 真的被建出來之後的那一段流程,畢竟它測的對象是 image,image 沒重建的話它驗的是舊的東西。這一輪沒有真的去加那個 tag,因為那牽涉到 CI 設定,而這個系列沒有 CI 設定可以改

說了這麼多,那花這些時間到底值不值得 ? 值得,而且應該一開始就寫,不是等到系統長大了才回頭補

測試金字塔最下面是單元測試,快又多,每改一行都能跑,往上每一層都更慢、數量更少,但離真正要上線的東西更近,BlackBoxTest 就在最上面那一格,它回答的不是某個函式對不對,而是「這個 image 丟上去會不會動」,環境變數有沒有接上、非 root 跑不跑得起來、SIGTERM 之後怎麼收尾,這幾個問題下面每一層都答不了

所以慢是它換來的代價,不是它的缺點,實務上的用法是開發的時候不跑,push 上去的時候跑一次,當成 CI / CD 部署流程之前的最後一道防線

跟 Relix 的對照

Relix 跑在 JDK 內建的 HttpServer 上,Relix 系列的 day 31 那篇寫得很清楚,「Relix 用 com.sun.net.httpserver.HttpServer 當底層引擎,好處是零依賴、API 簡單,限制也很明顯」

有意思的是,這篇做的事情 Relix 其實做過一半,那個系列的示範是真的起一台 server 再從外面 curl,day 30 那些回應都是這樣來的,連 Www-authenticate 的大小寫是「JDK HttpServer 正規化過的」這種細節都寫進去了,那就是 end to end,只是手動的

而 Relix 的測試走 relixTest { },跟 testApplication 一樣在 process 裡,所以 2 個系列是同一個形狀,測試在 process 內,示範走真的 HTTP,中間那條「自動化的真 HTTP」兩邊都沒有補,這篇補的就是那條

Relix 手動起 server 踩過的坑,正好是 port = 0 加 resolvedConnectors() 在解的問題,Relix 系列的同一篇 day 31 寫過 2 個

還有一點,main() 裡例外飛出來的時候 app.stop() 不會執行,JDK HttpServer 的 thread 不是 daemon thread,JVM 不會跟著結束,8080 會一直被佔住,下一次跑就變成 Address already in use,遇到的話先確認上一輪的 process 還在不在

以及

server 起在 8080,smoke test 卻打 9999,跑起來就是一行 Relix started on 0.0.0.0:8080 之後接一個 java.net.ConnectException: Connection refused

2 個都是「port 這個數字被寫在 2 個地方」造成的,測試裡給 0 再問 engine 要答案,這 2 種踩法都不會發生,因為只有一個地方知道 port 是多少,而那個地方就是 engine 自己

另一個對照沒那麼好看,Relix 手刻的時候不需要煩惱 graceful drain,因為它沒有那個功能可以誤會,Ktor 給了 stop(gracePeriodMillis, timeoutMillis) 這個簽名,看起來像是把問題解決了,實際上它解決的是「handler 跑不跑得完」而不是「回應送不送得到」,框架給的東西比手刻多,要確認的東西也跟著多一項

小結

這篇補上 2 層 end to end,第 1 層用 EngineMain.createServer 加 -port=0 起真的 Netty,用 resolvedConnectors() 問出實際的 port,再用真的 HttpClient 打進去,6 個測試 3.316 秒,第 2 層用 Testcontainers 起 day 33 那個 image 加一個 PostgreSQL,從容器外面走完登入、建立、查詢、刪除,再從資料庫容器那一側用 psql 確認資料真的寫進去了

看到 4 件前面測不到的事,Netty 對請求起始行有 4096 個 byte 的上限,超過就是 400 而且 routing 完全不會被叫到,同一個請求在 testApplication 裡 100000 個字元照樣進 handler,stop(grace, timeout) 不是 graceful drain,連線在關機的第一時間就斷,handler 照樣跑完而且 respondText 不丟例外,回應靜靜地掉了,day 33 那個 5 秒的 503 只有第 2 次之後才是 5 秒,第 1 次是幾十毫秒,差別在連線池手上還有沒有那條已經死掉的連線,憑證那 2 道關卡不是同一道,空字串過得了設定那一層,擋下它的是 day 32 才加進來的 cookie session

代價是 ./gradlew test 從 22 秒變成 96 秒,多出來的幾乎全是黑箱那 5 個測試,這種測試值得寫,但不值得每次都跑

留下的問題有 4 個,graceful drain 只量到行為,沒有追到是哪一個動作關掉了連線,也沒有試著修,空字串的 JWT_SECRET 目前是靠 day 32 的 cookie session 擋下來的,JWT 那一側對祕密長度沒有任何檢查,BlackBoxTest 沒有用 JUnit tag 從日常的 ./gradlew test 分出去,也沒有在測試裡觸發 jibDockerBuild,image 是舊的它不會抱怨,最後是 day 33 的 jib 沒有指定平台,建出來的 image 是 amd64,在這台 arm64 機器上是模擬跑的,黑箱那幾個秒數因此偏高


下一篇

下一篇不加新的東西,改成處理一件從一開始到現在都沒有正面講的事,主程式全部平放在同一個 package,官方文件其實有一頁專門講 application 該怎麼分,會拿那頁的表比對和重構一次


參考資料


同步刊登於 Blog

圖片來源:AI 產生


上一篇
Kotlin Ktor 實戰 101 Day 33 部署,fat JAR、Docker 與健康檢查
系列文
Kotlin Ktor 實戰 101 共 34 篇
圖片
  熱門推薦
圖片
{{ item.channelVendor }} | {{ item.webinarstarted }} |
{{ formatDate(item.duration) }}
直播中

尚未有邦友留言

立即登入留言