4

I'm the starting the Java client with the Java JRE on 32bits windows, with 

java -Xmx1024m -Xms1024m -verbose:gc -XX:+PrintGCDetails -jar myJar.jar

My jar contains a lot of data (tables of doubles, 600ish MB) which stay in memory for the entire life of the application.

It then gives logging messages, about each minute, saying:

[GC [DefNew: 279616K->279616K(314560K), 0.0002037 secs][Tenured: 595827K->599952K(699072K), 1.1020398 secs] 875443K->599952K(1013632K), [Perm : 10042K->10042K(16384K)], 1.1030218 secs] [Times: user=1.09 sys=0.01, real=1.11 secs]

and I really don't understand the bold part. It says the new generation goes from 279616K to 279616K (ie nothing changed), the old generation slightly increased (595827K->599952K) but in total it says 875443K->599952K, ie a ~30% reduction. How can this be?

edit: to be completely clear, I'd expected that if I add 279616K+595827K=875443K I get the first part in bold, ie the total heap size. Likewise, I'd expected that 279616K+599952K would total the second part in bold, but it doesn't. In the link Java Garbage Collection Log messages, specified below, it does add up, so I'm probably missing something.

Community
  • 1
  • 1
Frank Meulenaar
  • 1,207
  • 3
  • 13
  • 23
  • Do you use the Sun JDK? If so, you might wanna take a look at [Java Tuning White Paper](http://java.sun.com/performance/reference/whitepapers/tuning.html). Secondly, could you please provide a lot more context? I.e OS, the process data model (32-bit or 64-bit) ... –  Mar 21 '11 at 19:12
  • I first want to understand what the current log message says before I want to optimize something (in my case, NewRatio=4 and using the concurrent GC fixed my troughtput problems). – Frank Meulenaar Mar 21 '11 at 19:33

2 Answers2

3

The point is that DefNew and Tenured are results of minor collections, whereas the overall numbers also include the result of the following major collection. So, young generation can't be collected successfully during a minor collection and is only collected by major collection.

Diagnosing a Garbage Collection problem suggests that it can be caused by young generation being too large:

[GC [DefNew: 16000K->16000K(16192K), 0.0000498 secs][Tenured: 2535K->2319K(16384K), 0.0860925 secs] 18535K->2319K(32576K), 0.0863350 secs]

This is an example of the relative size of the young generation to the tenured generation being too large to allow the young generation promotion to be guaranteed (the young generation is about half the size of the tenured generation). The young generation cannot be collected successfully and only major collections are occurring. Note that in this cause the young generation is collected but only as part of the more expensive major collection.

I guess in your case it also can be caused by lack of free space in the tenured generation.

Community
  • 1
  • 1
axtavt
  • 239,438
  • 41
  • 511
  • 482
  • Thanks, but I still don't understand how `Tenured` can be part of the *minor* collection; wasn't the point that a *minor* collection only collects the young generation? And if it's part of the minor collection, why is the minor collection spending most of its time in the tenured generation? – Frank Meulenaar Mar 27 '11 at 12:11
1

One should search a little more in SO before asking. Anyhow, look at this:

Java Garbage Collection Log messages

Community
  • 1
  • 1
Alfabravo
  • 7,493
  • 6
  • 46
  • 82
  • Jep, saw that post & the original link in that, so I tried to check basis aritmetic on my log but it didn't add up. See my edit in the main post. – Frank Meulenaar Mar 21 '11 at 19:32