Collect timing data per unit for each phase (#4512)

This PR adds a `--dump-timings` flag to the `compile` subcommand
(similar to the existing `--dump-mem-usage` flag), which collects timing
data per compilation unit for each compilation phase. For example, on my
2020 M1 MacBook:

```
$ bazel build -c opt //toolchain
$ bazel-bin/toolchain/install/run_carbon compile --phase=lower --dump-timings examples/sieve.carbon | tail
...
---
filename:        'examples/sieve.carbon'
nanoseconds:
  lex:             30792
  parse:           25458
  check:           226625
  lower:           1136958
  Total:           1419833
...
```

Most of the changes are pretty straightforward. There were a couple I
wasn't sure about though; let me know if I should change:

- new `Timings` class in its own file, pretty similar to the existing
`MemUsage` class
- added a `timings_` field to the `CompilationUnit` class
- added a `timings` field to the `Check::Unit` struct
- renamed `CheckParseTree` function to `CheckParseTreeInner` for ease of
timing with early `return`

---------

Co-authored-by: Jon Ross-Perkins <jperkins@google.com>

toolchain/driver/compile_subcommand.cpp

@@ -7,6 +7,7 @@
 #include "common/vlog.h"
 #include "llvm/ADT/ScopeExit.h"
 #include "toolchain/base/pretty_stack_trace_function.h"
+#include "toolchain/base/timings.h"
 #include "toolchain/check/check.h"
 #include "toolchain/codegen/codegen.h"
 #include "toolchain/diagnostics/sorting_diagnostic_consumer.h"
@@ -236,6 +237,14 @@ Dumps the amount of memory used.
 )""",
       },
       [&](auto& arg_b) { arg_b.Set(&dump_mem_usage); });
+  b.AddFlag(
+      {
+          .name = "dump-timings",
+          .help = R"""(
+Dumps the duration of each phase for each compilation unit.
+)""",
+      },
+      [&](auto& arg_b) { arg_b.Set(&dump_timings); });
   b.AddFlag(
       {
           .name = "prelude-import",
@@ -346,6 +355,9 @@ class CompilationUnit {
     if (options_.dump_mem_usage && IncludeInDumps()) {
       mem_usage_ = MemUsage();
     }
+    if (options_.dump_timings && IncludeInDumps()) {
+      timings_ = Timings();
+    }
   }
 
   // Loads source and lexes it. Returns true on success.
@@ -364,8 +376,13 @@ class CompilationUnit {
     }
     CARBON_VLOG("*** SourceBuffer ***\n```\n{0}\n```\n", source_->text());
 
+    auto start_time = std::chrono::steady_clock::now();
     LogCall("Lex::Lex",
             [&] { tokens_ = Lex::Lex(value_stores_, *source_, *consumer_); });
+    if (timings_) {
+      auto end_time = std::chrono::steady_clock::now();
+      timings_->Add("lex", end_time - start_time);
+    }
     if (options_.dump_tokens && IncludeInDumps()) {
       consumer_->Flush();
       tokens_->Print(driver_env_->output_stream,
@@ -384,9 +401,14 @@ class CompilationUnit {
   auto RunParse() -> void {
     CARBON_CHECK(tokens_);
 
+    auto start_time = std::chrono::steady_clock::now();
     LogCall("Parse::Parse", [&] {
       parse_tree_ = Parse::Parse(*tokens_, *consumer_, vlog_stream_);
     });
+    if (timings_) {
+      auto end_time = std::chrono::steady_clock::now();
+      timings_->Add("parse", end_time - start_time);
+    }
     if (options_.dump_parse_tree && IncludeInDumps()) {
       consumer_->Flush();
       const auto& tree_and_subtrees = GetParseTreeAndSubtrees();
@@ -410,6 +432,7 @@ class CompilationUnit {
     CARBON_CHECK(parse_tree_);
     return {
         .value_stores = &value_stores_,
+        .timings = &timings_,
         .tokens = &*tokens_,
         .parse_tree = &*parse_tree_,
         .consumer = consumer_,
@@ -460,6 +483,7 @@ class CompilationUnit {
   auto RunLower(const Check::SemIRDiagnosticConverter& converter) -> void {
     CARBON_CHECK(sem_ir_);
 
+    auto start_time = std::chrono::steady_clock::now();
     LogCall("Lower::LowerToLLVM", [&] {
       llvm_context_ = std::make_unique<llvm::LLVMContext>();
       // TODO: Consider disabling instruction naming by default if we're not
@@ -469,6 +493,10 @@ class CompilationUnit {
                                    converter, input_filename_, *sem_ir_,
                                    &inst_namer, vlog_stream_);
     });
+    if (timings_) {
+      auto end_time = std::chrono::steady_clock::now();
+      timings_->Add("lower", end_time - start_time);
+    }
     if (vlog_stream_) {
       CARBON_VLOG("*** llvm::Module ***\n");
       module_->print(*vlog_stream_, /*AAW=*/nullptr,
@@ -483,7 +511,12 @@ class CompilationUnit {
 
   auto RunCodeGen() -> void {
     CARBON_CHECK(module_);
+    auto start_time = std::chrono::steady_clock::now();
     LogCall("CodeGen", [&] { success_ = RunCodeGenHelper(); });
+    if (timings_) {
+      auto end_time = std::chrono::steady_clock::now();
+      timings_->Add("codegen", end_time - start_time);
+    }
   }
 
   // Runs post-compile logic. This is always called, and called after all other
@@ -498,6 +531,10 @@ class CompilationUnit {
       Yaml::Print(driver_env_->output_stream,
                   mem_usage_->OutputYaml(input_filename_));
     }
+    if (timings_) {
+      Yaml::Print(driver_env_->output_stream,
+                  timings_->OutputYaml(input_filename_));
+    }
 
     // The diagnostics consumer must be flushed before compilation artifacts are
     // destructed, because diagnostics can refer to their state.
@@ -625,6 +662,8 @@ class CompilationUnit {
 
   // Tracks memory usage of the compile.
   std::optional<MemUsage> mem_usage_;
+  // Tracks timings of the compile.
+  std::optional<Timings> timings_;
 
   // These are initialized as steps are run.
   std::optional<SourceBuffer> source_;