如何從時延毛刺問題定位到Netty的性能統(tǒng)計設(shè)計

小編給大家分享一下如何從時延毛刺問題定位到Netty的性能統(tǒng)計設(shè)計，相信大部分人都還不怎么了解，因此分享這篇文章給大家參考一下，希望大家閱讀完這篇文章后大有收獲，下面讓我們一起去了解一下吧！

一、背景：

通常情況下，用戶以黑盒的方式使用Netty，通過Netty完成協(xié)議消息的讀取和發(fā)送，以及編解碼操作，不需要關(guān)注Netty的底層實(shí)現(xiàn)細(xì)節(jié)。

在高并發(fā)場景下，往往需要統(tǒng)計系統(tǒng)的關(guān)鍵性能KPI數(shù)據(jù)，結(jié)合日志、告警等對故障進(jìn)行定位分析，如果對Netty的底層實(shí)現(xiàn)細(xì)節(jié)不了解，獲取哪些關(guān)鍵性能數(shù)據(jù)，以及數(shù)據(jù)正確的獲取方式都將成為難點(diǎn)。錯誤或者不準(zhǔn)確的數(shù)據(jù)可能誤導(dǎo)定位思路和方向，導(dǎo)致問題遲遲不能得到正確解決。

二、時延毛刺故障排查的艱辛歷程:

問題現(xiàn)象：某電商生產(chǎn)環(huán)境在業(yè)務(wù)高峰期，偶現(xiàn)服務(wù)調(diào)用時延突刺問題，時延突然增大的服務(wù)沒有固定規(guī)律，問題發(fā)生的比例雖然很低，但是對客戶的體驗(yàn)影響很大，需要盡快定位出問題原因并解決。

• 時延毛刺問題初步分析：

服務(wù)調(diào)用時延增大，但并不是異常，因此運(yùn)行日志并不會打印ERROR日志，單靠傳統(tǒng)的日志無法進(jìn)行有效問題定位。利用分布式消息跟蹤系統(tǒng)，進(jìn)行分布式環(huán)境的故障定界。

通過對服務(wù)調(diào)用時延進(jìn)行排序和過濾，找出時延增大的服務(wù)調(diào)用鏈詳細(xì)信息，發(fā)現(xiàn)業(yè)務(wù)服務(wù)端處理很快，但是消費(fèi)者統(tǒng)計數(shù)據(jù)卻顯示服務(wù)端處理非常慢，調(diào)用鏈兩端看到的數(shù)據(jù)不一致，怎么回事？

對調(diào)用鏈的詳情進(jìn)行分析發(fā)現(xiàn)，服務(wù)端打印的時延是業(yè)務(wù)服務(wù)接口調(diào)用的耗時，并沒有包含：

（1）服務(wù)端讀取請求消息、對消息做解碼，以及內(nèi)部消息投遞、在線程池消息隊(duì)列排隊(duì)等待的時間。

（2）響應(yīng)消息編碼時間、消息隊(duì)列發(fā)送排隊(duì)時間以及消息寫入到Socket發(fā)送緩沖區(qū)的時間。

服務(wù)調(diào)用鏈的工作原理如下：

圖1 服務(wù)調(diào)用鏈工作原理

將調(diào)用鏈中的消息調(diào)用過程詳細(xì)展開，以服務(wù)端讀取請求和發(fā)送響應(yīng)消息為例進(jìn)行說明，如下圖所示：

圖2 服務(wù)端調(diào)用鏈詳情

對于服務(wù)端的處理耗時，除了業(yè)務(wù)服務(wù)自身調(diào)用的耗時之外，還應(yīng)該包含服務(wù)框架的處理時間，具體如下：

（1）請求消息的解碼（反序列化）時間。

（2）請求消息在業(yè)務(wù)線程池中排隊(duì)等待執(zhí)行時間。

（3）響應(yīng)消息編碼（序列化）時間。

（4）響應(yīng)消息ByteBuf在發(fā)送隊(duì)列的排隊(duì)時間。

由于服務(wù)端調(diào)用鏈只采集了業(yè)務(wù)服務(wù)接口的調(diào)用耗時，沒有包含服務(wù)框架本身的調(diào)度和處理時間，導(dǎo)致無法對故障進(jìn)行定界：服務(wù)端沒有統(tǒng)計服務(wù)框架的處理時間，因此不排除問題出在消息發(fā)送隊(duì)列或者業(yè)務(wù)線程池隊(duì)列積壓而導(dǎo)致時延變大。

• 服務(wù)調(diào)用鏈改進(jìn)：

對服務(wù)調(diào)用鏈埋點(diǎn)進(jìn)行優(yōu)化，具體措施如下：

