From 60eb06ce94dd23937d7b225ecca7a27adec65f60 Mon Sep 17 00:00:00 2001
From: Jon Ross-Perkins <jperkins@google.com>
Date: Wed, 7 Dec 2022 09:17:54 -0800
Subject: [PATCH] Move trace banners to driver and trace intermediate state.
 (#2443)

Printing intermediate state should be helpful to be able to examine the input when debugging later steps.

Intermediate state is hard to trace from the individual libraries since they don't know whether `dump` is going to print the state, so this moves some trace logic into the driver which is better equipped to make the decision.
---
 toolchain/driver/BUILD                              |  1 +
 toolchain/driver/driver.cpp                         | 13 +++++++++++++
 toolchain/parser/parser.cpp                         |  4 ----
 .../semantics/semantics_parse_tree_handler.cpp      |  2 --
 4 files changed, 14 insertions(+), 6 deletions(-)

diff --git a/toolchain/driver/BUILD b/toolchain/driver/BUILD
index 41c40d14f239..b63cfe16cf9b 100644
--- a/toolchain/driver/BUILD
+++ b/toolchain/driver/BUILD
@@ -15,6 +15,7 @@ cc_library(
     hdrs = ["driver.h"],
     textual_hdrs = ["flags.def"],
     deps = [
+        "//common:vlog",
         "//toolchain/diagnostics:diagnostic_emitter",
         "//toolchain/diagnostics:sorting_diagnostic_consumer",
         "//toolchain/lexer:tokenized_buffer",
diff --git a/toolchain/driver/driver.cpp b/toolchain/driver/driver.cpp
index f151ee79f03b..0db8a8090381 100644
--- a/toolchain/driver/driver.cpp
+++ b/toolchain/driver/driver.cpp
@@ -4,6 +4,7 @@
 
 #include "toolchain/driver/driver.h"
 
+#include "common/vlog.h"
 #include "llvm/ADT/ArrayRef.h"
 #include "llvm/ADT/StringExtras.h"
 #include "llvm/ADT/StringRef.h"
@@ -148,7 +149,9 @@ auto Driver::RunDumpSubcommand(DiagnosticConsumer& consumer,
     return false;
   }
 
+  CARBON_VLOG() << "*** SourceBuffer::CreateFromFile ***\n";
   auto source = SourceBuffer::CreateFromFile(input_file_name);
+  CARBON_VLOG() << "*** SourceBuffer::CreateFromFile done ***\n";
   if (!source) {
     error_stream_ << "ERROR: Unable to open input source file: ";
     llvm::handleAllErrors(source.takeError(),
@@ -159,29 +162,39 @@ auto Driver::RunDumpSubcommand(DiagnosticConsumer& consumer,
     return false;
   }
 
+  CARBON_VLOG() << "*** TokenizedBuffer::Lex ***\n";
   auto tokenized_source = TokenizedBuffer::Lex(*source, consumer);
+  CARBON_VLOG() << "*** TokenizedBuffer::Lex done ***\n";
   if (dump_mode == DumpMode::TokenizedBuffer) {
+    CARBON_VLOG() << "Finishing output.";
     consumer.Flush();
     tokenized_source.Print(output_stream_);
     return !tokenized_source.has_errors();
   }
+  CARBON_VLOG() << tokenized_source;
 
+  CARBON_VLOG() << "*** ParseTree::Parse ***\n";
   auto parse_tree = ParseTree::Parse(tokenized_source, consumer, vlog_stream_);
+  CARBON_VLOG() << "*** ParseTree::Parse done ***\n";
   if (dump_mode == DumpMode::ParseTree) {
     consumer.Flush();
     parse_tree.Print(output_stream_, parse_tree_preorder);
     return !tokenized_source.has_errors() && !parse_tree.has_errors();
   }
+  CARBON_VLOG() << parse_tree;
 
   const SemanticsIR builtin_ir = SemanticsIR::MakeBuiltinIR();
+  CARBON_VLOG() << "*** SemanticsIR::MakeFromParseTree ***\n";
   const SemanticsIR semantics_ir = SemanticsIR::MakeFromParseTree(
       builtin_ir, tokenized_source, parse_tree, consumer, vlog_stream_);
+  CARBON_VLOG() << "*** SemanticsIR::MakeFromParseTree done ***\n";
   if (dump_mode == DumpMode::SemanticsIR) {
     consumer.Flush();
     semantics_ir.Print(output_stream_);
     // TODO: Return false when SemanticsIR has errors (not supported right now).
     return !tokenized_source.has_errors() && !parse_tree.has_errors();
   }
+  CARBON_VLOG() << semantics_ir;
 
   llvm_unreachable("should handle all dump modes");
 }
diff --git a/toolchain/parser/parser.cpp b/toolchain/parser/parser.cpp
index 67236a8ff67c..2f6849b0ff76 100644
--- a/toolchain/parser/parser.cpp
+++ b/toolchain/parser/parser.cpp
@@ -433,8 +433,6 @@ auto Parser::Parse() -> void {
   // Traces state_stack_. This runs even in opt because it's low overhead.
   PrettyStackTraceParseState pretty_stack(this);
 
-  CARBON_VLOG() << "*** Parser::Parse Begin ***\n";
-
   PushState(ParserState::DeclarationLoop());
   while (!state_stack_.empty()) {
     switch (state_stack_.back().state) {
@@ -447,8 +445,6 @@ auto Parser::Parse() -> void {
   }
 
   AddLeafNode(ParseNodeKind::FileEnd(), *position_);
-
-  CARBON_VLOG() << "*** Parser::Parse End ***\n";
 }
 
 auto Parser::HandleBraceExpressionState() -> void {
diff --git a/toolchain/semantics/semantics_parse_tree_handler.cpp b/toolchain/semantics/semantics_parse_tree_handler.cpp
index d5f750f3bd53..e3b10ac1627c 100644
--- a/toolchain/semantics/semantics_parse_tree_handler.cpp
+++ b/toolchain/semantics/semantics_parse_tree_handler.cpp
@@ -63,7 +63,6 @@ auto SemanticsParseTreeHandler::Build() -> void {
   PrettyStackTraceNodeStack pretty_node_stack(this);
   PrettyStackTraceNodeBlockStack pretty_node_block_stack(this);
 
-  CARBON_VLOG() << "*** SemanticsParseTreeHandler::Build Begin ***\n";
   // Add a block for the ParseTree.
   node_block_stack_.push_back(semantics_->AddNodeBlock());
 
@@ -85,7 +84,6 @@ auto SemanticsParseTreeHandler::Build() -> void {
         CARBON_CHECK(it == range.end())
             << "FileEnd should always be last, found "
             << parse_tree_->node_kind(*it);
-        CARBON_VLOG() << "*** SemanticsParseTreeHandler::Build End ***\n";
         return;
       }
       case ParseNodeKind::InfixOperator(): {