一次堆外OOM問題的排查

jzlxiaohei 8年前發布 | 22K 次閱讀 OOM JVM Java開發

背景

線上服務有一臺機器訪問不通（一個管理平臺),在公司的服務治理平臺上查看服務的狀況是正常的，說明進程還在。進程并沒有完全crash掉。去線上查看機器日志，發現了大量的OOM異常:

017-03-15 00:00:00.041 [WARN] qtp1947699202-120772 nio handle failed
java.lang.OutOfMemoryError: Direct buffer memory
        at java.nio.Bits.reserveMemory(Bits.java:658) ~[?:1.7.0_76]
        at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123) ~[?:1.7.0_76]
        at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:306) ~[?:1.7.0_76]
        at sun.nio.ch.Util.getTemporaryDirectBuffer(Util.java:174) ~[?:1.7.0_76]
        at sun.nio.ch.IOUtil.read(IOUtil.java:195) ~[?:1.7.0_76]
        at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:379) ~[?:1.7.0_76]
        at org.eclipse.jetty.io.nio.ChannelEndPoint.fill(ChannelEndPoint.java:235) ~[jetty-io-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.io.nio.SelectChannelEndPoint.fill(SelectChannelEndPoint.java:326) ~[jetty-io-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1040) ~[jetty-http-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:280) ~[jetty-http-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) ~[jetty-http-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) ~[jetty-server-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628) [jetty-io-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) [jetty-io-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) [jetty-util-8.1.10.v20130312.jar:8.1.10.v20130312]
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) [jetty-util-8.1.10.v20130312.jar:8.1.10.v20130312]
        at java.lang.Thread.run(Thread.java:745) [?:1.7.0_76]
        at java.lang.Thread.run(Thread.java:745) [?:1.7.0_76]
2017-03-15 00:00:00.718 [WARN] elasticsearch[Thundra][transport_client_worker][T#6]{New I/O worker #6} AbstractNioSelector Unexpected exception in the selector loop.
java.lang.OutOfMemoryError: Direct buffer memory
        at java.nio.Bits.reserveMemory(Bits.java:658) ~[?:1.7.0_76]
        at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123) ~[?:1.7.0_76]
        at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:306) ~[?:1.7.0_76]
        at org.jboss.netty.channel.socket.nio.SocketReceiveBufferAllocator.newBuffer(SocketReceiveBufferAllocator.java:64) ~[netty-3.10.5.Final.jar:?]
        at org.jboss.netty.channel.socket.nio.SocketReceiveBufferAllocator.get(SocketReceiveBufferAllocator.java:41) ~[netty-3.10.5.Final.jar:?]
        at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:62) ~[netty-3.10.5.Final.jar:?]
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) ~[netty-3.10.5.Final.jar:?]
        at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337) [netty-3.10.5.Final.jar:?]
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.10.5.Final.jar:?]
        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.10.5.Final.jar:?]
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.10.5.Final.jar:?]
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.10.5.Final.jar:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [?:1.7.0_76]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [?:1.7.0_76]
        at java.lang.Thread.run(Thread.java:745) [?:1.7.0_76]</code></pre> 
  
可以發現是Direct buffer memory的native memory滿了，無法分配堆外內存。由于jetty使用的是nio，nio里面大量的使用native memeory。無法分配native memory之后，導致所有的請求都無效 
    
    
  排查 
  趕快去看了下監控系統上面內存和線程的一些監控指標 
    
   
    
   
    
   
    
   
    
   
    
   
    
  文件描述符、runable線程數 、directbuffer 已經達到了2G（我們-Xmx的值），老年代已經1G多了。但是沒有fullGC。youngc次數也不是很多，但是出現問題的機器young gc明顯比沒出現問題的機器多 
  根據上面的指標，初步定位是由線程創建的網絡連接造成了native memory不夠 。最上面的log日志顯示除了jetty之外還有一個就是ElasticSearch client的worker線程也出現的分配OOM。回想上次開發新功能的時候，會創建大量的ES client連接，會不會是這個問題。查看代碼發現確實是因為創建了大量的ES連接，但是并沒有主動close掉。導致線程數暴增，由于ElasticSearch client是用的netty做的網絡層，使用了大量的DirectByteBuffer.引用一直存在(client線程一直存在)，無法GC掉，DirectByteBuffer對象，導致native memory也無法回收。下圖是用jprofile測試ElasticSearch client的時候發現的。可以得到的是ElasticSearch client確實會產生大量的DirectByteBuffer 
    
   
    
   
    
  old gen為什么會多呢？ 
  那為什么old gen的對象這么多呢？其實就是一大堆的bytebuffer冰山對象進入了oldgen ，然而fullgc都沒有發生，bytebuffer不會被回收，但是這個時候native memory已經被分配完了，所以OOM了。查了資料發現我們在JVM參數中添加了這個:-XX:+DisableExplicitGC.這個參數會導致顯示調用System.gc()無效。然而在分配native memory中有這樣一段代碼: 
  // These methods should be called whenever direct memory is allocated or
