記一次outMemoryError的錯誤

這一次的錯誤是java heap spacejava

報錯日誌

[ERROR] 2019-05-11 00:15:22 [pool-1-thread-14] (ForgivingExceptionHandler.java:119) Consumer com.vwym.rabbitmq.QueueManager$1@2a43ded9 (amq.ctag-bl4ipZBl-EHg3AVh9te3Og) method handleDelivery for channel AMQChannel(amqp://admin@192.168.10.173:5672/,1) threw an exception for channel AMQChannel(amqp://admin@192.168.10.173:5672/,1)
java.lang.OutOfMemoryError: Java heap space
	at yaml.parser.ParserReader.<init>(Unknown Source)
	at yaml.parser.YamlParser.<init>(Unknown Source)
	at org.ho.yaml.YamlDecoder.readObject(Unknown Source)
	at org.ho.yaml.YamlConfig.load(Unknown Source)
	at org.ho.yaml.YamlConfig.load(Unknown Source)
	at org.ho.yaml.Yaml.load(Unknown Source)
	at com.vwym.rabbitmq.QueueManager.reflectDelivery(QueueManager.java:368)
	at com.vwym.rabbitmq.QueueManager.access$0(QueueManager.java:362)
	at com.vwym.rabbitmq.QueueManager$1.handleDelivery(QueueManager.java:229)
	at com.rabbitmq.client.impl.ConsumerDispatcher$5.run(ConsumerDispatcher.java:149)
	at com.rabbitmq.client.impl.ConsumerWorkService$WorkPoolRunnable.run(ConsumerWorkService.java:104)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

報錯緣由解釋

首先Runtime.getRuntime()有3個方法：freemomery、totalmemory、maxmemory。windows

分別是當前jvm的剩餘內存，目前可用總內存，容許向操做系統獲取的最大內存。數組

在不動jvm設置的狀況下，totalmemory默認取本機內存的1/64，maxmemory取本機內存的1/4。jvm

一旦totalmemory超出maxmemory，就會報錯，也就是上述錯誤。工具

排查

工具推薦

此次用到的環境是windows，工具是jdk中的VisualVM，目錄是$JAVA_HOME/bin/jvisualvm.exe，這個工具也能夠進行dump分析。打開後下圖spa

不過使用這個工具先，我我的推薦2個插件，Tracer-JVM Probes和Visual GC ，Tracer-JVM Probes插件能夠查看程序的io使用狀況，Visual GC能夠查看程序GC狀況。操作系統

菜單欄->工具->插件打開後，可用插件->Visual GC(選中)->Tracer-JVM Probes(選中)->安裝插件

而後雙擊已有程序，點擊打開線程

監視

監視這一欄，能夠看到目前程序的堆、類總數、線程、CPU4種狀況，通常程序出錯，也會直接反映在這4項參數上，後文分析就是在堆這裏發現了問題。3d

visual GC

主要用於查看GC的次數，full gc、ygc是咱們排查的時候重點關注的要素之一。

Tracer

用的比較少，通常是針對高讀寫的狀況才須要關注。

排查過程

運行一段時間後，dump堆的數據出來，dump的時間是14:57:40

能夠看見，所有都是ehcache中相關包，並且所有都是SelectableConcurrentHashMap的內部類Segment，50多M都是由下面組成，咱們直接點擊查看

附上我我的使用的ehcache的引用和配置

<!-- https://mvnrepository.com/artifact/net.sf.ehcache/ehcache -->
		<dependency>
			<groupId>net.sf.ehcache</groupId>
			<artifactId>ehcache</artifactId>
			<version>2.10.6</version>
		</dependency>

<cache name="Pingcache"
           maxElementsInMemory="1800000"
           eternal="false"
           timeToIdleSeconds="900"
           timeToLiveSeconds="900"
           overflowToDisk="false"
           memoryStoreEvictionPolicy="FIFO"/>

下處紅框顯示就是54的引用，能夠發現是SelectableConcurrentHashMap的內部類Segment數組。

429,720的字節中429,500都是在這2048個數組中，咱們看一下數組裏面的構成。

在0-16中，咱們發現0 3 6 8 10 11 15都是null，而其餘都有數據，咱們點擊一、2分別查看。

第1條數據，能夠看到，這條數據的時間是13:43:58的數據，並且最下方還保留了next引用。

第2條數據，能夠看到，這條數據的時間是10:23:51的數據，最下方的next引用爲null。

總體翻看，廣泛就是有些null有些存在的狀況，並且時間分佈遠超我設置的15分鐘過時，可是日誌顯示的ehcache的size依舊是穩定的數值。

應該是刪除策略的問題，惰性刪除策略是訪問到該數據的時候返回null再刪除，而不是定時刪除。惰性刪除策略是不適用於這種數據增減頻繁的需求的。

解決方案

我放棄使用ehcache，考慮數據量也不算大的狀況下，我直接寫了一個按期刪除數據的map去作。

當時沒注意到這裏，直接用了第二版的ehcache，不肯定新版是否還存在這種狀況。