96

I tend to write rather large templated header-only C++ libraries and my users commonly complain about compilation times. After thinking about the matter, it occurred to me that I have no idea where the time is going. Is there some simple way to profile the C++ compilation process with common compilers, such as GCC (g++), Intel C++ Compiler (icc), and XL C/C++ (xlC)? For instance, is it possible to get an idea of how much time is spent within each of the phases of C++ compilation?

Peter Mortensen
  • 30,738
  • 21
  • 105
  • 131
Jack Poulson
  • 1,305
  • 1
  • 10
  • 13
  • 2
    http://stackoverflow.com/questions/82128/displaying-build-times-in-visual-studio for visual studio – Karthik T Nov 26 '12 at 06:48
  • 3
    @KarthikT I appreciate the suggestion, but I am interested in much more fine-grained information than that (and for a wider array of compilers). For instance, if I build *one* object file out of a header-only library, how can I see where the time went? – Jack Poulson Nov 26 '12 at 06:52
  • I see, I am not able to find anything more fine grained than that, sorry. – Karthik T Nov 26 '12 at 07:09
  • https://devblogs.microsoft.com/cppblog/introducing-c-build-insights/ – Martin Ba Mar 09 '21 at 10:27

7 Answers7

78

For GCC there are debugging options to find how much time is spent within each of the phases of C++ compilation?

-Q Makes the compiler print out each function name as it is compiled, and print some statistics about each pass when it finishes.

-ftime-report Makes the compiler print some statistics about the time consumed by each pass when it finishes.

Passes are described in GCCINT 9: Passes and Files of the Compiler.

You can post output of g++ compilation of single source file with -v -ftime-report here to discuss it. There could be some help on the GCC mailing list.

For compilers other than GCC (or GCC more ancient than 3.3.6), see the other options in other answers.

Peter Mortensen
  • 30,738
  • 21
  • 105
  • 131
osgx
  • 90,338
  • 53
  • 357
  • 513
  • 2
    PS: `-Q` output may be grabbed, parsed and analyzed by some awk or perl script; or you can just watch on function name printing on the console, the any which was printed after long pause was hard to compile. – osgx Mar 03 '15 at 05:52
  • Any idea how to attach timing to the function names (short of hacking g++)? I have a 200 MB file with a spaghetti mess of functions and no idea which function took long to compile. They mostly compile fast, there are just many of them (it is also a template heavy code). I was thinking a pipe and a script but pipes have some buffer and the functions with short names might not get there until more is printed. – the swine Oct 06 '15 at 18:23
  • 1
    the swine, Try to grep 'quiet_flag' in gcc/cgraphunit.c and `gcc/toplev.c` ( `announce_function` - "when the start of a function definition is parsed, this function prints on stderr the name of the function"). This `announce_function` may be the point to add printing of timestamp (gettimeofday), or rewriting output to some unbuffered way. Or the other possible way is to enable debug dumps (`-fdump-rtl-all-all` `-fdump-tree-all-all` `-fdump-ipa-all-all`) but they will output 1 file per pass; you need convert them to output 1 file per pass and per function (get lot of files with creation time). – osgx Oct 07 '15 at 18:01
27

Clang 9 (and newer) has a -ftime-trace flag, which makes it output a profiling report as JSON (in addition to an object file).

You can import this file into a profiler that comes with Chrome (chrome://tracing) to get a nice visualisation:

pic

The bars correspond to headers that had to be parsed, and for each header, specific classes (and probably other constructs) that had to be parsed. It also reports time spent on instantiating specific templates.

HolyBlackCat
  • 78,603
  • 9
  • 131
  • 207
15

There's a tool from the Boost project, which could be useful for pretty much any compiler and build system.

The tool requires source code instrumentation with TEMPLATE_PROFILE_ENTER() and TEMPLATE_PROFILE_EXIT() macro calls. These macros then generate specific diagnostics (warnings) at compile-time, which are timed and collected along with instantiation callstacks (which consequently allow building and visualizing callgraphs) by a script. Not bad, IMO.

I didn't use it yet though.

Peter Mortensen
  • 30,738
  • 21
  • 105
  • 131
ulidtko
  • 14,740
  • 10
  • 56
  • 88
  • In its documentation page, I do not see the need for source code instrumentation. Where have you read that? – lrineau Feb 21 '14 at 13:02
  • @Irineau, in the source. The tool also provides some scripts which seem to perform the instrumentation on the fly automatically (although with unknown degree of granularity). – ulidtko Feb 22 '14 at 21:53
  • 2
    The link is dead. – rustyx Oct 05 '20 at 13:49
  • Well @rustyx that's no wonder, seeing **svn**.boost.org in the URL and 21-st century on the clock... Somebody has uploaded a [fork/mirror/rewrite?](https://github.com/psiha/profile_templates2) of it though, so maybe that helps. – ulidtko Oct 05 '20 at 16:04
5

You can separate them out to some extent (I'm assuming Make)

  • add a build rule that only preprocesses files (using the -E switch), and a .PHONY target that depends on the preprocessor output files just like the normal binary target depends on .o files. Measure how long it takes to build this target
  • add a 'PHONY target that depends on all the .o files, but doesn't link them. Measure how long it takes to build this target (from clean)
  • measure how long it takes to do a clean build of the usual binary

Now you have some idea how long it takes to pre-process, compile, and link. You can also compare optimized and non-optimized (-O0) versions of the second and third target, to see how long is spent in the optimizer.

Peter Mortensen
  • 30,738
  • 21
  • 105
  • 131
Useless
  • 64,155
  • 6
  • 88
  • 132
  • Thank you for the response. I think that this would be more than adequate for C programs, but for header-only C++ that does not build more than one .o file, almost all of the time will be spent in building the single .o. I'm upvoting but will cross my fingers that someone will propose a finer-grain approach. – Jack Poulson Nov 30 '12 at 15:46
  • Ah, so you're not so interested in the translation phases as in which bit of code takes the most time? – Useless Nov 30 '12 at 17:36
  • 2
    If you use clang/llvm you could use a similar technique to seperate the front-end (clang) from the backend(llvm-opt). In the back end you could even dump the optimizer graph and run them seperately. In gcc, you could compare build time between -O0 and -O3 and see the difference between time spent in optimization vs time spent elsewhere. You can then selectively enable optimizers to see which is the worst offender (if any). – Ze Blob Dec 01 '12 at 20:20
2

You might be able to get some traction with some variant on strace -e trace=process -f -r -ttt -T, at least for compilers like g++ that are broken up into many processes.

Phil Miller
  • 36,389
  • 13
  • 67
  • 90
2

Externis is a GCC plugin that will generate trace files very similar to Clang's -ftime-trace:

Enter image description here

Disclaimer: I'm the author of this plugin.

Peter Mortensen
  • 30,738
  • 21
  • 105
  • 131
unddoch
  • 5,790
  • 1
  • 24
  • 37
1

Others have already suggested the -ftime-report command line flag for GCC, which makes the compiler print some statistics about the time consumed by each compilation phase. The drawback is that it only shows summary for one unit.

I've written a Python script, which allows to print the total summary on all units, by each compilation phase, given the project build log file. It also allows sorting by different phases. And it also allows to compare two log files (e.g., if you're trying to understand the impact of your changes).

Peter Mortensen
  • 30,738
  • 21
  • 105
  • 131
Alex Che
  • 6,659
  • 4
  • 44
  • 53