（1）包含客戶端和服務(wù)端消息編碼和解碼的耗時。

（2）包含請求和應(yīng)答消息在隊(duì)列中的排隊(duì)時間。

（3）包含應(yīng)答消息在通信線程發(fā)送隊(duì)列（數(shù)組）中的排隊(duì)時間。

同時，為了方便問題定位，增加打印輸出Netty的性能統(tǒng)計日志，主要包括：

（1）當(dāng)前系統(tǒng)的總鏈路數(shù)、以及每個鏈路的狀態(tài)。

（2）每條鏈路接收的總字節(jié)數(shù)、周期T接收的字節(jié)數(shù)、消息接收吞吐量。

（3）每條鏈路發(fā)送的總字節(jié)數(shù)、周期T發(fā)送的字節(jié)數(shù)、消息發(fā)送吞吐量。

對服務(wù)調(diào)用鏈優(yōu)化之后，上線運(yùn)行一段時間，通過分析比對Netty性能統(tǒng)計日志、調(diào)用鏈日志，發(fā)現(xiàn)雙方的數(shù)據(jù)并不一致，Netty性能統(tǒng)計日志統(tǒng)計到的數(shù)據(jù)與前端門戶看到的也不一致，因此懷疑是新增的性能統(tǒng)計功能存在BUG，需要繼續(xù)對問題進(jìn)行定位。

• 都是同步思維惹的禍:

傳統(tǒng)的同步服務(wù)調(diào)用，發(fā)起服務(wù)調(diào)用之后，業(yè)務(wù)線程阻塞，等待響應(yīng)，接收到響應(yīng)之后，業(yè)務(wù)線程繼續(xù)執(zhí)行，對發(fā)送的消息進(jìn)行累加，獲取性能KPI數(shù)據(jù)。

使用Netty之后，所有的網(wǎng)絡(luò)I/O操作都是異步執(zhí)行的，即調(diào)用Channel的write方法，并不代表消息真正發(fā)送到TCP緩沖區(qū)中，如果在調(diào)用write方法之后就對發(fā)送的字節(jié)數(shù)做計數(shù)，統(tǒng)計結(jié)果就不準(zhǔn)確。

對消息發(fā)送功能進(jìn)行code review，發(fā)現(xiàn)代碼調(diào)用完writeAndFlush方法之后直接對發(fā)送的請求消息字節(jié)數(shù)進(jìn)行計數(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ò)上，它僅僅是個異步的消息發(fā)送操作而已，調(diào)用writeAndFlush之后，Netty會執(zhí)行一系列操作，最終將消息發(fā)送到網(wǎng)絡(luò)上，相關(guān)流程如下所示：

圖3 writeAndFlush處理流程圖

通過對writeAndFlush方法深入分析，我們發(fā)現(xiàn)性能統(tǒng)計代碼忽略了如下幾個耗時：

（1）業(yè)務(wù)ChannelHandler的執(zhí)行時間。

（2）被異步封裝的WriteTask/WriteAndFlushTask在NioEventLoop任務(wù)隊(duì)列中的排隊(duì)時間。

（3）ByteBuf在ChannelOutboundBuffer隊(duì)列中排隊(duì)時間。

（4）JDK NIO類庫將ByteBuffer寫入到網(wǎng)絡(luò)的時間。

由于性能統(tǒng)計遺漏了上述4個關(guān)鍵步驟的執(zhí)行時間，因此統(tǒng)計出來的發(fā)送速率比實(shí)際值會更高一些，這將干擾我們的問題定位思路。

• 正確的消息發(fā)送速率性能統(tǒng)計策略:

正確的消息發(fā)送速率性能統(tǒng)計方法如下：

（1）調(diào)用writeAndFlush方法之后獲取ChannelFuture。

（2）新增消息發(fā)送ChannelFutureListener并注冊到ChannelFuture中，監(jiān)聽消息發(fā)送結(jié)果，如果消息寫入SocketChannel成功，則Netty會回調(diào)ChannelFutureListener的operationComplete方法。

（3）在消息發(fā)送ChannelFutureListener的operationComplete方法中進(jìn)行性能統(tǒng)計。

正確的性能統(tǒng)計代碼示例如下：

public voidchannelRead(ChannelHandlerContext ctx, Object msg) {

        int sendBytes =((ByteBuf)msg).readableBytes();

        ChannelFuture writeFuture =ctx.write(msg);

        writeFuture.addListener((f) ->

        {

           totalSendBytes.getAndAdd(sendBytes);

        });

        ctx.flush();

}

