What is going on with java GC? PermGen space is filling up?

Question

I dont know what is going on with my java process. This process is an indexing process. It reads documents from a set of zip files, and adds them to the lucene index. The GC log shows that it is just running continuously Full GC.

4959.569: [Full GC 19960K->19960K(10617856K), 0.1648590 secs]
4959.764: [Full GC 19960K->19960K(10617856K), 0.1650240 secs]
4959.959: [Full GC 19960K->19960K(10617856K), 0.1649380 secs]
4960.154: [Full GC 19960K->19960K(10617856K), 0.1650000 secs]
4960.350: [Full GC 19960K->19960K(10617856K), 0.1648900 secs]

As far as I can interpret these lines, the size of objects before and after is around 19M, but why is it running it like all the time?

The thread dump looks like this:

........[Unloading class sun.reflect.GeneratedConstructorAccessor1]
[Unloading class sun.reflect.GeneratedConstructorAccessor2]
[Unloading class sun.reflect.GeneratedConstructorAccessor3]
2012-01-13 12:55:24
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.4-b02 mixed mode):

"org.cxv.CXVIndexer.main()" prio=10 tid=0x00007f4540474000 nid=0x4b15 waiting on condition [0x00007f453f5ed000]
   java.lang.Thread.State: RUNNABLE
        at org.apache.lucene.index.DocFieldProcessorPerThread.abort(DocFieldProcessorPerThread.java:72)
        at org.apache.lucene.index.DocumentsWriter.abort(DocumentsWriter.java:424)
        - locked <0x000000034ab44fb8> (a org.apache.lucene.index.DocumentsWriter)
        at org.apache.lucene.index.DocumentsWriter.flush(DocumentsWriter.java:659)
        - locked <0x000000034ab44fb8> (a org.apache.lucene.index.DocumentsWriter)
        at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3623)
        - locked <0x000000034aacf660> (a org.apache.lucene.index.IndexWriter)
        at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3588)
        at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1858)
        at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1822)
        at org.cxv.IndexCreator.close(IndexCreator.java:25)
        at org.cxv.CXVIndexer.doIndexing(CXVIndexer.java:41)
        at org.cxv.CXVIndexer.main(CXVIndexer.java:75)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:297)
        at java.lang.Thread.run(Thread.java:662)

"Low Memory Detector" daemon prio=10 tid=0x00007f4540003800 nid=0x4b0a runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007f4540001000 nid=0x4b09 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x000000004032d800 nid=0x4b08 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x000000004032b800 nid=0x4b07 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Surrogate Locker Thread (Concurrent GC)" daemon prio=10 tid=0x0000000040329800 nid=0x4b06 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x000000004030c800 nid=0x4b05 in Object.wait() [0x00007f453fdfc000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000034a6613a8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
        - locked <0x000000034a6613a8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x0000000040305000 nid=0x4b04 in Object.wait() [0x00007f453fefd000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000034a6627c0> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:485)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
        - locked <0x000000034a6627c0> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x0000000040111000 nid=0x4af7 in Object.wait() [0x00007f4563c79000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000034aadf6f8> (a java.lang.Thread)
        at java.lang.Thread.join(Thread.java:1186)
        - locked <0x000000034aadf6f8> (a java.lang.Thread)
        at org.codehaus.mojo.exec.ExecJavaMojo.joinThread(ExecJavaMojo.java:415)
        at org.codehaus.mojo.exec.ExecJavaMojo.joinNonDaemonThreads(ExecJavaMojo.java:405)
        at org.codehaus.mojo.exec.ExecJavaMojo.execute(ExecJavaMojo.java:317)
        at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:107)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:209)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
        at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:84)
        at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:59)
        at org.apache.maven.lifecycle.internal.LifecycleStarter.singleThreadedBuild(LifecycleStarter.java:183)
        at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:161)
        at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:319)
        at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:156)
        at org.apache.maven.cli.MavenCli.execute(MavenCli.java:534)
        at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:196)
        at org.apache.maven.cli.MavenCli.main(MavenCli.java:141)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:290)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:230)
        at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:409)
        at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:352)

"VM Thread" prio=10 tid=0x00000000402fe000 nid=0x4b03 runnable 

"Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x0000000040120000 nid=0x4af8 runnable 

"Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x0000000040122000 nid=0x4af9 runnable 

"Gang worker#2 (Parallel GC Threads)" prio=10 tid=0x0000000040123800 nid=0x4afa runnable 

"Gang worker#3 (Parallel GC Threads)" prio=10 tid=0x0000000040125800 nid=0x4afb runnable 

"Gang worker#4 (Parallel GC Threads)" prio=10 tid=0x0000000040127800 nid=0x4afc runnable 

"Gang worker#5 (Parallel GC Threads)" prio=10 tid=0x0000000040129000 nid=0x4afd runnable 

"Gang worker#6 (Parallel GC Threads)" prio=10 tid=0x000000004012b000 nid=0x4afe runnable 

"Gang worker#7 (Parallel GC Threads)" prio=10 tid=0x000000004012d000 nid=0x4aff runnable 

"Concurrent Mark-Sweep GC Thread" prio=10 tid=0x0000000040220800 nid=0x4b02 runnable 
"Gang worker#0 (Parallel CMS Threads)" prio=10 tid=0x000000004021c800 nid=0x4b00 runnable 

"Gang worker#1 (Parallel CMS Threads)" prio=10 tid=0x000000004021e800 nid=0x4b01 runnable 

"VM Periodic Task Thread" prio=10 tid=0x000000004033a000 nid=0x4b0b waiting on condition 

JNI global references: 1154

Heap
 par new generation   total 153344K, used 0K [0x0000000340000000, 0x000000034a660000, 0x000000034a660000)
  eden space 136320K,   0% used [0x0000000340000000, 0x0000000340000000, 0x0000000348520000)
  from space 17024K,   0% used [0x00000003495c0000, 0x00000003495c0000, 0x000000034a660000)
  to   space 17024K,   0% used [0x0000000348520000, 0x0000000348520000, 0x00000003495c0000)
 concurrent mark-sweep generation total 10464512K, used 19960K [0x000000034a660000, 0x00000005c91a0000, 0x0000000780000000)
 concurrent-mark-sweep perm gen total 2097152K, used 2097151K [0x0000000780000000, 0x0000000800000000, 0x0000000800000000)

From the thread dump, it looks like the 2G perm gen is filling up. Does it really need that much space for perm gen?

Answer 1

This will happen if your memory is fragmented, or there is nothing to clean up. It happens often when you are close to the maximum memory size.

I have never heard of anyone needing a 2 G per gen size. Are you sure its not the young and tenured spaces you need to be looking at?

BTW: intern()ed String are placed in the main heap spaces in Java 7. Before Java 7, they used to be placed into the perm gen space, which makes it a bad idea to make too much data interned()

Answer 2

The permanent generation (perm gen) in JVMs with generational garbage collection contain "permanent" data which does not get collected. This memory segment consists mainly of class definitions loaded by the system classloader, so if your program loads lots of classes (e.g. has many large dependencies) then this space will fill up. Note that classes (typically) will not get unloaded unless you are using a custom classloader (i.e. other than the default, system classloader).

See this guide for information about sizing the perm gen space.