原创链接:http://blog.csdn.net/zhao_3546/article/details/12946275,转载请注明。
在 我工作这几年(三) -- 实现短信平台 中提及短信平台上线后,遇到了Heap OutOfMemory的问题,这也是我当时工作1年多来遇到的最难解决的问题。
下面就讲讲这个问题的定位过程。
一、概述
首先这个问题是在现网运行了一个多月之后都出现,之前我们在实验室环境也跑过很久,一直没有遇到过,而且也跑过10小时的性能测试,没有出现同样的问题,但现网出现了,说明我们在家里模拟得还不到位。
于是我又将所有的代码又重新走读了一遍,没有发现问题。
领导又协调测试组帮助重新做性能测试,之前测试了10个小时,这次就加大并发压力和测试时长。在测试了大概20个小时左右,问题重现了,从日志中异常的信息来看,很相似。但是问题到底出在哪里,还是不知道。这个问题就是个定时炸弹,不找到根因,现网迟早还要出问题,当时压力很大,但又束手无策。
后来我们当时的大领导从其他部门协调了一个专家(这个专家后来成为了我的直接主管),来协助我们解决。
这个专家牵头,成立了一个攻关小组,其实也就三人,他、我、还有个负责性能测试的兄弟,开了一个短会,明确了每个人的职责。
会后他和我一起分析了一下问题,看了一下我们的当时环境,发现连基本的GC监控都没有加,所以就把我们环境的Tomcat的脚本给修改了,加上了GC相关的配置。
由于代码量还不小,就没有一起分析代码了,但是他建议我重点把所有的全局MAP、LIST等之类的全局容器,再重点分析一遍,看看是不是有容器中的元素没有正常清理掉。
同时让负责性能测试的兄弟,再协助重点重现问题。
虽然我在解决这方面问题没有太多的经验,但是Java内存泄漏的主要原因还是知道的,内存中所有涉及到MAP、List等变量的地方,都有重点分析过,没有找出问题。
将GC日志通过工具分析出的曲线图看,Heap内存确实是在持续上升。
在没有找到原因的几天,很郁闷,也想了很多办法,但就是没处入手。于是开始上网狂找资料,Java官网、各种技术网站等等,反正和内网相关的网站都逛遍了,
期间了解了Java内存模型的一些基本原理,同时还接触了几个非常有用的工具,特别是jmap这个工具,最后就是通过这个工具找到问题根因的。
二、Java 内存模型
Java Heap内存分代图
Java 的内存模型分为:
- Young(年轻代)
- Tenured(终身代)
- Perm(永久代)
注意Young(年轻代)还可以分为Eden区和两个Survivor区(from和to,这两个Survivor区大小严格一至),新的对象实例总是首先放在Eden区,Survivor区作为Eden区和 Tenure(终生代)的缓冲,可以向 Tenure(终生代)转移活动的对象实例。
Tenure(终生代)中存放生命周期长久的实例对象,但并不是如它的名字那样是终生的,里面的对象照样会被回收掉。
Young和Tenure共同组成了堆内存。
Perm(永久代)则是非堆内存的组成部分。主要存放加载的Class类级对象如class本身,method,field等等。
有同学可能已经注意到了,每个代都有的Virtual区又是什么?
我们知道有一些参数可以影响以上各代的大小。
在JVM启动时,就已经保留了固定的内存空间给Heap内存,这部分内存并不一定都会被JVM使用,但是可以确定的是这部分保留的内存不会被其他进程使用。这部分内存大小由 -Xmx参数指定。
而另一部分内存在JVM启动时就分配给JVM,作为JVM的初始Heap内存使用。影响这个的参数是 -Xms ,如果 -Xms 指定的值比-Xmx 的小,那么两者的差值就是Virtual内存值。随着程序的运行,Eden区、 Tenured区和Perm区会逐渐使用保留的Virtual空间。
三、实际解决过程模拟回放
下面通过一个示例简单地分析一下当时定位解决的过程。
如下是模拟Heap OutOfMemory的最简单的Java代码:
import java.util.HashMap;
import java.util.Map;
public class Main
{
public static void main(String[] args)
{
Map<String, String> map = new HashMap<String, String>();
for (int i = 0; i < Integer.MAX_VALUE; ++i)
{
map.put("test" + i, "test" + i);
if (i % 10000 == 0)
{
System.out.println("i = " + i);
}
}
}
}
编译得到Main.class后,执行: java -Xmx512m Main
运行结果如下:
......
i = 3070000
i = 3080000
i = 3090000
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
at Main.main(Main.java:11)
要执行下面的命令,必须要在 Linux环境下:
jmap
Usage:
jmap [option] <pid>
(to connect to running process)
jmap [option] <executable <core>
(to connect to a core file)
jmap [option] [server_id@]<remote server IP or hostname>
(to connect to remote debug server)
where <option> is one of:
<none> to print same info as Solaris pmap
-heap to print java heap summary
-histo[:live] to print histogram of java object heap; if the "live"
suboption is specified, only count live objects
-permstat to print permanent generation statistics
-finalizerinfo to print information on objects awaiting finalization
-dump:<dump-options> to dump java heap in hprof binary format
dump-options:
live dump only live objects; if not specified,
all objects in the heap are dumped.
format=b binary format
file=<file> dump heap to <file>
Example: jmap -dump:live,format=b,file=heap.bin <pid>
-F force. Use with -dump:<dump-options> <pid> or -histo
to force a heap dump or histogram when <pid> does not
respond. The "live" suboption is not supported
in this mode.
-h | -help to print this help message
-J<flag> to pass <flag> directly to the runtime system
jmap -histo PID的运行结果如下:
jmap -histo 16558
num #instances #bytes class name
----------------------------------------------
1: 11751104 469925224 [C
2: 11751085 282026040 java.lang.String
3: 5875112 188003584 java.util.HashMap$Entry
4: 17 33555728 [Ljava.util.HashMap$Entry;
5: 367 4806936 [I
6: 5415 741496 <methodKlass>
7: 5415 653896 <constMethodKlass>
8: 360 417464 <constantPoolKlass>
9: 326 264768 <constantPoolCacheKlass>
10: 360 257704 <instanceKlassKlass>
11: 497 84368 [B
12: 419 51328 java.lang.Class
13: 590 39048 [[I
14: 541 34912 [S
15: 42 24192 <objArrayKlassKlass>
16: 312 13144 [Ljava.lang.Object;
17: 32 11000 <methodDataKlass>
18: 110 7920 java.lang.reflect.Field
19: 8 4608 <typeArrayKlassKlass>
20: 108 3456 java.util.Hashtable$Entry
21: 11 2288 <klassKlass>
22: 53 1920 [Ljava.lang.String;
23: 38 1824 sun.util.locale.LocaleObjectCache$CacheEntry
24: 55 1760 java.util.concurrent.ConcurrentHashMap$HashEntry
25: 42 1680 java.util.concurrent.ConcurrentHashMap$Segment
26: 42 1344 java.util.concurrent.locks.ReentrantLock$NonfairSync
27: 42 1136 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
28: 6 992 [Ljava.util.Hashtable$Entry;
29: 15 840 java.util.HashMap
30: 13 832 java.net.URL
31: 19 760 java.io.ObjectStreamField
32: 19 760 sun.util.locale.BaseLocale$Key
33: 16 640 java.lang.ref.SoftReference
34: 10 624 [Ljava.lang.reflect.Field;
35: 6 624 java.lang.Thread
36: 19 608 sun.util.locale.BaseLocale
37: 15 600 java.util.LinkedHashMap$Entry
38: 37 592 java.lang.Object
39: 6 480 [Ljava.util.concurrent.ConcurrentHashMap$Segment;
40: 19 456 java.util.Locale
41: 19 456 java.util.Locale$LocaleKey
42: 6 432 java.lang.reflect.Constructor
43: 5 400 [Ljava.util.WeakHashMap$Entry;
44: 6 384 java.nio.DirectByteBuffer
45: 6 336 java.nio.DirectLongBufferU
46: 10 320 java.security.AccessControlContext
47: 13 312 java.io.ExpiringCache$Entry
48: 6 288 sun.misc.URLClassPath$JarLoader
49: 6 288 java.util.concurrent.ConcurrentHashMap
50: 5 280 java.util.WeakHashMap
51: 8 256 java.lang.OutOfMemoryError
52: 8 256 java.lang.ref.ReferenceQueue
53: 9 240 [Ljava.io.ObjectStreamField;
54: 4 224 java.util.Hashtable
55: 5 200 java.util.WeakHashMap$Entry
56: 6 192 java.util.Vector
57: 7 168 java.io.File
58: 2 160 [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
59: 4 160 java.lang.ref.Finalizer
60: 10 160 java.lang.ref.ReferenceQueue$Lock
61: 6 144 sun.misc.MetaIndex
62: 3 144 sun.nio.cs.UTF_8$Encoder
63: 6 144 sun.misc.PerfCounter
64: 6 144 java.util.ArrayList
65: 2 128 java.io.ExpiringCache$1
66: 3 120 java.security.ProtectionDomain
67: 2 112 java.util.Properties
68: 1 112 java.lang.ref.Finalizer$FinalizerThread
69: 6 112 [Ljava.lang.Class;
70: 2 112 sun.nio.cs.StreamEncoder
71: 1 104 java.lang.ref.Reference$ReferenceHandler
72: 3 96 java.lang.ThreadLocal$ThreadLocalMap$Entry
73: 2 96 java.lang.ThreadGroup
74: 2 96 java.io.BufferedWriter
75: 3 96 java.security.CodeSource
76: 3 96 java.util.Stack
77: 2 96 java.nio.HeapByteBuffer
78: 1 80 java.lang.reflect.Method
79: 1 80 sun.misc.Launcher$ExtClassLoader
80: 2 80 sun.misc.URLClassPath
81: 1 80 sun.misc.Launcher$AppClassLoader
82: 5 80 java.lang.ThreadLocal
83: 2 80 java.io.ExpiringCache
84: 3 72 java.io.FileDescriptor
85: 3 72 sun.misc.Signal
86: 3 72 java.lang.RuntimePermission
87: 3 72 java.util.concurrent.atomic.AtomicLong
88: 3 72 java.util.Collections$SynchronizedSet
89: 3 72 [Ljava.lang.reflect.Constructor;
90: 3 72 sun.reflect.NativeConstructorAccessorImpl
91: 2 64 java.lang.VirtualMachineError
92: 2 64 java.io.FileOutputStream
93: 2 64 java.util.Random
94: 2 64 java.io.PrintStream
95: 2 64 [Ljava.lang.Thread;
96: 2 64 java.io.OutputStreamWriter
97: 2 64 java.lang.ref.ReferenceQueue$Null
98: 4 64 java.util.concurrent.atomic.AtomicInteger
99: 1 48 [J
100: 3 48 java.security.ProtectionDomain$Key
101: 3 48 [Ljava.security.Principal;
102: 3 48 java.nio.charset.CodingErrorAction
103: 2 48 sun.misc.NativeSignalHandler
104: 2 48 java.io.BufferedOutputStream
105: 3 48 java.lang.Integer
106: 3 48 sun.reflect.DelegatingConstructorAccessorImpl
107: 2 48 java.nio.charset.CoderResult
108: 2 48 java.lang.ThreadLocal$ThreadLocalMap
109: 1 40 sun.nio.cs.UTF_8$Decoder
110: 1 40 java.io.BufferedInputStream
111: 1 40 sun.nio.cs.StandardCharsets$Aliases
112: 1 40 sun.nio.cs.StandardCharsets$Classes
113: 1 40 sun.nio.cs.StandardCharsets$Cache
114: 1 32 java.io.FilePermission
115: 1 32 java.lang.StringCoding$StringDecoder
116: 2 32 java.nio.ByteOrder
117: 1 32 java.security.Permissions
118: 1 32 java.lang.StringCoding$StringEncoder
119: 1 32 java.util.Collections$SynchronizedMap
120: 1 32 java.lang.ClassLoader$NativeLibrary
121: 1 32 [Ljava.lang.ThreadGroup;
122: 1 32 java.security.BasicPermissionCollection
123: 2 32 [Ljava.lang.StackTraceElement;
124: 1 32 sun.nio.cs.StandardCharsets
125: 2 32 java.util.HashSet
126: 2 32 java.lang.Boolean
127: 1 32 java.util.concurrent.atomic.AtomicReferenceFieldUpdater$AtomicReferenceFieldUpdaterImpl
128: 2 32 sun.net.www.protocol.jar.Handler
129: 1 32 java.lang.NullPointerException
130: 1 32 java.lang.ArithmeticException
131: 1 32 java.io.UnixFileSystem
132: 1 32 [Ljava.lang.OutOfMemoryError;
133: 1 32 java.io.FileInputStream
134: 1 24 sun.launcher.LauncherHelper
135: 1 24 java.io.FilePermissionCollection
136: 1 24 [Lsun.launcher.LauncherHelper;
137: 1 24 java.util.Collections$EmptyMap
138: 1 24 java.lang.StringBuilder
139: 1 24 java.util.Locale$Cache
140: 1 24 [Ljava.lang.reflect.Method;
141: 1 24 java.util.Collections$UnmodifiableRandomAccessList
142: 1 24 sun.util.locale.BaseLocale$Cache
143: 1 24 java.util.BitSet
144: 1 24 sun.nio.cs.UTF_8
145: 1 24 java.lang.reflect.ReflectPermission
146: 1 24 java.util.Collections$SetFromMap
147: 1 24 sun.misc.URLClassPath$FileLoader
148: 1 16 java.lang.reflect.ReflectAccess
149: 1 16 java.util.Collections$EmptySet
150: 1 16 sun.net.www.protocol.file.Handler
151: 1 16 java.io.FileDescriptor$1
152: 1 16 java.util.Collections$EmptyList
153: 1 16 java.lang.Runtime
154: 1 16 java.security.ProtectionDomain$1
155: 1 16 java.nio.Bits$1
156: 1 16 java.security.ProtectionDomain$3
157: 1 16 java.lang.String$CaseInsensitiveComparator
158: 1 16 sun.misc.Unsafe
159: 1 16 sun.misc.Perf
160: 1 16 java.lang.Terminator$1
161: 1 16 java.util.Hashtable$EntrySet
162: 1 16 sun.reflect.ReflectionFactory
163: 1 16 java.lang.ref.Reference$Lock
164: 1 16 java.lang.System$2
165: 1 16 [Ljava.security.cert.Certificate;
166: 1 16 sun.misc.Launcher
167: 1 16 java.util.WeakHashMap$KeySet
168: 1 16 sun.misc.Launcher$Factory
169: 1 16 java.net.URLClassLoader$7
170: 1 16 [Ljava.lang.Throwable;
171: 1 16 java.util.zip.ZipFile$2
172: 1 16 java.lang.CharacterDataLatin1
173: 1 16 java.nio.charset.CoderResult$1
174: 1 16 java.nio.charset.CoderResult$2
Total 29393047 980958624
通过上面jmap -histo PID的输出,排在前几个的都是内存占用特别多的类,根据这个类就知道大概是哪里出了问题。
在我们的实际代码中,当时我们定义了一个Sms2SaveBean,所有的发送出去的短信和接收到的短信,我们都需要保存至DB中保留一段时间。
根据《我工作这几年(三) -- 实现短信平台》中的描述,实际上有N个线程在同时处理短信的发送和接收,但最终入库时,只有一个线程负责入库。
在短信量很大的情况下,这个短信入库线程根本就处理不过来。最后就造成Sms2SaveBean对象在内存中的大量集压,集压到一定程度,最后就OutOfMemory了。
这个问题其实是非常隐藏一个的OutOfMemory问题,刚开始工作经验不足,根本就意识不到这样的非常潜在的bug,后来我在review其他同事的代码时,也发现过同样的问题。
找到根因了,解决其实非常地简单,将短信入库线程改成多个,之前单个单个短信进行入库,现在修改成1次20个短信批量入库,实测多次问题解决。
通过这个问题的解决,对Java又有了一些新的认识和理解。我的新领导后来又让我认识到一个更重要的问题,通过在程序代码中加入一些关键统计信息来实时监控程序的运行状态,这个比出现问题后再补救更有效,也更省成本。
这个在下一篇再详细介绍。
四、参考
深入JVM内存机制讲解得比较不错的几个链接:
http://www.infoq.com/cn/articles/java-memory-model-1