// freed.  They allow the user to control the amount of direct memory
// which a process may access.  All sizes are specified in bytes.
static void reserveMemory(long size, int cap) {
    synchronized (Bits.class) {
        if (!memoryLimitSet && VM.isBooted()) {
            maxMemory = VM.maxDirectMemory();
            memoryLimitSet = true;
        }
        // -XX:MaxDirectMemorySize limits the total capacity rather than the
        // actual memory usage, which will differ when buffers are page
        // aligned.
        if (cap <= maxMemory - totalCapacity) {
            reservedMemory += size;
            totalCapacity += cap;
            count++;
            return;
        }
    }
    //提醒jvm該gc了，回收下死掉的對象
    System.gc();
    try {
        Thread.sleep(100);
    } catch (InterruptedException x) {
        // Restore interrupt status
        Thread.currentThread().interrupt();
    }
    synchronized (Bits.class) {
        //計算可分配的是否已經超過maxMemeory，超過則拋出OOM異常
        if (totalCapacity + cap > maxMemory)
            throw new OutOfMemoryError("Direct buffer memory");
        reservedMemory += size;
        totalCapacity += cap;
        count++;
    }
}</code></pre> 
  
通過這段代碼發現，每次分配native memory的時候會通知jvm進行一次GC。如果我們配置了上面的jvm參數會導致這行代碼不起任何作用。old gen里面的對象就算死掉也不會回收，除非old gen本身滿了，但是通過上面的old gen使用了1G，還沒有到old gen的最大值。沒有full gc所以native memory一直沒有被回收。其實就算我們沒有設置jvm參數估計也會OOM ，因為bytebuffer因為線程只有的關系不會全部死掉。大部分bytebuffer也不會被回收 
    
    
  關于DirectByteBuffer 
   
   
   Perm中主要放一些class和meta信息，常量池，靜態字段等。這些東西都放在所謂的方法區中，在hotspot中也就是“持久帶”。 
   對于習慣在HotSpot虛擬機上開發和部署程序的開發者來說，很多人愿意把方法區稱為“永久代”（Permanent Generation），本質上兩者并不等價，僅僅是因為HotSpot虛擬機的設計團隊選擇把GC分代收集擴展至方法區，或者說使用永久代來實現方法區而已 
   用-Xmx -Xms -Xmn 指定堆的最大值、初始值、和年輕帶的大小，由上圖可知young區也分為Eden 、from 、to上個區，比例默認是8:1:1 可以用-XX:SurvivorRatio設置年輕代中Eden區與Survivor區的大小比值 
   堆內內存由JVM gc統一管理回收,關于垃圾回收算法，這里不再贅述 
   
    
  堆外內存（off-heap memory) 
  和堆內內存相對應，堆外內存就是把內存對象分配在Java虛擬機的堆以外的內存，這些內存直接受操作系統管理（而不是虛擬機），這樣做的結果就是能夠在一定程度上減少垃圾回收對應用程序造成的影響。堆外內存默認是和-Xmx默認一樣大，也可以使用-XX:MaxDirectMemorySize指定堆外內存大小 
  作為JAVA開發者我們經常用java.nio.DirectByteBuffer對象進行堆外內存的管理和使用，它會在對象創建的時候就分配堆外內存。DirectByteBuffer類是在Java Heap外分配內存，對堆外內存的申請主要是通過成員變量unsafe來操作。關于Cleaner回收native memory又是另一個重要的點了。比如：為什么不用finalize來回收native memory。另外找機會寫. 
  我們可以知道的是，隨著DirectByteBuffer被GC掉之后，被分配的native memory會被回收 
  DirectByteBuffer(int cap) {

    super(-1, 0, cap, cap);
    //內存是否按頁分配對齊
    boolean pa = VM.isDirectMemoryPageAligned();
    //獲取每頁內存大小
    int ps = Bits.pageSize();
    //分配內存的大小，如果是按頁對齊方式，需要再加一頁內存的容量
    long size = Math.max(1L, (long)cap + (pa ? ps : 0));
    //用Bits類保存總分配內存(按頁分配)的大小和實際內存的大小
    Bits.reserveMemory(size, cap);

long base = 0;
try {
   //在堆外內存的基地址，指定內存大小
    base = unsafe.allocateMemory(size);
} catch (OutOfMemoryError x) {
    Bits.unreserveMemory(size, cap);
    throw x;
}
unsafe.setMemory(base, size, (byte) 0);
//計算堆外內存的基地址
if (pa && (base % ps != 0)) {
    // Round up to page boundary
    address = base + ps - (base & (ps - 1));
} else {
    address = base;
}
//當this對象即directByteBuffer被gc回收時，釋放native memory（為什么不用）
cleaner = Cleaner.create(this, new Deallocator(base, size, cap));
att = null;

}
private static class Deallocator implements Runnable  {
    private static Unsafe unsafe = Unsafe.getUnsafe();
    private long address;
    private long size;
    private int capacity;
    private Deallocator(long address, long size, int capacity) {
        assert (address != 0);
        this.address = address;
        this.size = size;
        this.capacity = capacity;
    }

public void run() {
    if (address == 0) {
        // Paranoia
        return;
    }
    //回收native memory
    unsafe.freeMemory(address);
    address = 0;
    Bits.unreserveMemory(size, capacity);
}

}</code></pre> 
  
