An unexpected long app pause in cms concurrent-mark phase

[Ramki Ramakrishna]

Hello BueDavy --

When large objects (which would not normally fit in Eden)
are allocated, concurrent background collection must "yield"
to allow the allocation to proceed. I recall some issues
in yielding having been fixed a while ago, although I must
confess I do not recall the exact timeline of those changes.
I suggest a test with the latest 6u28(?) JVM, and if the
problem persists to log a formal CR to have this investigated
through formal support channels.

-- ramki

On 10/24/2011 6:44 AM, BlueDavy Lin wrote:
> hi!
>
>       In our hadoop namenode,it occurs a long pause in cms
> concurrent-mark phase,it's very strange.
>
>       JDK Version: Oracle JDK 6u23
>       Startup options:
>       -Xmx81920m -Xms81920m -Xmn4096m -XX:+PrintGCDateStamps
> -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError
> -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=85
> -XX:+UseCMSCompactAtFullCollection
> -XX:CMSMaxAbortablePrecleanTime=1000 -XX:+CMSClassUnloadingEnabled
> -XX:+DisableExplicitGC
>
>       The CMS concurrent mark log:
> 2011-10-24T18:27:08.138+0800: 2947720.684: [CMS-concurrent-mark-start]
> 2011-10-24T18:30:33.394+0800: 2947925.940:
> [CMS-concurrent-mark:203.338/205.255 secs] [Times: user=689.21
> sys=49.08, real=205.23 secs]
>
>       We do pstack every 4 seconds when cms gc occurs,It seems when cms
> do concurrent-mark phase,GenCollectorPolicy::mem_allocate_work
> locked,it cause the app thread paused,an example from pstack.zip/31
> (begin 24):
> Thread 136 (Thread 0x432a6940 (LWP 32457)):
> #0  0x00000034db00ab99 in pthread_cond_wait@@GLIBC_2.3.2 ()
> #1  0x00002af84215544e in os::PlatformEvent::park ()
> #2  0x00002af84212b389 in Monitor::ILock ()
> #3  0x00002af84212b962 in Monitor::lock ()
> #4  0x00002af84212ba58 in Monitor::lock ()
> #5  0x00002af841df20aa in GenCollectorPolicy::mem_allocate_work ()
> #6  0x00002af841ecea98 in GenCollectedHeap::mem_allocate ()
> #7  0x00002af841d3bfab in CollectedHeap::common_mem_allocate_noinit ()
> #8  0x00002af841f0c335 in instanceKlass::allocate_objArray ()
> #9  0x00002af842149873 in oopFactory::new_objArray ()
> #10 0x00002af8421c0b66 in OptoRuntime::new_array_C ()
>
>       I attached the gc log&  partial pstack log.
>
>       Can someone help me to give some advices,thks.
>