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