记录一次线上超时异常查询

超、凢脫俗 2023-03-13 15:26 34阅读 0赞

#### 线上事故复盘 ####

##### 前言 #####

*  前一次上线，当时正常，第二天发现有部分超时报警，最终发现应为Dubbo接口一次传输数据量太大导致线程虚拟内存占用

##### 线上问题排查过程 #####

*  报警邮件中查询到有一部分接口超时量激增，查询定位到某个Dubbo接口，从服务器中top名查询如下：
 *  ![在这里插入图片描述][20200515165908969.png]
 *  如上图显示dubbo项目进程CPU占用已经飙高到128%，并且不断在波动，一直维持在130%左右，初步推算是调用量激增导致Dubbo接口请求量变大，导致线程数量消耗，使用Arthas查询消耗CPU资源最多的前面几个线程如下图：  
    图不见了： 反正CPU前几名都指向同一个Dubbo接口，命令 Thread -n 5, 查询CPU资源消耗最多的前五名
 *  查询对应Dubbo接口的请求数量，用Awk命令统计今天的请求量看是否增多如下：  
    ![在这里插入图片描述][20200515171022459.png]
 *  量居然这么小，因为是新的接口，只有部分功能使用，那么上面估计的请求量的问题应该不存在，但是CPU消耗的却很大，估计是因为耗时太长，在通过TOP命令查询，问题发现Men区域内核缓冲使用量很高39562828，比之空闲的物理内存379888高两个数量级  
    ![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpYW9qaWFtaW4wMTAy_size_16_color_FFFFFF_t_70]
 *  量这么小的Dubbo接口能把交换区的资源耗尽，那问题就比较明显了，应该是每次处理的数据体量太大，内存不够，导致处理数据变慢，接口响应时间变慢，那之后就好查询了，继续更这个接口，看那部分信息有问题，发现在sql查询中查了一个这个字段，text类型，超级大，并且一次查出来的数据条数也比较大，导致最终Dubbo接口需要返回的数据量太多

`detail` text COMMENT '摘要',

*  因dubbo协议采用单一长连接，如果每次请求的数据包大小为500KByte，假设网络为千兆网卡(1024Mbit=128MByte)，每条连接最大7MByte(不同的环境可能不一样，供参考)，单个服务提专供者的TPS(每秒处理事务数)最大为：128MByte / 500KByte = 262，单个消费者调用单个服务提供者的TPS(每秒处理事务数)最大为：7MByte / 500KByte = 14。
 *  如上名计算如果我数据量继续变得更大，但是没有超过Dubbo限制情况下，其实每次处理数据是非常消耗内存与IO的。
 *  最终修改将不必要字段去除，上线发布，耗时下降，内存信息，cpu都恢复正常，如下图：  
    ![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpYW9qaWFtaW4wMTAy_size_16_color_FFFFFF_t_70 1]

[20200515165908969.png]: /images/20230312/f367908a4d0944e2a8297092c038815b.png
[20200515171022459.png]: /images/20230312/6f49ff2cdd3a4cd19f591788c24f04b4.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpYW9qaWFtaW4wMTAy_size_16_color_FFFFFF_t_70]: /images/20230312/1004d494eea74f368d6dcc4b725e4d64.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2xpYW9qaWFtaW4wMTAy_size_16_color_FFFFFF_t_70 1]: /images/20230312/c67ae4b116b44b3f9ce8df42dd5f50cc.png