問題初現(xiàn)

某基于node.js開發(fā)的業(yè)務(wù)系統(tǒng)向外提供了一個dubbo服務(wù)，提供向第三方緩存查詢、設(shè)置多項業(yè)務(wù)數(shù)據(jù)并聚合操作結(jié)果。在QPS達到800時（兩臺虛擬機，每臺機器4Core8G4node進程），在監(jiān)控平臺上出現(xiàn)了非常多的slow rt警告，平均接口響應(yīng)達到60+ms，請求報警率達到80%+。

為找到造成該服務(wù)吞吐量過低的罪魁禍首，業(yè)務(wù)人員在請求日志中打點了所有查詢緩存的操作，結(jié)果顯示每個請求查詢緩存耗時在50-100ms之間跳動。查詢了redis-server的監(jiān)控數(shù)據(jù)發(fā)現(xiàn)，不存在server端的慢查詢，在整個監(jiān)控區(qū)間內(nèi)服務(wù)端處理時間在40us徘徊，因此排除了redis-server的處理能力不足原因；

通過登錄內(nèi)網(wǎng)機器進行不斷測試到對應(yīng)redis server機器的端到端時延發(fā)現(xiàn)內(nèi)部局域網(wǎng)的帶寬、時延與抖動足夠正常，都不是造成該問題的原因。

因此，錯誤原因定位到了調(diào)用redis client的業(yè)務(wù)代碼以及redis client的I/O性能。

本文中提到的node redis client采用的基于node-redis封裝的二方包，因此問題排查也基于node-redis這個模塊。

瓶頸在哪

為了在本地模擬線上環(huán)境的并發(fā)，可以做一個不是很嚴謹?shù)臏y試：

async ()=>{
  let dd = Date.now()
  let arr = []
  for(let i=0;i<200;i++){
    arr.push(new Promise((res,rej)=>{
      let hrtime = process.hrtime();
      client.send_command('get',['key'], function(e,r) {
      let diff = process.hrtime(hrtime);
      let cost = (diff[0] * NS_PER_SEC + diff[1])/1000000;
      console.log(`final: ${cost} ms`)
      res();
      });
    }));
  }
  await Promise.all(arr)
  console.log('ops/sec:',200*1000/(Date.now() - dd),Date.now() - dd);
}

會發(fā)現(xiàn)每個請求的rt都會比前一個請求來的大

 最后一個請求的rt竟然達到了257 ms！雖然在node單進程像示例代碼那樣并發(fā)執(zhí)行200次get請求是非常少見而且愚蠢的（關(guān)于示例代碼的優(yōu)化在在下節(jié)講述），但是針對這個示例必須找到請求delay增加的原因。

 為此繼續(xù)分析，redis client采用的是單連接模式，底層采用的非阻塞網(wǎng)絡(luò)I/O，socket.recv()在node層面是通過監(jiān)聽socket的data事件完成的，因此先分析redis-client讀性能如何：

上圖每段日志的含義分別表示：

- data events trigger times: socket data事件觸發(fā)的次數(shù)
- data event start from prevent event: data事件距離上次觸發(fā)的時間間隔
- data events exec time(ms): 本次事件處理函數(shù)執(zhí)行時間

 上圖只是截取了最初的請求日志，發(fā)現(xiàn)當(dāng)?shù)?次觸發(fā)data事件時，竟然距離上次觸發(fā)事件隔了35ms，在隨后的請求中會復(fù)

現(xiàn)這種現(xiàn)象，因此這也就導(dǎo)致了在并發(fā)200次查詢請求時，每個請求的rt都會隨之增大，并且有些響應(yīng)之間間隔了30ms。

從表象看造成問題在于redis-server發(fā)送的響應(yīng)不是一個數(shù)據(jù)塊，而是多個數(shù)據(jù)塊導(dǎo)致觸發(fā)socket的data事件過多，而且data事件抖動過大導(dǎo)致響應(yīng)之間存在30ms的突變（data事件是無法同時觸發(fā)兩次的，每次data事件處理函數(shù)執(zhí)行完后才能繼續(xù)觸發(fā)下一個data事件）；當(dāng)然也有可能和socket寫入（即發(fā)送req）有關(guān)，如緩存請求等。為了繼續(xù)探查，監(jiān)控與socket寫入相關(guān)的接口 **_write()**,記錄每次寫入socket的數(shù)據(jù)時距離上一次寫入的間隔：

可見，在使用redis-client發(fā)送請求時，write方法也不是瓶頸。

采用同樣方法，對socket的push()（該方法觸發(fā)socket的data事件）進行監(jiān)控，發(fā)現(xiàn)socket的數(shù)據(jù)到達間隔抖動非常大：

 因此，造成redis-client并發(fā)請求下響應(yīng)rt抖動較大的情況與單連接下響應(yīng)數(shù)據(jù)到達本地的時刻有關(guān)，具體可能與底層libuv的緩存策略有關(guān)（筆者并未再往下探查）。

在一個node實例中通過一個單連接與redis server通信，在高并發(fā)下會出現(xiàn)排隊等待響應(yīng)的情況，并且有可能會出現(xiàn)響應(yīng)rt雪崩效應(yīng)（如上文demo所示），因此需要盡可能減少或緩存客戶端的請求數(shù)量，進行批量發(fā)送。

調(diào)優(yōu)

1. pipeline(涉及到寫模式及時序)
2. script

對于pipeline方式，redis server是默認支持的。通俗點說，pipeline可以合并一系列請求一次發(fā)送，并將這些請求對應(yīng)的結(jié)果一次性拿到。因此這種方式可以有效減少響應(yīng)次數(shù)，從而減少socket觸發(fā)data事件的次數(shù)，盡可能快的拿到響應(yīng)體。

 需要強調(diào)的是，在node中，是通過底層socket的**_writev**實現(xiàn)一次發(fā)送多條redis命令的，_writev又叫做聚合寫，它支持將不同緩沖區(qū)的多條數(shù)據(jù)通過一次系統(tǒng)調(diào)用寫入目標(biāo)流，因此性能上比每次寫單個緩沖區(qū)的單個數(shù)據(jù)來的好得多。在node的Writeable對象中，有cork和uncork方法，通過這兩個方法可以在node write stream中緩存多條數(shù)據(jù)，通過_writev一次性發(fā)送。

關(guān)于 _writev的數(shù)據(jù)結(jié)構(gòu)

redis在拿到數(shù)據(jù)后，根據(jù)resp協(xié)議解析出命令集合緩存在隊列中，直到收到exec命令，開始批量執(zhí)行命令集，并將所有命令執(zhí)行的結(jié)果轉(zhuǎn)換為數(shù)組返回給redis client。這樣就可以通過一次寫、一次讀實現(xiàn)高性能I/O。

async ()=>{
  let dd = Date.now()
  let batch = await client.batch();
  for(let i=0;i<200;i++){
    batch.get('vdWeex_com.koudai.weidian.buyer_1');
  }
  let rt = await batch.exec();
  process.exit();
}

而對于script方法，則是由redis client傳入script命令，在server端執(zhí)行script邏輯，批量執(zhí)行命令，并返回結(jié)果。同樣是一次寫、一次讀。

收獲

1. node socket默認采用writev 集合寫
2. 無依賴批量請求采用pipeline
3. eval script解決有依賴批量請求
4. redis高性能體現(xiàn)在服務(wù)端處理能力，但瓶頸往往出現(xiàn)在客戶端，因此增強客戶端I/O能力與并發(fā)并行多客戶端才是高并發(fā)解決方案

最新評論