服务器假死日志按时间统计排查

场景

服务器假死，进程还在，但是已经接不到请求了。因此有客户报事，发现服务假死了。

解决方案

这种假死问题一般不太好排查，常规来说有几种可能。
1、慢sql导致卡死。
2、大数据列表等导致内存占慢。
3、gc的回收问题。

操作步骤：
1、首先要把gc日志备份，这一步一定要先做，因为常规的gc文件重启后就会覆盖，就找不到了。
2、然后才是重启。
3、后续的排查。

排查过程

首先是gc.out，很不幸忘了备份了，因为好久不遇到，忘了要先备份gc日志再重启。

那么没办法，从日志找吧。
服务假死，日志输出会明显减少，甚至不输出。 这个彻底死掉的时间很好判断，很长时间没日志，最后一条就是彻底死掉的时间。

但是如何排查何时开始变慢的呢?
有种思路就是根据分钟统计日志行数，正常来说基本会差不太多，如果某个时间日志条数明显减少，就说明开始有问题了。

命令：

例如日志为：
2023-09-22 11:26:47,266 [http-nio-8081-exec-244] - INFO  com.ttt.common.aop.ServiceDigestAop$$EnhancerBySpringCGLIB$$42f78b6 -
实际上我们截取到分钟就行了。

awk '{print $1FS$2}' business.log |cut -c 1-16 |sort | uniq -c 
	$1 是 2023-09-22
	FS是分隔符，默认是空格，加这个主要是可以区分日 和 时分
	$2 是 11:26:47
	cut -c 1-16 截取1-16个字符，正好到分钟

如果要根据数量倒序排序，可以加个 sort -nr
awk '{print $1FS$2}' business.log |cut -c 1-16 |sort | uniq -c | sort -nr
1
2
3
4
5
6
7
8
9
10
11
12

获取到的数据如：

4048 2023-09-22 11:28
2503 2023-09-22 11:29
3891 2023-09-22 11:30
4902 2023-09-22 11:31
  700  2023-09-22 11:32
  300 2023-09-22 11:33
      1 2023-09-22 11:34
1
2
3
4
5
6
7

很明显，700对应的时间就开始有问题了。

然后就可以把这30分钟的数据全拿出来。

 grep "2023-09-22 11:30" business.log > /tmp/11点30.txt 
 输处到/tmp目录，可以不受服务器账户权限限制，例如下载等
1
2

根据cost时间来筛选

还有一种思路，是根据cost时间来筛选，项目中一般都做了log日志拦截器，会打印耗费的时间，例如：

日志未：
2023-09-22 11:30:28,526 [http-nio-8081-exec-305] - INFO  com.www.common.aop.ServiceDigestAop - *** cost 77945 ms

grep "cost*ms" business > /tmp/cost-12点所有的.txt
1
2
3
4

这样导出的日志都是带时间的，找到比较大的，再根据线程号去看具体某条请求。