線上問題排查定位實戰(zhàn)(游戲服務(wù)器)

1. 監(jiān)控先行
2. 線上常見問題
3. 問題排查、定位、解決
4. 參考、補(bǔ)充
5. Q & A

監(jiān)控先行

1. 游戲正式上線后，研發(fā)這邊可能沒有線上服務(wù)器的權(quán)限，不能直接在線上服務(wù)器排查問題，所以必須要監(jiān)控先行-grafana
   • 測試期間有線上服務(wù)器權(quán)限，可以使用一些命令行直接排查問題
   • 不過強(qiáng)烈建議將監(jiān)控指標(biāo)定時采樣到監(jiān)控服務(wù)器
2. 監(jiān)控指標(biāo)
   • 業(yè)務(wù)參數(shù)
     • tps(throughput)、latency
     • connections
     • threadpool#queue size
     • method execute time(logic handler/db save/db load/startup/shutdown/login/logout)
     • error log
   • jvm 參數(shù)(jstat/jmx)
     • class
     • S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
     • DeadlockDetector
     • thread state
     • cpu
   • db
     • mongo/redis
     • slow operations
     • high flow
     • connections
   • os參數(shù)
     • cpu、memory、io（帶寬/流量）、network
3. 業(yè)務(wù)參數(shù)直接打點監(jiān)控、jvm參數(shù)可直接通過jmx api獲取
   • 注騰訊的機(jī)器只能往里進(jìn) 不能出來 即不能push信息到外部；只開放部分端口
   • 要使用pull的方式
4. 監(jiān)控圖形化界面、報警（釘釘）

線上常見問題和現(xiàn)象

1. 玩家卡
   • cpu高（如死循環(huán)、無限遞歸、fgc-stw），當(dāng)前業(yè)務(wù)線程被占用，其他消息排隊
   • 線程被阻塞，如訪問一個三方http，超時
   • 死鎖
   • 方法執(zhí)行耗時如大量玩家登錄
   • 并發(fā)太高，線程處理不過來，導(dǎo)致排隊，出現(xiàn)'雪崩效應(yīng)'
2. 內(nèi)存飆高（溢出、泄露）
   • java 進(jìn)程#res、OU一直增加
   • FGC、FGCT增加，回收后內(nèi)存沒有明顯變化
   • 注：GC后res不變，不會還內(nèi)存給os
   • oom
   • oom-killer
   • 堆外內(nèi)存泄露
3. 數(shù)據(jù)庫
   • crash(如mongo primary節(jié)點掛掉-如被oom-kill)
   • 連接數(shù)問題，可能出現(xiàn)操作mongo時拋出異常
   • redis變慢
   • 數(shù)據(jù)庫內(nèi)網(wǎng)流量很大（一個mongo副本集可能服務(wù)器多臺backend），內(nèi)網(wǎng)帶寬被撐爆
4. 業(yè)務(wù)bug
   • 刷資源-回檔
     • 如策劃配錯了一個大數(shù)值
     • 如郵件領(lǐng)取bug導(dǎo)致郵件未刪除
     • 如業(yè)務(wù)bug先加未扣
     • 如扣錢邏輯不驗證，外掛發(fā)過來負(fù)數(shù)，導(dǎo)致加鉆
   • 邏輯參數(shù)驗證問題
     • 如輸入被外掛攻擊，如之前的商店購買，正常最多購買10個，但是外掛發(fā)過來1億個
   • 未處理異常
     • 時間調(diào)度業(yè)務(wù)未處理異常，導(dǎo)致影響其他時間調(diào)度的業(yè)務(wù)
     • 打點、推送、日志等拋出異常，影響業(yè)務(wù)邏輯
   • 網(wǎng)絡(luò)層問題
     • 頂號、斷線重連、每日重置
   • 登錄異常(登錄拋異常導(dǎo)致玩家無法登錄,要注意新業(yè)務(wù)不要影響就玩家要做數(shù)據(jù)兼容，或者數(shù)據(jù)時要登錄做腳本修復(fù)-避免玩家無法登錄)、支付問題(支付未發(fā)貨、刷單—未排重、丟單)
   • vms/global
     • 版本更新、登錄驗證、支付
   • 三方http未做超時處理（連接超時、read超時），導(dǎo)致卡住業(yè)務(wù)線程，如監(jiān)控的上報服務(wù)
   • ...

問題排查定位、解決

1. 整體情況

   top # 監(jiān)控整體CPU和內(nèi)存
   P   # 按照CPU排序
   M   # 按照內(nèi)存排序 可主要觀察res
   
   jps -v # 查看java進(jìn)程啟動參數(shù)
   
   load/us/id/...也可以看一下
   
   整體cpu如果超過70% 就要報警
   整體內(nèi)存如果超過70% 就要報警
   
   free -g # 需要看 + buffers/cache
   

2. 整體卡

   jstat -gcutil # 確認(rèn)一下是否是fgc引起的stw
   top –Hp pid  # 查看哪個線程占用cpu高
   printf 0x%x tid # 轉(zhuǎn)為16進(jìn)制
   jstack pid | grep nid –A 10 # 查看線程堆棧，找到占用cpu高的線程堆棧從而確認(rèn)
   
   # 可多次jstack，如果發(fā)現(xiàn)某業(yè)務(wù)線程的堆棧一直是固定的某一個，可能死循環(huán)、死鎖、blocked
   

