RFR(S): 8005885: enhance PrintCodeCache to print more data

Christian Thalinger christian.thalinger at oracle.com
Fri Aug 23 12:24:33 PDT 2013


On Aug 23, 2013, at 11:34 AM, Vladimir Kozlov <vladimir.kozlov at oracle.com> wrote:

> Albert,
> 
> I think you are missing constant section from nmethods or something else because % are not add up to 100%. Can you also try on SPARC?
> 
>   #500 Java methods = 1119K (hdr 12%,  loc 4%, code 38%, stub 2%, [oops 0%, data 1%, pcs 24%])
> 
> Use Kb when you show size.

Actually, kB (http://en.wikipedia.org/wiki/Kilobyte).

> 
> I agree with Chris P. that output is too verbose for product *by default* - I thinks we don't need splitting per tiers and detail section sizes information. Note, this will be put into hs_err files. I don't see how this additional information will help to debug problems.
> 
> I think by default PrintCodeCache should should sligthly verbose current output: add sizes, split live/dead nmethods, add interpreter and stubs instead of blobs and may be something else:
> 
> CodeCache: size=49152Kb used=1729Kb max_used=1782Kb free=47422Kb
> bounds [0x00007fbc13fb1000, 0x00007fbc14221000, 0x00007fbc16fb1000]
> interpreter=199Kb stubs=302(400Kb) live_nmethods=510(1119Kb) dead_nmethods=2(85Kb) adapters=254(116Kb)
> compilation: enabled
> 
> 
> It could be important when you are working on codecache improvement or want to see how it is used. And, yes it would be nice to get detailed info in product VM also. Unfortunately Verbose flag is not product and in some places it guards code which we don't want in product VM so we can't make it product.
> 
> Maybe you can convert PrintCodeCache2 to 'diagnostic' flag and use it for detailed information (it already does additional printing). But add new develop flag to replace it in print_trace():
> 
> void CodeCache::print_trace(const char* event, CodeBlob* cb, int size) {
>  if (PrintCodeCache2) {  // Need to add a new flag

I agree with Vladimir.  Can you also rename PrintCodeCache2 to PrintCodeCacheDetails?

-- Chris

> 
> Thanks,
> Vladimir
> 
> On 8/23/13 6:31 AM, Albert Noll wrote:
>> Hi,
>> 
>> could I get reviews for the following patch?
>> 
>> jbs: https://bugs.openjdk.java.net/browse/JDK-8005885
>> webrev: http://cr.openjdk.java.net/~anoll/8005885/webrev.00/
>> <http://cr.openjdk.java.net/%7Eanoll/8005885/webrev.00/>
>> 
>> Many thanks in advance,
>> Albert
>> 
>> Problem: Currently we only print:
>> 
>> CodeCache:
>> nmethod dependency checking time 0.037552
>>  #944 live = 3681K (hdr 4%, loc 2%, code 74%, stub 1%, [oops 0%, data
>> 0%, pcs 5%])
>>  #92 dead = 247K (hdr 7%, loc 6%, code 46%, stub 3%, [oops 0%, data 0%,
>> pcs 12%])
>> 
>> It would be helpful to have more detailed information about the code cache.
>> 
>> Solution: add more detailed information about the content of the code
>> cache when
>>                exiting the VM.
>> 
>> 
>> See sample outputs:
>> java -XX:-TieredCompilation -XX:+PrintCodeCache -jar
>> dacapo-9.12-bach.jar fop
>> ===== DaCapo 9.12 fop starting =====
>> ===== DaCapo 9.12 fop PASSED in 7676 msec =====
>> CodeCache: size=49152Kb used=1729Kb max_used=1782Kb free=47422Kb
>>  bounds [0x00007fbc13fb1000, 0x00007fbc14221000, 0x00007fbc16fb1000]
>>  total_blobs=814 nmethods=512 adapters=254
>>  compilation: enabled
>> 
>> Interpreter:  total=199k, used=124k
>> 
>> Total number of live methods: 510
>>  Tier 1:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 2:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 3:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 4:
>>   #500 Java methods = 1119K (hdr 12%,  loc 4%, code 38%, stub 2%, [oops
>> 0%, data 1%, pcs 24%])
>>   #5 OSR methods = 37K (hdr 3%,  loc 3%, code 41%, stub 2%, [oops 0%,
>> data 1%, pcs 30%])
>>  Native methods:
>>   #5 Native methods = 4K (hdr 31%,  loc 10%, code 55%, stub 0%, [oops
>> 0%, data 0%, pcs 0%])
>> 
>> Total number of dead methods: 2
>>  Tier 1:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 2:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 3:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 4:
>>   #1 Java methods = 67K (hdr 0%,  loc 3%, code 41%, stub 0%, [oops 0%,
>> data 0%, pcs 40%])
>>   #1 OSR methods = 18K (hdr 1%,  loc 4%, code 39%, stub 2%, [oops 0%,
>> data 1%, pcs 31%])
>>  Native methods:
>>   #0 Native methods
>> 
>> Total number of stubs: 302
>>   #23 runtime = 5K (hdr 25%,  loc 1%, code 67%, stub 0%, [oops 0%, data
>> 0%, pcs 0%])
>>   #1 deoptimization = 1K (hdr 7%,  loc 0%, code 89%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #1 uncommon trap = 0K (hdr 13%,  loc 1%, code 83%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #1 exception = 0K (hdr 27%,  loc 3%, code 65%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #3 safepoint = 1K (hdr 10%,  loc 1%, code 86%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #254 C2I/I2C adapter = 116K (hdr 13%,  loc 1%, code 82%, stub 0%,
>> [oops 0%, data 0%, pcs 0%])
>>   #0 method handles adapter
>>   #19 other = 308K (hdr 0%,  loc 0%, code 99%, stub 0%, [oops 0%, data
>> 0%, pcs 0%])
>> 
>> 
>> java -XX:+TieredCompilation -XX:+PrintCodeCache -jar
>> dacapo-9.12-bach.jar fop
>> ===== DaCapo 9.12 fop starting =====
>> ===== DaCapo 9.12 fop PASSED in 4850 msec =====
>> CodeCache: size=245760Kb used=7355Kb max_used=7370Kb free=238404Kb
>>  bounds [0x00007f49fd000000, 0x00007f49fd740000, 0x00007f4a0c000000]
>>  total_blobs=2578 nmethods=2240 adapters=254
>>  compilation: enabled
>> 
>> Interpreter:  total=199k, used=123k
>> 
>> Total number of live methods: 2205
>>  Tier 1:
>>   #466 Java methods = 333K (hdr 39%,  loc 5%, code 25%, stub 19%, [oops
>> 0%, data 0%, pcs 1%])
>>   #0 OSR methods
>>  Tier 2:
>>   #429 Java methods = 1047K (hdr 11%,  loc 5%, code 40%, stub 8%, [oops
>> 0%, data 1%, pcs 18%])
>>   #0 OSR methods
>>  Tier 3:
>>   #1069 Java methods = 3817K (hdr 7%,  loc 4%, code 53%, stub 5%, [oops
>> 0%, data 0%, pcs 17%])
>>   #5 OSR methods = 92K (hdr 1%,  loc 4%, code 57%, stub 2%, [oops 0%,
>> data 0%, pcs 23%])
>>  Tier 4:
>>   #190 Java methods = 648K (hdr 8%,  loc 3%, code 43%, stub 1%, [oops
>> 0%, data 1%, pcs 26%])
>>   #3 OSR methods = 15K (hdr 5%,  loc 3%, code 47%, stub 1%, [oops 0%,
>> data 0%, pcs 28%])
>>  Native methods:
>>   #43 Native methods = 37K (hdr 31%,  loc 10%, code 55%, stub 0%, [oops
>> 0%, data 0%, pcs 0%])
>> 
>> Total number of dead methods: 35
>>  Tier 1:
>>   #0 Java methods
>>   #0 OSR methods
>>  Tier 2:
>>   #3 Java methods = 22K (hdr 3%,  loc 5%, code 40%, stub 6%, [oops 0%,
>> data 1%, pcs 27%])
>>   #0 OSR methods
>>  Tier 3:
>>   #31 Java methods = 193K (hdr 4%,  loc 4%, code 54%, stub 3%, [oops
>> 0%, data 0%, pcs 21%])
>>   #1 OSR methods = 2K (hdr 11%,  loc 5%, code 52%, stub 7%, [oops 0%,
>> data 0%, pcs 7%])
>>  Tier 4:
>>   #0 Java methods
>>   #0 OSR methods
>>  Native methods:
>>   #0 Native methods
>> 
>> Total number of stubs: 338
>>   #57 runtime = 24K (hdr 14%,  loc 3%, code 79%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #1 deoptimization = 1K (hdr 7%,  loc 0%, code 89%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #1 uncommon trap = 0K (hdr 13%,  loc 1%, code 83%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #1 exception = 0K (hdr 27%,  loc 3%, code 65%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #3 safepoint = 1K (hdr 10%,  loc 1%, code 86%, stub 0%, [oops 0%,
>> data 0%, pcs 0%])
>>   #254 C2I/I2C adapter = 116K (hdr 13%,  loc 1%, code 82%, stub 0%,
>> [oops 0%, data 0%, pcs 0%])
>>   #0 method handles adapter
>>   #21 other = 871K (hdr 0%,  loc 0%, code 99%, stub 0%, [oops 0%, data
>> 0%, pcs 0%])
>> 
>> 
>> Please let me know if you think more/less/different data should be printed.



More information about the hotspot-compiler-dev mailing list