线上 OutOfMemoryError 了，没头绪... ...

[Solace202]

• 前提

  查看了应用日志，是凌晨就已经 OOM 了，但是直到早上八点多客服反馈登录不了才发现问题，当时在路上，于是让运维 dump 了堆栈和线程信息，重启了服务器。

  jvm 配置：

  -Xmx2000M
  -Xms2000M
  -Xmn500M
  -XX:PermSize=250M
  -XX:MaxPermSize=250M
  -Xss256K
  -XX:-UseGCOverheadLimit
  -Djava.net.preferIPv4Stack=true
  -Djava.net.preferIPv4Addresses
  -XX:+DisableExplicitGC
  -XX:SurvivorRatio=1
  -XX:+UseConcMarkSweepGC
  -XX:+UseParNewGC
  -XX:+CMSParallelRemarkEnabled
  -XX:+UseCMSCompactAtFullCollection
  -XX:CMSFullGCsBeforeCompaction=0
  -XX:+CMSClassUnloadingEnabled
  -XX:LargePageSizeInBytes=128M
  -XX:+UseFastAccessorMethods
  -XX:+UseCMSInitiatingOccupancyOnly
  -XX:CMSInitiatingOccupancyFraction=60
  -XX:SoftRefLRUPolicyMSPerMB=0
  -XX:+PrintClassHistogram
  -XX:+PrintGCDetails
  -XX:+PrintGCTimeStamps
  -XX:+PrintHeapAtGC
  -Xloggc:/data/apps/apache-tomcat-6.0.36/logs/gc.log
  

• jvm.heap

  2020-05-07 08:46:
  
  using parallel threads in the new generation.
  using thread-local object allocation.
  Concurrent Mark-Sweep GC
  
  Heap Configuration:
     MinHeapFreeRatio = 40
     MaxHeapFreeRatio = 70
     MaxHeapSize      = 2097152000 (2000.0MB)
     NewSize          = 524288000 (500.0MB)
     MaxNewSize       = 524288000 (500.0MB)
     OldSize          = 5439488 (5.1875MB)
     NewRatio         = 2
     SurvivorRatio    = 1
     PermSize         = 262144000 (250.0MB)
     MaxPermSize      = 262144000 (250.0MB)
  
  Heap Usage:
  New Generation (Eden + 1 Survivor Space):
     capacity = 349569024 (333.375MB)
     used     = 137905504 (131.51693725585938MB)
     free     = 211663520 (201.85806274414062MB)
     39.45014990801931% used
  Eden Space:
     capacity = 174850048 (166.75MB)
     used     = 129558040 (123.5561752319336MB)
     free     = 45292008 (43.193824768066406MB)
     74.09665681075478% used
  From Space:
     capacity = 174718976 (166.625MB)
     used     = 8347464 (7.960762023925781MB)
     free     = 166371512 (158.66423797607422MB)
     4.777651627262284% used
  To Space:
     capacity = 174718976 (166.625MB)
     used     = 0 (0.0MB)
     free     = 174718976 (166.625MB)
     0.0% used
  concurrent mark-sweep generation:
     capacity = 1572864000 (1500.0MB)
     used     = 532712344 (508.0340805053711MB)
     free     = 1040151656 (991.9659194946289MB)
     33.86893870035807% used
  Perm Generation:
     capacity = 262144000 (250.0MB)
     used     = 149215056 (142.3025665283203MB)
     free     = 112928944 (107.69743347167969MB)
     56.921026611328124% used
  2020-05-07 08:46:
  
  using thread-local object allocation.
  Parallel GC with 4 thread(s)
  
  Heap Configuration:
     MinHeapFreeRatio = 40
     MaxHeapFreeRatio = 70
     MaxHeapSize      = 1566572544 (1494.0MB)
     NewSize          = 1310720 (1.25MB)
     MaxNewSize       = 17592186044415 MB
     OldSize          = 5439488 (5.1875MB)
     NewRatio         = 2
     SurvivorRatio    = 8
     PermSize         = 21757952 (20.75MB)
     MaxPermSize      = 174063616 (166.0MB)
  
  Heap Usage:
  PS Young Generation
  Eden Space:
     capacity = 1966080 (1.875MB)
     used     = 628456 (0.5993423461914062MB)
     free     = 1337624 (1.2756576538085938MB)
     31.964925130208332% used
  From Space:
     capacity = 196608 (0.1875MB)
     used     = 98304 (0.09375MB)
     free     = 98304 (0.09375MB)
     50.0% used
  To Space:
     capacity = 196608 (0.1875MB)
     used     = 0 (0.0MB)
     free     = 196608 (0.1875MB)
     0.0% used
  PS Old Generation
     capacity = 65273856 (62.25MB)
     used     = 4938552 (4.709770202636719MB)
     free     = 60335304 (57.54022979736328MB)
     7.565895907850151% used
  PS Perm Generation
     capacity = 25296896 (24.125MB)
     used     = 25255776 (24.085784912109375MB)
     free     = 41120 (0.039215087890625MB)
     99.8374504128886% used
  