3. 內(nèi)存問題較高

   jinfo pid/jps -v # 確認(rèn)整體jvm啟動參數(shù)
   top + M + res # 確認(rèn)Java進(jìn)程res是否較高
   jmap -heap # 確認(rèn)java內(nèi)存整體占用(cms#jdk低版本顯示有bug)，主要確認(rèn)堆內(nèi)存和metaspace是否占用過高
   jstat -gcuitl # 二者結(jié)合
   jmap -histo | head # 按照實例排序，注意如果加上live參數(shù)的話，會強(qiáng)制執(zhí)行一次fgc
   
   jcmd pid VM.native_memory summary # Native Memory Tracking，需要啟動參數(shù)增加-XX:NativeMemoryTracking=detail
   
   # 其他工具
   pmap -x pid
   google-perftools #分析堆外內(nèi)存
   
   # 注：如果發(fā)現(xiàn)內(nèi)存確實漲的很厲害，很快可能要oom了
   1. 使用jmap -dump:format=b,live,file=MemoryLeak.hprof pid # 將堆內(nèi)存快照導(dǎo)出來分析，可能會卡幾秒，mat進(jìn)行分析
   2. 如果無法即時發(fā)現(xiàn)oom的問題，那么此時建議重啟服務(wù)器，否則oom或者oom-killer可能會回檔，后果比較嚴(yán)重
   
   # 之前出現(xiàn)過的oom-killer問題
   1. python進(jìn)程占用內(nèi)存較高，觸發(fā)了oom-killer，killer了java進(jìn)程
   2. java進(jìn)程越來越多的臨時對象進(jìn)入ou，但是一直未觸發(fā)fgc(但此時res可能已經(jīng)很高)，此時mongod觸發(fā)存庫，也占用內(nèi)存，觸發(fā)了oom-killer(單機(jī)集群)
   3. 可以強(qiáng)制執(zhí)行一次fgc 如通過jmap histo:live或者jcmd pid GC.run或者System.gc
   

4. 數(shù)據(jù)庫統(tǒng)計

   # mongo統(tǒng)計
   mongostat -h xxx:40001  -u 'uuu' -p ppp--authenticationDatabase admin -n 10
   
   mongotop -h 10.3.11.22:40001  -u 'achilles' -p 5364e02856f513 --authenticationDatabase admin -n 1
   
   db.serverStatus();
   db.stats();
   db.players.stats();
   rs.status();
   
   開啟Profiling，慢查詢
   
   # redis
   1. redis-benchmark
   2. info(注：掌趣包括騰訊的一些機(jī)器很多命令不能使用，如keys *)
   
   

5. 其他輔助

   • http://xxx 玩家實時在線
   • http://yyy 監(jiān)控系統(tǒng)信息(cpu/內(nèi)存/流量)
   • 如果是內(nèi)部測試可以使用jconsole/jvisualvm/yourkit/jprofiler直接觀察
     • 建議使用java11開源的jfr
   • 日常開發(fā)可直接使用遠(yuǎn)程調(diào)試debug
   • 服務(wù)器日志
     • 熟練使用less(/、G、gg、n、N、ctrl + b、ctrl + f)、grep(-A、-B、-C)
     • 注：線上服務(wù)器通常不要直接使用less或者vim打開大文件，會比較占用內(nèi)存和cpu，而且使用完畢一定要退出，否則會一直在后臺，如top直接就可以看到less會占用很高的cpu

6. 問題定位和解決

   • 直接增加日志排查，更建議使用btrace/greys/jvm-sandbox
   • 使用bsh，查詢內(nèi)存數(shù)據(jù)
   • 導(dǎo)號到內(nèi)網(wǎng)，嘗試復(fù)現(xiàn)解決bug
   • 配置表可以直接熱更(指后端)
   • hotfix解決bug(建議使用instrumentation)

參考、補(bǔ)充

1. java -profiling-practice
2. Java調(diào)優(yōu)系列之工具篇之btrace、gperftools
3. JVM內(nèi)存非典型術(shù)語介紹
4. oom-metaspace
5. fastjson-heap-oom
6. 游戲服務(wù)器數(shù)據(jù)存儲策略和宕機(jī)保護(hù)
7. Java項目中mongo問題總結(jié)
8. jvm-sandbox
9. greys
10. btrace
11. gperftools
12. show-busy-java-threads
13. 【譯】MongoDB的監(jiān)控
14. Redis性能監(jiān)控

Q & A

1. jmap -histo 發(fā)現(xiàn)Player實例有819個，但在線玩家只有90多個，而數(shù)據(jù)庫實際的玩家也只有690多個？why?
   • jmap -histo:live參數(shù)后，執(zhí)行fgc后，Player實例變?yōu)?17個，說明確實是臨時對象
   • TODO 需要排除原因，為什么實例有819個？難道有多個實例Player指向同一個player?
2. 做一個實現(xiàn)，有一個hashmap，put了很多對象，然后調(diào)用了clear，但是沒有觸發(fā)gc，此時實際占用的內(nèi)存？
   • TODO 測試
3. jdk11的zgc可以了解一下，避免stw
4. 之前服務(wù)器突然卡了一下(所以玩家卡了一小下)，可能是因為fgc#stw