記錄兩次多端排查問題的過程

2022-07-25 09:01:19

  我們組會負責後端的一些服務,因此出現問題時不僅僅是介面的樣式相容問題,還有很多其他的後臺服務問題。

  排查後面這類問題,需要具備些伺服器端的排查手段,否則就會難以定位問題所在。

一、聊天問題

  公司有一個即時聊天的功能,在 6 月 2 日週五,上了一個自動推播個性文案的功能,大受好評,存取量迅速躥升。

  UV 一度增加了六七千,在高興的同時,問題也接踵而至,例如匹配不到聊天物件、跳轉頁面時卡住白屏和聊天介面卡頓問題。

  其實這些問題之前也存在,但因為使用者量小,沒有被大規模的曝光。

  這次使用者量上來後,在 3、4、5 號端午三天,客服不間斷地收到投訴。由此可見,量大後,再小的問題也會被放大。

  鑑於問題的表現都是在我們 Web 這一端,所以需要我們先進行排查。

  排查的步驟分三步:首先需要確定問題是由哪一端觸發的,其次確定問題影響範圍和制定優先順序,最後聯合相關組一同給出解決方案。

  在讓其他端配合排查之前,需要先確保自己那塊沒有問題。

  在將目前上報的所有問題分類後,發現大部分遇到的是第三個問題:聊天卡頓,這部分要安排更多的精力來解決。

1)匹配不到

  當匹配不到時,就會像下圖那樣一直處於等待匹配中,使用者不得不關閉介面。

  

  匹配失敗是因為賬號被鎖住了,由我們組負責優化。

  在匹配時會建立一個並行鎖,正常情況是3秒後過期或在某個位置解鎖,但出現異常後,沒有成功解鎖導致使用者一直處於鎖住狀態。

  // redis原子性控制並行
  async incrLock(key, option) {
    const incrLock = await redis.aws.incr(key);
    if (incrLock && Number(incrLock) > 1) {
      return false;
    }
    const lockDuration = option && option.duration ? option.duration : 5;
    const momentstamp = moment().add(lockDuration, 's').valueOf();
    await redis.aws.pexpireat(key, momentstamp);
    return true;
  }

  為了保證鎖能過期,將過期的設定提升至if語句之前。

  

2)跳轉卡住

  這個問題非常奇怪,遇到此問題的都是安卓使用者(華為、VIVO 和小米),進度條卡在下圖的位置就進行不下去了。

  

  檢視使用者端紀錄檔,發現其實已經請求了聊天頁面(chat.html)。

06-05 12:08:12.730 1 INFO/AppForeground: WebViewActivity onCreate true
06-05 12:08:12.841 1 INFO/WebViewActivity: loadUrl https://security.xxx.me/safe_redirect?url=https%3A%2F%2Fs.xxx.me%2Fc%2F1Gf4Gf
06-05 12:08:12.867 1 INFO/AppForeground: WebViewActivity onStart
06-05 12:08:12.872 1 INFO/ChatServiceManager: startService true
06-05 12:08:12.873 1 INFO/AppForeground: WebViewActivity onResume
06-05 12:08:13.074 1 INFO/WebViewActivity: processUrl else true url:https://s.xxx.me/c/1Gf4Gf
06-05 12:08:13.394 1 INFO/AppForeground: MainActivity onStop
06-05 12:08:13.669 1 INFO/WebViewActivity: processUrl else true url:https://www.xxx.me/game/chat.html?entry=appchatpush
06-05 12:08:15.063 1 INFO/AppForeground: WebViewActivity onPause
06-05 12:08:16.064 1 INFO/AppForeground: WebViewActivity onStop

  檢視Nginx 伺服器存取紀錄檔,發現的確在那個時刻收到了來自於使用者端的請求。

url: "/game/chat.html?entry=appchatpush" not url: zh_cn and http_user_agent: MED-AL00

  

  但是在查詢指令碼的請求紀錄檔時(game/js/chat.719c3c70.js 和 game/js/chunk-vendors.11311460.js),並沒有發現。

  

  由此可推斷,要麼就是使用者端沒有傳送請求,要麼就是伺服器當時沒有響應,需要使用者端幫忙排查。

3)聊天卡頓

  這個問題主要是使用者端排查,我們組配合列印關鍵資訊(console.warn())。

  

  後面我們對頁面指令碼也做了一次優化,實現元件區域化的渲染,避免整個大元件的渲染。

4)異常流量

  在將相關組拉在一起開會時,運維反饋,在 6 月 4 日 23:42-23:43 之間有股異常流量,而 22:00-01:00 也是公司 APP 最為活躍的時間。

  這股異常流量促使短鏈服務和長連線發生大量的 502/503/504 的報錯。

  檢視 Nginx 紀錄檔(如下圖所示),發現有個明顯的凸起高峰,也正好是在那段時間發生的。

  

  經查,在這段時間內,進入聊天頁面的埋點只收到了 1 個。運維懷疑是 api 專案的一個回撥介面影響了 api 的其他服務。

  6 月 6 日晚上 20 點,將此介面服務遷出,單獨作為一個服務(就是路由轉發),當天晚上的錯誤從之前的 500 多降到了 60 多。

  為了弄清楚長連線發生異常時,有哪些使用者受到了影響,因此在 /socket 地址上還附帶上了使用者 ID。

    

5)下一步動作

  在 6 號開完會議後,就馬上修復了我們這邊的幾個問題,以及運維的問題。

  查詢聊天匹配完成的曲線圖,發生呈明顯的上升趨勢,匹配率增幅 23% 以上,這是一個讓人振奮的訊息。

  使用者端因為無法復現,所以需要新增埋點,例如增加鍵盤互動等事件的監聽,還需要優化鍵盤彈出方案,這些都得釋出新版本。

  所以要下一個版本中解決卡頓的問題。

二、記憶體問題

  我們組的靜態資源都單獨放在一臺伺服器中,靜態資源就是圖片、HTML、JavaScript 和 CSS 等檔案。

  運維和我反饋說,這些伺服器的記憶體會一直漲,除非重啟容器後,記憶體才會降下來。

  

  我的第一反應是記憶體是不是洩漏了,伺服器中有個聊天的頁面,會不會是建立了大量的 websocket 連線,沒有被釋放掉。

  但是轉而一想,應該不是,因為這些檔案會被傳輸到使用者瀏覽器中,發起的連線也是存在於使用者端,不會影響伺服器端的記憶體。

  進入到伺服器中,輸入 ps aux 命令,檢視正在執行的程序,發現有好多 worker process。

  

  問運維,說這些都是 Nginx 的程序,後面就讓他去優化,他改了個設定,記憶體增長的幅度是變小,不過依然會慢慢增長。