记录一次生产环境bug的调试

记录一次生产环境bug的调试

• 先交代下问题以及背景：
          公司数据处理中的一个job一直跑的好好的，突然从某一天开始job执行失败，重启环境后又正常执行，简单查看问题日志，日志中出现大量connection reset信息，问题不间断出现，并且dev环境无法重现。

• 初始思路
          一开始运维把问题当作一个简单的网络连接中断问题来对待，修复思路大概开发是对运算框架中如果出现了类似的connection中断问题添加对应的重连机制进行应对。

• 实际问题
          随着时间推移，问题越来越频繁，甚至重启后job都会继续失败。于是需要对线上的实际情况进行进一步摸排。首先查看了业务代码，发现一些做join的表没有做合适的缓存，另外一些数据量非常大的raw data中的filter数据貌似也没有生效，导致上亿的数据直接被计算框架拉入了jvm中，而之前的运算又迟迟没有结束，大量的线程处于运算中。有了这个发现于是在任务失败后让运维拉取了jstat -gcutil状况，发现果不其然，一次任务执行触发了多次的fullgc ，因为生产环境使用的是G1，如此多的的full gc充分说明了问题

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT

  0.00 100.00  65.99  41.09  91.41      -   3327  668.558    24 1436.491 2105.048

        如上所示一次full gc时间居然长达1分钟，到此问题应该就水落石出了，长时间的gc导致了connection中断。
        接下来的问题便是要在dev重现类似问题，从而确认是fgc导致了connection中断，但是由于dev环境中数据量比生产少很多，很难复现问题，而且生产的数据是不可能全部给导入到dev的，这下给重现造成了很大的麻烦，但是某天偶然间在浏览jvm相关页面的时候看到了jmap，于是灵机一动jmap不正是可以导致fgc吗，于是乎在dev执行了如下指令jmap–histo:live pid来模拟full gc, 随着一次长达30多秒的fgc问题在dev得以重现，connection reset也在dev的log中同时出现。

• 扩展思路
          修复代码很简单，但是因为公司流程等问题，修复的代码要发布到生产又要10天半个月，所以笔者在此又想到了一个临时的fix方案，该方案并不能彻底解决问题，但是确实可以大大减缓问题的发生，主要思路如下：
          batch job在执行的时候会从data region拉取大量的数据到计算节点，从而生成的很多java大对象，因为G1收集器的原因这些大对象会独占掉堆上的每个小块，这样导致了每个小的分块中仍然有一定数量的内存被浪费，而连续的大内存分配又进一步导致了FGC的发生，所以只要我们提高jvm中-XX:G1HeapRegionSize的大小，就可以大大减少了大对象的数量，FGC也会随之减少很多。