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

Fri Sep 28 04:36:38 PDT 2012

This is standard windows behavior.  When you minimize an app, the kernel
will trim the working set of the app.  What this means is that the resident
memory pages *may* (depends on what else is running) get swapped out to
disk so that they can be used by other foreground processes.

When you bring your app back into the foreground, you can then get a lot of
hard page faults, especially if the GC runs which may need to load all the
pages as it walks the heap.

If you're running a lot of memory intensive apps and/or don't have a lot of
physical memory and/or don't have an SSD drive, then you can run into this
problem.

Sent from my phone
On Sep 28, 2012 3:37 AM, "Qian, Haodong (EXT-Hudson - CN/Hangzhou)" <
haodong.qian.ext at nsn.com> wrote:

> 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=76831for 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****
>
> _______________________________________________
> 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/48016e06/attachment.html 