一、背景：
通常情况下，用户以黑盒的方式使用Netty，通过Netty完成协议消息的读取和发送，以及编解码操作，不需要关注Netty的底层实现细节。
在高并发场景下，往往需要统计系统的关键性能KPI数据，结合日志、告警等对故障进行定位分析，如果对Netty的底层实现细节不了解，获取哪些关键性能数据，以及数据正确的获取方式都将成为难点。错误或者不准确的数据可能误导定位思路和方向，导致问题迟迟不能得到正确解决。
二、时延毛刺故障排查的艰辛历程:
问题现象：某电商生产环境在业务高峰期，偶现服务调用时延突刺问题，时延突然增大的服务没有固定规律，问题发生的比例虽然很低，但是对客户的体验影响很大，需要尽快定位出问题原因并解决。
- 时延毛刺问题初步分析：
服务调用时延增大，但并不是异常，因此运行日志并不会打印ERROR日志，单靠传统的日志无法进行有效问题定位。利用分布式消息跟踪系统，进行分布式环境的故障定界。
通过对服务调用时延进行排序和过滤，找出时延增大的服务调用链详细信息，发现业务服务端处理很快，但是消费者统计数据却显示服务端处理非常慢，调用链两端看到的数据不一致，怎么回事？
对调用链的详情进行分析发现，服务端打印的时延是业务服务接口调用的耗时，并没有包含：
（1）服务端读取请求消息、对消息做解码，以及内部消息投递、在线程池消息队列排队等待的时间。
（2）响应消息编码时间、消息队列发送排队时间以及消息写入到Socket发送缓冲区的时间。
服务调用链的工作原理如下：
图1 服务调用链工作原理
将调用链中的消息调用过程详细展开，以服务端读取请求和发送响应消息为例进行说明，如下图所示：
图2 服务端调用链详情
对于服务端的处理耗时，除了业务服务自身调用的耗时之外，还应该包含服务框架的处理时间，具体如下：
（1）请求消息的解码（反序列化）时间。
（2）请求消息在业务线程池中排队等待执行时间。
（3）响应消息编码（序列化）时间。
（4）响应消息ByteBuf在发送队列的排队时间。
由于服务端调用链只采集了业务服务接口的调用耗时，没有包含服务框架本身的调度和处理时间，导致无法对故障进行定界：服务端没有统计服务框架的处理时间，因此不排除问题出在消息发送队列或者业务线程池队列积压而导致时延变大。
- 服务调用链改进：
对服务调用链埋点进行优化，具体措施如下：
（1）包含客户端和服务端消息编码和解码的耗时。
（2）包含请求和应答消息在队列中的排队时间。
（3）包含应答消息在通信线程发送队列（数组）中的排队时间。
同时，为了方便问题定位，增加打印输出Netty的性能统计日志，主要包括：
（1）当前系统的总链路数、以及每个链路的状态。
（2）每条链路接收的总字节数、周期T接收的字节数、消息接收吞吐量。
（3）每条链路发送的总字节数、周期T发送的字节数、消息发送吞吐量。
对服务调用链优化之后，上线运行一段时间，通过分析比对Netty性能统计日志、调用链日志，发现双方的数据并不一致，Netty性能统计日志统计到的数据与前端门户看到的也不一致，因此怀疑是新增的性能统计功能存在BUG，需要继续对问题进行定位。
- 都是同步思维惹的祸:
传统的同步服务调用，发起服务调用之后，业务线程阻塞，等待响应，接收到响应之后，业务线程继续执行，对发送的消息进行累加，获取性能KPI数据。
使用Netty之后，所有的网络I/O操作都是异步执行的，即调用Channel的write方法，并不代表消息真正发送到TCP缓冲区中，如果在调用write方法之后就对发送的字节数做计数，统计结果就不准确。
对消息发送功能进行code review，发现代码调用完writeAndFlush方法之后直接对发送的请求消息字节数进行计数，代码示例如下：
public void channelRead(ChannelHandlerContextctx, Object msg) {
int sendBytes =((ByteBuf)msg).readableBytes();
ctx.writeAndFlush(msg);
totalSendBytes.getAndAdd(sendBytes);
}
调用writeAndFlush并不代表消息已经发送到网络上，它仅仅是个异步的消息发送操作而已，调用writeAndFlush之后，Netty会执行一系列操作，最终将消息发送到网络上，相关流程如下所示：
图3 writeAndFlush处理流程图
通过对writeAndFlush方法深入分析，我们发现性能统计代码忽略了如下几个耗时：
（1）业务ChannelHandler的执行时间。
（2）被异步封装的WriteTask/WriteAndFlushTask在NioEventLoop任务队列中的排队时间。
（3）ByteBuf在ChannelOutboundBuffer队列中排队时间。
（4）JDK NIO类库将ByteBuffer写入到网络的时间。
由于性能统计遗漏了上述4个关键步骤的执行时间，因此统计出来的发送速率比实际值会更高一些，这将干扰我们的问题定位思路。