• 应用日志

• jstack 信息

  2020-05-07 08:47 cpu_busy: 1
  "scheduler-9" prio=10 tid=0x00007f962c6e6000 nid=0x3a0d waiting on condition [0x00007f962437f000]
     java.lang.Thread.State: TIMED_WAITING (parking)
  	at sun.misc.Unsafe.park(Native Method)
  	- parking to wait for  <0x0000000796111028> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2081)
  	at java.util.concurrent.DelayQueue.take(DelayQueue.java:193)
  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:688)
  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:681)
  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1131)
  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
  	at java.lang.Thread.run(Thread.java:679)
  
  "scheduler-8" prio=10 tid=0x00007f962cb95800 nid=0x3a0c waiting on condition [0x00007f96248d4000]
     java.lang.Thread.State: TIMED_WAITING (parking)
  	at sun.misc.Unsafe.park(Native Method)
  	- parking to wait for  <0x0000000796111028> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
  	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2081)
  	at java.util.concurrent.DelayQueue.take(DelayQueue.java:193)
  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:688)
  	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:681)
  	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1069)
  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1131)
  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
  	at java.lang.Thread.run(Thread.java:679)
  
  "scheduler-7" prio=10 tid=0x00007f962c7c6000 nid=0x3a0b waiting on condition [0x00007f962468b000]
     java.lang.Thread.State: TIMED_WAITING (parking)
  	at sun.misc.Unsafe.park(Native Method)
  
  
  
  2020-05-07 08:47 cpu_busy: 1
  "VM Thread" prio=10 tid=0x00007f962c0fe800 nid=0x38e1 runnable 
  
  "Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x00007f962c010800 nid=0x38dc runnable 
  
  "Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x00007f962c012800 nid=0x38dd runnable 
  
  "Gang worker#2 (Parallel GC Threads)" prio=10 tid=0x00007f962c014800 nid=0x38de runnable 
  
  "Gang worker#3 (Parallel GC Threads)" prio=10 tid=0x00007f962c016000 nid=0x38df runnable 
  
  "Concurrent Mark-Sweep GC Thread" prio=10 tid=0x00007f962c0a5000 nid=0x38e0 runnable 
  "VM Periodic Task Thread" prio=10 tid=0x00007f962c258000 nid=0x39b4 waiting on condition 
  
  JNI global references: 1952
  
  
  
  
  2020-05-07 08:47 cpu_busy: 1
  "DefaultQuartzScheduler_QuartzSchedulerThread" prio=10 tid=0x00007f1c8c39c000 nid=0x6687 waiting on condition [0x00007f1c4b9f8000]
     java.lang.Thread.State: TIMED_WAITING (sleeping)
  	at java.lang.Thread.sleep(Native Method)
  	at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:275)
  
  "DefaultQuartzScheduler_Worker-10" prio=10 tid=0x00007f1c8c3a8000 nid=0x6686 in Object.wait() [0x00007f1c4baf9000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a06000> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-9" prio=10 tid=0x00007f1c8c3d1000 nid=0x6685 in Object.wait() [0x00007f1c4bbfa000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a001a8> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-8" prio=10 tid=0x00007f1c8c1e7800 nid=0x6684 in Object.wait() [0x00007f1c4bcfb000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a04020> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-7" prio=10 tid=0x00007f1c8c3a5000 nid=0x6683 in Object.wait() [0x00007f1c4bdfc000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a00228> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-6" prio=10 tid=0x00007f1c8c241000 nid=0x6682 in Object.wait() [0x00007f1c3bffe000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  
  
  
  2020-05-07 08:47 cpu_busy: 1
  "Attach Listener" daemon prio=10 tid=0x00007f1c68001000 nid=0x30d waiting on condition [0x0000000000000000]
     java.lang.Thread.State: RUNNABLE
  
  "DestroyJavaVM" prio=10 tid=0x00007f1c8c008000 nid=0x665b waiting on condition [0x0000000000000000]
     java.lang.Thread.State: RUNNABLE
  
  "DefaultQuartzScheduler_QuartzSchedulerThread" prio=10 tid=0x00007f1c8c39c000 nid=0x6687 waiting on condition [0x00007f1c4b9f8000]
     java.lang.Thread.State: TIMED_WAITING (sleeping)
  	at java.lang.Thread.sleep(Native Method)
  	at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:275)
  
  "DefaultQuartzScheduler_Worker-10" prio=10 tid=0x00007f1c8c3a8000 nid=0x6686 in Object.wait() [0x00007f1c4baf9000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a06000> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-9" prio=10 tid=0x00007f1c8c3d1000 nid=0x6685 in Object.wait() [0x00007f1c4bbfa000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a001a8> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-8" prio=10 tid=0x00007f1c8c1e7800 nid=0x6684 in Object.wait() [0x00007f1c4bcfb000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  	at java.lang.Object.wait(Native Method)
  	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:523)
  	- locked <0x00000000a2a04020> (a org.quartz.simpl.SimpleThreadPool$WorkerThread)
  
  "DefaultQuartzScheduler_Worker-7" prio=10 tid=0x00007f1c8c3a5000 nid=0x6683 in Object.wait() [0x00007f1c4bdfc000]
     java.lang.Thread.State: TIMED_WAITING (on object monitor)
  

• 用 jhat -J-Xmx50m jvm.dump 查看所有类的实例数

---

这是我第一次碰到 OOM，我不理解的是为什么我看 jvm.heap 里面，堆内存使用率不是百分百，但请求依然是 OOM 呢？这些堆栈文件是运维用脚本生成的，必要的话我可以把脚本贴上来。

我会继续排查问题，希望哪位看到了也能帮我瞅瞅，非常感谢。

[Solace202]

@limbo0 凌晨一般产品就没人使用了，只是凌晨一般会议很多定时任务开始执行

[25OHd2qObJmJ6P10]

从应用日志来看是 spring 注入一个类的时候报了堆空间不足，spring 注入属性会去加载相应的类到永久区，根据你的日志分析，你的 jdk 应该是 1.8 以下，而且你的 jvm 内存空间也显示你的永久区只有 24M,使用达到 99%,所以初步分析就可以增大永久区 -XX:PermSize=75M -XX:MaxPermSize=100M 尝试，然后再根据 jstat 和 jmap 分析内存变化，确定原因以及调整最合适的 jvm 参数

[Solace202]

@rayduan 我是有个地方不理解，两个 GC，为什么注入的类会放到下面这个 GC 的 Perm Generation 而不是上面的那个 Perm Generation ？

[zwx327634]

如果是 jdk1.7,升到 1.8 就没问题了，永久代变成元空间，放在堆里了。快速的话就是像楼上，增加永久代空间

[Solace202]

@zwx327634 jdk1.6，瑟瑟发抖，老项目快十年了

[1ffree]

好奇应用运行期间 还有 autowire 是啥使用场景呢

[pangleon]

你这个提示的是 heap space 而不是 permgen space，后者是永久代满了，那么基本上可以定位到你们的程序创建了大量的临时对象

如果真是凌晨 OOM，凌晨也不是用户高峰那么基本可以确定是定时任务导致的。
你可以查询下有哪些定时任务在运行，他们是否创建了大量的 LIST,MAP 这种集合类对象或者拼接了大量字符串对象。

[pmispig]

@Solace202 -XX:HeapDumpPath=/logs/gc.hprof 看看能不能重现一次，拿到这个 dump 出来分析就比较好定位

[liukzz]

https://gceasy.io/gc-index.jsp 这个网站下个离线版的分析工具，把 gc.log 导进去分析下

[Solace202]

@pmispig 嗯，已经在 jvm 加了，今晚要是再出现就好处理了。

[gadsavesme]

Perm Generation 满了，这个 jdk1.8 以下的时候 fullgc 的时候不会清理空间，满了就 oom 十分蛋疼。

[bonke]

hashMap 的 key 是重写了 hashCode 方法么 看下有没有重写 equals 方法

[admol]

推荐一下这个工具 https://console.perfma.com/

[chibupang]

我看 OOM 日志错误是在“work”反射调用的时候，是不是创建了大内存对象。

[kingwang]

应该是出报表的时候跪了，看一下这些报表里会不会象楼上们所说的产生大量集合对象

[iFlicker]

如果是 macOS 我推荐 Jprofiler ，平时 Android dump 堆内存查问题就是用这个看 比 as 强大

[EmdeBoas]

机器内存多大？

[cheng6563]

强烈推荐 Jprofiler 来观测 jvm 内存转存。轻松找到哪有问题

[Huozy]

用的 was 吗？看看 was 控制台最大内存和最小内存是多少，如果操作的数据多了 超出一定范围会报内存溢出的

[Solace202]

@Huozy was 是啥？ AWS 吧？不是 AWS