GC cause application threads were stopped long time (16 seconds) in Windows XP

[Qian, Haodong (EXT-Hudson - CN/Hangzhou)]

Hi 

 

Yes, In my observation, when I minimize application view, from task
manager, the memory will be reduced to 5M, 

So I guess, maybe GC need reload all data from virtual memory. 

 

Is there any way to avoid swaps out  ?

 

 

Best Regards

Qian Haodong (Holden)

 

From: ext Miles [mailto:miles at worldoflogs.com] 
Sent: Friday, September 28, 2012 3:27 PM
To: Qian, Haodong (EXT-Hudson - CN/Hangzhou)
Cc: hotspot-gc-use at openjdk.java.net
Subject: Re: GC cause application threads were stopped long time (16
seconds) in Windows XP

 

Windows XP (and other win32/64 os) swaps out minimized applications even
if there is enough memory over time.

On the first GC, every page of that 400M heap must be paged in again,
16s is fast for that ;)

Firefox used to have this issue too, fixed it with a do not reduce
working set when idle flag, see
https://bugzilla.mozilla.org/show_bug.cgi?id=76831 for details. Maybe
that's an idea for the jvm too.

On Sep 28, 2012 5:12 AM, "Qian, Haodong (EXT-Hudson - CN/Hangzhou)"
<haodong.qian.ext at nsn.com> wrote:

Hi all

Recently, I meet a problem that application no response, the timer not
invoke in time.

After investigation, I find a GC cost 16 seconds, and cause application
threads were stopped 16 seconds, it's incredible, The application is
less than 400M memory.

Have someone can help me find the root cause?

Test step:

        1. Start application, the application is GUI application.

        2. Minimize application, from task manager, the memory will be
reduced to 5M, the virtual memory less then 400M,

        3. Press win + L, lock computer, then unlock it. 

        4. no operation until issue happened, maybe need wait 3 or 4
hours. 

In addition, I observed a strange thing, after I lock computer and
unlock it, the GC log output very slowly. 

When I open GC log, the latest line only have "Total time ", after 5-10
minutes, the latest line change to "Total time for", and still waiting
5-10 minutes, the latest line change to "Total time for whic", 

Seems output thread has been blocked. 

Here is part of GC log:

{Heap before GC invocations=7 (full 1):

 PSYoungGen      total 153600K, used 147456K [0x129c0000, 0x1e9c0000,
0x1e9c0000)

  eden space 147456K, 100% used [0x129c0000,0x1b9c0000,0x1b9c0000)

  from space 6144K, 0% used [0x1b9c0000,0x1b9c0000,0x1bfc0000)

  to   space 43008K, 0% used [0x1bfc0000,0x1bfc0000,0x1e9c0000)

 PSOldGen        total 157824K, used 60287K [0x069c0000, 0x103e0000,
0x129c0000)

  object space 157824K, 38% used [0x069c0000,0x0a49ffd0,0x103e0000)

 PSPermGen       total 65024K, used 36167K [0x029c0000, 0x06940000,
0x069c0000)

  object space 65024K, 55% used [0x029c0000,0x04d11df8,0x06940000)

2012-09-26T19:00:49.468+0800: 9622.177: [GC9638.861: [SoftReference, 0
refs, 0.0000050 secs]9638.861: [WeakReference, 3176 refs, 0.0005855
secs]9638.862: [FinalReference, 1005 refs, 0.0661215 secs]9638.928:
[PhantomReference, 751 refs, 0.0058066 secs]9638.934: [JNI Weak
Reference, 0.0040648 secs] [PSYoungGen: 147456K->19930K(154624K)]
207743K->80218K(312448K), 16.7716327 secs] [Times: user=2.31 sys=0.42,
real=16.77 secs] 

Heap after GC invocations=7 (full 1):

 PSYoungGen      total 154624K, used 19930K [0x129c0000, 0x1e9c0000,
0x1e9c0000)

  eden space 111616K, 0% used [0x129c0000,0x129c0000,0x196c0000)

  from space 43008K, 46% used [0x1bfc0000,0x1d336af8,0x1e9c0000)

  to   space 41984K, 0% used [0x196c0000,0x196c0000,0x1bfc0000)

 PSOldGen        total 157824K, used 60287K [0x069c0000, 0x103e0000,
0x129c0000)

  object space 157824K, 38% used [0x069c0000,0x0a49ffd0,0x103e0000)

 PSPermGen       total 65024K, used 36167K [0x029c0000, 0x06940000,
0x069c0000)

  object space 65024K, 55% used [0x029c0000,0x04d11df8,0x06940000)

}

Total time for which application threads were stopped: 16.8318711
seconds

JRE version is:

java version "1.6.0_27"

Java(TM) SE Runtime Environment (build 1.6.0_27-b07)

Java HotSpot(TM) Client VM (build 20.2-b06, mixed mode)

Here is JVM parameters of application:

Xms96m -Xmx384m -client -XX:NewRatio=1 -Xss128k -XX:+UseParallelGC
-XX:ParallelGCThreads=4 -XX:+HeapDumpOnOutOfMemoryError
-Duser.country=US -Duser.language=en -XX:+PrintReferenceGC
-XX:+PrintGCDetails -XX:+PrintGCApplicationStoppedTime
-XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:gclog.log

If you need detail GC log or other log, please let me know. 

 

Best Regards

Qian Haodong (Holden)


_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120928/0b43b698/attachment.html