對Netty消息發(fā)送相關(guān)源碼進(jìn)行分析，當(dāng)發(fā)送的字節(jié)數(shù)大于0時，進(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)行對比，判斷當(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()方法時，最終會調(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)聽中計數(shù)，結(jié)果才更精確。

需要注意的是，異步回調(diào)通知由Netty的NioEventLoop線程執(zhí)行，即便異步回調(diào)代碼寫在業(yè)務(wù)線程中，也是由Netty的I/O線程來執(zhí)行累加計數(shù)的，因此這塊兒需要考慮多線程并發(fā)安全問題，調(diào)用堆棧示例如下：

圖4 消息發(fā)送結(jié)果異步回調(diào)通知執(zhí)行線程

如果消息報文比較大，或者一次批量發(fā)送的消息比較多，可能會出現(xiàn)“寫半包”問題，即一個消息無法在一次write操作中全部完成發(fā)送，可能只發(fā)送了一半，針對此類場景，可以創(chuàng)建GenericProgressiveFutureListener用于實(shí)時監(jiān)聽消息發(fā)送進(jìn)度，做更精準(zhǔn)的統(tǒng)計，相關(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);

        }

}

問題定位出來之后，按照正確的做法對Netty性能統(tǒng)計代碼進(jìn)行了修正，上線之后，結(jié)合調(diào)用鏈日志，很快定位出了業(yè)務(wù)高峰期偶現(xiàn)的部分服務(wù)時延毛刺較大問題，優(yōu)化業(yè)務(wù)線程池參數(shù)配置之后問題得到解決。

• 常見的消息發(fā)送性能統(tǒng)計誤區(qū):

在實(shí)際業(yè)務(wù)中比較常見的性能統(tǒng)計誤區(qū)如下：

（1）調(diào)用write/ writeAndFlush方法之后就開始統(tǒng)計發(fā)送速率。

（2）消息編碼時進(jìn)行性能統(tǒng)計：編碼之后，獲取out可讀的字節(jié)數(shù)，然后做累加。編碼完成并不代表消息被寫入到SocketChannel中，因此性能統(tǒng)計也不準(zhǔn)確。

• Netty關(guān)鍵性能指標(biāo)采集:

除了消息發(fā)送速率，還有其它一些重要的指標(biāo)需要采集和監(jiān)控，無論是在調(diào)用鏈詳情中展示，還是統(tǒng)一由運(yùn)維采集、匯總和展示，這些性能指標(biāo)對于故障的定界和定位幫助都很大。

• Netty I/O線程池性能指標(biāo):

Netty I/O線程池除了負(fù)責(zé)網(wǎng)絡(luò)I/O消息的讀寫，還需要同時處理普通任務(wù)和定時任務(wù)，因此消息隊(duì)列積壓的任務(wù)個數(shù)是衡量Netty I/O線程池工作負(fù)載的重要指標(biāo)。由于Netty NIO線程池采用的是一個線程池/組包含多個單線程線程池的機(jī)制，因此不需要像原生的JDK線程池那樣統(tǒng)計工作線程數(shù)、最大線程數(shù)等。相關(guān)代碼如下所示：

publicvoid channelActive(ChannelHandlerContext ctx) throws Exception {

kpiExecutorService.scheduleAtFixedRate(()->

        {

            Iterator<EventExecutor>executorGroups = ctx.executor().parent().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)計KPI數(shù)據(jù)

• Netty發(fā)送隊(duì)列積壓消息數(shù)：

Netty消息發(fā)送隊(duì)列積壓數(shù)可以反映網(wǎng)絡(luò)速度、通信對端的讀取速度、以及自身的發(fā)送速度等，因此對于服務(wù)調(diào)用時延的精細(xì)化分析對于問題定位非常有幫助，它的采集方式代碼示例如下：

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對應(yīng)的消息發(fā)送隊(duì)列性能KPI數(shù)據(jù)

由于totalPendingSize是volatile的，因此統(tǒng)計線程即便不是Netty的I/O線程，也能夠正確的讀取其最新值。

• Netty消息讀取速率性能統(tǒng)計:

針對某個Channel的消息讀取速率性能統(tǒng)計，可以在解碼ChannelHandler之前添加一個性能統(tǒng)計ChannelHandler，用來對讀取速率進(jìn)行計數(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)計

以上是“如何從時延毛刺問題定位到Netty的性能統(tǒng)計設(shè)計”這篇文章的所有內(nèi)容，感謝各位的閱讀！相信大家都有了一定的了解，希望分享的內(nèi)容對大家有所幫助，如果還想學(xué)習(xí)更多知識，歡迎關(guān)注億速云行業(yè)資訊頻道！