小編給大家分享一下如何從時(shí)延毛刺問題定位到Netty的性能統(tǒng)計(jì)設(shè)計(jì),相信大部分人都還不怎么了解,因此分享這篇文章給大家參考一下,希望大家閱讀完這篇文章后大有收獲,下面讓我們一起去了解一下吧!
創(chuàng)新互聯(lián)主要從事成都網(wǎng)站建設(shè)、做網(wǎng)站、網(wǎng)頁設(shè)計(jì)、企業(yè)做網(wǎng)站、公司建網(wǎng)站等業(yè)務(wù)。立足成都服務(wù)南芬,十載網(wǎng)站建設(shè)經(jīng)驗(yàn),價(jià)格優(yōu)惠、服務(wù)專業(yè),歡迎來電咨詢建站服務(wù):028-86922220
一、背景:
通常情況下,用戶以黑盒的方式使用Netty,通過Netty完成協(xié)議消息的讀取和發(fā)送,以及編解碼操作,不需要關(guān)注Netty的底層實(shí)現(xiàn)細(xì)節(jié)。
在高并發(fā)場景下,往往需要統(tǒng)計(jì)系統(tǒng)的關(guān)鍵性能KPI數(shù)據(jù),結(jié)合日志、告警等對(duì)故障進(jìn)行定位分析,如果對(duì)Netty的底層實(shí)現(xiàn)細(xì)節(jié)不了解,獲取哪些關(guān)鍵性能數(shù)據(jù),以及數(shù)據(jù)正確的獲取方式都將成為難點(diǎn)。錯(cuò)誤或者不準(zhǔn)確的數(shù)據(jù)可能誤導(dǎo)定位思路和方向,導(dǎo)致問題遲遲不能得到正確解決。
二、時(shí)延毛刺故障排查的艱辛歷程:
問題現(xiàn)象:某電商生產(chǎn)環(huán)境在業(yè)務(wù)高峰期,偶現(xiàn)服務(wù)調(diào)用時(shí)延突刺問題,時(shí)延突然增大的服務(wù)沒有固定規(guī)律,問題發(fā)生的比例雖然很低,但是對(duì)客戶的體驗(yàn)影響很大,需要盡快定位出問題原因并解決。
時(shí)延毛刺問題初步分析:
服務(wù)調(diào)用時(shí)延增大,但并不是異常,因此運(yùn)行日志并不會(huì)打印ERROR日志,單靠傳統(tǒng)的日志無法進(jìn)行有效問題定位。利用分布式消息跟蹤系統(tǒng),進(jìn)行分布式環(huán)境的故障定界。
通過對(duì)服務(wù)調(diào)用時(shí)延進(jìn)行排序和過濾,找出時(shí)延增大的服務(wù)調(diào)用鏈詳細(xì)信息,發(fā)現(xiàn)業(yè)務(wù)服務(wù)端處理很快,但是消費(fèi)者統(tǒng)計(jì)數(shù)據(jù)卻顯示服務(wù)端處理非常慢,調(diào)用鏈兩端看到的數(shù)據(jù)不一致,怎么回事?
對(duì)調(diào)用鏈的詳情進(jìn)行分析發(fā)現(xiàn),服務(wù)端打印的時(shí)延是業(yè)務(wù)服務(wù)接口調(diào)用的耗時(shí),并沒有包含:
(1)服務(wù)端讀取請(qǐng)求消息、對(duì)消息做解碼,以及內(nèi)部消息投遞、在線程池消息隊(duì)列排隊(duì)等待的時(shí)間。
(2)響應(yīng)消息編碼時(shí)間、消息隊(duì)列發(fā)送排隊(duì)時(shí)間以及消息寫入到Socket發(fā)送緩沖區(qū)的時(shí)間。
服務(wù)調(diào)用鏈的工作原理如下:
圖1 服務(wù)調(diào)用鏈工作原理
將調(diào)用鏈中的消息調(diào)用過程詳細(xì)展開,以服務(wù)端讀取請(qǐng)求和發(fā)送響應(yīng)消息為例進(jìn)行說明,如下圖所示:
圖2 服務(wù)端調(diào)用鏈詳情
對(duì)于服務(wù)端的處理耗時(shí),除了業(yè)務(wù)服務(wù)自身調(diào)用的耗時(shí)之外,還應(yīng)該包含服務(wù)框架的處理時(shí)間,具體如下:
(1)請(qǐng)求消息的解碼(反序列化)時(shí)間。
(2)請(qǐng)求消息在業(yè)務(wù)線程池中排隊(duì)等待執(zhí)行時(shí)間。
(3)響應(yīng)消息編碼(序列化)時(shí)間。
(4)響應(yīng)消息ByteBuf在發(fā)送隊(duì)列的排隊(duì)時(shí)間。
由于服務(wù)端調(diào)用鏈只采集了業(yè)務(wù)服務(wù)接口的調(diào)用耗時(shí),沒有包含服務(wù)框架本身的調(diào)度和處理時(shí)間,導(dǎo)致無法對(duì)故障進(jìn)行定界:服務(wù)端沒有統(tǒng)計(jì)服務(wù)框架的處理時(shí)間,因此不排除問題出在消息發(fā)送隊(duì)列或者業(yè)務(wù)線程池隊(duì)列積壓而導(dǎo)致時(shí)延變大。
服務(wù)調(diào)用鏈改進(jìn):
對(duì)服務(wù)調(diào)用鏈埋點(diǎn)進(jìn)行優(yōu)化,具體措施如下:
(1)包含客戶端和服務(wù)端消息編碼和解碼的耗時(shí)。
(2)包含請(qǐng)求和應(yīng)答消息在隊(duì)列中的排隊(duì)時(shí)間。
(3)包含應(yīng)答消息在通信線程發(fā)送隊(duì)列(數(shù)組)中的排隊(duì)時(shí)間。
同時(shí),為了方便問題定位,增加打印輸出Netty的性能統(tǒng)計(jì)日志,主要包括:
(1)當(dāng)前系統(tǒng)的總鏈路數(shù)、以及每個(gè)鏈路的狀態(tài)。
(2)每條鏈路接收的總字節(jié)數(shù)、周期T接收的字節(jié)數(shù)、消息接收吞吐量。
(3)每條鏈路發(fā)送的總字節(jié)數(shù)、周期T發(fā)送的字節(jié)數(shù)、消息發(fā)送吞吐量。
對(duì)服務(wù)調(diào)用鏈優(yōu)化之后,上線運(yùn)行一段時(shí)間,通過分析比對(duì)Netty性能統(tǒng)計(jì)日志、調(diào)用鏈日志,發(fā)現(xiàn)雙方的數(shù)據(jù)并不一致,Netty性能統(tǒng)計(jì)日志統(tǒng)計(jì)到的數(shù)據(jù)與前端門戶看到的也不一致,因此懷疑是新增的性能統(tǒng)計(jì)功能存在BUG,需要繼續(xù)對(duì)問題進(jìn)行定位。
都是同步思維惹的禍:
傳統(tǒng)的同步服務(wù)調(diào)用,發(fā)起服務(wù)調(diào)用之后,業(yè)務(wù)線程阻塞,等待響應(yīng),接收到響應(yīng)之后,業(yè)務(wù)線程繼續(xù)執(zhí)行,對(duì)發(fā)送的消息進(jìn)行累加,獲取性能KPI數(shù)據(jù)。
使用Netty之后,所有的網(wǎng)絡(luò)I/O操作都是異步執(zhí)行的,即調(diào)用Channel的write方法,并不代表消息真正發(fā)送到TCP緩沖區(qū)中,如果在調(diào)用write方法之后就對(duì)發(fā)送的字節(jié)數(shù)做計(jì)數(shù),統(tǒng)計(jì)結(jié)果就不準(zhǔn)確。
對(duì)消息發(fā)送功能進(jìn)行code review,發(fā)現(xiàn)代碼調(diào)用完writeAndFlush方法之后直接對(duì)發(fā)送的請(qǐng)求消息字節(jié)數(shù)進(jìn)行計(jì)數(shù),代碼示例如下:
public void channelRead(ChannelHandlerContextctx, Object msg) {
int sendBytes =((ByteBuf)msg).readableBytes();
ctx.writeAndFlush(msg);
totalSendBytes.getAndAdd(sendBytes);
}
調(diào)用writeAndFlush并不代表消息已經(jīng)發(fā)送到網(wǎng)絡(luò)上,它僅僅是個(gè)異步的消息發(fā)送操作而已,調(diào)用writeAndFlush之后,Netty會(huì)執(zhí)行一系列操作,最終將消息發(fā)送到網(wǎng)絡(luò)上,相關(guān)流程如下所示:
圖3 writeAndFlush處理流程圖
通過對(duì)writeAndFlush方法深入分析,我們發(fā)現(xiàn)性能統(tǒng)計(jì)代碼忽略了如下幾個(gè)耗時(shí):
(1)業(yè)務(wù)ChannelHandler的執(zhí)行時(shí)間。
(2)被異步封裝的WriteTask/WriteAndFlushTask在NioEventLoop任務(wù)隊(duì)列中的排隊(duì)時(shí)間。
(3)ByteBuf在ChannelOutboundBuffer隊(duì)列中排隊(duì)時(shí)間。
(4)JDK NIO類庫將ByteBuffer寫入到網(wǎng)絡(luò)的時(shí)間。
由于性能統(tǒng)計(jì)遺漏了上述4個(gè)關(guān)鍵步驟的執(zhí)行時(shí)間,因此統(tǒng)計(jì)出來的發(fā)送速率比實(shí)際值會(huì)更高一些,這將干擾我們的問題定位思路。
正確的消息發(fā)送速率性能統(tǒng)計(jì)策略:
正確的消息發(fā)送速率性能統(tǒng)計(jì)方法如下:
(1)調(diào)用writeAndFlush方法之后獲取ChannelFuture。
(2)新增消息發(fā)送ChannelFutureListener并注冊(cè)到ChannelFuture中,監(jiān)聽消息發(fā)送結(jié)果,如果消息寫入SocketChannel成功,則Netty會(huì)回調(diào)ChannelFutureListener的operationComplete方法。
(3)在消息發(fā)送ChannelFutureListener的operationComplete方法中進(jìn)行性能統(tǒng)計(jì)。
正確的性能統(tǒng)計(jì)代碼示例如下:
public voidchannelRead(ChannelHandlerContext ctx, Object msg) {
int sendBytes =((ByteBuf)msg).readableBytes();
ChannelFuture writeFuture =ctx.write(msg);
writeFuture.addListener((f) ->
{
totalSendBytes.getAndAdd(sendBytes);
});
ctx.flush();
}
對(duì)Netty消息發(fā)送相關(guān)源碼進(jìn)行分析,當(dāng)發(fā)送的字節(jié)數(shù)大于0時(shí),進(jìn)行ByteBuf的清理工作,代碼如下:
protected voiddoWrite(ChannelOutboundBuffer in) throws Exception {
//代碼省略...
if (localWrittenBytes <= 0) {
incompleteWrite(true);
return;
}
adjustMaxBytesPerGatheringWrite(attemptedBytes, localWrittenBytes,maxBytesPerGatheringWrite);
in.removeBytes(localWrittenBytes);
--writeSpinCount;
break;
//代碼省略...
}
接著分析ChannelOutboundBuffer的removeBytes(long writtenBytes)方法,將發(fā)送的字節(jié)數(shù)與當(dāng)前ByteBuf可讀的字節(jié)數(shù)進(jìn)行對(duì)比,判斷當(dāng)前的ByteBuf是否完成發(fā)送,如果完成則調(diào)用remove()清理它,否則只更新下發(fā)送進(jìn)度,相關(guān)代碼如下:
protected voiddoWrite(ChannelOutboundBuffer in) throws Exception {
//代碼省略...
if (readableBytes <=writtenBytes) {
if (writtenBytes != 0) {
progress(readableBytes);
writtenBytes -=readableBytes;
}
remove();
} else {
if (writtenBytes != 0) {
buf.readerIndex(readerIndex+ (int) writtenBytes);
progress(writtenBytes);
}
break;
}
//代碼省略...
}
當(dāng)調(diào)用remove()方法時(shí),最終會(huì)調(diào)用消息發(fā)送ChannelPromise的trySuccess方法,通知監(jiān)聽Listener消息已經(jīng)完成發(fā)送,相關(guān)代碼如下所示:
public booleantrySuccess(V result) {
//代碼省略...
if (setSuccess0(result)) {
notifyListeners();
return true;
}
return false;
}
//代碼省略...
}
經(jīng)過以上分析可以看出,調(diào)用write/writeAndFlush方法本身并不代表消息已經(jīng)發(fā)送完成,只有監(jiān)聽write/writeAndFlush的操作結(jié)果,在異步回調(diào)監(jiān)聽中計(jì)數(shù),結(jié)果才更精確。
需要注意的是,異步回調(diào)通知由Netty的NioEventLoop線程執(zhí)行,即便異步回調(diào)代碼寫在業(yè)務(wù)線程中,也是由Netty的I/O線程來執(zhí)行累加計(jì)數(shù)的,因此這塊兒需要考慮多線程并發(fā)安全問題,調(diào)用堆棧示例如下:
圖4 消息發(fā)送結(jié)果異步回調(diào)通知執(zhí)行線程
如果消息報(bào)文比較大,或者一次批量發(fā)送的消息比較多,可能會(huì)出現(xiàn)“寫半包”問題,即一個(gè)消息無法在一次write操作中全部完成發(fā)送,可能只發(fā)送了一半,針對(duì)此類場景,可以創(chuàng)建GenericProgressiveFutureListener用于實(shí)時(shí)監(jiān)聽消息發(fā)送進(jìn)度,做更精準(zhǔn)的統(tǒng)計(jì),相關(guān)代碼如下所示:
privatestatic void notifyProgressiveListeners0(
ProgressiveFuture> future,GenericProgressiveFutureListener>[] listeners, long progress,long total) {
for(GenericProgressiveFutureListener> l: listeners) {
if (l == null) {
break;
}
notifyProgressiveListener0(future,l, progress, total);
}
}
問題定位出來之后,按照正確的做法對(duì)Netty性能統(tǒng)計(jì)代碼進(jìn)行了修正,上線之后,結(jié)合調(diào)用鏈日志,很快定位出了業(yè)務(wù)高峰期偶現(xiàn)的部分服務(wù)時(shí)延毛刺較大問題,優(yōu)化業(yè)務(wù)線程池參數(shù)配置之后問題得到解決。
常見的消息發(fā)送性能統(tǒng)計(jì)誤區(qū):
在實(shí)際業(yè)務(wù)中比較常見的性能統(tǒng)計(jì)誤區(qū)如下:
(1)調(diào)用write/ writeAndFlush方法之后就開始統(tǒng)計(jì)發(fā)送速率。
(2)消息編碼時(shí)進(jìn)行性能統(tǒng)計(jì):編碼之后,獲取out可讀的字節(jié)數(shù),然后做累加。編碼完成并不代表消息被寫入到SocketChannel中,因此性能統(tǒng)計(jì)也不準(zhǔn)確。
Netty關(guān)鍵性能指標(biāo)采集:
除了消息發(fā)送速率,還有其它一些重要的指標(biāo)需要采集和監(jiān)控,無論是在調(diào)用鏈詳情中展示,還是統(tǒng)一由運(yùn)維采集、匯總和展示,這些性能指標(biāo)對(duì)于故障的定界和定位幫助都很大。
Netty I/O線程池性能指標(biāo):
Netty I/O線程池除了負(fù)責(zé)網(wǎng)絡(luò)I/O消息的讀寫,還需要同時(shí)處理普通任務(wù)和定時(shí)任務(wù),因此消息隊(duì)列積壓的任務(wù)個(gè)數(shù)是衡量Netty I/O線程池工作負(fù)載的重要指標(biāo)。由于Netty NIO線程池采用的是一個(gè)線程池/組包含多個(gè)單線程線程池的機(jī)制,因此不需要像原生的JDK線程池那樣統(tǒng)計(jì)工作線程數(shù)、最大線程數(shù)等。相關(guān)代碼如下所示:
publicvoid channelActive(ChannelHandlerContext ctx) throws Exception {
kpiExecutorService.scheduleAtFixedRate(()->
{
Iterator
while (executorGroups.hasNext())
{
SingleThreadEventExecutorexecutor = (SingleThreadEventExecutor)executorGroups.next();
int size = executor.pendingTasks();
if (executor == ctx.executor())
System.out.println(ctx.channel() + "--> " + executor +" pending size in queue is : --> " + size);
else
System.out.println(executor+ " pending size in queue is : --> " + size);
}
},0,1000, TimeUnit.MILLISECONDS);
}
}
運(yùn)行結(jié)果如下所示:
圖5 Netty I/O線程池性能統(tǒng)計(jì)KPI數(shù)據(jù)
Netty發(fā)送隊(duì)列積壓消息數(shù):
Netty消息發(fā)送隊(duì)列積壓數(shù)可以反映網(wǎng)絡(luò)速度、通信對(duì)端的讀取速度、以及自身的發(fā)送速度等,因此對(duì)于服務(wù)調(diào)用時(shí)延的精細(xì)化分析對(duì)于問題定位非常有幫助,它的采集方式代碼示例如下:
publicvoid channelActive(ChannelHandlerContext ctx) throws Exception {
writeQueKpiExecutorService.scheduleAtFixedRate(()->
{
long pendingSize =((NioSocketChannel)ctx.channel()).unsafe().outboundBuffer().totalPendingWriteBytes();
System.out.println(ctx.channel() +"--> " + " ChannelOutboundBuffer's totalPendingWriteBytes is: "
+ pendingSize + "bytes");
},0,1000, TimeUnit.MILLISECONDS);
}
執(zhí)行結(jié)果如下:
圖6 Netty Channel對(duì)應(yīng)的消息發(fā)送隊(duì)列性能KPI數(shù)據(jù)
由于totalPendingSize是volatile的,因此統(tǒng)計(jì)線程即便不是Netty的I/O線程,也能夠正確的讀取其最新值。
Netty消息讀取速率性能統(tǒng)計(jì):
針對(duì)某個(gè)Channel的消息讀取速率性能統(tǒng)計(jì),可以在解碼ChannelHandler之前添加一個(gè)性能統(tǒng)計(jì)ChannelHandler,用來對(duì)讀取速率進(jìn)行計(jì)數(shù),相關(guān)代碼示例如下(ServiceTraceProfileServerHandler類):
public voidchannelActive(ChannelHandlerContext ctx) throws Exception {
kpiExecutorService.scheduleAtFixedRate(()->
{
int readRates =totalReadBytes.getAndSet(0);
System.out.println(ctx.channel() +"--> read rates " + readRates);
},0,1000, TimeUnit.MILLISECONDS);
ctx.fireChannelActive();
}
public void channelRead(ChannelHandlerContextctx, Object msg) {
int readableBytes =((ByteBuf)msg).readableBytes();
totalReadBytes.getAndAdd(readableBytes);
ctx.fireChannelRead(msg);
}
運(yùn)行結(jié)果如下所示:
圖7 NettyChannel 消息讀取速率性能統(tǒng)計(jì)
以上是“如何從時(shí)延毛刺問題定位到Netty的性能統(tǒng)計(jì)設(shè)計(jì)”這篇文章的所有內(nèi)容,感謝各位的閱讀!相信大家都有了一定的了解,希望分享的內(nèi)容對(duì)大家有所幫助,如果還想學(xué)習(xí)更多知識(shí),歡迎關(guān)注創(chuàng)新互聯(lián)行業(yè)資訊頻道!