Java事故排查

rag系列文章目录

---

前言

作为一名软件开发人员，经常会遇到各种各样的事故，一般凭借日志就可以定位到异常问题，然后修复测试，即可验证是否解决，这种较为简单的问题。

复杂一点的是，长时间运行出现的问题，比如运行几天之后，程序发生异常，这种不是部署上线后立即发现的，很难排查，但是一般也可以归结为并发性能异常、内存漏洞之类异常。这种情况，日志比较少，需要dump程序的信息，进行分析，以内存泄露为例来说，需要定位到程序中的大对象，然后查看相关代码定位。

还有一类问题，较为困难，也没有日志，内存dump数据也看不出什么，程序一直卡主，无从下手，今天就介绍一种。

---

一、异常现象

Springboot项目，使用sharding进行分库分表，程序使用mysql作为数据源，上线一直没问题，现在需要切换到postgres进行测试，发现程序一直起不来。

二、排查过程

1.查看日志

首先，检查程序日志，发现驱动报错，很开心，竟然有日志。

但是很快发现，这个日志并不是导致程序卡主的原因，这个错误反而导致排查的方向走错，浪费了时间。

2.查询堆栈信息

报错日志没有作用，排查没有了方向，为了排查方便，我单独建个项目，只是使用sharding来验证，发现同样的问题，但是这可以方便后续排查。

接下来只能看下程序内部信息，因为并没有内存溢出之类的问题，也无需排查内存dump信息。

接下来想到内存栈信息，看下main线程是不是没有起来，卡主了。

使用jstack命令查看，结果如下：

3.查询数据库

初次看到stack信息，也是一头雾水，看到main方法好像在正常运行，状态是正常的。最后在查询postgres数据库，那么就想到是不是数据库卡主了呢？

执行以下SQL来查看当前是否有被阻塞的查询以及锁的等待情况：

SELECT pg_stat_activity.pid,pg_stat_activity.query,pg_stat_activity.state,pg_locks.mode,pg_locks.granted,pg_blocking_pids(pg_stat_activity.pid) AS blocking_pids
FROM pg_stat_activity
JOIN pg_locks ON pg_locks.pid = pg_stat_activity.pid
WHERE pg_stat_activity.state = 'active'
AND pg_locks.mode LIKE '%ExclusiveLock%'
AND pg_stat_activity.query NOT LIKE '%pg_stat_activity%'; -- 排除掉这个查询本身

发现数据库查询有点慢，但是呢，好像一直在变化，也不是一个sql一直在卡主。而且把超时时间设置短了，好像不应该是一个大sql导致数据库查询卡主，如果超时了，日志也会打印出来，看起来是好像一直在执行sql查询。

4.调查栈方法

现在看起来有没有了思路，想着看下sharding的源码，看看哪里一直在执行，这也是合理的想法。

Stack栈信息里面也有很多方法，也不知道哪个重要，只知道sharding需要查询元数据。看代码，逐渐定位到sharding的loadDefaultTables方法，这里是查询表，然后去找元数据信息，要分库分表嘛。

自己在这个循环里面也debug的很多步，想着顺利执行也没啥问题，想着是不是表太多了导致的。

于是删除了所有的表，但是发现这里还是有数据，debug看下，都是在查询哪些表的数据，竟然发现是其他shema的数据！！！

三、结论

通过debug’发现，sharding需要查询这个数据库下面所有的表，进行统计，然后导致特别慢，这个数据库有1万多张表，看到数据库里面的元数据sql查询也比较慢，估计3s，乘以12000，就是36000s，相当于10个小时。

但是我url上面带了shema信息，应该不会去查询其他的schema，后面确认这个没有效果。
将sharding从4.0.1升级到4.1.1版本，schema指定是有效的。

---

总结

之前遇到没有日志的问题，也是很头疼的，无从下手，只能各种情况尝试，效率低，通过这次排查，帮自己梳理了思路，后面就不怕遇到类似的问题了。