JDK-8085886 : Noticable log issue during Full GC when Metadata GC Threshold is reached
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 8u45
  • Priority: P4
  • Status: Closed
  • Resolution: Won't Fix
  • OS: linux
  • CPU: x86_64
  • Submitted: 2015-05-12
  • Updated: 2017-06-02
  • Resolved: 2017-06-02
Related Reports
Relates :  
Description
FULL PRODUCT VERSION :

java version "1.8.0_45"
Java(TM) SE Runtime Environment (build 1.8.0_45-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode)


FULL OS VERSION :
Red Hat 6.5 (2.6.32-431.el6.x86_64)

EXTRA RELEVANT SYSTEM CONFIGURATION :
-XX:+PrintGC -XX:-PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseG1GC -XX:MaxGCPauseMillis=30 -Xms1024m -Xmx1024m -XX:MaxMetaspaceSize=128m

A DESCRIPTION OF THE PROBLEM :
We are experienceng a logging issue when we reach the Metadata GC Threashold and a Full GC is commenced. In this case a new GC log message shows up on the output about this action, but instead of writing each and every GC log messages in a separate line, it appears that in this particular case, a line can consist of not one but two GC log messages. See the example below:

2015-05-12T13:26:02.398+0200: [Full GC (Metadata GC Threshold) 2015-05-12T13:26:02.398+0200: [GC concurrent-root-region-scan-start]
2015-05-12T13:26:02.398+0200: [GC concurrent-root-region-scan-end, 0.0002125 secs]
2015-05-12T13:26:02.398+0200: [GC concurrent-mark-start]
 290M->189M(1024M), 0.5072168 secs]
As you can see the last line should be in the same line as the line starting with the Full GC log.

THE PROBLEM WAS REPRODUCIBLE WITH -Xint FLAG: Did not try

THE PROBLEM WAS REPRODUCIBLE WITH -server FLAG: Yes

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
We are able to reroduce it with the following steps:
We use Wildfly 8.2 app server with the mentioned Java version and when we issue deploys and undeploys several times (with a particular enterprise application) and "Full GC (Metadata GC Threshold)" shows up in the log, then it's written always like in the Description.

EXPECTED VERSUS ACTUAL BEHAVIOR :
Each and every GC log should appear in its separate line
ERROR MESSAGES/STACK TRACES THAT OCCUR :
A snippet from the GC log:

2015-05-12T13:26:01.927+0200: [GC pause (G1 Evacuation Pause) (young) 402M->295M(1024M), 0.0308823 secs]
2015-05-12T13:26:02.373+0200: [GC pause (Metadata GC Threshold) (young) (initial-mark) 317M->290M(1024M), 0.0249139 secs]
2015-05-12T13:26:02.398+0200: [Full GC (Metadata GC Threshold) 2015-05-12T13:26:02.398+0200: [GC concurrent-root-region-scan-start]
2015-05-12T13:26:02.398+0200: [GC concurrent-root-region-scan-end, 0.0002125 secs]
2015-05-12T13:26:02.398+0200: [GC concurrent-mark-start]
 290M->189M(1024M), 0.5072168 secs]
2015-05-12T13:26:02.906+0200: [GC concurrent-mark-abort]
2015-05-12T13:26:03.028+0200: [GC pause (Metadata GC Threshold) (young) (initial-mark) 192M->193M(1024M), 0.0134625 secs]
2015-05-12T13:26:03.042+0200: [Full GC (Metadata GC Threshold) 2015-05-12T13:26:03.042+0200: [GC concurrent-root-region-scan-start]
2015-05-12T13:26:03.042+0200: [GC concurrent-root-region-scan-end, 0.0002307 secs]
2015-05-12T13:26:03.042+0200: [GC concurrent-mark-start]
 193M->183M(1024M), 0.3746577 secs]
2015-05-12T13:26:03.417+0200: [GC concurrent-mark-abort]
2015-05-12T13:26:03.437+0200: [GC pause (Metadata GC Threshold) (young) (initial-mark) 184M->186M(1024M), 0.0101472 secs]
2015-05-12T13:26:03.447+0200: [Full GC (Metadata GC Threshold) 2015-05-12T13:26:03.447+0200: [GC concurrent-root-region-scan-start]
2015-05-12T13:26:03.448+0200: [GC concurrent-root-region-scan-end, 0.0001437 secs]
2015-05-12T13:26:03.448+0200: [GC concurrent-mark-start]
 186M->183M(1024M), 0.3165751 secs]
