工程師與貓
ESC
Content
    ↑↓ navigate open esc close
    Published on

    三成的 500 卡在剛好 10 秒:undici 預設的 connect timeout

    Authors
    • avatar
      Name
      Alex Yu

    那是四月底的一個晚上。網站開始一波一波回 500,也就是伺服器自己出錯的那種錯誤頁。

    這些數字是從 ALB 的紀錄看到的。ALB(Application Load Balancer)擋在我們網站最前面,負責把使用者的請求分給後面幾台伺服器,每一筆請求它都會留一行記錄。4.5 小時內出現 16 波,總共 1,941 筆 500。

    一波大概一兩分鐘,然後自己好。隔十七、十八分鐘再來一次。

    那三個月我們已經有過四次 5xx,但沒有一次是這樣。

    前情提要:一個請求會經過哪幾層

    先講一個請求從瀏覽器出發、到畫面出來為止,中間會經過哪些東西。後面查到的每一個數字,都是其中某一段花掉的時間。

    瀏覽器 → CDN → ALB → Next.js pod(nginx + Node)→ 後端 API
                              └─ SSR 期間還要再去拿一次資料

    最後那一行是這次的重點。頁面在伺服器上渲染的時候還要去拿資料,那個請求是從 pod 自己發出去的。所以「等後端回應」這件事,在 SSR 這一段會再發生一次,而它卡住的時候,卡住的是整個頁面。

    這個安排配上兩個決定,回後端的量會被放大:

    // Next.js 自己的頁面快取全關,快取交給 CDN 一層處理
    export const dynamic = 'force-dynamic'
     
    // SSR 拿資料一律不快取
    await fetch(`${apiBaseUrl}/articles/${id}`, { cache: 'no-store' })

    這條線我在爬蟲把 search 頁打掛那篇寫過,這裡不重複。

    前面四次都不是這個原因

    那三個月的紀錄長這樣:

    那三個月有三次是爬蟲把搜尋頁的 CPU 吃滿,一台伺服器撐不住、流量轉到下一台,跟著一起倒。另外一次是後端自己滿載,回應時間整段拉長。

    四次都是「有人或有什麼東西真的把它打爆了」。所以 04-26 這次,我一開始也往流量的方向查。

    結果對不上:

    • 後端全程 0 個 5xx,回應時間維持在正常的毫秒級。逐支 API 查也一樣。
    • 前一天同時段只有 8 筆 5xx。
    • 流量只有平常的 1.5 到 2 倍,來源分布正常,台灣為主,正常瀏覽器加合法的 bot。
    • 每一顆 pod 都均勻中彈,不是某一顆壞掉。

    同一批 pod 上,正常請求是毫秒級,噴 500 的那些竟然平均十幾秒。

    卡在 10 秒的那一組

    我把這 1,941 筆照「ALB 等後端回應等了多久」(target_processing_time)分成幾組:

    處理時間筆數占比區間寬度每秒筆數
    < 5s47224.3%5.0s約 94
    5–9.5s27514.2%4.5s約 61
    9.5–10.6s55628.6%1.1s約 505
    10.6–15s22111.4%4.4s約 50
    15–19.5s1226.3%4.5s約 27
    19.5–21.5s1306.7%2.0s約 65
    21.5–30s824.2%8.5s約 10
    30–60s834.3%30.0s約 3

    最後一欄才是重點。這些區間的寬度不一樣,只看筆數會被騙:筆數第二多的是 10.6 到 15 秒那組(221 筆),但它橫跨 4.4 秒;9.5 到 10.6 秒那組只有 1.1 秒寬,卻裝了 556 筆。

    換算成每秒幾筆,10 秒那個區間比隔壁高一個量級。這種形狀通常代表撞到了某個 timeout 的預設值。如果只是那批請求比較慢,數字會散在一個比較寬的範圍裡,不會像這樣集中在一個窄窄的區間。

    19.5 到 21.5 秒那個區間是第二個凸起。把兩個凸起跟它們左右的區間擺在一起看:

    凸起的區間每秒筆數左邊區間右邊區間比左右區間高幾倍
    9.5–10.6s約 505約 61(5–9.5s)約 50(10.6–15s)8 到 10 倍
    19.5–21.5s約 65約 27(15–19.5s)約 10(21.5–30s)2 到 6 倍

    所以 20 秒那個區間也是真的凸起,只是沒有 10 秒那麼極端。

    我會注意它,是因為那個區間在秒數上剛好是 10 秒的兩倍(不是筆數兩倍,也不是占比兩倍):同一次渲染裡連續打兩支 API、兩支都等滿 10 秒,加起來就是 20 秒。這是我的推測,我沒有把那 130 筆的紀錄撈出來對。

    兩個凸起加起來 35.3%。剩下的六成多沒有這麼整齊,其中 24.3% 落在 5 秒以內,那些是很快就失敗的錯誤。

    先把話說清楚:這篇只解釋得了最大的那一組,剩下的六成我沒有答案。

    我去查我們打 API 的那一層,timeout 一個都沒設,用的全是預設值。

    為什麼是 10 秒:undici 的 connect.timeout 預設值

    我們的 Next.js 跑在 Node 24,SSR 期間用內建的 fetch。Node 的 fetch 底層是 undici

    undici 裡負責對外連線的東西叫 Agent。它替每一個網域維護一個連線池,決定要開幾條連線、閒置的連線留多久、什麼時候重用、什麼時候放棄。你沒有自己指定的話,fetch 用的就是一個預設的 Agent,而那些預設值是這樣:

    // undici Agent 的預設值(節錄)
    {
      connect: { timeout: 10_000 },     // 建立連線最多等 10 秒
      keepAliveTimeout: 4_000,          // 請求做完後,這條連線閒置 4 秒才關
      keepAliveTimeoutThreshold: 2_000, // 伺服器說它留 N 秒時,我們自己減掉 2 秒的安全邊界
      headersTimeout: 300_000,          // 連上了但等不到回應,最多等 5 分鐘
      // ...
    }

    上面那些數字中間的底線是 JavaScript 的數字分隔符,10_000 就等於 10000,只是位數多的時候比較好讀。單位都是毫秒,所以 10_000 是 10 秒、4_000 是 4 秒、300_000 是 5 分鐘。

    四個參數管的是不同階段:

    • connect.timeout:連線還沒建立起來的那一段。TCP 加 TLS 握手都算在裡面。
    • keepAliveTimeout:請求做完之後,這條連線不要馬上關,留著給下一個請求用,閒置超過這個時間才關掉。
    • keepAliveTimeoutThreshold:有些伺服器會在回應裡用 Keep-Alive: timeout=N 告訴你它打算留多久。undici 會把 N 減掉這個邊界當成自己的閒置時間,免得在伺服器正要關的那一瞬間送出請求。
    • headersTimeout:連線建立好了,但對方一直不回第一行回應,最多等這麼久。

    這次的線索是第一個。10 秒到了,connect.timeout 才丟例外。

    第一個假設,被我們自己的測試推翻

    SRE 同事的第一個猜測是:CDN 會回收閒置的連線,我們的 fetch 從連線池裡拿到一條已經死掉的連線,送出去沒有下文。

    本以為就是這個。我在筆電上把幾種斷線方式都跑一遍,Node 20 和 Node 24 各跑一輪:

    情境(Node 24)失敗率失敗前等了多久錯誤碼
    server 正常關掉閒置連線(FIN)0%沒有失敗
    server 回完就送 RST0%沒有失敗
    連線靜默斷掉(不送 FIN/RST)40%301,533 msUND_ERR_HEADERS_TIMEOUT
    新的連線建不起來100%10,543 msUND_ERR_CONNECT_TIMEOUT

    表格第三列是關鍵。如果真的是「重用一條死掉的連線」,會卡到 headersTimeout 的 5 分鐘才失敗。而正式站那張表的八組加起來就是全部的 1,941 筆,最久的一組也只到 60 秒,根本沒有卡到 5 分鐘的資料

    所以方向反過來了。真正卡住的是重新建連線那一步:舊連線被判定不能用,於是開一條新的,而那條新的連不上。

    最後一種情境用一個封包會被直接丟掉的 IP 就能重現。192.0.2.1 是 RFC 5737 保留給文件用的位址:

    // connect-test.mjs
    const t0 = Date.now()
    try {
      await fetch('http://192.0.2.1/')
    } catch (e) {
      console.log(`FAIL in ${Date.now() - t0}ms: ${e.cause?.code}`)
    }
    $ node connect-test.mjs   # Node 24
    FAIL in 10543ms: UND_ERR_CONNECT_TIMEOUT

    10.5 秒,跟正式站那 556 筆對得上。

    順便也測掉一個假設:我們三月才從 Node 20 升到 Node 24,很自然會懷疑是升級把問題放大了。兩版的 connect.timeout 預設值都是 10 秒,實測 10053 毫秒對 10543 毫秒,這一層沒有差異

    至於那 10 秒裡發生了什麼:那個 SSR 請求一直掛在 pod 上。它佔著一個正在渲染的頁面、一份記憶體,還有 ALB 那一條連線。同時卡著的請求越積越多,pod 就開始整批回 500。

    我沒有排除掉的另一個解釋

    寫這篇的時候我回頭翻了公開的 issue,發現一件當時沒想到的事。

    先解釋一下 Happy Eyeballs。這是一套標準做法(RFC 8305),要解決的是「IPv6 到底通不通」。

    一個網域名稱常常同時有 IPv6 和 IPv4 的位址。如果照順序一個一個試,而 IPv6 那條剛好不通,使用者就得等第一個位址超時才會換下一個。Happy Eyeballs 的做法是不要乾等:先試第一個,過一小段時間還沒成功就同時去試下一個,誰先接通就用誰。

    Node 從 20 開始預設打開它(參數叫 autoSelectFamily),每個位址等 250 毫秒還沒成功就去試下一個。undici 沒有把這個開關關掉,所以吃的是 Node 的預設。

    而 undici v7 沒有 v8 後來補的錯誤正規化。如果位址清單裡最後一個候選剛好被黑洞掉,那次嘗試不受 250 毫秒的限制,就會一路撐到 undici 自己的 10 秒,丟出來的錯誤碼一樣是 UND_ERR_CONNECT_TIMEOUT

    所以「一個 IP 連不上」和「Happy Eyeballs 把整個清單走完」,在錯誤碼跟秒數上長得一模一樣。而我的本地重現用的是寫死的 192.0.2.1,沒有 DNS、只有一個位址,它證明了 10 秒是 connect.timeout,但證明不了是哪一種。

    要分辨其實只差一個欄位:

    ConnectTimeoutError: Connect Timeout Error
      (attempted address: 203.0.113.10:443, timeout: 10000ms)
      ↑ 單數。只有一個位址,我的說法成立
     
      (attempted addresses: 2001:db8::1:443, 203.0.113.10:443, ..., timeout: 10000ms)
      ↑ 複數。清單走完了,主因要改寫成 Happy Eyeballs

    當時的 log 沒有留這一段。下一次要先撈這個欄位再下結論。

    順帶一提,10 秒為什麼實際量到 10.5 秒:undici 的計時器解析度是半秒,所以 10,000 毫秒的上限實際會在 10.0 到 10.5 秒之間觸發。ALB 那組落在 9.5 到 10.6 秒,剛好對得上。

    為什麼不在全域改

    那把 timeout 改短不就好了?一開始的修法確實是這樣寫的,在啟動檔裡換掉整個 process 的預設:

    // ❌ 換掉整個 process 的 dispatcher
    import { setGlobalDispatcher, Agent } from 'undici'
    setGlobalDispatcher(new Agent({ connect: { timeout: 3_000 } }))

    但這會影響同一個 process 裡所有對外的 fetch,包含錯誤追蹤工具送事件、OpenTelemetry(OTEL)的 trace export、第三方 SDK 的請求。它們沒出問題,我不想為了修一條路徑,把它們的行為一起改掉。

    所以範圍縮成「只給打後端 API 的那個 client 一個專屬的 dispatcher」。dispatcher 是 undici 裡負責送請求、管連線的物件,fetch 可以用參數指定要用哪一個。

    改完的長相

    // lib/api/client.ts
    let ssrDispatcherPromise: Promise<unknown> | undefined
     
    function getSsrDispatcher(): Promise<unknown> | undefined {
      if (typeof window !== 'undefined') return undefined         // ← client 不用
      if (process.env.NEXT_RUNTIME !== 'nodejs') return undefined // ← Edge 不用
      if (!ssrDispatcherPromise) {
        ssrDispatcherPromise = import(
          /* webpackIgnore: true */ 'undici'
        ).then(({ Agent }) => {
          return new Agent({
            keepAliveTimeout: 4_000,
            keepAliveTimeoutThreshold: 1_000,
            connect: { timeout: 3_000 }, // ← 從 10s 改成 3s
          })
        })
      }
      return ssrDispatcherPromise
    }
     
    export class ApiClient {
      // ...
      async request(endpoint: string, init: RequestInit) {
        const dispatcher = await getSsrDispatcher()
        const fetchInit = dispatcher ? { ...init, dispatcher } : init
        return fetch(url, fetchInit)
      }
    }

    同一個會被丟封包的 IP,換上 3 秒的 dispatcher 再測一次:

    $ node connect-test-fixed.mjs   # connect.timeout: 3_000
    FAIL in 3517ms: UND_ERR_CONNECT_TIMEOUT

    typeof windowNEXT_RUNTIME 雙重守衛

    undici 是 Node 專用的套件。光看 typeof window 不夠。Next.js 的 Edge runtime 也沒有 window,但它跑在 V8 isolate 裡,載入 undici 會在 import 階段就炸在 node:console 這類解不開的相依上。

    if (typeof window !== 'undefined') return undefined         // 排除 client
    if (process.env.NEXT_RUNTIME !== 'nodejs') return undefined // 排除 Edge

    webpackIgnore: true

    import(/* webpackIgnore: true */ 'undici')

    Next.js 會把 middleware 整包 bundle 成 Edge runtime 用的格式。即使上面已經有 runtime 的守衛,webpack 在編譯期還是會把 import('undici') 解析進 dependency graph、嘗試打包,然後在 Edge bundle 那一步炸掉。webpackIgnore 這個註解是告訴 webpack 別碰這個 import,留給 runtime 處理。

    dispatcher 是 lazy,而且整個 module 共用一個

    Agent 自己會管連線池,沒必要每個 request 都建一個。但放在 module 最上層又會在 Edge bundle 那一步被 evaluate 到,所以包成 Promise,第一次 request 才初始化。

    undici 的版本要釘對

    當時 undici 的最新大版本已經是 v8,但 Node 24 內建的 fetch 用的是 v7。我們自己裝的 Agent 是要傳給內建 fetch 用的,大版本對不上就接不起來,所以 package.json 要釘 ^7

    {
      "dependencies": {
        "undici": "^7.0.0"
      }
    }

    3 秒這個數字,我到現在還是有點心虛

    3 秒是猜的。票上我自己寫了風險:這個值對 SSR 的 fetch 偏短,如果後端冷啟動、建立連線真的需要超過 3 秒,正常的請求會被誤殺。

    而且我當初給自己的理由,後來發現有一半不成立。我那時想的是「早點失敗,那條連線就能放回池子,下一個請求可以直接拿去用」。寫這篇的時候去翻了 undici 的原始碼:

    // undici/lib/dispatcher/pool.js(節錄)
    this[kConnections] = connections || null   // ← 預設 null,等於不限制
     
    // 要拿連線的時候
    if (!this[kConnections] || this[kClients].length < this[kConnections]) {
      // 沒有空的就再開一條,不會排隊等那條卡住的
    }

    Agentconnections 預設就是不限制,而 Node 內建的 fetch 用的正是這個預設。所以下一個請求根本不必等那條卡住的連線,池子會直接再開一條。「把連線讓出來」要在池子有上限的時候才成立。

    3 秒真正換到的是另一件事:那次請求進來的網頁渲染會提早七秒結束,同一時間卡在 pod 上的請求就少一點。至於本來就會失敗的那些請求,還是會失敗。

    所以上線是分兩段走的:先在測試環境跑一天,再到正式站先開一顆 pod 觀察,真的不行就調回 5 秒,或者整個 revert。驗收條件本來還有一行啟動時印 log 確認 dispatcher 掛上了,上線前把那行拿掉了。

    而且那兩個 keep-alive 的參數,後來發現根本不用設。

    keepAliveTimeout: 4_000,          // ← 跟 undici 的預設一模一樣,等於沒設
    keepAliveTimeoutThreshold: 1_000, // ← undici 2024 年把這個預設提高到 2_000 了

    這三個值是我從自己寫的事故報告裡複製過來的。時間軸長這樣:

    04-26 晚上   事故發生,當晚查到 10 秒那條線索
    04-28        事故報告與本地重現的腳本整理好,進值班手冊
    04-30 早上   兩份文件加一包腳本掛回票上
    05-06        程式碼才開始寫,那三個值原封不動抄過去
    05-12        上線

    兩次搬動,中間隔了一週多,沒有人回頭把那三個值跟當下的預設對一次,包括我自己。

    1_000 曾經就是 undici 的預設,2024 年才被提高到 2_000,因為舊的算法配上 1 秒等於沒有緩衝。所以它看起來很正常,也就沒有人起疑。本地重現那四輪測試也測不到它:跟 keep-alive 有關的兩種情境結果都是 0% 失敗,這個參數從頭到尾沒有產生訊號。

    官方對這種情境的建議也不是把 connect timeout 調短。維護者在 issue 裡講的是用 retry interceptor 或 RetryAgent,要動 Happy Eyeballs 就去調每個位址的等待上限。縮短 timeout 只會讓失敗來得更快,不會讓失敗變少。

    review 只有 AI 跑過,沒有人類留言。它提了兩件事:dispatcher 的型別不該用 unknown、dynamic import 應該加 fallback。到現在兩件都還沒做。

    這次只解決了一部分

    那張票的驗收條件,一項都沒有勾。我沒有回頭撈一次紀錄,去證明 9.5 到 10.6 秒那一組真的變少了。

    剩下六成多的 500,這個機制也解釋不了。它為什麼每十七、十八分鐘來一次,那個節奏到現在都不知道從哪來。

    至於更根本的做法,方向我知道,那是另一張票的事,不在這篇的範圍。

    下次我會先做的三件事

    一、先看處理時間的分布,不要先看流量。

    我一開始往流量的方向查,是因為前面四次都是被打爆。但這次後端是健康的,真正有話講的是那張分布表。窄窄的區間裡堆出一個尖峰,通常代表撞到了某個預設值;攤平在很寬的範圍裡,那才是「就是比較慢」。

    二、把錯誤整包記下來,特別是 err.cause

    catch (e) {
      logger.error({
        code: e.cause?.code,          // UND_ERR_CONNECT_TIMEOUT
        message: e.cause?.message,    // 裡面有 attempted address 那一段
      })
    }

    Node 丟出來的第一層訊息常常只有 TypeError: fetch failed,看不出任何東西,真正的原因都在 err.cause 裡。

    少了那一段,「一個位址連不上」跟「Happy Eyeballs 把清單走完」會長得一模一樣,我到現在都還不能確定是哪一種。

    三、要改預設值之前,先去確認那個預設值現在是多少。

    我那三個參數是從自己一週前寫的文件抄過來的,其中一個在 2024 年就被上游調整過。抄的時候沒有人回頭對,包含我自己。

    還有一件更基本的:你沒有設 timeout,不代表沒有 timeout。Node 內建的 fetch 底下是 undici,它的預設值就是你的預設值。

    延伸閱讀

    參考資料