某天上午，我喝着茶看着技术博客，突然接到一个系统告警短信，还没来得及看内容，公司的客服小姐姐就飞快的跑到面前说，“系统出问题了”，吓得我一口茶水喷了出来......
1、问题反馈
听了客服小姐姐的反馈之后，我又赶紧看了下系统的告警短信内容（某个微服务内存达到了阈值），紧接着我查看了系统异常日志，内容如下：
2023-08-01 14:00:12|ERROR|com.xxx.xxx.xxx.ordercenter.api.DubboApiAop:validResultSize|79|DubboServerHandler-10.11.4.4:20880-thread-195|"orderCenter dubbo interface result is too large, size：321673424, class：com.xxx.xxx.xxx.ordercenter.api.impl.ClueApiImpl@5dc7881d, method：queryList"|""
2023-08-01 14:00:13|ERROR|org.apache.dubbo.remoting.transport.AbstractCodec:checkPayload|52|NettyServerWorker-6-4|"Data length too large: 59892326, max payload: 8388608, channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]]"|"org.apache.dubbo.remoting.transport.ExceedPayloadLimitException: Data length too large: 59892326, max payload: 8388608, channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]] at org.apache.dubbo.remoting.transport.AbstractCodec.checkPayload(AbstractCodec.java:50) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encodeResponse(ExchangeCodec.java:296) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encode(ExchangeCodec.java:71) at org.apache.dubbo.rpc.protocol.dubbo.DubboCountCodec.encode(DubboCountCodec.java:40) at org.apache.dubbo.remoting.transport.netty4.NettyCodecAdapter$InternalEncoder.encode(NettyCodecAdapter.java:69)"2023-08-01 14:00:13|WARN|org.apache.dubbo.remoting.exchange.codec.ExchangeCodec:encodeResponse|311|NettyServerWorker-6-4|" [DUBBO] Data length too large: 59892326, max payload: 8388608, channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]], dubbo version: 2.7.8, current host: 10.11.4.4"|"org.apache.dubbo.remoting.transport.ExceedPayloadLimitException: Data length too large: 59892326, max payload: 8388608, channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]] at org.apache.dubbo.remoting.transport.AbstractCodec.checkPayload(AbstractCodec.java:50) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encodeResponse(ExchangeCodec.java:296) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encode(ExchangeCodec.java:71) at org.apache.dubbo.rpc.protocol.dubbo.DubboCountCodec.encode(DubboCountCodec.java:40) at org.apache.dubbo.remoting.transport.netty4.NettyCodecAdapter$InternalEncoder.encode(NettyCodecAdapter.java:69) // ===================================
2023-08-01 14:20:12|ERROR|com.xxx.xxx.xxx.ordercenter.api.DubboApiAop:validResultSize|79|DubboServerHandler-10.11.1.186:20880-thread-198|"orderCenter dubbo interface result is too large, size：321689904, class：com.xxx.xxx.xxx.ordercenter.api.impl.ClueApiImpl@3b850bb7, method：queryList"|""
2023-08-01 14:20:12|ERROR|org.apache.dubbo.remoting.transport.AbstractCodec:checkPayload|52|NettyServerWorker-6-3|"Data length too large: 59896419, max payload: 8388608, channel: NettyChannel [channel=[id: 0xfa3545c4, L:/10.11.1.186:20880 - R:/10.11.0.124:48306]]"|"org.apache.dubbo.remoting.transport.ExceedPayloadLimitException: Data length too large: 59896419, max payload: 8388608, channel: NettyChannel [channel=[id: 0xfa3545c4, L:/10.11.1.186:20880 - R:/10.11.0.124:48306]] at org.apache.dubbo.remoting.transport.AbstractCodec.checkPayload(AbstractCodec.java:50) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encodeResponse(ExchangeCodec.java:296) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encode(ExchangeCodec.java:71) at org.apache.dubbo.rpc.protocol.dubbo.DubboCountCodec.encode(DubboCountCodec.java:40) at org.apache.dubbo.remoting.transport.netty4.NettyCodecAdapter$InternalEncoder.encode(NettyCodecAdapter.java:69)"2023-08-01 14:20:12|WARN|org.apache.dubbo.remoting.exchange.codec.ExchangeCodec:encodeResponse|311|NettyServerWorker-6-3|" [DUBBO] Data length too large: 59896419, max payload: 8388608, channel: NettyChannel [channel=[id: 0xfa3545c4, L:/10.11.1.186:20880 - R:/10.11.0.124:48306]], dubbo version: 2.7.8, current host: 10.11.1.186"|"org.apache.dubbo.remoting.transport.ExceedPayloadLimitException: Data length too large: 59896419, max payload: 8388608, channel: NettyChannel [channel=[id: 0xfa3545c4, L:/10.11.1.186:20880 - R:/10.11.0.124:48306]] at org.apache.dubbo.remoting.transport.AbstractCodec.checkPayload(AbstractCodec.java:50) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encodeResponse(ExchangeCodec.java:296) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encode(ExchangeCodec.java:71) at org.apache.dubbo.rpc.protocol.dubbo.DubboCountCodec.encode(DubboCountCodec.java:40) at org.apache.dubbo.remoting.transport.netty4.NettyCodecAdapter$InternalEncoder.encode(NettyCodecAdapter.java:69)
复制代码
2、问题分析
2.1、大致原因
看到异常日志后，接下来就是分析原因和解决问题了。我们系统架构是 SpringCloudAlibaba + Dubbo 的微服务架构，采用云原生的部署方式，有一套 Kubernetes 的 Dashboard 和监控告警系统。
从上面的 Dubbo 的错误信息Data length too large: 59896419, max payload: 8388608，能猜出是某个微服务接口响应对象的大小超过默认值引发的异常。是哪个接口响应对象过大呢？继续分析。
2.2、深度剖析
1、之前我对 Dubbo 服务提供者做了统一的切面，在切面里会判断接口响应对象的内存占用是否过大，如果过大，会把相关的类和方法打印出来。所以，能看到下面这段日志。从这段日志能定位出是哪个系统的哪个接口出现的对象过大的问题。
2023-08-01 14:20:12|ERROR|com.xxx.xxx.xxx.ordercenter.api.DubboApiAop:validResultSize|79|DubboServerHandler-10.11.1.186:20880-thread-198|"orderCenter dubbo interface result is too large, size：321689904, class：com.xxx.xxx.xxx.ordercenter.api.impl.ClueApiImpl@3b850bb7, method：queryList"|""
复制代码
2、哪个服务提供者的哪个接口确定之后，如果判断是哪个服务调用者呢？继续分析这段日志：
2023-08-01 14:00:13|ERROR|org.apache.dubbo.remoting.transport.AbstractCodec:checkPayload|52|NettyServerWorker-6-4|"Data length too large: 59892326, max payload: 8388608, channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]]"|"org.apache.dubbo.remoting.transport.ExceedPayloadLimitException: Data length too large: 59892326, max payload: 8388608, channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]] at org.apache.dubbo.remoting.transport.AbstractCodec.checkPayload(AbstractCodec.java:50) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encodeResponse(ExchangeCodec.java:296) at org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encode(ExchangeCodec.java:71) at org.apache.dubbo.rpc.protocol.dubbo.DubboCountCodec.encode(DubboCountCodec.java:40) at org.apache.dubbo.remoting.transport.netty4.NettyCodecAdapter$InternalEncoder.encode(NettyCodecAdapter.java:69)
复制代码
3、这段日志里有一行信息引入注目：channel: NettyChannel [channel=[id: 0xa9b42a62, L:/10.11.4.4:20880 - R:/10.11.2.152:42026]]，看来突破口要从这里找了，于是我赶紧翻看了 Dubbo 源码，找到了源码对应的位置，见下图：
4、顺着checkPayload方法，找到encodeResponse方法。至此可以判断，Dubbo 将服务提供者的响应对象序列化后通过 Netty 传输的出去的过程中会对接口响应对象的大小做校验。
5、checkPayload方法里打印的信息是channel，入参也是Channel，所以继续挖Channel类。从上面的日志可以看出，此Channel接口的实现类是NettyChannel，所以继续挖源码，找到了与上面日志内容相匹配的代码了，见下图：
6、那上面这段代码里的channel是个啥呢？上面日志里的 L、R 和 2 个 IP 地址又是什么意思呢？ 想弄明白这个问题，只能在小小的源码里面继续挖呀挖呀挖。终于在 Dubbo 里的 Netty 的源码部分里挖到了这段代码，代码里打印的信息和上面的异常日志信息完全一致，见下图：
7、至此我们已经清晰地看到上面的异常是怎么引发出来的了。也明白了日志里的 L、R 和 2 个 IP 地址代表的意思，L 代表本地 IP 地址，R 代表远程 IP 地址。
8、接下来就很轻松了，通过远程 IP 地址在 Kubernetes 的 Dashboard 里找到了 IP 地址对应的 Kubernetes-Pod，从而确定了是哪个微服务。
9、找到微服务之后，继续找到了调用的地方。最后发现，是因为程序员小贾，在调用 queryList 接口的时候，缺少了一些查询条件，导致查询到了大量数据，引发了内存阈值告警。
3、问题总结
结合异常日志和 Dubbo 源码，通过层层源码分析，得出结论：程序员小贾写代码调用某个微服务的查询接口时，由于少传了核心条件，导致大量数据被查询加载到了内存里，引发了内存告警。幸好，Dubbo 有接口响应数据过大的校验，才没引发更严重的问题。
问题至此分析完毕，接下来程序员小贾要赶紧修复代码上线了，然后要背上一口锅，顺带我也要分一口小锅。
4、经验教训
通过分析问题，也得出些经验教训：
系统的监控告警功能非常重要。它有助于及时发现问题，解决问题，避免给公司造成损失。再次确定了它的重要性。
作为服务提供者，对接口的入参校验必不可少，不能任由别的微服务服务随意传参调用。
在服务提供者层面，要做好限流、异常操作的限制等，加强接口的健壮性。
再次见证了 dubbo 的生产级别的强大。
建议大家多阅读开源框架的源码。
评论