RFR: 8159974: G1 String deduplication logging not aligned with the rest of G1

Per Liden per.liden at oracle.com
Mon Jun 27 13:25:25 UTC 2016


Hi,

Summary: With the introduction of Unified Logging, the style/conventions 
used for GC logging was changed in various ways. Some of the logging 
done by StringDedup was however left using the old style. This patch 
aligns the dedup logging with the rest of G1.

Webrev: http://cr.openjdk.java.net/~pliden/8159974/webrev.0/
Bug: https://bugs.openjdk.java.net/browse/JDK-8159974

Example, before:
----------------
[11.927s][info ][gc,stringdedup] Concurrent String Deduplication 
32.3M->32.3M(0.0B), avg 0.0%, 0.7633528 secs
[11.927s][debug][gc,stringdedup]    [Last Exec: 0.7633528 secs, Idle: 
0.5195570 secs, Blocked: 0/0.0000000 secs]
[11.927s][debug][gc,stringdedup]       [Inspected:         1410367]
[11.927s][debug][gc,stringdedup]          [Skipped:              0(  0.0%)]
[11.927s][debug][gc,stringdedup]          [Hashed:         1410367(100.0%)]
[11.927s][debug][gc,stringdedup]          [Known:                0(  0.0%)]
[11.927s][debug][gc,stringdedup]          [New: 
1410367(100.0%)     32.3M]
[11.927s][debug][gc,stringdedup]       [Deduplicated:            0( 
0.0%)      0.0B(  0.0%)]
[11.927s][debug][gc,stringdedup]          [Young:                0( 
0.0%)      0.0B(  0.0%)]
[11.927s][debug][gc,stringdedup]          [Old:                  0( 
0.0%)      0.0B(  0.0%)]
[11.927s][debug][gc,stringdedup]    [Total Exec: 4/6.7536909 secs, Idle: 
4/4.1289840 secs, Blocked: 9/0.8971700 secs]
[11.927s][debug][gc,stringdedup]       [Inspected:         7163002]
[11.927s][debug][gc,stringdedup]          [Skipped:              0(  0.0%)]
[11.927s][debug][gc,stringdedup]          [Hashed:         7159929(100.0%)]
[11.927s][debug][gc,stringdedup]          [Known:             2916(  0.0%)]
[11.927s][debug][gc,stringdedup]          [New: 
7160086(100.0%)    163.9M]
[11.927s][debug][gc,stringdedup]       [Deduplicated:          177( 
0.0%)   5120.0B(  0.0%)]
[11.927s][debug][gc,stringdedup]          [Young:                0( 
0.0%)      0.0B(  0.0%)]
[11.927s][debug][gc,stringdedup]          [Old: 
177(100.0%)   5120.0B(100.0%)]
[11.927s][debug][gc,stringdedup]    [Table]
[11.927s][debug][gc,stringdedup]       [Memory Usage: 250.6M]
[11.927s][debug][gc,stringdedup]       [Size: 4194304, Min: 1024, Max: 
16777216]
[11.927s][debug][gc,stringdedup]       [Entries: 7162825, Load: 170.8%, 
Cached: 0, Added: 7162825, Removed: 0]
[11.927s][debug][gc,stringdedup]       [Resize Count: 12, Shrink 
Threshold: 2796202(66.7%), Grow Threshold: 8388608(200.0%)]
[11.927s][debug][gc,stringdedup]       [Rehash Count: 0, Rehash 
Threshold: 120, Hash Seed: 0x0]
[11.927s][debug][gc,stringdedup]       [Age Threshold: 3]
[11.927s][debug][gc,stringdedup]    [Queue]
[11.927s][debug][gc,stringdedup]       [Dropped: 0]

Example, after:
---------------
[11.073s][info ][gc,stringdedup] Concurrent String Deduplication (11.073s)
[11.975s][info ][gc,stringdedup] Concurrent String Deduplication 
33.2M->33.2M(0.0B) avg 0.0% (11.073s, 11.975s) 901.918ms
[11.975s][debug][gc,stringdedup]   Last Exec: 901.918ms, Idle: 
407.930ms, Blocked: 0/0.000ms
[11.975s][debug][gc,stringdedup]     Inspected:         1450663
[11.975s][debug][gc,stringdedup]       Skipped:               0(  0.0%)
[11.975s][debug][gc,stringdedup]       Hashed:          1450663(100.0%)
[11.975s][debug][gc,stringdedup]       Known:                 0(  0.0%)
[11.975s][debug][gc,stringdedup]       New:             1450663(100.0%) 
     33.2M
[11.975s][debug][gc,stringdedup]     Deduplicated:            0(  0.0%) 
      0.0B(  0.0%)
[11.975s][debug][gc,stringdedup]       Young:                 0(  0.0%) 
      0.0B(  0.0%)
[11.975s][debug][gc,stringdedup]       Old:                   0(  0.0%) 
      0.0B(  0.0%)
[11.975s][debug][gc,stringdedup]   Total Exec: 4/7275.988ms, Idle: 
4/3620.653ms, Blocked: 8/929.258ms
[11.975s][debug][gc,stringdedup]     Inspected:         7348199
[11.975s][debug][gc,stringdedup]       Skipped:               0(  0.0%)
[11.975s][debug][gc,stringdedup]       Hashed:          7345126(100.0%)
[11.975s][debug][gc,stringdedup]       Known:              2916(  0.0%)
[11.975s][debug][gc,stringdedup]       New:             7345283(100.0%) 
    168.1M
[11.975s][debug][gc,stringdedup]     Deduplicated:          177(  0.0%) 
   5120.0B(  0.0%)
[11.975s][debug][gc,stringdedup]       Young:                 0(  0.0%) 
      0.0B(  0.0%)
[11.975s][debug][gc,stringdedup]       Old:                 177(100.0%) 
   5120.0B(100.0%)
[11.975s][debug][gc,stringdedup]   Table
[11.975s][debug][gc,stringdedup]     Memory Usage: 256.2M
[11.975s][debug][gc,stringdedup]     Size: 4194304, Min: 1024, Max: 16777216
[11.975s][debug][gc,stringdedup]     Entries: 7348022, Load: 175.2%, 
Cached: 0, Added: 7348022, Removed: 0
[11.975s][debug][gc,stringdedup]     Resize Count: 12, Shrink Threshold: 
2796202(66.7%), Grow Threshold: 8388608(200.0%)
[11.975s][debug][gc,stringdedup]     Rehash Count: 0, Rehash Threshold: 
120, Hash Seed: 0x0
[11.975s][debug][gc,stringdedup]     Age Threshold: 3
[11.975s][debug][gc,stringdedup]   Queue
[11.975s][debug][gc,stringdedup]     Dropped: 0

cheers,
Per




More information about the hotspot-gc-dev mailing list