Java内存优化之POI Excel(一)

结算系统上线后,每到月初月末,都有点胆战心惊,最怕听到“某某某,我这个下载又不行”、“我这个都下载了20分钟了,怎么还不行啊!”…… 我能怎么办哇,停下来把锅捡起来呗。

捡锅记之检锅

捡锅了,然后呢?当然是查一查问题出在哪了。ssh上服务器,先说说服务器配置吧。这台服务器是在某离职大神的建议下购买的,配置还不错。单核SSD硬盘,其他配置如下:

1
2
3
4
5
6
7
[web@monitor ~]$ free -m
total used free shared buff/cache available
Mem: 3790 2467 173 0 1150 1021
Swap: 0 0 0

[web@monitor ~]$ cat /etc/redhat-release
CentOS Linux release 7.3.1611 (Core)

查看服务状态

记得当初车险系统刚升级SpringBoot的时候,经常发现系统挂掉,Java进程也被kill掉,还纠结了好久,排查了很久发现是被由于Linux的OOM Killer机制杀掉的。

Linux OOM_killer是Linux自我保护的方式,当内存不足时不至于出现太严重问题,有点壮士断腕的意味。在kernel 2.6,内存不足将唤醒oom_killer,挑出/proc//oom_score最大者并将之kill掉,可以把/proc//oom_score_adj值改小(最小-17)来临时避免此种情况。

所以出现服务停止后,我第一反应就是查看Java进程还在不在。

1
2
3
[web@monitor ~]$ jcmd
19335 settlement.jar --spring.profiles.active=prod
30142 sun.tools.jcmd.JCmd

居然还在,唯一的借口都不给我!

检查Java进程栈

我第一个想到的是死锁,导致进程假死。看看Java栈:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
[web@monitor ~]$ jstack -l 19335
2017-11-03 21:44:07
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode):

"http-nio-8087-exec-10" #1017 daemon prio=5 os_prio=0 tid=0x00007f2cd0016000 nid=0x5c31 waiting on condition [0x00007f2c9d21a000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000920abcf8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:103)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:31)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)

Locked ownable synchronizers:
- None
.....

太长了,此处截取部分。我记得jstack 有时候可以帮我们检测出死锁的,可以直接

1
jstack -l <pid> | grep deadlock

如果有结果,则表示有死锁,当然也不排除其他情况(ps: 也遇到过数据库链接失效,导致某任务执行了3个多小时后失败的。)jstack的其他情况可以参考下:http://blog.csdn.net/wanglha/article/details/51133819

检查Java堆

Java对象大部分情况实在堆上创建的(有时候会在栈上或者有块叫做TLAB的空间),那么来检查下堆的情况吧。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
[web@monitor ~]$ jmap -heap 19335
Attaching to process ID 19335, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.144-b01

using thread-local object allocation.
Parallel GC with 2 thread(s)

Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
MaxHeapSize = 1879048192 (1792.0MB)
NewSize = 625999872 (597.0MB)
MaxNewSize = 625999872 (597.0MB)
OldSize = 1253048320 (1195.0MB)
NewRatio = 2
SurvivorRatio = 5
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)

Heap Usage:
PS Young Generation
Eden Space:
capacity = 569901056 (543.5MB)
used = 105560864 (543.5MB)
free = 464340192 (0MB)
100% used
From Space:
capacity = 27262976 (26.0MB)
used = 6621032 (6.314308166503906MB)
free = 20641944 (19.685691833496094MB)
24.28580064039964% used
To Space:
capacity = 26214400 (25.0MB)
used = 0 (0.0MB)
free = 26214400 (25.0MB)
0.0% used
PS Old Generation
capacity = 1253048320 (1195.0MB)
used = 55013328 (1195.0MB)
free = 1198034992 (0MB)
100% used

纳尼!!!Eden区和老年代都耗尽了(这些数据是后来假造的,当时的确看到的是两个100%)。

看看gc情况

1
2
3
[web@monitor ~]$ jstat -gcutil 19335
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 99.79 99.89 98.99 97.96 96.07 901 3.654 287 1.160 4.814

介绍下这几个参数,S0、S1表示两个Survivor区(复制GC算法使用),E表示Eden区,大部分对象在此创建,O老年代,多次GC后对象存活区域,M表示元数据区(JAVA8后取代永久代,存放一些class元数据,我们不用太关心它,基本上有JVM帮我们管理),YGC和FGC分别表示Eden区GC次数和Full GC的次数,正常情况下Full GC次数比较少,跑个几天Full GC几次差不多了,如果很多次就不正常了(当然排除哪个二货手动调用System.gc()),Full GC比较多,你可能会看到如下错误:java.lang.OutOfMemoryError: GC overhead limit exceeded,这个表示JVM试图通过GC回收内存,但是什么也没有回收到。默认情况下,JVM花费了98%的时间在GC上,但是GC过之后只有不到2%的堆内存被回收。

甩锅记之内存的锅

我去看下这群货到底要下载什么数据,一看吓一跳,两个月全国所有的保单数据。这是什么概念呢?两个月差不多20多万数据吧,如果不做关联单,那差不多是30多万到40万左右,30万行的Excel什么概念?自己想想吧。

我当然不能说你们别下这么多数据啊,反正我一个打工小弟说了也没人听啊!好吧,升级内存总可以吧,这锅你背。

1
java -Xms1536m -Xmx1536m -jar service.jar

初始化内存和最大内存设置一样是为了减少GC次数,为啥要减少GC呢?简单说就是GC比较霸道,它工作的时候STOP THE WORLD,所有的工作都得停下,等待GC完成。话说什么时候开始GC呢?你可以使用如下命令观察下:

1
2
 jstat -gcutil <pid> [intervalTime] [invokeCount]
其中intervalTime表示多久执行一次(单位毫秒),invokeCount表示总共会执行多少次。如:jstat -gcutil 19335 1000

大概当Eden区打到100%时会发生一次Young GC,Full GC类似。

堆内存的各个区

改完内存继续观察(后面还会升内存,毕竟这锅给内存背比较简单🤣),发现其实Eden、Survivor、Old区使用情况有很大差异,有的区很快就满了,有的还不到才20几。不行啊,得改,平均点!(这里说的是使用情况,不是都一样大)。

各个区大小比例

可以通过jmap命令查看

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
[jarvan4dev@Macbook] ~ $ jmap -heap 34890
Attaching to process ID 34890, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.74-b02

using thread-local object allocation.
Parallel GC with 4 thread(s)

Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
MaxHeapSize = 2147483648 (2048.0MB)
NewSize = 44564480 (42.5MB)
MaxNewSize = 715653120 (682.5MB)
OldSize = 89653248 (85.5MB)
NewRatio = 2
SurvivorRatio = 8
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)

默认情况下(JDK8,不同版本可能不一样),NewRatio=2,表示新生代和老年代比例为1:2,SurvivorRatio=8,表示一个Survivor区和新生代比例为1:8,两个Survivor区(S0和S1),即每个Survivor区占堆内存的1/10,调节这两个参数可以调节各区大小比例,来达到最优的使用情况。

1
java -Xms1792m -XmX1792m -XX:NewRatio=2 -XX:SurvivorRatio=5 -jar service.jar

我知道是不会有人点的,但万一有人想不开呢!