RFR: Rework rich PrintCompilation logs

[Aleksey Shipilev]

I have been studying javac benchmark behavior, and current `PrintCompilation` logs are very useful to figure out how much time is spent in creation, queueing, work time for each task. Current logs are quite a bit confusing, though:
 - The columns are misindented
 - The precision is too low to capture short events: most of the times are zero
 - Output seems to rely on "now" timestamp, which depends on _when_ we print
 
This PR reworks the logs to be more straightforward.

Example before:


   S296 C0 Q229 3531      A  2       com.sun.tools.javac.parser.JavacParser::typeName (37 bytes)
   S296 C0 Q245 2030      A  2       com.sun.tools.javac.tree.TreeInfo::innermostType (102 bytes)
   S296 C0 Q0 4169         3       com.sun.tools.javac.comp.Flow$AliveAnalyzer$$Lambda/0x800000105::accept (12 bytes)
   S296 C0 Q245 2042      A  2       com.sun.tools.javac.tree.JCTree$JCPrimitiveTypeTree::accept (9 bytes)
   S296 C0 Q0 4170         3       com.sun.tools.javac.comp.Flow$AssignAnalyzer$$Lambda/0x800000108::accept (12 bytes)
   S296 C0 Q0 4171         3       com.sun.tools.javac.comp.Flow$FlowAnalyzer$$Lambda/0x80000010a::accept (12 bytes)
   S296 C0 Q245 2098      A  2       com.sun.tools.javac.code.Symbol$RecordComponent::getOriginalAnnos (24 bytes)
   S296 C0 Q244 2348      A  2       com.sun.tools.javac.tree.TreeCopier::visitPrimitiveType (24 bytes)
   S296 C0 Q244 2349      A  2       com.sun.tools.javac.tree.TreeCopier::visitPrimitiveType (7 bytes)


Example after:


    346    C0.0                   4146         3       com.sun.tools.javac.comp.Check::checkAllDefined (66 bytes)
    346    C0.0    Q0.0    W0.1   4144         3       com.sun.tools.javac.comp.Attr$$Lambda/0x80000004f::<init> (10 bytes)
    346    C0.6  Q281.9    W0.1   3535      A  2       com.sun.tools.javac.parser.JavacParser::variableDeclaratorId (529 bytes)
    346    C0.0                   4148         3       com.sun.tools.javac.comp.Check::checkDefaultMethodClashes (383 bytes)
    346    C0.0    Q0.0    W0.1   4145         3       com.sun.tools.javac.comp.Attr$$Lambda/0x800000052::test (8 bytes)
    346    C0.4                   2631      A  2       com.sun.tools.javac.jvm.Items$ImmediateItem::numericValue (14 bytes)
    346    C0.0                   4149         3       com.sun.tools.javac.comp.Check::checkPotentiallyAmbiguousOverloads (79 bytes)
    346    C0.4  Q295.2    W0.0   2631      A  2       com.sun.tools.javac.jvm.Items$ImmediateItem::numericValue (14 bytes)
    346    C0.1                   2790      A  2       java.lang.invoke.InnerClassLambdaMetafactory::methodDesc (45 bytes)
    346    C0.1  Q294.5    W0.0   2790      A  2       java.lang.invoke.InnerClassLambdaMetafactory::methodDesc (45 bytes)


Note this effectively prints the task twice: one in the "usual" place we do it (near task creation), and one at the end, when we know all counters are populated and trustworthy.

-------------

Commit messages:
 - Work

Changes: https://git.openjdk.org/leyden/pull/16/files
  Webrev: https://webrevs.openjdk.org/?repo=leyden&pr=16&range=00
  Stats: 40 lines in 3 files changed: 23 ins; 0 del; 17 mod
  Patch: https://git.openjdk.org/leyden/pull/16.diff
  Fetch: git fetch https://git.openjdk.org/leyden.git pull/16/head:pull/16

PR: https://git.openjdk.org/leyden/pull/16