凌晨 1 點(diǎn) 47 分值班群被一條告警刷屏訂單服務(wù)可用率掉到 91%用戶支付頁反復(fù)報(bào)“系統(tǒng)繁忙”。我打開 WeClaw 日志平臺目標(biāo)索引最近 24 小時已經(jīng)積累了 3.8 億條日志屏幕上滾動最快的那個 “error” 檢索結(jié)果膨脹到幾十萬條。這個場面相信做后端的人都不陌生日志不是沒有而是多到讓你不知道從哪一條看起。我后來總結(jié)出一個結(jié)論海量日志定位根因靠的不是“看得多”而是“收斂得快”。這篇文章就寫一寫我用 WeClaw 做日志分析的一套實(shí)戰(zhàn)打法從億級日志里快速把候選范圍壓到幾十條再順著鏈路把根因揪出來。適合正在做服務(wù)排障、穩(wěn)定性建設(shè)或者剛開始搭日志平臺的同學(xué)參考。1. 先想清楚日志分析的目的是收斂不是翻日志1.1 為什么日志越多越難定位日志本來是系統(tǒng)的黑匣子但把它接入統(tǒng)一平臺之后黑匣子變成了洪流。以前單機(jī)幾百萬條日志人工 grep 還能接受現(xiàn)在微服務(wù)一拆、副本一拉正常業(yè)務(wù)流量就能每天產(chǎn)出幾十億條日志單個服務(wù)一晚上的 ERROR 就有好幾萬條。問題不是沒有信號而是信號被噪音按在地上摩擦。我見過不少同事在 WeClaw 里排障從頭到尾都在做一件事?lián)Q關(guān)鍵詞。搜“Exception”看幾條搜“timeout”再看幾條又搜“error code”循環(huán)幾輪半小時過去還在原始日志里打轉(zhuǎn)。這種做法的核心誤區(qū)是把“日志分析”理解成了“搜關(guān)鍵詞”。真正的日志分析是三條動作的循環(huán)過濾、聚合、關(guān)聯(lián)。過濾做減法聚合找模式關(guān)聯(lián)串因果。三條動作循環(huán)幾輪根因自然浮出水面。1.2 一條可以復(fù)制的黃金分析路線我自己這幾年用過不少日志工具最后固定下來一條排障路線先鎖時間窗口再定服務(wù)范圍用聚合壓掉重復(fù)噪音最后用鏈路 ID 串因果。每一步做的事都是把候選集合縮小億級日志先壓到百萬級再壓到千級然后從幾百條可疑記錄里挑出幾條關(guān)鍵 trace打開鏈路視圖確認(rèn)真兇。這條路線的關(guān)鍵不是某個單點(diǎn)技巧而是“不能跳步”的順序感。對應(yīng)到 WeClaw 上四個動作分別會用到四類能力檢索頁做過濾統(tǒng)計(jì)圖表做聚合日志看板做觀測鏈路檢索做串聯(lián)。很多人只會用檢索頁等于只發(fā)揮了 WeClaw 四分之一的能力。2. 分析前的準(zhǔn)備工作接入、索引與字段規(guī)劃2.1 日志接入與采集配置別以為日志分析是故障發(fā)生后才做的事真正的分水嶺在接入階段就決定了。如果日志格式亂七八糟后面再強(qiáng)的工具也幫不上忙。我現(xiàn)在的做法是所有業(yè)務(wù)服務(wù)統(tǒng)一輸出 JSON 格式日志把關(guān)鍵信息暴露成獨(dú)立字段。一份典型的日志長這樣{ time: 2025-04-17T01:47:23.123Z, level: ERROR, service: order-svc, trace_id: 6f8c9d2e1a4b, message: invoke pay timeout, cost_ms: 3021, code: PAY_TIMEOUT }JSON 的好處是字段天然結(jié)構(gòu)化WeClaw 采集端可以直接把 key 解析成獨(dú)立字段后續(xù)檢索就能寫code:PAY_TIMEOUT而不是在 message 里做文本匹配。如果你還在用純文本日志至少也要通過分隔符、正則等方式把 service、level、trace_id、code 這幾個關(guān)鍵字段解析出來。接入時還有幾個細(xì)節(jié)值得注意日志統(tǒng)一用 UTC 時間避免跨時區(qū)聚合錯位采集路徑要精確到目錄避免把無關(guān)系統(tǒng)日志也采進(jìn)來編碼統(tǒng)一 UTF-8不然中文日志會變成亂碼。這些在故障時全都會變成致命干擾項(xiàng)。2.2 索引如何設(shè)計(jì)直接決定了查詢快不快很多人在 WeClaw 上排障慢不是工具慢而是索引設(shè)計(jì)沒做對。索引不是把所有字段都建上就叫好而是只給“會用來篩選和聚合的字段”建索引。常規(guī)做法是給高頻過濾字段做成 keyword 類型例如service: keyword level: keyword trace_id: keyword code: keyword host: keyword time: date帶時區(qū) cost_ms: long message: text開啟分詞用于模糊檢索keyword 和 text 的區(qū)別很關(guān)鍵。keyword 適合精確匹配、范圍過濾、分組聚合速度快text 適合模糊搜索但檢索開銷大聚合也不太方便。如果把 service 誤配成 text查詢時可能查得到但group by service的時候會得到你完全想不到的分桶結(jié)果因?yàn)榉衷~把字段拆碎了。保留策略也不能忽略。熱數(shù)據(jù)近幾天在 SSD 上冷數(shù)據(jù)轉(zhuǎn)入歸檔存儲既省錢又保證熱查詢速度。如果所有索引都按 180 天全量保留光掃描范圍就能把查詢拖慢一個數(shù)量級。2.3 這些配置坑我?guī)缀趺總€項(xiàng)目都見過接入和索引配置踩過的坑我基本都能背出來了。第一個是時間字段時區(qū)錯亂。有些服務(wù)上報(bào)本地時間有些上報(bào) UTC混在一起后在 WeClaw 里看到的日志時間線是扭曲的聚合出的高峰期根本對不上真實(shí)故障窗口。解決辦法就是接入規(guī)范里強(qiáng)制要求統(tǒng)一 UTC 時間戳或者在采集端做一次時區(qū)歸一。第二個是采集路徑導(dǎo)致日志體積虛高。之前有次排障明明只查訂單服務(wù)結(jié)果檢索結(jié)果里混進(jìn)了一堆全鏈路健康檢查日志。后來查出來是采集器把整個根目錄都掃了健康檢查日志全部灌進(jìn)索引。日志量翻了三倍查詢自然變慢。第三個是多行日志被拆散。Java 異常堆棧天生是多行的默認(rèn)按行采集會把一個異常拆成幾十條獨(dú)立日志聚合時 count 出來的不是“異常次數(shù)”而是“堆棧行數(shù)”。WeClaw 這類平臺一般都有多行合并配置按堆棧首行特征把完整異常合并成一條日志。這個沒配好你后面做的任何堆棧聚合都是錯的。3. 檢索篩選從億級日志中快速收斂到可疑范圍3.1 單條檢索的語法和習(xí)慣WeClaw 的檢索語法和主流日志平臺類似基礎(chǔ)能力就是布爾表達(dá)式加字段過濾。常用的幾類寫法# 字段精確匹配 service:order-svc # 多個條件組合 service:order-svc AND level:ERROR # 帶數(shù)值范圍 service:order-svc AND cost_ms:3000 # 排除干擾 service:order-svc AND level:ERROR AND NOT message:health check # 通配符 message:redis * timeout用詞大小寫、引號規(guī)則不同版本可能略有差異但核心習(xí)慣是一樣的先做字段精確過濾再做內(nèi)容模糊檢索。上來就在 message 里搜一個不帶引號的 error結(jié)果匹配的范圍會比你想的大得多因?yàn)?error 可能是單詞的一部分也可能出現(xiàn)在 URL、響應(yīng)頭等位置。3.2 不要一上來就搜 error這大概是排障里最違反直覺的一條建議先別搜 error。因?yàn)楹芏嘞到y(tǒng)的 ERROR 日志數(shù)量本身就很大而且大部分 ERROR 不是根因而是根因引發(fā)的連鎖反應(yīng)。我之前處理過的一個案例就能說明問題表面上是支付服務(wù)瘋狂報(bào)“上游連接被拒”搜 error 全線飄紅。順著 error 一條條看都是網(wǎng)關(guān)服務(wù)在重試看起來像是網(wǎng)關(guān)掛了。但追到網(wǎng)關(guān)日志才發(fā)現(xiàn)真正的起因是數(shù)據(jù)庫連接池被打滿所有請求在數(shù)據(jù)庫層排隊(duì)超時網(wǎng)關(guān)只是把超時錯誤翻譯成了連接失敗。如果一開始就盯著 error 細(xì)看很容易把“重試引起的次生錯誤”誤判成根因。更合理的起點(diǎn)是“已知的異常信號”告警里提到的錯誤碼、監(jiān)控曲線突變的時刻、耗時最高的請求類型。拿這些信號去構(gòu)造檢索條件比從 error 開頭更接近真相。3.3 排障篩選三連時間窗口、服務(wù)維度、日志級別我每次定位都嚴(yán)格按三步做檢索收斂這一步做扎實(shí)后面的聚合和關(guān)聯(lián)才有意義。第一步把時間窗口縮到故障前后五分鐘。告警是 01:47 觸發(fā)的我就先看 01:42 到 01:52 這十分鐘。半小時前和半小時后的日志對這次事故沒有意義只會增加噪音。時間窗口收窄之后檢索速度也能快一個量級WeClaw 只需要掃極少的分片即可。第二步用服務(wù)維度固定范圍。故障影響的是訂單服務(wù)就先看service:order-svc不要一開始就全平臺搜。等確定根因在依賴鏈路后再用 trace_id 跳轉(zhuǎn)到其他服務(wù)。第三步再決定要不要限定日志級別。業(yè)務(wù)自定義的錯誤碼比日志級別更可靠優(yōu)先用 code 過濾。比如service:order-svc AND code:PAY_TIMEOUT通常比level:ERROR準(zhǔn)確得多。三個動作做完候選集合通常已經(jīng)從百萬級降到了萬級以內(nèi)下一步就可以做聚合了。4. 聚合分析讓海量日志自己開口說話4.1 高頻錯誤聚合把幾萬條壓成幾個桶排障最怕的是條條日志長得都不一樣你看到一萬條錯誤卻沒看出它們其實(shí)是同一個錯誤的重復(fù)演繹。聚合就是用來解決這個問題的。WeClaw 里常見的聚合操作是按字段分組后統(tǒng)計(jì)次數(shù)。比如先查service:order-svc AND level:ERROR然后按 code 分組統(tǒng)計(jì)service:order-svc AND level:ERROR | group by code, top 10出來的結(jié)果大概率是一個 code 占比 70%另一個占比 20%剩下的是零散異常。最占優(yōu)勢的那個 code就是你后面要重點(diǎn)追的方向。這一步至關(guān)重要它把幾萬條錯誤收斂成了幾個可數(shù)的統(tǒng)計(jì)桶。4.2 趨勢與時間切片對齊操作和故障時間線聚合不僅看數(shù)量還要看時間分布。WeClaw 的統(tǒng)計(jì)圖表功能可以按分鐘、按小時做直方圖把錯誤數(shù)畫成一條時間線。這條時間線的用途是讓你的大腦把“故障”和“某個操作”關(guān)聯(lián)起來。有一次排障錯誤聚合結(jié)果一直指向空指針但場景怎么都說不通。我把錯誤數(shù)量按分鐘拉成圖表后發(fā)現(xiàn)某個 NPE 是在下午 2 點(diǎn)零幾分突然出現(xiàn)且持續(xù)增長而下午 2 點(diǎn)恰好是某次發(fā)布窗口。順著發(fā)布變更回溯代碼定位到一次參數(shù)校驗(yàn)邏輯被改漏了。如果沒有時間切片對齊就永遠(yuǎn)停留在“代碼為什么空指針”的靜態(tài)層面根本不會想到去看發(fā)布操作。時間分布還有一個用法是和正常基線對比。看某條錯誤碼曲線相對前一天同時段是否陡增能快速區(qū)分“積壓性的慢性問題”和“突然爆發(fā)的急性問題”。慢性問題看趨勢急性問題找尖刺排障策略完全不一樣。4.3 從聚合結(jié)果里識別“異常模式”而不是看單條日志做聚合分析時我會刻意做一個操作把 message 里的動態(tài)部分抽象成模板。比如原始日志是2025-04-17 01:47:23 ERROR order-svc 請求 /api/order/12345 處理超時, cost3021ms 2025-04-17 01:47:25 ERROR order-svc 請求 /api/order/67890 處理超時, cost2876ms兩條日志的 message 看起來是兩條不同的但把訂單號替換成{orderId}后模式完全一致。WeClaw 里有些版本支持按表達(dá)式提取模式或者你可以在檢索時手動用通配符message:請求 /api/order/* 處理超時來歸并同類日志。這一步就是在把“離散日志”變成“類型視圖”。排障時你應(yīng)該關(guān)注的是類型而不是單條文本。等到你看到“某個類型占 90% 的錯誤量”時根因方向往往已經(jīng)很明確了。5. 關(guān)聯(lián)分析從可疑片段連出完整因果鏈5.1 用 trace_id 把散落的日志串成一條鏈日志分析做到聚合這步基本能鎖定“哪個錯誤類型最可疑”但還差最后一擊搞清楚這條錯誤在調(diào)用鏈中處于什么位置是誰調(diào)誰才觸發(fā)出來的。這就輪到 trace_id 上場了。trace_id 是貫穿整個調(diào)用鏈路的唯一標(biāo)識。你在 WeClaw 里直接輸入trace_id:6f8c9d2e1a4b得到的不是一條日志而是從入口網(wǎng)關(guān)到下游服務(wù)的完整鏈路日志按時間排序后一眼就能看出每個環(huán)節(jié)的耗時和狀態(tài)。這是把“一條可疑錯誤”升級為“一段完整因果”的關(guān)鍵動作。如果項(xiàng)目里還沒有打 trace_id我建議盡快在網(wǎng)關(guān)或 RPC 中間件統(tǒng)一生成并在日志上下文里帶上。沒有 trace_id 的日志平臺排障能力至少砍掉一半因?yàn)樗腥罩径际腔ハ喙铝⒌乃槠肋h(yuǎn)拼不出整張圖。5.2 跨服務(wù)上下文檢索與上下游判斷鏈路日志變多后怎么判斷問題出在哪一環(huán)我的判斷標(biāo)準(zhǔn)是三個維度耗時、狀態(tài)碼、依賴資源。耗時維度看哪一環(huán)的時間占比最大。比如 trace_id 展開后網(wǎng)關(guān)耗時 3000ms 里3900ms 花在調(diào)數(shù)據(jù)庫那數(shù)據(jù)庫基本就是瓶頸。狀態(tài)碼維度看哪個下游返回了 5xx 或?qū)?yīng)超時碼。依賴資源維度則是看 DB、Redis、MQ 這些外部組件的連接數(shù)、慢查詢指標(biāo)有沒有同步異常。有一次排障支付服務(wù)調(diào)用訂單服務(wù)一直超時order-svc 自身報(bào)錯不過兩三條。我拿 trace_id 一查發(fā)現(xiàn)所有請求都卡在 sso-cache 這個中間環(huán)節(jié)。再往下追是緩存服務(wù)連接池被異常請求打滿連接獲取等了 4 秒。如果只看 order-svc 一家的日志這個問題根本定位不了因?yàn)檎鎯丛谏嫌蔚木彺鎸印?.3 一個實(shí)戰(zhàn)推演日志表象到根因的距離拿一次完整的排障推演來演示整條鏈路。某跨平臺系統(tǒng)在 00:00 左右開始出現(xiàn)訂單創(chuàng)建失敗告警規(guī)則觸發(fā)后我按前面三步走第一步鎖定 00:02 到 00:12 這個時間窗口查詢service:order-svc AND level:ERROR。第二步按 code 聚合發(fā)現(xiàn)DB_CONN_TIMEOUT占比突破 80%。第三步隨便挑一條該 code 的高頻 trace_id在 WeClaw 鏈路視圖里展開00:03:01.204 gateway DEBUG 收到創(chuàng)建訂單請求, trace_id7f3a... 00:03:01.210 order-svc INFO 調(diào)用訂單服務(wù) 00:03:02.502 order-svc INFO 嘗試獲取數(shù)據(jù)庫連接, pool_wait4120ms 00:03:02.503 order-svc ERROR 獲取數(shù)據(jù)庫連接超時, codeDB_CONN_TIMEOUT問題很快就浮出水面不是 SQL 慢不是業(yè)務(wù)邏輯錯而是應(yīng)用拿不到數(shù)據(jù)庫連接連接池在 00:00 之后被耗盡了。繼續(xù)看數(shù)據(jù)庫監(jiān)控發(fā)現(xiàn)大量慢查詢把連接占住不釋放。再回看慢查詢是某條統(tǒng)計(jì)報(bào)表 SQL 在跨天結(jié)算任務(wù)里被打了出來。從“訂單創(chuàng)建失敗”到“跨天慢查詢占滿連接池”中間隔了四層錯誤聚合收斂到錯誤碼、trace_id 展開定位環(huán)節(jié)、連接池指標(biāo)反映資源瓶頸、慢查詢定位最終 SQL。每一步都通過 WeClaw 的分析能力完成整個定位過程大約二十分鐘。如果一上來就在日志里搜“訂單失敗”可能到天亮也理不清因果。6. 常見問題與排查技巧實(shí)錄6.1 查詢變慢的幾個原因與解決思路用 WeClaw 排障時最煩躁的莫過于檢索轉(zhuǎn)圈。遇到這種情況先別怪平臺先從自己的查詢習(xí)慣找原因。最常見的問題是時間范圍開得太大默認(rèn)七天實(shí)際只需要看十分鐘。日志平臺掃描的數(shù)據(jù)量和時間范圍成正比把窗口縮到分鐘級速度立刻不一樣。其次是把模糊查詢當(dāng)成萬能藥。message:超時這種全文檢索在大型索引上比字段級過濾慢得多。能寫成code:PAY_TIMEOUT就不要用模糊匹配。還有一個隱藏因素聚合并發(fā)度。如果你同時打開多個聚合圖表后端會執(zhí)行多路統(tǒng)計(jì)速度自然會慢。排障時只保留最必要的聚合圖。6.2 檢索結(jié)果出現(xiàn)偏差的典型坑結(jié)果不準(zhǔn)比結(jié)果慢更可怕它會直接把你引到錯誤方向。我整理幾個常見的坑都是親手踩過的。第一個是索引刷新延遲。日志寫入索引后通常不是立即可查有幾十秒到幾分鐘的延遲。剛發(fā)生故障時查最近一分鐘的日志可能查不到。解決方法是看日志下標(biāo)時間不要盯著當(dāng)前時間判斷。第二個是時區(qū)錯亂導(dǎo)致“看不到日志”。某次查詢最近十分鐘沒有任何結(jié)果以為是采集斷了后來發(fā)現(xiàn)是應(yīng)用日志時間是 UTC8WeClaw 檢索界面按 UTC 計(jì)算導(dǎo)致時間窗口整體偏移了八小時。避免方法是接入時統(tǒng)一成 UTC或者在檢索界面上把時區(qū)選項(xiàng)對齊。第三個是日志被截?cái)?。超長日志字段會被平臺默認(rèn)截?cái)喽褩．惓Ｓ绕淙菀装l(fā)生。排障時發(fā)現(xiàn)堆棧到一半就沒了先檢查字段長度限制而不是急著懷疑代碼。第四個是采樣丟失。對超大日志量環(huán)境有些平臺默認(rèn)對 DEBUG、INFO 級日志做采樣排障時查不到低級日志屬于正?，F(xiàn)象。日常排障可以用 ERROR 級日志但如果要定位低概率問題需要確保關(guān)鍵鏈路的全量日志沒有采樣。6.3 一套“壓箱底”的排查清單最后分享一套我貼在工位上的排查清單每次故障告警來了就照著執(zhí)行打開 WeClaw先把時間窗縮到告警前后五分鐘用服務(wù)名加錯誤碼做第一輪過濾不要直接搜 error對過濾結(jié)果按 code 聚合找到占比最高的一類錯誤如果 code 不能解釋就對 message 做模式提取找出共性模板從聚合結(jié)果里挑一條有 trace_id 的日志打開鏈路視圖在鏈路里對比各環(huán)節(jié)耗時和狀態(tài)碼定位最可疑的一環(huán)沿時間線回溯該環(huán)節(jié)依賴的資源結(jié)合數(shù)據(jù)庫、緩存、消息隊(duì)列的監(jiān)控看是否同步異常如果一輪找不到就收窄時間窗把重點(diǎn)從 ERROR 級放到 INFO 級日志上還原操作細(xì)節(jié)。這套清單的特點(diǎn)是把“搜索”變成了“排查流程”每一步都在喂給下一步更精確的輸入最終收斂到根因。7. 寫在最后排障之后我最常做的事日志排障其實(shí)是個可以先苦后甜的活。我在好幾次事故里嘗到過“沒有 trace_id、字段亂配、時間格式不統(tǒng)一”的苦頭后來才把索引模板、日志規(guī)范和 trace_id 注入這些事當(dāng)成了基礎(chǔ)建設(shè)而不是事故后的補(bǔ)救。如果你剛開始用 WeClaw 做日志分析我建議你先把索引和字段模型打磨好平時就順手做幾次演練千萬不要等故障發(fā)生了才第一次打開聚合功能。日常排障多體會“過濾、聚合、關(guān)聯(lián)”這三板斧的順序感熟練之后面對億級日志時心里就有底了。最后再說一個小技巧每次定位完一個根因把當(dāng)時用的檢索語句、聚合圖表和鏈路截圖整理成一份“排障書簽”下次遇到同類問題直接復(fù)用這是用日志平臺越用越快的秘訣。