Hi Peter,

On 7 Apr 2011, at 18:45, Peter Schuller wrote:

>> * GC kicking in
> 
> -XX:+PrintGC
> -XX:+PrintGCDetails
> -XX:+PrintGCTimeStamps
> 
> Will tell you immediately.

This is brilliant, thanks for letting me know about it.

Here's a short snippet of my system running. I'm using the following jvm flags:
jvm.opts = -XX:+UseParNewGC -XX:MaxNewSize=256m -XX:NewSize=256m -Xms1g -Xmx1g 
-XX:+UseConcMarkSweepGC -XX:SurvivorRatio=128 -XX:MaxTenuringThreshold=0 
-XX:+UseTLAB -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

213.366: [GC 213.366: [ParNew: 258176K->0K(260160K), 0.0047777 secs] 
297424K->39377K(1046592K), 0.0048287 secs] [Times: user=0.01 sys=0.01, 
real=0.01 secs]
232.112: [GC 232.112: [ParNew: 258176K->0K(260160K), 0.0048751 secs] 
297553K->39389K(1046592K), 0.0049279 secs] [Times: user=0.01 sys=0.01, 
real=0.01 secs]
251.477: [GC 251.477: [ParNew: 258176K->0K(260160K), 0.0046450 secs] 
297565K->39403K(1046592K), 0.0046953 secs] [Times: user=0.01 sys=0.00, 
real=0.00 secs]
269.485: [GC 269.485: [ParNew: 258176K->0K(260160K), 0.0047293 secs] 
297579K->39415K(1046592K), 0.0047770 secs] [Times: user=0.01 sys=0.01, 
real=0.00 secs]
287.574: [GC 287.574: [ParNew: 258176K->0K(260160K), 0.0046624 secs] 
297591K->39424K(1046592K), 0.0047127 secs] [Times: user=0.01 sys=0.00, 
real=0.00 secs]
305.692: [GC 305.692: [ParNew: 258176K->0K(260160K), 0.0045113 secs] 
297600K->39434K(1046592K), 0.0045659 secs] [Times: user=0.02 sys=0.00, 
real=0.01 secs]
late 0.071147622
341.872: [GC 341.872: [ParNew: 258176K->0K(260160K), 0.0056084 secs] 
297622K->39454K(1046592K), 0.0056777 secs] [Times: user=0.02 sys=0.00, 
real=0.00 secs]
359.914: [GC 359.914: [ParNew: 258176K->0K(260160K), 0.0046537 secs] 
297630K->39465K(1046592K), 0.0047131 secs] [Times: user=0.02 sys=0.00, 
real=0.00 secs]
378.026: [GC 378.026: [ParNew: 258176K->0K(260160K), 0.0050940 secs] 
297641K->39478K(1046592K), 0.0051550 secs] [Times: user=0.01 sys=0.00, 
real=0.01 secs]
396.225: [GC 396.225: [ParNew: 258176K->0K(260160K), 0.0050148 secs] 
297654K->39488K(1046592K), 0.0050710 secs] [Times: user=0.01 sys=0.00, 
real=0.01 secs]
414.295: [GC 414.295: [ParNew: 258176K->0K(260160K), 0.0043778 secs] 
297664K->39497K(1046592K), 0.0044259 secs] [Times: user=0.01 sys=0.00, 
real=0.01 secs]
433.498: [GC 433.498: [ParNew: 258176K->0K(260160K), 0.0043805 secs] 
297673K->39505K(1046592K), 0.0044285 secs] [Times: user=0.01 sys=0.00, 
real=0.01 secs]
451.614: [GC 451.614: [ParNew: 258176K->0K(260160K), 0.0045982 secs] 
297681K->39512K(1046592K), 0.0046462 secs] [Times: user=0.01 sys=0.00, 
real=0.01 secs]
469.732: [GC 469.732: [ParNew: 258176K->0K(260160K), 0.0045055 secs] 
297688K->39524K(1046592K), 0.0045541 secs] [Times: user=0.02 sys=0.00, 
real=0.01 secs]
487.799: [GC 487.799: [ParNew: 258176K->0K(260160K), 0.0048340 secs] 
297700K->39533K(1046592K), 0.0048916 secs] [Times: user=0.02 sys=0.00, 
real=0.00 secs]
505.840: [GC 505.840: [ParNew: 258176K->0K(260160K), 0.0046585 secs] 
297709K->39542K(1046592K), 0.0047076 secs] [Times: user=0.01 sys=0.00, 
real=0.00 secs]
late 0.267990601
late 0.142990601
late 0.017990601
524.157: [GC 524.157: [ParNew: 258176K->0K(260160K), 0.0045401 secs] 
297718K->39551K(1046592K), 0.0045923 secs] [Times: user=0.02 sys=0.00, 
real=0.00 secs]
542.283: [GC 542.283: [ParNew: 258176K->0K(260160K), 0.0047124 secs] 
297727K->39566K(1046592K), 0.0047730 secs] [Times: user=0.02 sys=0.00, 
real=0.01 secs]
560.511: [GC 560.511: [ParNew: 258176K->0K(260160K), 0.0044768 secs] 
297742K->39578K(1046592K), 0.0045319 secs] [Times: user=0.02 sys=0.00, 
real=0.01 secs]

the late statemens come from the system that my JNI calls are communicating 
with. It indicates when the system was called later than expected. It feels to 
me that the GC is actually doing a really great job and is behaving pretty 
routinely. These sporadic pauses causing the lates surely isn't the GC in this 
case?

> 
> A couple of hundred ms seems very very plausible for GC. What is your
> target/desired maximum pause time?

below the 10s of milliseconds if possible.


Sam

---
http://sam.aaron.name

-- 
You received this message because you are subscribed to the Google
Groups "Clojure" group.
To post to this group, send email to clojure@googlegroups.com
Note that posts from new members are moderated - please be patient with your 
first post.
To unsubscribe from this group, send email to
clojure+unsubscr...@googlegroups.com
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en

Reply via email to