[RFC] Additional frontend timers in -ftime-report

Hello all,

I'd like to hear your thoughts on expanding the amount of information
provided by `clang -ftime-report`.

I noticed that `gcc -ftime-report` provides a breakdown of how much
time GCC spends doing preprocessing, parsing, template instantiation,
and more. `clang -ftime-report`, on the other hand, gives an
incredibly detailed breakdown of how long each LLVM pass takes, but
does not provide much detail on front-end tasks such as preprocessing
and template instantiation.

Here's an example of output from `clang -ftime-report` and `gcc
-ftime-report`:
https://gist.github.com/modocache/d74833818107ed50d11387a5a4e3fb72

As a result, when attempting to diagnose slow compile times with
Clang, my understanding is that users have two choices:

1. Use external profiling tools on a `clang` executable that does not
have its symbols stripped in order to determine what the bottleneck
is.
2. Compile the same code with `gcc -ftime-report` to determine which
phase is taking a long time. This workflow suits users who aren't
interested in improving Clang's performance, and are happy to simply
rewrite their source code so that it compiles faster.

I think it would be an improvement if Clang output more front-end
information in `clang -ftime-report`. For example, I've sent up a diff
that adds timers related to preprocessing:
https://reviews.llvm.org/D36492. Would anyone be interested in
reviewing it?

In addition, if anyone has thoughts on the general idea of adding more
timers to `clang -ftime-report`, please let me know. Assuming there's
interest in better resembling `gcc -ftime-report` behavior, I would be
happy to add timers for preprocessing, parsing, template
instantiation, and more.

Thanks!

- Brian Gesiak

Hello all,

I'd like to hear your thoughts on expanding the amount of information
provided by `clang -ftime-report`.

I noticed that `gcc -ftime-report` provides a breakdown of how much
time GCC spends doing preprocessing, parsing, template instantiation,
and more. `clang -ftime-report`, on the other hand, gives an
incredibly detailed breakdown of how long each LLVM pass takes, but
does not provide much detail on front-end tasks such as preprocessing
and template instantiation.

Here's an example of output from `clang -ftime-report` and `gcc
-ftime-report`:
https://gist.github.com/modocache/d74833818107ed50d11387a5a4e3fb72

As a result, when attempting to diagnose slow compile times with
Clang, my understanding is that users have two choices:

1. Use external profiling tools on a `clang` executable that does not
have its symbols stripped in order to determine what the bottleneck
is.
2. Compile the same code with `gcc -ftime-report` to determine which
phase is taking a long time. This workflow suits users who aren't
interested in improving Clang's performance, and are happy to simply
rewrite their source code so that it compiles faster.

I think it would be an improvement if Clang output more front-end
information in `clang -ftime-report`. For example, I've sent up a diff
that adds timers related to preprocessing:
https://reviews.llvm.org/D36492. Would anyone be interested in
reviewing it?

In addition, if anyone has thoughts on the general idea of adding more
timers to `clang -ftime-report`, please let me know. Assuming there's
interest in better resembling `gcc -ftime-report` behavior, I would be
happy to add timers for preprocessing, parsing, template
instantiation, and more.

This sounds like a great idea, thanks for working on it!

vedant

Hi Brian,

I've been unreasonably interested in compile times over the years, so
I think improvement in this area is a great idea!

One thing that caught my eye in the GCC report is the parser breakdown:

parser (global) : 0.00 ( 0%) usr 0.03 (38%) sys 0.04 (21%) wall 6603 kB (37%) ggc
parser struct body : 0.04 (40%) usr 0.00 ( 0%) sys 0.04 (21%) wall 2791 kB (15%) ggc
parser enumerator list : 0.01 (10%) usr 0.00 ( 0%) sys 0.00 ( 0%) wall 44 kB ( 0%) ggc
parser function body : 0.00 ( 0%) usr 0.02 (25%) sys 0.02 (11%) wall 1047 kB ( 6%) ggc
parser inl. meth. body : 0.01 (10%) usr 0.01 (13%) sys 0.03 (16%) wall 1093 kB ( 6%) ggc
template instantiation : 0.02 (20%) usr 0.01 (12%) sys 0.02 (11%) wall 3280 kB (18%) ggc

Do you know if these data points are consistent between source files
or is it a fine-grained breakdown of what you had in your source file?

Thanks,
- Kim