2015-05-12T13:26:03.764+0200: [Full GC (Last ditch collection)  183M->181M(1024M), 0.3506834 secs]
2015-05-12T13:26:04.115+0200: [GC concurrent-mark-abort]
2015-05-12T13:26:04.116+0200: [GC pause (Metadata GC Threshold) (young) (initial-mark) 181M->181M(1024M), 0.0110965 secs]
2015-05-12T13:26:04.128+02002015-05-12T13:26:04.128+0200: [Full GC (Metadata GC Threshold) : [GC concurrent-root-region-scan-start]
2015-05-12T13:26:04.128+0200: [GC concurrent-root-region-scan-end, 0.0001523 secs]
2015-05-12T13:26:04.128+0200: [GC concurrent-mark-start]
 181M->168M(1024M), 0.3077973 secs]
2015-05-12T13:26:04.436+0200: [GC concurrent-mark-abort]
2015-05-12T13:26:38.826+0200: [GC pause (G1 Evacuation Pause) (young) 392M->198M(1024M), 0.0631935 secs]
2015-05-12T13:27:09.168+0200: [GC pause (G1 Evacuation Pause) (young) 221M->180M(1024M), 0.0211185 secs]
2015-05-12T13:27:09.339+0200: [GC pause (G1 Evacuation Pause) (young) 226M->187M(1024M), 0.0184767 secs]
2015-05-12T13:27:09.477+0200: [GC pause (G1 Evacuation Pause) (young) 231M->193M(1024M), 0.0190939 secs]

REPRODUCIBILITY :
This bug can be reproduced always.


Comments
Closing as "Won't Fix" because JDK 9 doesn't have this problem. FYI, below log is generated from the reproducer. And there's no problem with JDK 9. [8.325s][info][gc ] GC(14) Pause Full (Metadata GC Clear Soft References) 73M->72M(1024M) 386.618ms [8.325s][info][gc,cpu ] GC(14) User=0.49s Sys=0.00s Real=0.38s [8.325s][info][gc,metaspace,freelist] Metaspace (class) allocation failed for size 65 [8.325s][info][gc,marking ] GC(12) Concurrent Mark From Roots 707.229ms [8.325s][info][gc,marking ] GC(12) Concurrent Mark Abort [8.325s][info][gc,metaspace,freelist] All Metaspace: [8.325s][info][gc ] GC(12) Concurrent Cycle 709.545ms [8.356s][info][gc,metaspace,freelist] data space: Chunk accounting: used in chunks 31649K + unused in chunks 57167K + capacity in free chunks 3K = 88820K capacity in allocated chunks 88817K [8.380s][info][gc,metaspace,freelist] class space: Chunk accounting: used in chunks 11859K + unused in chunks 30377K + capacity in free chunks 2K = 42239K capacity in allocated chunks 42237K Exception in thread "main" java.lang.OutOfMemoryError: Metaspace [8.384s][info][gc,metaspace,freelist] Total fragmentation waste (words) doesn't count free space at java.base/java.lang.ClassLoader.defineClass1(Native Method) [8.384s][info][gc,metaspace,freelist] data: 5 specialized(s) 9, 20891 small(s) 8, 18 medium(s) 35, large count 1 [8.387s][info][gc,metaspace,freelist] class: 5 specialized(s) 0, 20892 small(s) 2, 2 medium(s) 5, large count 1 [8.392s][info][gc,heap,exit ] Heap [8.393s][info][gc,heap,exit ] garbage-first heap total 1048576K, used 73896K [0x00000000c0000000, 0x00000000c0102000, 0x0000000100000000) [8.393s][info][gc,heap,exit ] region size 1024K, 1 young (1024K), 0 survivors (0K) [8.393s][info][gc,heap,exit ] Metaspace used 43557K, capacity 131054K, committed 131072K, reserved 1138688K [8.393s][info][gc,heap,exit ] class space used 11864K, capacity 42237K, committed 42240K, reserved 1048576K at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:996) at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:173) at java.base/java.net.URLClassLoader.defineClass(URLClassLoader.java:545) at java.base/java.net.URLClassLoader.access$100(URLClassLoader.java:83) at java.base/java.net.URLClassLoader$1.run(URLClassLoader.java:453) at java.base/java.net.URLClassLoader$1.run(URLClassLoader.java:447) at java.base/java.security.AccessController.doPrivileged(Native Method) at java.base/java.net.URLClassLoader.findClass(URLClassLoader.java:446) at com.leaker.LeakClassLoader.loadClass(LeakClassLoader.java:15) at com.leaker.LeakClassInstanceGenerator.newInstance(LeakClassInstanceGenerator.java:7) at com.leaker.LeakTester.main(LeakTester.java:10)
02-06-2017

