RFR: FreeSet should report its internal state before/after GC cycle

[Aleksey Shipilev]

http://cr.openjdk.java.net/~shade/shenandoah/freeset-log-af/webrev.01/

This introduces the extended logging for FreeSet, that makes sense to dump before/after Allocation
Failure. This helps to diagnose the reason for the AF itself, as well as see how efficiently GC is
dealing with cleaning up the space. With our current mechanics, we might just dump the freeset
before/after the GC cycle, because that handles the AF paths as well.

Testing: hotspot_gc_shenandoah

Sample output:

[9.177s][info][gc      ] GC(6) Cancelling concurrent GC: Allocation Failure During Evac
[9.180s][info][gc      ] GC(6) Concurrent evacuation 7117M->10234M(10240M) 195.019ms
[9.180s][info][gc,ergo ] Free set:
[9.180s][info][gc,ergo ]   Used: 3121M of 3121M
[9.180s][info][gc,ergo ]   Mutator view:
[9.180s][info][gc,ergo ]     Regions: 0
[9.180s][info][gc,ergo ]     Max regular: 0K
[9.180s][info][gc,ergo ]     Max humongous: 0K
[9.180s][info][gc,ergo ]   Collector view:
[9.180s][info][gc,ergo ]     Regions: 0
[9.180s][info][gc,ergo ]     Max regular: 0K
[9.180s][info][gc,ergo ] Pacer for Idle. Initial: 204M, Alloc Tax Rate: 1.0x
[9.181s][info][gc,ergo ] Free set:
[9.181s][info][gc,ergo ]   Used: 3121M of 3121M
[9.181s][info][gc,ergo ]   Mutator view:
[9.181s][info][gc,ergo ]     Regions: 0
[9.181s][info][gc,ergo ]     Max regular: 0K
[9.181s][info][gc,ergo ]     Max humongous: 0K
[9.181s][info][gc,ergo ]   Collector view:
[9.181s][info][gc,ergo ]     Regions: 0
[9.181s][info][gc,ergo ]     Max regular: 0K
[9.181s][info][gc,start] GC(7) Pause Degenerated GC (Evacuation)
[9.181s][info][gc      ] GC(7) Cancelling concurrent GC: Allocation Failure
[9.181s][info][gc      ] GC(7) Cannot finish degeneration, upgrading to Full GC
[10.330s][info][gc,ergo ] GC(7) Free: 3752M, Regions: 2558 mutator, 0 collector
[10.337s][info][gc      ] GC(7) Pause Degenerated GC (Evacuation) 10234M->6487M(10240M) 1155.771ms
[10.337s][info][gc,ergo ] GC(7) Adjusting free threshold to: 64% (6553M)
[10.337s][info][gc,ergo ] Free set:
[10.337s][info][gc,ergo ]   Used: 0M of 3752M
[10.337s][info][gc,ergo ]   Mutator view:
[10.337s][info][gc,ergo ]     Regions: 2558
[10.337s][info][gc,ergo ]     Max regular: 4096K
[10.337s][info][gc,ergo ]     Max humongous: 3219456K
[10.337s][info][gc,ergo ]     External fragmentation: 17%
[10.337s][info][gc,ergo ]     Internal fragmentation: 63%
[10.337s][info][gc,ergo ]   Collector view:
[10.337s][info][gc,ergo ]     Regions: 0
[10.337s][info][gc,ergo ]     Max regular: 0K
[10.337s][info][gc,ergo ] Pacer for Idle. Initial: 204M, Alloc Tax Rate: 1.0x
[10.339s][info][gc,ergo ] Concurrent marking triggered. Free: 3731M, Free Threshold: 6553M;
Allocated: 40M, Alloc Threshold: 0M
[10.339s][info][gc,ergo ] Free set:
[10.339s][info][gc,ergo ]   Used: 21M of 3752M
[10.339s][info][gc,ergo ]   Mutator view:
[10.339s][info][gc,ergo ]     Regions: 1065
[10.339s][info][gc,ergo ]     Max regular: 4096K
[10.339s][info][gc,ergo ]     Max humongous: 3219456K
[10.339s][info][gc,ergo ]     External fragmentation: 16%
[10.339s][info][gc,ergo ]     Internal fragmentation: 12%
[10.339s][info][gc,ergo ]   Collector view:
[10.339s][info][gc,ergo ]     Regions: 0
[10.339s][info][gc,ergo ]     Max regular: 0K
[10.339s][info][gc,start] GC(8) Pause Init Mark
[10.356s][info][gc,ergo ] GC(8) Pacer for Mark. Used: 6506M, Free: 3730M, Non-Taxable: 373M, Alloc
Tax Rate: 6.4x
[10.356s][info][gc      ] GC(8) Pause Init Mark 16.612ms
[10.356s][info][gc,start] GC(8) Concurrent marking