堆外內存溢出 
  我們知道了回收堆內的DriectByteBuffer就會回收native memory，出現OOM的情況就是native memory被分配完了。也同時因為這個原因，假設進入Old gen的對象本來已經死了，但是并沒有full gc回收，native memory不能被及時回收。為了避免這種情況，在分配DirectByteByffer的時候會主動調用一次System.GC().通知JVM進行一次full gc。定期清理堆中的垃圾，及時的釋放native memory。 
  但是用了-XX:+DisableExplicitGC參數后，System.gc()的調用就會變成一個空調用，完全不會觸發任何GC（但是“函數調用”本身的開銷還是存在的).為啥要用這個參數呢？最主要的原因是為了防止某些手賤的同學在代碼里到處寫System.gc()的調用而STW干擾了程序的正常運行吧。有些應用程序本來可能正常跑一天也不會出一次full GC，但就是因為有人在代碼里調用了System.gc()而不得不間歇性被暫停。也有些時候這些調用是在某些庫或框架里寫的，改不了它們的代碼但又不想被這些調用干擾也會用這參數。 
  但是如果使用堆外內存，同時使用了這個參數，比如同時滿足下面3個條件，就很容易發生OOM 
   
   應用本身在GC堆內的對象行為良好，正常情況下很久都不發生full GC； 
   應用大量使用了NIO的direct memory，經常、反復的申請DirectByteBuffer 
   使用了-XX:+DisableExplicitGC 
   
  下面使用一些實例在看看在使用了DisableExplicitGC這個參數之后，到底會發生什么。 
    
  第一種 
  native memory滿了，但是young區沒滿，沒有發生young gc回收DirectByteBuffer，所以堆外OOM（如果去掉DisableExplicitGC參數程序會一直有Full GC的信息輸出，因為分配native memory的時候會主動調用System.GC()） 
  -Xmx64m
-Xms64m
-Xmn32m
-XX:+UseConcMarkSweepGC
-XX:+PrintGCDetails
-XX:+DisableExplicitGC//限制GC限制調用
-XX:MaxDirectMemorySize=10M//堆外10M
int i =1;
while(true){
    System.out.println("第"+(i++)+"次");
    ByteBuffer byteBuffer = ByteBuffer.allocateDirect( 1024*1024);
}
//輸出
第10次
第11次//10M就分配滿了，分配第11次的時候會OOM
Heap
 par new generation   total 29504K, used 3149K [0x00000007f6e00000, 0x00000007f8e00000, 0x00000007f8e00000)
  eden space 26240K,  12% used [0x00000007f6e00000, 0x00000007f7113578, 0x00000007f87a0000)//eden區只用了12%
  from space 3264K,   0% used [0x00000007f87a0000, 0x00000007f87a0000, 0x00000007f8ad0000)
  to   space 3264K,   0% used [0x00000007f8ad0000, 0x00000007f8ad0000, 0x00000007f8e00000)
 concurrent mark-sweep generation total 32768K, used 0K [0x00000007
Exception in thread "main" java.lang.OutOfMemoryError: Direct buffer memory
    at java.nio.Bits.reserveMemory(Bits.java:658)
    at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123)
    at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:306)</code></pre> 
  
  
  第二種 
  native memory沒滿，但是young區在native memory滿之前提前滿了，發生young gc回收DirectByteBuffer，不會發生OOM 
  如果代碼換成了下面這種(jvm參數一樣),一次分配的native memory足夠小，會導致在native memory沒有分配滿的情況下，發生young gc會搜DirectByteBuffer。同時會回收native memory 
  ByteBuffer byteBuffer = ByteBuffer.allocateDirect( 1024/2/2/2/2/2);
