線上ES集群參數(shù)配置引起的業(yè)務異常案例分析
一、故障描述
1.1 故障現(xiàn)象
1). 業(yè)務反饋
業(yè)務部分讀請求拋出請求超時的錯誤。
2). 故障定位信息獲取
- 故障開始時間
19:30左右開始 - 故障拋出異常日志
錯誤日志拋出timeout錯誤。 - 故障之前的幾個小時業(yè)務是否有進行發(fā)版迭代。
未進行相關的發(fā)版迭代。 - 故障的時候流量是否有出現(xiàn)抖動和突刺情況。
內(nèi)部監(jiān)控平臺觀察業(yè)務側(cè)并沒有出現(xiàn)流量抖動和突刺情況。 - 故障之前的幾個小時Elasticsearch集群是否有出現(xiàn)相關的變更操作。
Elasticsearch集群沒有做任何相關的變更操作。
1.2 環(huán)境
- Elaticsearch的版本:6.x。
- 集群規(guī)模:集群數(shù)據(jù)節(jié)點超過30+。
二、故障定位
我們都知道Elasticsearch是一個分布式的數(shù)據(jù)庫,一般情況下每一次查詢請求協(xié)調(diào)節(jié)點會將請求分別路由到具有查詢索引的各個分片的實例上,然后實例本身進行相關的query和fetch,然后將查詢結(jié)果匯總到協(xié)調(diào)節(jié)點返回給客戶端,因此存在木桶效應問題,查詢的整體性能則是取決于是查詢最慢的實例上。所以我們需要確認導致該故障是集群整體的問題還是某些實例的問題導致的。
2.1 集群還是實例的問題
1). 查看所有實例的關鍵監(jiān)控指標
從監(jiān)控圖可以很明顯的綠色監(jiān)控指標代表的實例在19:30左右開始是存在異?,F(xiàn)象,在這里我們假設該實例叫做A。
- 實例A的指標
es.node.threadpool.search.queue的值長時間達到了1000,說明讀請求的隊列已經(jīng)滿了。 - 實例A的指標
es.node.threadpool.search.rejected的值高峰期到了100+,說明實例A無法處理來自于業(yè)務的所有請求,有部分請求是失敗的。 - 集群整體的指標
es.node.threadpool.search.completed有出現(xiàn)增長,經(jīng)過業(yè)務溝通和內(nèi)部平臺監(jiān)控指標的觀察,業(yè)務流量平緩,并沒有出現(xiàn)抖動現(xiàn)象,但是客戶端有進行異常重試機制,因此出現(xiàn)增長是因為重試導致。 - 實例A的指標
es.node.threadpool.search.completed相比集群其他實例高50%以上,說明實例A上存在一個到多個熱點索引。 - 實例A的指標
es.node.threadpool.cpu.percent的值有50%以上的增長。 - 可通過指標
es.node.indices.search.querytime和
es.node.indices.search.querytimeinmillis的趨勢可實例級別的請求耗時大致情況。
通過上面的分析,我們能給確認的是實例A是存在異常,但是導致業(yè)務請求超時是否是實例A異常導致,還需進一步分析確認。
2.2 實例異常的原因
到了這一步,我們能夠非常明確實例是存在異常情況,接下來我們需要定位是什么導致實例異常。在這里我們觀察下實例所在機器的MEM.CACHED、
DISK.nvme0n1.IO.UTIL、
CPU.SERVER.LOADAVG.PERCORE、CPU.IDLE這些CPU、MEMMORY、DISK IO等指標。
1). CPU or IO
通過監(jiān)控,我們可以很明顯的看得到,DISK.nvme0n1.IO.UTIL、
CPU.SERVER.LOADAVG.PERCORE、CPU.IDLE這三個監(jiān)控指標上是存在異常情況的。
DISK.nvme0n1.IO.UTIL上深紅色和深褐色指標代表的機器IO使用率存在異常,在這里我們假設深紅色的機器叫做X,深褐色的機器叫做Y。
CPU.SERVER.LOADAVG.PERCORE和CPU.IDLE這倆個反應CPU使用情況的指標上代表綠色的機器在存在異常,在這里我們假設綠色的機器叫做Z。
- 機器X的IO在故障時間之前就處于滿載情況,機器X在整個過程當中是沒有出現(xiàn)波動,因此可移除機器X可能導致集群受到影響。
- 機器Y的IO在故障時間之前是處于滿載情況,但是在故障期間IO使用率差不多下降到了50%,因此可移除機器Y可能導致集群受到影響。
- 機器Z的CPU使用率在在故障期間直線下降,CPU.IDLE直接下降到個位數(shù);CPU.SERVER.LOADAVG.PERCORE(是單核CPU的平均負載,2.5表示當前負載是CPU核數(shù)*2.5)直接增長了4倍,此時整個機器幾乎都是處于阻塞的情況;DISK.nvme0n1.IO.UTIL則是從20%增長到了50%左右。其中CPU的指標是直線增長,IO的指標則是一個曲線增長。
異常實例A所在的機器是Z,目前機器Z的CPU和IO都存在增長情況,其中CPU已經(jīng)到了系統(tǒng)的瓶頸,系統(tǒng)已經(jīng)受到了阻塞,IO的利用率從20%增長到了50%,雖然有所增長,但是還未到達磁盤的瓶頸。
通過上面的分析,我們比較傾向于機器Z的CPU的異常導致了實例A的異常。這個時候我們需要確認是什么原因?qū)е铝藱C器Z的CPU異常,這個時候可通過內(nèi)部監(jiān)控平臺的快照查看機器Z的快照信息。
通過內(nèi)部監(jiān)控平臺的快照,我們可以看到PID為225543的CPU使用率是2289.66%,166819的CPU的使用率是1012.88%。需要注意的是我們機器Z的邏輯核是32C,因此我們可認為CPU機器CPU的使用率理論上最高是3200%。但是使用率CPU最高的倆個實例的值加起來已經(jīng)是超過了這個值,說明CPU資源已經(jīng)是完全被使用完畢了的。
通過登陸機器Z,查詢獲取得到PID為225543的進程就是實例A的elasticsearch進程。
2). 實例CPU異常的原因
其實Elasticsearch本身是有接口提供獲取實例上的熱點進程,但是當時執(zhí)行接口命令的時候長時間沒有獲取到結(jié)果,因此只能從其他方案想辦法了。
獲取實例上的熱點進程:
curl -XGET /_nodes/xx.xx.xx.xx/hot_threads?pretty -s
實例A的CPU使用率高一般導致這個情況原因一個是并發(fā)過高導致實例處理不過來,另外一個則是存在任務長時間占據(jù)了進程資源,導致無多余的資源處理其他的請求。所以我們首先基于這倆個情形進行分析。
(1)是否并發(fā)度過高引起實例CPU異常
從之前的分析我們可以得知業(yè)務側(cè)的流量是沒有出現(xiàn)突增,search.completed的增長只是因為業(yè)務重試機制導致的,因此排除并發(fā)過高的原因了,那么剩下的就只有存在長任務的原因了。
(2)是否長任務導致實例CPU異常
根據(jù)_cat/tasks查看當前正在執(zhí)行的任務,默認會根據(jù)時間進行排序,任務running時間越長,那么就會排到最前面,上面我們得知異常的實例只有A,因此我們可以只匹配實例A上的任務信息。
curl -XGET '/_cat/tasks?v&s=store' -s | grep A
一般情況下大部分任務都是在秒級以下,若是出現(xiàn)任務執(zhí)行已超過秒級或者分鐘級的任務,那么這個肯定就是屬于長任務。
(3)什么長任務比較多
根據(jù)接口可以看得到耗時較長的都是relocate任務,這個時候使用查看接口/_cat/shards查看分片遷移信息,并且并發(fā)任務還很多,持續(xù)時間相較于其他任務來說很長。
curl -XGET '/_cat/shards?v&s=store' -s | grep A
由于當時是優(yōu)先恢復業(yè)務,因此沒有截圖,最后只能從監(jiān)控獲取得到這個時間是有進行relocate分片的遷移操作:
- es.node.indices.segment.count:實例級別segment的個數(shù)。
- es.cluster.relocatingshards:集群級別正在進行relocate的分片數(shù)量。
(4)什么原因?qū)е铝朔制w移變多
根據(jù)日常的運維,一般出現(xiàn)分片遷移的情況有:
- 實例故障。
- 人工進行分片遷移或者節(jié)點剔除。
- 磁盤使用率達到了高水平位。
根據(jù)后續(xù)的定位,可以排除實例故障和人工操作這倆項,那么進一步定位是否由于磁盤高水平位導致的。
查看實例級別的監(jiān)控:
查看master的日志:
[xxxx-xx-xxT19:43:28,389][WARN ][o.e.c.r.a.DiskThresholdMonitor] [master] high disk watermark [90%] exceeded on [ZcphiDnnStCYQXqnc_3Exg][A][/xxxx/data/nodes/0] free: xxxgb[9.9%], shards will be relocated away from this node
[xxxx-xx-xxT19:43:28,389][INFO ][o.e.c.r.a.DiskThresholdMonitor] [$B] rerouting shards: [high disk watermark exceeded on one or more nodes]
根據(jù)監(jiān)控和日志能夠進一步確認是磁盤使用率達到了高水平位從而導致的遷移問題。
(5)確認引起磁盤上漲的實例
通過內(nèi)部監(jiān)控平臺的DB監(jiān)控,查看機器級別上所有實例的監(jiān)控指標
es.instance.data_size
通過監(jiān)控我們分析可以得到淺黃色、深藍色、淺綠色三個實例是存在較大的磁盤數(shù)據(jù)量大小的增長情況,可以比較明顯導出磁盤增長到90%的原因是淺黃色線代表的實例導致的原因。
2.3 根因分析
針對實例A磁盤波動情況進行分析:
查看這個監(jiān)控圖,你會發(fā)現(xiàn)存在異常:
- 磁盤數(shù)據(jù)量的下降和上升并不是一個緩慢的曲線。
- 2023-02-07 19:20左右也發(fā)生過磁盤下降的情況。
出現(xiàn)磁盤的下降和趨勢一次性比較多的情況,根據(jù)以往的經(jīng)驗存在:
- 大規(guī)模的刷數(shù)據(jù)。
- relocate的分片是一個大分片。
- relocate并發(fā)數(shù)比較大。
第一個排除了,大規(guī)模的刷數(shù)據(jù)只會導致數(shù)據(jù)上升,并不會出現(xiàn)數(shù)據(jù)下降的情況,因此要么就是大分片,要么就是并發(fā)較大。
查看是否存在大分片:
# curl -XGET '/_cat/shards?v&s=store' -s | tail
index_name 4 r STARTED 10366880 23.2gb
index_name 4 p STARTED 10366880 23.2gb
index_name 0 r STARTED 10366301 23.2gb
index_name 0 p STARTED 10366301 23.2gb
index_name 3 p STARTED 10347791 23.3gb
index_name 3 r STARTED 10347791 23.3gb
index_name 2 p STARTED 10342674 23.3gb
index_name 2 r STARTED 10342674 23.3gb
index_name 1 r STARTED 10328206 23.4gb
index_name 1 p STARTED 10328206 23.4gb
查看是否存在重定向并發(fā)數(shù)較大:
# curl -XGET '/_cluster/settings?pretty'
{
... ...
"transient" : {
"cluster" : {
"routing" : {
"allocation" : {
"node_concurrent_recoveries" : "5",
"enable" : "all"
}
}
}
}
}
發(fā)現(xiàn)參數(shù)
cluster.allocation.node_concurrent_recoveries設置成了5,我們看下官方針對這個參數(shù)的解釋:
https://www.elastic.co/guide/en/elasticsearch/reference/6.3/shards-allocation.html
大致意思是同一個時間允許多個的分片可以并發(fā)的進行relocate或者recovery,我們就按照較大的分片數(shù)量20G*5,差不多就是100G左右,這個就解釋了為什么data_size的增長和下降短時間內(nèi)非常大的數(shù)據(jù)量的原因了。
到目前為止,我們能夠確認的是因為分片遷移的問題消耗了實例A很大的CPU資源,從而導致實例A的CPU指標非常的高。
三、解決方案
基于上面的分析,我們假設由于實例A的異常導致集群整的異常;基于這種假設,我們嘗試將實例A剔除集群,觀察集群和業(yè)務的請求是否能夠恢復。
3.1 猜想驗證
將實例的分片遷移到其他的實例上,執(zhí)行以下命令之后,可以明顯的發(fā)現(xiàn)實例上的請求基本上下降為零了,并且業(yè)務反饋超時也在逐步的減少,基于這個情況驗證了我們的猜想,是實例A的異常導致了業(yè)務的請求超時的情況。
curl -XPUT /_cluster/settings?pretty -H 'Content-Type:application/json' -d '{
"transient":{
"cluster.routing.allocation.exclude._ip": "xx.xx.xx.xx"
}
}'
3.2 根本解決
猜想驗證確認之后,那我們現(xiàn)在基于實例A的CPU的異常結(jié)果進行相關的優(yōu)化:
修改參數(shù)
cluster.routing.allocation.node_concurrent_recoveries
該參數(shù)默認值是2,一般是不建議修改這個參數(shù),但是有需要快速遷移要求的業(yè)務可以動態(tài)修改這個參數(shù),建議不要太激進,開啟之后需要觀察實例、機器級別的CPU、磁盤IO、網(wǎng)絡IO的情況。
修改參數(shù)
cluster.routing.use_adaptive_replica_selection
- 開啟該參數(shù)之后,業(yè)務針對分片的讀取會根據(jù)請求的耗時的響應情況選擇下次請求是選擇主分片還是副分片。
- 6.3.2版本默認是關閉了該參數(shù),業(yè)務默認會輪詢查詢主副分片,這在部分實例異常的情況會影響集群的整體性能。針對生產(chǎn)環(huán)境、單機多實例混合部署的情況下,建議開啟該參數(shù),對集群的性能有一定的提高。
- 7.x的版本默認是開啟了這個參數(shù)。
curl -XPUT /_cluster/settings?pretty -H 'Content-Type:application/json' -d '{
"transient":{
"cluster.routing.allocation.node_concurrent_recoveries": 2,
"cluster.routing.use_adaptive_replica_selection":true
}
}'
直接擴容或者遷移實例也是比較合適的。
四、總結(jié)
在本次故障,是由于集群參數(shù)配置不正確,導致集群的一個實例出現(xiàn)異常從而導致了業(yè)務的請求異常。但是在我們在進行故障分析的時候,不能僅僅只是局限于數(shù)據(jù)庫側(cè),需要基于整個請求鏈路的分析,從業(yè)務側(cè)、網(wǎng)絡、數(shù)據(jù)庫三個方面進行分析:
- 業(yè)務側(cè):需確認業(yè)務的所在的機器的CPU、網(wǎng)絡和磁盤IO、內(nèi)存是否使用正常,是否有出現(xiàn)資源爭用的情況;確認JVM的gc情況,確認是否是因為gc阻塞導致了請求阻塞;確認流量是否有出現(xiàn)增長,導致Elasticsearch的瓶頸。
- 網(wǎng)絡側(cè):需確認是否有網(wǎng)絡抖動的情況。
- 數(shù)據(jù)庫側(cè):確認是Elasticsearch是否是基于集群級別還是基于實例級別的異常;確認集群的整體請求量是否有出現(xiàn)突增的情況;確認異常的實例的機器是否有出現(xiàn)CPU、網(wǎng)絡和磁盤IO、內(nèi)存的使用情況。
確認哪方面的具體故障之后,就可以進一步的分析導致故障的原因。
參數(shù)控制:
Elasticsearch本身也有一些參數(shù)在磁盤使用率達到一定的情況下來控制分片的分配策略,默認該策略是開啟的,其中比較重要的參數(shù):
- cluster.routing.allocation.disk.threshold_enabled:默認值是true,開啟磁盤分分配決策程序。
- cluster.routing.allocation.disk.watermark.low:默認值85%,磁盤使用低水位線。達到該水位線之后,集群默認不會將分片分配達到該水平線的機器的實例上,但是新創(chuàng)建的索引的主分片可以被分配上去,副分片則不允許。
- cluster.routing.allocation.disk.watermark.high:默認值90%,磁盤使用高水位線。達到該水位線之后,集群會觸發(fā)分片的遷移操作,將磁盤使用率超過90%實例上的分片遷移到其他分片上。
- cluster.routing.allocation.disk.watermark.high:默認值95%。磁盤使用率超過95%之后,集群會設置所有的索引開啟參數(shù)read_only_allow_delete,此時索引是只允許search和delete請求。
補充:
一旦一臺機器上的磁盤使用率超過了90%,那么這臺機器上所有的ES實例所在的集群都會發(fā)起分片的遷移操作,那么同一時間發(fā)起并發(fā)的最大可能是:ES實例數(shù)
*cluster.routing.allocation.node_concurrent_recoveries,這個也會導致機器的CPU、IO等機器資源進一步被消耗,從而所在的實例性能會更差,從而導致路由到機器上實例的分片的性能會更差。
一旦一臺機器上磁盤使用率超過95%,那么這臺機器上所有的實例所在的集群都會開啟集群級別的參數(shù)read_only_allow_delete,此時不僅僅是一個集群,而是一個或者多個集群都無法寫入,只能進行search和delete。