Include self-profiler results

[wesleywiser]

rustc has the option to emit self-profiling data at the end of a compilation. It would be cool to include this data in the performance metrics which would allow us to see what parts of the compiler are broadly responsible for performance gains/regressions.

Running the compiler with rustc -Z self-profile -Z profile-json will cause a self_profiler_results.json file to be created in the working directory. The output looks like this:

[
  {
    "category": "Parsing",
    "time_ms": 1
  },
  {
    "category": "Expansion",
    "time_ms": 2
  },
  {
    "category": "TypeChecking",
    "time_ms": 3
  },
  {
    "category": "BorrowChecking",
    "time_ms": 4
  },
  {
    "category": "Codegen",
    "time_ms": 5
  },
  {
    "category": "Linking",
    "time_ms": 6
  },
  {
    "category": "Other",
    "time_ms": 7
  }
]

cc @nikomatsakis who's wanted this for a while and probably has ideas for what it should look like 😃

[Mark-Simulacrum]

I discussed this around a week ago with @nikomatsakis and we arrived at the conclusion that just collecting the data would be an excellent start; I hope to have some time this next week to do just that.

[Mark-Simulacrum]

I'm seeing the following results which are not valid JSON on a file just containing fn main() {}. Is it possible the support here isn't fully fleshed out yet? It would be good to eliminate the NaNs and make the JSON generated be valid I think before integration into perf is done. @wesleywiser would you perhaps know if I'm doing something wrong? I'm compiling with rustc -Zprofile-json -Zself-profile t.rs on rustc 1.32.0-nightly (13c943992 2018-11-18).

{ "category_data": [{ "category": Parsing, "time_ms": 0,
                            "query_count": 0, "query_hits": NaN }{ "category": Expansion, "time_ms": 10,
                            "query_count": 0, "query_hits": NaN }{ "category": TypeChecking, "time_ms": 1,
                            "query_count": 3444, "query_hits": 80.55 }{ "category": BorrowChecking, "time_ms": 0,
                            "query_count": 20, "query_hits": 40.00 }{ "category": Codegen, "time_ms": 3,
                            "query_count": 763, "query_hits": 65.27 }{ "category": Linking, "time_ms": 65,
                            "query_count": 64, "query_hits": 46.88 }{ "category": Other, "time_ms": 56,
                            "query_count": 13572, "query_hits": 38.73 }], "compilation_options": { "optimization_level": "No", "incremental": false } }

[wesleywiser]

@Mark-Simulacrum Nope, looks like you found a bug. I filed a fix here

[Mark-Simulacrum]

The category labels are not currently allowed per the JSON spec; they need to be strings. I'm working on a patch now.

[Mark-Simulacrum]

@wesleywiser Could we not print out the table if the -Zprofile-json is passed?

[wesleywiser]

@Mark-Simulacrum Absolutely!

[Mark-Simulacrum]

Empirically, I'm also seeing high Other counts -- could we somehow dig into those? I happened to run this on librustc in rustc and I see, which is quite ... unhelpful since the vast majority of the time (133 seconds) is in "other"

Self profiling results for rustc:

| Phase            | Time (ms)      | Queries        | Hits (%) |
| ---------------- | -------------- | -------------- | -------- |
| Parsing          | 419            |                |          |
| Expansion        | 1539           |                |          |
| TypeChecking     | 31186          | 147616813      | 96.87    |
| BorrowChecking   | 6976           | 556902         | 72.80    |
| Codegen          | 71564          | 7517292        | 95.36    |
| Linking          | 2785           | 1425238        | 97.82    |
| Other            | 133209         | 96020418       | 98.11    |

Optimization level: Default
Incremental: off