Removed '9' from Affect Version(s) as after JDK-8059805: JEP 271: Unified GC Logging, log format is totally changed.
02-06-2017

Test Result [Oracle Linux 7 64 bit]: **************************************** 8u45 : Fail 8u60 : Fail 9 : Fail 8u45 b 14: ######### [ababroy@localhost src]$ java -version java version "1.8.0_45" Java(TM) SE Runtime Environment (build 1.8.0_45-b14) Java HotSpot(TM) 64-Bit Server VM (build 25.45-b02, mixed mode) [ababroy@localhost src]$ [ababroy@localhost src]$ javac com/leaker/Leak*.java Note: com/leaker/LeakTester.java uses unchecked or unsafe operations. Note: Recompile with -Xlint:unchecked for details. [ababroy@localhost src]$ java -XX:+PrintGC -XX:-PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseG1GC -XX:MaxGCPauseMillis=30 -Xms1024m -Xmx1024m -Djava.net.preferIpv4Stack=true -XX:MaxMetaspaceSize=128m com.leaker.LeakTester 2015-06-05T04:05:35.126-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 30M->9984K(1024M), 0.1138827 secs] 2015-06-05T04:05:35.248-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:05:35.334-0400: [GC concurrent-root-region-scan-end, 0.0857424 secs] 2015-06-05T04:05:35.334-0400: [GC concurrent-mark-start] 2015-06-05T04:05:35.340-0400: [GC concurrent-mark-end, 0.0065363 secs] 2015-06-05T04:05:35.416-0400: [GC remark, 0.0030755 secs] 2015-06-05T04:05:35.465-0400: [GC cleanup 10M->10M(1024M), 0.0019221 secs] 2015-06-05T04:05:36.676-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 35M->19M(1024M), 0.1146739 secs] 2015-06-05T04:05:36.791-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:05:36.819-0400: [GC concurrent-root-region-scan-end, 0.0279750 secs] 2015-06-05T04:05:36.819-0400: [GC concurrent-mark-start] 2015-06-05T04:05:36.906-0400: [GC concurrent-mark-end, 0.0870038 secs] 2015-06-05T04:05:36.965-0400: [GC remark, 0.0050170 secs] 2015-06-05T04:05:36.970-0400: [GC cleanup 21M->21M(1024M), 0.0011618 secs] 2015-06-05T04:05:38.465-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 61M->34M(1024M), 0.2852963 secs] 2015-06-05T04:05:38.751-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:05:38.839-0400: [GC concurrent-root-region-scan-end, 0.0877099 secs] 2015-06-05T04:05:38.839-0400: [GC concurrent-mark-start] 2015-06-05T04:05:39.325-0400: [GC concurrent-mark-end, 0.4860770 secs] 2015-06-05T04:05:39.325-0400: [GC remark, 0.1361127 secs] 2015-06-05T04:05:39.463-0400: [GC cleanup 39M->38M(1024M), 0.0018785 secs] 2015-06-05T04:05:39.465-0400: [GC concurrent-cleanup-start] 2015-06-05T04:05:39.465-0400: [GC concurrent-cleanup-end, 0.0000145 secs] 2015-06-05T04:05:42.419-0400: [GC pause (G1 Evacuation Pause) (young) (initial-mark) 77M->50M(1024M), 0.2047203 secs] 2015-06-05T04:05:42.623-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:05:42.867-0400: [GC concurrent-root-region-scan-end, 0.2436671 secs] 2015-06-05T04:05:42.867-0400: [GC concurrent-mark-start] 2015-06-05T04:05:43.639-0400: [GC concurrent-mark-end, 0.7717606 secs] 2015-06-05T04:05:43.639-0400: [GC remark, 0.0095178 secs] 2015-06-05T04:05:43.660-0400: [GC cleanup 58M->57M(1024M), 0.0014990 secs] 2015-06-05T04:05:43.661-0400: [GC concurrent-cleanup-start] 2015-06-05T04:05:43.661-0400: [GC concurrent-cleanup-end, 0.0000125 secs] 2015-06-05T04:05:45.324-0400: [GC pause (G1 Evacuation Pause) (young) 93M->65M(1024M), 0.2804247 secs] 2015-06-05T04:05:46.571-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 85M->73M(1024M), 0.2418340 secs] 2015-06-05T04:05:46.813-0400: [Full GC (Metadata GC Threshold) 2015-06-05T04:05:46.813-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:05:46.815-0400: [GC concurrent-root-region-scan-end, 0.0016500 secs] 2015-06-05T04:05:46.815-0400: [GC concurrent-mark-start] 73M->66M(1024M), 0.6838298 secs] 2015-06-05T04:05:47.497-0400: [Full GC (Last ditch collection) 66M->65M(1024M), 0.8239027 secs] Exception in thread "main" java.lang.OutOfMemoryError: Metaspace at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:760) at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) at java.net.URLClassLoader.defineClass(URLClassLoader.java:467) at java.net.URLClassLoader.access$100(URLClassLoader.java:73) at java.net.URLClassLoader$1.run(URLClassLoader.java:368) at java.net.URLClassLoader$1.run(URLClassLoader.java:362) at java.security.AccessController.doPrivileged(Native Method) at java.net.URLClassLoader.findClass(URLClassLoader.java:361) at com.leaker.LeakClassLoader.loadClass(LeakClassLoader.java:15) at com.leaker.LeakClassInstanceGenerator.newInstance(LeakClassInstanceGenerator.java:7) at com.leaker.LeakTester.main(LeakTester.java:10) 2015-06-05T04:05:48.334-0400: [GC concurrent-mark-abort] [ababroy@localhost src]$ 8u60 ea b18: ########### [ababroy@localhost src]$ source /etc/profile [ababroy@localhost src]$ [ababroy@localhost src]$ java -version java version "1.8.0_60-ea" Java(TM) SE Runtime Environment (build 1.8.0_60-ea-b18) Java HotSpot(TM) 64-Bit Server VM (build 25.60-b18, mixed mode) [ababroy@localhost src]$ [ababroy@localhost src]$ javac com/leaker/Leak*.javaNote: com/leaker/LeakTester.java uses unchecked or unsafe operations. Note: Recompile with -Xlint:unchecked for details. [ababroy@localhost src]$ [ababroy@localhost src]$ java -XX:+PrintGC -XX:-PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseG1GC -XX:MaxGCPauseMillis=30 -Xms1024m -Xmx1024m -Djava.net.preferIpv4Stack=true -XX:MaxMetaspaceSize=128m com.leaker.LeakTester 2015-06-05T04:53:56.923-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 30M->10M(1024M), 0.0324707 secs] 2015-06-05T04:53:56.959-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:53:57.152-0400: [GC concurrent-root-region-scan-end, 0.1923084 secs] 2015-06-05T04:53:57.152-0400: [GC concurrent-mark-start] 2015-06-05T04:53:57.169-0400: [GC concurrent-mark-end, 0.0177899 secs] 2015-06-05T04:53:57.316-0400: [GC remark, 0.0037253 secs] 2015-06-05T04:53:57.331-0400: [GC cleanup 13M->13M(1024M), 0.0022733 secs] 2015-06-05T04:53:59.119-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 38M->21M(1024M), 0.1843009 secs] 2015-06-05T04:53:59.303-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:53:59.349-0400: [GC concurrent-root-region-scan-end, 0.0455827 secs] 2015-06-05T04:53:59.349-0400: [GC concurrent-mark-start] 2015-06-05T04:53:59.748-0400: [GC concurrent-mark-end, 0.3994368 secs] 2015-06-05T04:53:59.777-0400: [GC remark, 0.0434364 secs] 2015-06-05T04:53:59.822-0400: [GC cleanup 27M->27M(1024M), 0.0010531 secs] 2015-06-05T04:54:02.209-0400: [GC pause (G1 Evacuation Pause) (young) (initial-mark) 65M->37M(1024M), 0.2084108 secs] 2015-06-05T04:54:02.417-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:54:02.514-0400: [GC concurrent-root-region-scan-end, 0.0972154 secs] 2015-06-05T04:54:02.514-0400: [GC concurrent-mark-start] 2015-06-05T04:54:02.876-0400: [GC concurrent-mark-end, 0.3615076 secs] 2015-06-05T04:54:02.876-0400: [GC remark, 0.0084141 secs] 2015-06-05T04:54:02.885-0400: [GC cleanup 40M->39M(1024M), 0.0980513 secs] 2015-06-05T04:54:02.994-0400: [GC concurrent-cleanup-start] 2015-06-05T04:54:02.994-0400: [GC concurrent-cleanup-end, 0.0000001 secs] 2015-06-05T04:54:05.683-0400: [GC pause (G1 Evacuation Pause) (young) 80M->52M(1024M), 0.3208316 secs] 2015-06-05T04:54:07.515-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 83M->64M(1024M), 0.1432221 secs] 2015-06-05T04:54:07.658-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:54:07.768-0400: [GC concurrent-root-region-scan-end, 0.1100390 secs] 2015-06-05T04:54:07.768-0400: [GC concurrent-mark-start] 2015-06-05T04:54:08.335-0400: [GC concurrent-mark-end, 0.5664845 secs] 2015-06-05T04:54:08.380-0400: [GC remark, 0.1019014 secs] 2015-06-05T04:54:08.489-0400: [GC cleanup 69M->67M(1024M), 0.0020304 secs] 2015-06-05T04:54:08.491-0400: [GC concurrent-cleanup-start] 2015-06-05T04:54:08.491-0400: [GC concurrent-cleanup-end, 0.0000149 secs] 2015-06-05T04:54:09.385-0400: [GC pause (Metadata GC Threshold) (young) (initial-mark) 90M->73M(1024M), 0.2221802 secs] 2015-06-05T04:54:09.608-0400: [Full GC (Metadata GC Threshold) 2015-06-05T04:54:09.608-0400: [GC concurrent-root-region-scan-start] 2015-06-05T04:54:09.610-0400: [GC concurrent-root-region-scan-end, 0.0021716 secs] 2015-06-05T04:54:09.610-0400: [GC concurrent-mark-start] 73M->67M(1024M), 0.8522842 secs] 2015-06-05T04:54:10.460-0400: [Full GC (Last ditch collection) 67M->65M(1024M), 0.7196357 secs] Exception in thread "main" java.lang.OutOfMemoryError: Metaspace at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:760) at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) at java.net.URLClassLoader.defineClass(URLClassLoader.java:467) at java.net.URLClassLoader.access$100(URLClassLoader.java:73) at java.net.URLClassLoader$1.run(URLClassLoader.java:368) at java.net.URLClassLoader$1.run(URLClassLoader.java:362) at java.security.AccessController.doPrivileged(Native Method) at java.net.URLClassLoader.findClass(URLClassLoader.java:361) at com.leaker.LeakClassLoader.loadClass(LeakClassLoader.java:15) at com.leaker.LeakClassInstanceGenerator.newInstance(LeakClassInstanceGenerator.java:7) at com.leaker.LeakTester.main(LeakTester.java:10) 2015-06-05T04:54:11.192-0400: [GC concurrent-mark-abort] [ababroy@localhost src]$ 9 ea b67: ######## [ababroy@localhost src]$ source /etc/profile [ababroy@localhost src]$ java -version java version "1.9.0-ea" Java(TM) SE Runtime Environment (build 1.9.0-ea-b67) Java HotSpot(TM) 64-Bit Server VM (build 1.9.0-ea-b67, mixed mode) [ababroy@localhost src]$ [ababroy@localhost src]$ javac com/leaker/Leak*.javaNote: com/leaker/LeakTester.java uses unchecked or unsafe operations. Note: Recompile with -Xlint:unchecked for details. [ababroy@localhost src]$ java -XX:+PrintGC -XX:-PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseG1GC -XX:MaxGCPauseMillis=30 -Xms1024m -Xmx1024m -Djava.net.preferIpv4Stack=true -XX:MaxMetaspaceSize=128m com.leaker.LeakTester 2015-06-05T04:48:20.740-0400: #0: [GC pause (Metadata GC Threshold) (young) (initial-mark) 32M->9832K(1024M), 0.0862348 secs] 2015-06-05T04:48:20.829-0400: #1: [GC concurrent-root-region-scan-start] 2015-06-05T04:48:20.871-0400: #1: [GC concurrent-root-region-scan-end, 0.0413320 secs] 2015-06-05T04:48:20.871-0400: #1: [GC concurrent-mark-start] 2015-06-05T04:48:20.877-0400: #1: [GC concurrent-mark-end, 0.0058809 secs] 2015-06-05T04:48:20.932-0400: #1: [GC remark, 0.0034218 secs] 2015-06-05T04:48:20.935-0400: #1: [GC cleanup 12M->12M(1024M), 0.0035526 secs] 2015-06-05T04:48:22.421-0400: #2: [GC pause (Metadata GC Threshold) (young) (initial-mark) 37M->19M(1024M), 0.1064133 secs] 2015-06-05T04:48:22.527-0400: #3: [GC concurrent-root-region-scan-start] 2015-06-05T04:48:22.712-0400: #3: [GC concurrent-root-region-scan-end, 0.1847495 secs] 2015-06-05T04:48:22.712-0400: #3: [GC concurrent-mark-start] 2015-06-05T04:48:22.745-0400: #3: [GC concurrent-mark-end, 0.0330905 secs] 2015-06-05T04:48:22.763-0400: #3: [GC remark, 0.0055453 secs] 2015-06-05T04:48:22.769-0400: #3: [GC cleanup 22M->21M(1024M), 0.0016186 secs] 2015-06-05T04:48:22.770-0400: #3: [GC concurrent-cleanup-start] 2015-06-05T04:48:22.770-0400: #3: [GC concurrent-cleanup-end, 0.0000169 secs] 2015-06-05T04:48:24.485-0400: #4: [GC pause (G1 Evacuation Pause) (young) (initial-mark) 62M->32M(1024M), 0.1504080 secs] 2015-06-05T04:48:24.636-0400: #5: [GC concurrent-root-region-scan-start] 2015-06-05T04:48:24.784-0400: #5: [GC concurrent-root-region-scan-end, 0.1482242 secs] 2015-06-05T04:48:24.784-0400: #5: [GC concurrent-mark-start] 2015-06-05T04:48:25.121-0400: #5: [GC concurrent-mark-end, 0.3373533 secs] 2015-06-05T04:48:25.122-0400: #5: [GC remark, 0.0070157 secs] 2015-06-05T04:48:25.129-0400: #5: [GC cleanup 35M->35M(1024M), 0.0014734 secs] 2015-06-05T04:48:27.631-0400: #6: [GC pause (G1 Evacuation Pause) (young) 76M->46M(1024M), 0.2754763 secs] 2015-06-05T04:48:29.597-0400: #7: [GC pause (Metadata GC Threshold) (young) (initial-mark) 78M->57M(1024M), 0.1897262 secs] 2015-06-05T04:48:29.788-0400: #8: [GC concurrent-root-region-scan-start] 2015-06-05T04:48:29.817-0400: #8: [GC concurrent-root-region-scan-end, 0.0291640 secs] 2015-06-05T04:48:29.817-0400: #8: [GC concurrent-mark-start] 2015-06-05T04:48:30.628-0400: #8: [GC concurrent-mark-end, 0.8108050 secs] 2015-06-05T04:48:30.645-0400: #8: [GC remark, 0.0144252 secs] 2015-06-05T04:48:30.706-0400: #8: [GC cleanup 66M->66M(1024M), 0.0050157 secs] 2015-06-05T04:48:31.904-0400: #9: [GC pause (Metadata GC Threshold) (young) (initial-mark) 97M->70M(1024M), 0.2862071 secs] 2015-06-05T04:48:32.190-0400: #11: [Full GC (Metadata GC Threshold) 2015-06-05T04:48:32.190-0400: #10: [GC concurrent-root-region-scan-start] 2015-06-05T04:48:32.192-0400: #10: [GC concurrent-root-region-scan-end, 0.0018120 secs] 2015-06-05T04:48:32.192-0400: #10: [GC concurrent-mark-start] 70M->64M(1024M), 0.7243658 secs] 2015-06-05T04:48:32.915-0400: #12: [Full GC (Last ditch collection) 64M->62M(1024M), 0.7542191 secs] Exception in thread "main" java.lang.OutOfMemoryError: Metaspace at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:759) at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) at java.net.URLClassLoader.defineClass(URLClassLoader.java:467) at java.net.URLClassLoader.access$100(URLClassLoader.java:73) at java.net.URLClassLoader$1.run(URLClassLoader.java:368) at java.net.URLClassLoader$1.run(URLClassLoader.java:362) at java.security.AccessController.doPrivileged(Native Method) at java.net.URLClassLoader.findClass(URLClassLoader.java:361) at com.leaker.LeakClassLoader.loadClass(LeakClassLoader.java:15) at com.leaker.LeakClassInstanceGenerator.newInstance(LeakClassInstanceGenerator.java:7) at com.leaker.LeakTester.main(LeakTester.java:10) 2015-06-05T04:48:33.686-0400: #10: [GC concurrent-mark-abort] [ababroy@localhost src]$
17-02-2016