技术问题系列--查询过大引发的Dubbo问题

  |   0 评论   |   0 浏览

某天上午，我喝着茶看着技术博客，突然接到一个系统告警短信，还没来得及看内容，公司的客服小姐姐就飞快的跑到面前说，“系统出问题了”，吓得我一口茶水喷了出来......

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、经验教训

通过分析问题，也得出些经验教训：

  1. 系统的监控告警功能非常重要。它有助于及时发现问题，解决问题，避免给公司造成损失。再次确定了它的重要性。
  2. 作为服务提供者，对接口的入参校验必不可少，不能任由别的微服务服务随意传参调用。
  3. 在服务提供者层面，要做好限流、异常操作的限制等，加强接口的健壮性。
  4. 再次见证了dubbo的生产级别的强大。
  5. 建议大家多阅读开源框架的源码。

原文链接： http://www.mangod.top/articles/2023/08/01/1690904592378.html、https://mp.weixin.qq.com/s/7INpeFoGDP9IftvYXqGNEA

感谢你的阅读，码字不易，欢迎点赞 关注 收藏！！！

标题：技术问题系列--查询过大引发的Dubbo问题
作者：不焦躁程序员
地址：http://mangod.top/articles/2023/08/01/1690904592378.html