[prev in list] [next in list] [prev in thread] [next in thread] 

List:       openjdk-hotspot-gc-dev
Subject:    Parsing GC log for Thread Stops
From:       Y.S.Ramakrishna () Sun ! COM (Y ! S ! Ramakrishna at Sun ! COM)
Date:       2009-10-27 18:42:24
Message-ID: 4AE73F10.5050709 () Sun ! COM
[Download RAW message or body]

You seem to have deleted some o/p, but
the stop time printing strictly follows the stop;
it does not precede it in the log.

(Note of course that threads may be stopped for
stuff other than GC as well, and those reasons
may not necessarily be published to the log
(even though the fact that threads were stopped
and for how long is).)

-- ramki

On 10/27/09 09:49, Sujit.Das at cognizant.com wrote:
> Hi,
>  
> We are using JDK jdk1.6.0_14 on Solaris 10 platform. I am having 
> difficulty in associating timestamp to thread stop time. Please refer 
> the log snippet below.
>  
> There are two occurence of thread stops. The first is at 18:06 with 
> thread stop time value of 0.0336887 seconds. The second thread stop 
> time, of value 3.4217414 seconds, has no associated timestamp. My 
> question - what is the associated timestamp for second thread stop? Is 
> it 18:06 or 18:09?
> 
> 2009-10-26T18:06:19.008-0500: 3534.051: [GC Before GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 385976134
> Max   Chunk Size: 385976134
> Number of Blocks: 1
> Av.  Block  Size: 385976134
> Tree      Height: 1
> Before GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 0
> Max   Chunk Size: 0
> Number of Blocks: 0
> Tree      Height: 0
> 3534.051: [ParNew
> Desired survivor size 218431488 bytes, new threshold 4 (max 4)
> - age   1:    4747768 bytes,    4747768 total
> - age   2:    8973152 bytes,   13720920 total
> - age   3:   16305200 bytes,   30026120 total
> - age   4:    1050896 bytes,   31077016 total
> : 4300016K->43704K(4693376K), 0.0265603 secs] 
> 5380449K->1124137K(8789376K)After GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 385976134
> Max   Chunk Size: 385976134
> Number of Blocks: 1
> Av.  Block  Size: 385976134
> Tree      Height: 1
> After GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 0
> Max   Chunk Size: 0
> Number of Blocks: 0
> Tree      Height: 0
> , 0.0272833 secs] [Times: user=0.36 sys=0.01, real=0.03 secs]
> Heap after GC invocations=213 (full 2):
>  par new generation   total 4693376K, used 43704K [0xfffffd7dbf600000, 
> 0xfffffd7ef7e00000, 0xfffffd7ef7e00000)
>   eden space 4266752K,   0% used [0xfffffd7dbf600000, 
> 0xfffffd7dbf600000, 0xfffffd7ec3cc0000)
>   from space 426624K,  10% used [0xfffffd7ec3cc0000, 0xfffffd7ec676e090, 
> 0xfffffd7eddd60000)
>   to   space 426624K,   0% used [0xfffffd7eddd60000, 0xfffffd7eddd60000, 
> 0xfffffd7ef7e00000)
>  concurrent mark-sweep generation total 4096000K, used 1080433K 
> [0xfffffd7ef7e00000, 0xfffffd7ff1e00000, 0xfffffd7ff1e00000)
>  concurrent-mark-sweep perm gen total 131072K, used 62140K 
> [0xfffffd7ff1e00000, 0xfffffd7ff9e00000, 0xfffffd7ff9e00000)
> }
> *Total time for which application threads were stopped: 0.0336887 seconds
> *3878       ...class name-method name...
> 3879       ...class name-method name...
> 3880       ...class name-method name...
> 3881       ...class name-method name...
> 3882       ...class name-method name...
> Application time: 163.9563827 seconds
> 3867       ...class name-method name...
> 3868       ...class name-method name...
> Before GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 385976134
> Max   Chunk Size: 385976134
> Number of Blocks: 1
> Av.  Block  Size: 385976134
> Tree      Height: 1
> Before GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 0
> Max   Chunk Size: 0
> Number of Blocks: 0
> Tree      Height: 0
> After GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 385976134
> Max   Chunk Size: 385976134
> Number of Blocks: 1
> Av.  Block  Size: 385976134
> Tree      Height: 1
> After GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
> Total Free Space: 0
> Max   Chunk Size: 0
> Number of Blocks: 0
> Tree      Height: 0
> *Total time for which application threads were stopped: 3.4217414 seconds*
> Application time: 0.3801325 seconds
> {Heap before GC invocations=213 (full 2):
>  par new generation   total 4693376K, used 1247868K [0xfffffd7dbf600000, 
> 0xfffffd7ef7e00000, 0xfffffd7ef7e00000)
>   eden space 4266752K,  28% used [0xfffffd7dbf600000, 
> 0xfffffd7e08df1070, 0xfffffd7ec3cc0000)
>   from space 426624K,  10% used [0xfffffd7ec3cc0000, 0xfffffd7ec676e090, 
> 0xfffffd7eddd60000)
>   to   space 426624K,   0% used [0xfffffd7eddd60000, 0xfffffd7eddd60000, 
> 0xfffffd7ef7e00000)
>  concurrent mark-sweep generation total 4096000K, used 1080433K 
> [0xfffffd7ef7e00000, 0xfffffd7ff1e00000, 0xfffffd7ff1e00000)
>  concurrent-mark-sweep perm gen total 131072K, used 62142K 
> [0xfffffd7ff1e00000, 0xfffffd7ff9e00000, 0xfffffd7ff9e00000)
> 2009-10-26T18:09:45.836-0500: 3740.882: [Full GC Before GC:
> Statistics for BinaryTreeDictionary:
> ------------------------------------
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use

[prev in list] [next in list] [prev in thread] [next in thread]