线上排查导致Kafka客户端频繁断开的原因竟然是一行count++代码

清疚 2022-10-15 00:45 364阅读 0赞

> 就在上周公司某个系统的Kafka多个环境频繁宕机，让我给你慢慢说来！

--------------------

是这样的，上周的某一天，接到同事的报案：数据库没有回显，看一下Kafka数据目前处理不正常。接到报案后我就开始排查。

排查的开始我以为是心跳检测的时间不足以完成业务处理呢，于是我修改了Kafka的这两个配置项`session.timeout.ms`（心跳检测时间）、`max.poll.records`（一次拉取消息条数），根据我的估算修改参数后，发现并没有任何效果。

Kafka宕机后，重新启动Kafka所在的服务器，随后Kafka就开始分配消费者组等就可以进行消费了，但是消费消息有些异常。经过多次测试，发现了一个Kafka消费异常的规律

消费异常规律：每次重启Kafka客户端之后，在宕机的时间段内堆积的消息就会被Kafka消费掉，直到生产者生产一条消息送到消费端开始消费，期间并没有返回任何结果，随后Kafka客户端再次离线。如果再重启Kakfa客户端，将循环往复这个过程。

<table> 
 <thead> 
  <tr> 
   <th align="center">Kafka监控</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td align="center"><img src="https://img-blog.csdnimg.cn/20210522225402447.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80NDE3MDIyMQ==,size_16,color_FFFFFF,t_70" alt="在这里插入图片描述"></td> 
  </tr> 
 </tbody> 
</table>

根据系统打印的日志，重新启动Kafka客户端之后，生产者生产一条消息时，查看监控确定Kafka将消息送往了消费端。查看消费端日志，消费端有开始业务处理的日志，但是没有业务处理结果的日志。可以判定消费者业务代码有一定的问题。必须得经过业务代码的进一步排查才可以！

查看过后，真正的业务处理是没问题的。但是在调用一个日志记录的方法的时候发现了一些端倪！

> 虽然我把业务代码相关用马赛克覆盖了，但是剩余的这些代码细心的你也会发现一些问题！

<table> 
 <thead> 
  <tr> 
   <th align="center">日志记录业务处理</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td align="center"><img src="https://img-blog.csdnimg.cn/20210522225418247.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80NDE3MDIyMQ==,size_16,color_FFFFFF,t_70" alt="在这里插入图片描述"></td> 
  </tr> 
 </tbody> 
</table>

**日志记录代码分析：** 这个日志记录的代码可以说有一个地方写的不太地道，那就是`if()else()`代码块。既然用了return返回了为什么还写一个`else()`呢？由于不是我写的，这里也就点到为止了，毕竟是前同事写的代码，也要留一些尊重的！

由于业务通过xxxNo号码去获取记录日志，而这个号码业务处理提交事务并不能及时的拿到，所以他采用了线程休眠和短递归的方式去处理的，递归次数用count来计算最多递归五次，看到这里还是合理的，也许你没有发现什么问题！

### 那为什么我说是这个日志记录的业务代码导致Kafka客户端离线的呢？ ###

首先，Kafka宕机的问题已经锁定在了消费端业务代码，就可以得出一个简单的结论，这个问题是由于业务处理时间过长，没有得到正常返回，Kafka心跳检测机制没有在设置的时间内得出响应而导致Kafka客户端离线！

**Kafka客户端离线的原因：** 要知道Kafka是有一个心跳检测的机制，每过设定时间发一次请求确保Kafka消费端存活能正常消费消息，而在设置Kafka心跳参数的时候一定要超过业务的处理时间的，如果业务处理不完，Kafka心跳检测没有得到正常返回的话，就默认消费端与Kafka客户端断开连接（简单描述就是心跳检测后认为你的Kafka死掉了）

回归正题，日志记录业务的编码导致Kafka客户端离线，想必大家看到了用count来控制递归次数心里早已有了答案吧~

于是我随便写一个测试类，模拟一下这个递归！（由于业务的特殊count之类我传值为0，正常业务也传值是0！）

> 不得不说IDEA还是很强大的，递归的调用也给了标识！也是因为IDEA的强大，让我开发离不开它！

执行main方法，我打了一个断点，大家看一下断点。

然后会发现，不管你执行多少次，count永远等于0。这是为什么呢？

这需要你搞清楚两个概念，如下：

// count++ 简单来说是先用后加，也就是先赋值后做加法操作
    count++
    // ++count 简单来说是先加后用，也就是先做相加操作后赋值
    ++count

其实这里说明一下，IDEA工具早已给出了答案。如下：

<table> 
 <thead> 
  <tr> 
   <th align="center">鼠标放到count++上IDEA提示</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td align="center"><img src="https://img-blog.csdnimg.cn/20210522225508443.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80NDE3MDIyMQ==,size_16,color_FFFFFF,t_70" alt="在这里插入图片描述"></td> 
  </tr> 
 </tbody> 
</table>

`The value changed at 'count++' is never used`译为`在'count++'处更改的值永远不会被使用`，不得不说IDEA还是很强大的，强大到能给你找BUG！

这里可以简单解释为：用count约束递归次数，递归调用的时候用到了count++，注意count++是先赋值后相加的操作。不管入参count为几，递归调用的时候先赋值后相加的操作就导致count永远为入参时候的那个值，从此死循环在这个递归当中！（这个业务永远都处理不完，forever and ever！）

修改这个BUG很简单，就是将`count++`改为`++count`即可解决这个问题！（是不是很简单！）

> 正是由于前任的疏忽，导致了一系列问题的发生。同事就问道为什么之前没有爆出这个问题，这么久才爆出这个BUG引起的问题呢？

其实这个问题也很简单，因为之前业务处理的时候，在递归开始之前的那个`if()`中就已经返回了结果了。正式因为这次的业务一次性没有返回结果，导致了递归的调用，这调用了一次将一发不可收拾，问题就爆出了！

--------------------

这次问题是不是很魔幻呢？这告诉了我们，基础很重要，就像我们在这个互联网"内卷化"的时代，每天都沉浸在自己的领域，往往忽略很简单、很基础的问题，而这很简单、很基础的问题就能造成很大的问题，当那时再排查起来才会幡然醒悟！

如果你喜欢我的文章，对你还算是有所收获的话，请点赞、评论、收藏，你对我的支持将是我最大的动力！Thank You！