遇到个小BUG之后

时间:2022-07-24
本文章向大家介绍遇到个小BUG之后,主要内容包括其使用实例、应用技巧、基本知识点总结和需要注意事项,具有一定的参考价值,需要的朋友可以参考一下。

事故开始

时间在回到一周前,测试跑过来跟我说:压测500w同步数据失败了。我保持以往的态度,莫慌莫慌,多大点事儿,然后打开运行日志,然后一看居然是内存不足,如下图:

# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 12288 bytes for committing reserved memory.

做了那么久Java开发还是第一次遇到这种情况,然后free命令,查看一下服务器剩余内存,发现有5个G剩余,然后想一下,这不应该啊。然后自己也来测试一下,重新启动同步程序,一开始还是没有问题。过了10分钟后,Linux命令free查看剩余内存,10s钟刷新一下,内存消耗200M,到最后没有错10min钟后就跑蹦了。这时候我想了一下,应该遇到内存泄漏OOM了(真倒霉)。

第一次尝试

1.1、分析定位应用

从刚才的分析来看肯定是OOM导致的了,那要定位到底是哪个服务占用内存是一直飙升的。

Linux下运行如下命令可以查看,内存消耗最多的前10个进程:

ps auxw|head -1;ps auxw|sort -rn -k4|head -10

从图中基本锁定的了是第一个应用A或者第二个应用B

1.2、大数据量分小批次执行

查看运行日志后,发现A应用的数据库连接报错。mybatis进行批量update时报错了,打印了sql。这时候我的悬着的心突然放了下来,有种幸亏你报错了的感觉!!执行了打印的sql发现执行批量update操作1w条数据导致异常,估计是超时导致,但是该sql的where条件是主键,应该比较快的。所以现在只能降低数据量了,最终改为1000条数据进行操作速度就跟上了。改好问题然后测试环境执行一下,没有报错,内存也没有什么异常,下班!!!

第二天打开日志文件一看update还是报错,我擦傻眼了,服务又停了,又是内存溢出。

第二次尝试

服务B多线程通过fegin调用服务A中的接口,从服务A的报错日志来看是批量update导致mysql死锁的,然后搜索一下如何解决,类似如图:

发现了这位兄台的分析比较符合我的情况:https://www.cnblogs.com/pufeng/p/12069835.html

问题总结:应该是由于多线程同时修改同一条数据导致mysql死锁。比如你正在update某会员C的信息,另一条线程也在udpate该会员的信息这就会导致死锁。

2.1、加分布式锁

分布式锁的方式有很多,这里我的项目中用的jedis,各位可以自己搜索redis分布锁。类似逻辑如下

           boolean isLock = false;
            try {
                //调用路由服务同步数据
                while (!isLock) {
                    //获取分布式锁(20秒过期)
                    isLock = this.jedisClient.tryGetDistributedLock(RedisKey.CAS_SELLER_TRADES + sellerTable.getUserName(), sellerTable.getUserName(), 20);
                    try {
                        Thread.sleep(1000);
                    } catch (Exception e) {
                        logger.error("同步交易|获取分布式锁异常:" + e.getMessage());
                    }
                }
                long timeMillis = System.currentTimeMillis();
                 //TODO 执行业务,调用服务A中的同步接口
                  //***********************
                logger.info("同步交易|卖家账号:{}|调用路由同步数据耗时:{}毫秒", sellerTable.getUserName(), System.currentTimeMillis() - timeMillis);
            } catch (Exception e) {
                logger.error("同步交易|卖家账号:{}|线程异常:{}", sellerTable.getUserName(), ExceptionUtil.getStackTrace(e));
            } finally {
                //每条线程完成就释放
                if (isLock) {
                     this.jedisClient.releaseDistributedLock(RedisKey.CAS_SELLER_TRADES + sellerTable.getUserName(), sellerTable.getUserName());
                }
            }

然后重新执行应用程序,以为现在就应该ok了吧。但30分钟后,服务A居然还是停了,这次报错是关于fegin hystrix报错,结合日志打印的应该是服务接口处理时间过长(主要是入库update耗时),导致大量线程请求堆积到服务A接口。

2.2、改变分布式锁位置

从上面可知道,目前是因为大量线程堆积到了服务A,服务A受不了就报错给你看。

那么最简单的办法应该就是将分布式锁移到服务B调用服务A接口的位置,加上信号量Semaphore对线程数进行控制应该就可以了。此处做法就与上面相同,各位看需求是否需要加信号量Semaphore控制线程数量。

然后部署继续进行测试观察。。。跑了2个200w数据,大约20分钟,服务A还是内存溢出了,日志报错,这次报错是mysql的某一条select查询超时。

第三次尝试

在Navicat中执行日志的sql,居然耗时20s多都还没返回,估计问题就是在这里了。

3.1、加索引

因为表中的数据已经有400w数据,所以此次查询的条件没有索引,这样子当然慢的。所以将服务A该接口的所有操作的sql语句都检查一遍是否需要加联合索引或者普通索引或者主键之类的。

注意:索引的最左原则。最好是通过explain分析一下sql语句是否使用了索引。

explain分析sql语句:

https://www.cnblogs.com/tufujie/p/9413852.html

3.2、减少非必要的列返回

此处就不多说了,特别注意的是有一些字段所占的数据是特别大的,如果没有业务必要的话尽量不要查询返回。

到此,应该不会出现什么问题了吧,然后部署测试环境。大约过了20分钟左右,内存还是溢出了,这次日志文件都没有报错。。。。。这就尴尬了!!!!

第四次尝试

经过请教大神,这种情况应该是对象引用没有释放才会导致堆栈溢出的。

本地运行相关服务程序,windows可以打开jdk目录下的jvisualvm.exe工具、jconsole.exe工具对内存进行监控看看哪一步出现的问题。至于这两个工具怎么用可以网上搜索一下哈。

Linux下可以使用命令进行监控:

jstat -gc [pid] [ms]

4.1、jstat命令分析

相关参数的含义如下:

  • S0C、S1C、S0U、S1U:Survivor 0/1区容量(Capacity)和使用量(Used)
  • EC、EU:Eden区容量和使用量
  • OC、OU:年老代容量和使用量
  • PC、PU:永久代容量和使用量
  • YGC、YGT:年轻代GC次数和GC耗时
  • FGC、FGCT:Full GC次数和Full GC耗时

主要留意图中的两个参数OC,OU。如果OC一直飚升,OU一直往上飚没有回落的情况的话,那就是老年代溢出了,这就表明你的代码中有对象一直引用着没有释放。

多观察几个周期,OU有规律性的下降就是正常,如下图:

关于该jstat 命令可以参考文章:https://www.cnblogs.com/qmfsun/p/5601734.html

4.2、内存溢出解决方案

各自写的代码不一样,这里就很难判断的。有同学说可以查看内存溢出文件分析一下就知道了。的确没有错,如下链接:https://www.cnblogs.com/lemon-flm/p/11599505.html

但是,我是直接将所有用到的对象、集合等都给清空并置空。这样子100%不会溢出了吧。

最终稳定地运行了!!花费了2天时间终于把它搞定了,差点掏空了我所有的Java知识。主要是代码写的不够严谨导致的,要多学习多思考!!