這次查裝置日誌的 500,讓我印象最深的是,兩個各自有道理的決定,隔了幾個月疊在一起才出事。而且兩個都是我做的。

一開始是 console 的裝置日誌頁面回 500。Sentry 上是 Elasticsearch timeout,十月初每天個位數,10/07 變 61 次,10/08 變 111 次。流量沒變,寫入量也沒變,每天還是 250 萬筆上下。

我把同一個查詢對 production 的 ES 重放,跑了 20 秒。UIS 等 ES 的上限是 15 秒,所以使用者看到的是 timeout。ES 的回應裡還有一個 shard failure:

CircuitBreakingException: [fielddata] Data too large,
data for [_id] would be [1.6gb], which is larger than the limit of [1.5gb]

_id 排序為什麼會吃記憶體

一般欄位寫入時就會建好排序用的 doc values,排序直接讀磁碟上的那份。_id 沒有 doc values。要按它排,ES 得把整個 shard 每一筆的 _id 讀進 heap 建成 fielddata,不是只讀命中的那幾筆,而且讀進去就留著,直到有人清掉或 index 被刪。

ES 對這種記憶體有一道 circuit breaker,每台 node 加總不能超過 heap 的 40%,這裡是 1.5 GB,超過就拒絕查詢。

那時候正在寫的 index 是 14 天週期的尾端,3,950 萬筆、7.4 GB。它一個 shard 的 _id 要將近 1 GB,冷讀就是那 20 秒。前一個週期的 index 還有 590 MB 留在同一台 node 上,兩個加起來,過線。

這兩個決定都是六、七月的我做的

六月的時候,ES 的 heap 長期在 70%,CPU 很閒。查下去是裝置時鐘亂跳,一台跑到 2036 年的裝置上傳日誌,Logstash 就按那個時間戳建一個 2036 年的 index。幾百個這種幾乎空的 index,每個 5 primary 加 5 replica 共 10 個 shard,就是幾千個 shard,每個都佔一點 heap。

我把 index template 改成 1 primary,舊的等 retention 自己刪。不碰既有資料,heap 的目標達成了。

七月,日誌頁面翻到很後面會撞 ES 一萬筆的上限,我把分頁改成 search_after。這種翻法需要一個同時間時決勝負的欄位,我用了 _id。當時評估的是翻頁不重複不漏,沒有想到記憶體。7.x 對 _id 排序其實會發 deprecation warning,我沒去看。

兩張票是同一天開的,我沒有把它們放在一起看。

後來我算了一次,如果六月還是 5 個 shard 會怎樣。5 primary 加 5 replica 是 10 份,散在 3 台 node 上,每台大約 3.3 份,每份 200 MB,再加前一週期攤過來的 390 MB,每台大約 1 GB 出頭,離 1.5 GB 還有三成,而且 5 份平行讀。改成 1 shard 之後,是兩台 node 各扛完整的 1 GB,單機從頭讀到尾。

總量其實一樣,差別是集中了。_id 排序乘上資料成長是成本的來源,1 shard 決定的是在哪個週期、哪兩台 node 越線。這件事在七月就算得出來,只是沒有人去算。

九月那次盤點,我看到了,但量錯了東西

九月中我盤過 production 的 index。設定上同時只該有 3 個裝置日誌 index,實際有 69 個,但只有 73 個 shard。扣掉一個 5 shard 的,剩下 68 個全是 1 shard,都是六月之後建的。六月前那幾百個舊 index,retention 確實清掉了。

那 68 個裡,61 個是裝置補傳舊日誌時,Logstash 按舊時間戳把剛刪掉的 index 又建回來,隔天 retention 再刪一次,兩邊在打乒乓。這個原因十月才找到。

retention 真正漏掉的是那個 5 shard 的:dls-device-logs-2026-p%{period}。Logstash 算不出週期,變數沒被換掉就拿去當名字。清理程式靠名字裡的週期數字算年齡,對不上就跳過。它的時間欄位被 mapping 成 text,任何按時間排序都在它身上失敗。UIS 查日誌用 pattern 掃所有 index,每次都掃到它,十天 13,620 次 shard failure。

當時我量了最重的裝置,冷查詢 2.4 秒,就寫下「這是 housekeeping 問題,不是延遲問題」。我量的是正常狀態下的單次延遲。等 _id 讓查詢從 1 秒變 20 秒之後,每次還要多掃幾十個 shard、在壞 index 上多失敗一次,它就從噪音變成放大器。放大了多少我沒有數字,search slow log 當時是關的。

修法,還有一個順序

當天的止血是 DevOps 把前一週期的 fielddata 清掉,查詢從 20 秒回到 0.8 秒。不過現在這個週期每天還會長 60 MB,一週後要再清一次。

排序改成 _index 加 _seq_no,兩個都有 doc values,heap 不用載東西。前提是日誌只追加不更新,_seq_no 才穩定。其他用同樣排序的查詢一起改。

查詢改成只打時間範圍會落到的那幾個 index,不再掃全部。Logstash 算不出週期就用伺服器時間,不再生出壞名字。壞的那個 index 關掉之後刪。

DevOps 提議把 index 改成 3 個 shard,在幾千個小 shard 和一個 4,000 萬筆的大 shard 之間找平衡。但 _seq_no 是每個 shard 自己的流水號,多 shard 會撞號。要先在寫入時給每筆一個全域唯一的欄位,再加 shard;反過來做,分頁會在切 shard 那一刻開始漏資料。六月沒做的交叉檢查,這次做了。

這次讓我學到,改 shard 數的時候,要順手把現有查詢裡跟 shard 大小成正比的操作算一遍,fielddata 是一個,aggregation 也是。說「交給 retention」的時候,要寫清楚它看得到哪些名字。量到「不慢」的時候,要寫是在什麼前提下量的。修正現在合進 QA,還沒上 production;production 靠清記憶體撐著,10/15 前後要再清一次。不能只看 PR 合了就說這件事結束了。