現在剩下的零星失敗有兩個來源。第一是 PM2 reload 時,有大約 1 秒沒有任何 worker 在 listen;這是設定問題,可以修。第二是 Cloudflare tunnel 的連線偶爾斷線重連,不是 app 的問題。LINE console 的錯誤變少,主要是因為 9/28 起 reload 從每小時改成每 3 小時。#417 沒有處理到主要原因。#416 看起來有效。
10/1 02:16 UTC merge,release/20261001。prod container 於 10/1 04:26 UTC(台灣 12:26)重建,之後沒有再換。
LINE console 的錯誤和 Cloudflare 的非 200 紀錄一筆一筆都對得上(LINE 顯示 JST,換成 UTC 後時間一致)。cloudflared 的 log 也能對到每一筆,所以可以看出每次失敗的原因。
reload 每次約有 2–4% 機率掉 1–2 個 webhook,#417 前後一樣。每天失敗變少,是因為 reload 從每天 24 次降到 8 次。#417 上線後 5 天共 6 筆失敗:2 筆來自 reload,4 筆來自 tunnel 斷線。
目前每 3 小時一次(UTC :15)。reload 造成的失敗主要是 PM2 沒等新 worker 開始 listen 就停掉舊的(見下方)。修好後 reload 頻率對失敗數的影響應該會小很多。
10/4、10/5 兩次無法用 reload 解釋的失敗,時間點都對上 cloudflared 的 tunnel 斷線重連。9/19–9/27 那波 499 仍然沒有答案:只有 line-bot 受影響、和 tunnel 斷線對不上,大多數請求也沒有在 cloudflared 留下紀錄。那段時間 app 是 3 月起就沒換過的同一個 image,9/28 除了 cron 也沒有其他變動。
日期以 UTC 計。「reload/部署瞬間」指發生在 PM2 reload 或部署後 20 秒內的失敗(:15:00–:15:20)。403/405 是無關的掃描流量,已排除。每天總請求數約 1 萬筆。
| 日期 | 499 | reload | 其他 502 |
|---|
9/6–10/5,所有 line-bot.cofacts.tw 路徑,以「事件」計(同一秒內的多筆算一次)。
| cloudflared 錯誤 | 代表什麼 | #416 前 | #416 後 |
|---|---|---|---|
dial tcp … connection refused,發生在 reload/部署當下 | 那一瞬間沒有 worker 在 listen | 10 | 3 |
connection reset by peer,發生在 reload 當下 | 舊 worker 結束時切斷 keep-alive 連線 | 4 | 1 |
reset、server closed idle connection、broken pipe,平常時段 | keep-alive 逾時的 race(#416 處理的問題) | 5 | 0 |
tunnel Retrying connection 同時發生 | Cloudflare 與 cloudflared 之間的 QUIC 連線斷線 | — | 2 |
#416 在 9/26 08:21 UTC 上線。前一列在 #416 前的 20 天出現 5 次,之後 10 天 0 次,看起來 #416 有效。
10/5 00:15 那次 reload 的時間線(PM2 與 app log):
| UTC | 發生什麼 |
|---|---|
| 00:15:02.1 | 新 worker 0、1 啟動,PM2 標示為 online |
| 00:15:05.1 | 3 秒後 PM2 就停掉舊 worker 0、1。此時新 worker 還沒開始 listen,只剩舊 worker 2 在接請求 |
| 00:15:08.4 | PM2 停掉舊 worker 2。此時沒有任何 worker 在 listen |
| 00:15:08–09 | cloudflared 收到 connection refused ×2,也就是 LINE console 上 JST 09:15:09 的那 2 筆 502 |
| 00:15:09.1 | 新 worker 終於印出 Listening port 5001,距離啟動約 7 秒 |
app 啟動到開始 listen 大約要 7 秒,但 ecosystem.config.js 沒有設定 wait_ready。PM2 只等預設的 listen_timeout(3 秒)就認定新 worker 已就緒,開始停舊的。修法(#418)是設定 wait_ready: true,在 server.listen 的 callback 裡 process.send('ready'),並把 listen_timeout 拉到 15 秒左右。
#417 改的是舊 worker 的關閉流程,對這個問題沒有幫助。而且舊 worker 收到 SIGINT 後 60–200ms 就結束(handler 沒有等 server.close(),Node 16 也不會主動關閉閒置的 keep-alive 連線),所以 kill_timeout 也沒有用到。reset 這類失敗目前很少,可以晚點再處理。
cloudflared 和 Cloudflare 之間維持 4 條 QUIC 連線。其中一條逾時(no recent network activity)後會重連,期間走那條連線的請求就會失敗。這個月大約每 2–3 天發生一次。
| LINE console(JST) | cloudflared(UTC) | 結果 |
|---|---|---|
| 10/5 08:36 | 10/4 23:36:07 重連,23:36:19 恢復 | 502 ×2 |
| 10/5 16:48 | 10/5 07:48:38 兩條同時重連,07:49:07 恢復 | request_timeout ×2 |
目前跑的 cloudflared 是 2026.3.0,log 一直提示建議升到 2026.9.0。升版不一定能消除斷線,但成本低,值得先做。
context canceled。大部分請求在 cloudflared 那邊沒有錯誤紀錄。/callback 驗完簽章後就直接回 200,處理是非同步的,所以正常情況下不應該慢到讓 LINE 放棄。和 cron 調整的時間吻合,但 9/6–9/17 cron 也是每小時,當時沒有出現,所以還不能下結論。下一步可以看那幾個晚上 app 的 event loop 是否被卡住,或是 LINE 平台那段時間是否有異常。
PM2 加上 wait_ready(已開 PR:cofacts/rumors-line-bot#418):在 server.listen 的 callback 裡送 process.send('ready'),listen_timeout 設 15 秒。這可以處理目前 reload 失敗的大部分。
升級 cloudflared,從 2026.3.0 升到 2026.9.0。
確認 LINE 的 webhook redelivery 有沒有開。有開的話,tunnel 斷線這類短暫失敗會自動重送,影響就很小。
之後再處理:SIGINT handler 改成等 server.close() 完成並關閉閒置連線(Node 18 以上有 closeIdleConnections())。Apollo API key 失效造成的 401/406 log 也順手清掉。