//輸出會有
[GC[ParNew: 29503K->3262K(29504K), 0.0369960 secs] 44757K->25060K(62272K), 0.0370220 secs] [Times: user=0.18 sys=0.00, real=0.04 secs]
...
...
Heap
//退出程序時會發現young區并沒有滿
 par new generation   total 29504K, used 12716K [0x00000007f6e00000, 0x00000007f8e00000, 0x00000007f8e00000)
  eden space 26240K,  36% used
 [0x00000007f6e00000, 0x00000007f773b530, 0x00000007f87a0000)
 from space 3264K,  99% used [0x00000007f8ad0000, 0x00000007f8dffbc0, 0x00000007f8e00000)
 to   space 3264K,   0% used 
    
  第三種 
  大量DirectByteBuffer對象移動到old gen。沒有Full gc的發生，導致在程序中可能死掉的DirectByteBuffer對象沒有回收掉，native memory則滿了，發生OOM 
  -Xmx64m
-Xms64m
-Xmn32m
-XX:+PrintGCDetails
-XX:MaxTenuringThreshold=1//設置進去old gen的壽命是1，默認是15次才進入old gen
-XX:MaxDirectMemorySize=10M
-XX:+DisableExplicitGC//不能顯示full gc
int i = 1;
List<ByteBuffer> list = new ArrayList<ByteBuffer>();
while (true) {
            System.out.println("第" + (i++) + "次");
            ByteBuffer.allocate(1024 * 1024);//分配堆內內存
            ByteBuffer byteBuffer = ByteBuffer.allocateDirect(1024 / 2 / 2 / 2 );
            list.add(byteBuffer);//保證引用不被younggc
        }
//輸出
[GC[ParNew: 25620K->6K(29504K), 0.0004310 secs] 38176K->12564K(62272K), 0.0004450 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//中途有一些young gc
//.....
//最終輸出
Heap
//young 區也沒有滿
 PSYoungGen      total 32256K, used 26419K [0x000000010d700000, 0x000000010f700000, 0x000000010f700000)
  eden space 31744K, 82% used [0x000000010d700000,0x000000010f0a4c70,0x000000010f600000)
  from space 512K, 31% used [0x000000010f680000,0x000000010f6a8000,0x000000010f700000)
  to   space 512K, 0% used [0x000000010f600000,0x000000010f600000,0x000000010f680000)
//old gen 已經用了62%了
 ParOldGen       total 32768K, used 20586K [0x000000010b700000, 0x000000010d700000, 0x000000010d700000)
  object space 32768K, 62% used [0x000000010b700000,0x000000010cb1a908,0x000000010d700000)
 PSPermGen       total 21504K, used 3097K [0x0000000106500000, 0x0000000107a00000, 0x000000010b700000)
  object space 21504K, 14% used [0x0000000106500000,0x00000001068065e8,0x0000000107a00000)</code></pre> 
  
  
  如果你在使用Oracle/Sun JDK 6，應用里有任何地方用了direct memory，那么使用-XX:+DisableExplicitGC要小心。如果用了該參數而且遇到direct memory的OOM，可以嘗試去掉該參數看是否能避開這種OOM 
  先寫到這里，關于DirectByteBuffer的Cleaner方式如何回收Native memory方面，以后在添加(微笑) 
    
    
  參考資料 
   
   http://hllvm.group.iteye.com/group/topic/27945%EF%BC%89%E3%80%82 
   http://blog.sina.com.cn/s/blog_6940cab30101ghgj.html 
   https://ymgd.github.io/codereader/2016/10/17/%E4%BB%8E0%E5%88%B01%E8%B5%B7%E6%AD%A5-%E8%B7%9F%E6%88%91%E8%BF%9B%E5%85%A5%E5%A0%86%E5%A4%96%E5%86%85%E5%AD%98%E7%9A%84%E5%A5%87%E5%A6%99%E4%B8%96%E7%95%8C/ 
   http://huangyunbin.iteye.com/blog/1848394 
   http://www.blogjava.net/fancydeepin/archive/2013/09/29/jvm_heep.html 
   
   
  歡迎您掃一掃上面的微信公眾號，訂閱我的博客！ 
  來自：http://xiezhaodong.me/2017/07/22/%E4%B8%80%E6%AC%A1%E5%A0%86%E5%A4%96OOM%E9%97%AE%E9%A2%98%E7%9A%84%E6%8E%92%E6%9F%A5/


                    
                         本文由用戶 jzlxiaohei 自行上傳分享，僅供網友學習交流。所有權歸原作者，若您的權利被侵害，請聯系管理員。
                         轉載本站原創文章，請注明出處，并保留原始鏈接、圖片水印。
                         本站是一個以用戶分享為主的開源技術平臺，歡迎各類分享！
                         本文地址：http://www.baiduhome.net/lib/view/open1500968386194.html
                         OOM JVM Java開發

一次堆外OOM問題的排查

背景

排查

關于DirectByteBuffer

堆外內存（off-heap memory)

堆外內存溢出

第一種

第二種

第三種

參考資料

相關經驗

相關資訊

相關文檔

目錄