天天看点

我工作这几年(四) -- 解决短信平台OutOfMemory问题及收获

原创链接: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 内存模型

我工作这几年(四) -- 解决短信平台OutOfMemory问题及收获

Java Heap内存分代图

Java 的内存模型分为:

  1. Young(年轻代)
  2. Tenured(终身代)
  3. 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] [[email protected]]<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

http://aub.iteye.com/blog/1872868

http://how-it-works.iteye.com/blog/1142888

我工作这几年(一) -- 读“有多少人像这样这样苦苦挣扎”有感

我工作这几年(二) 

我工作这几年(三) -- 实现短信平台