From 9df70fb1159f6409840b8487f283d7ee321e2387 Mon Sep 17 00:00:00 2001
From: Jon Ross-Perkins <jperkins@google.com>
Date: Wed, 22 Feb 2023 13:41:12 -0800
Subject: [PATCH] Disable most tracing in the prelude. (#2616)

This is intended to address currently flaky timeouts that are likely caused by the size of the prelude. I'm addressing a performance bottleneck in AnalyzeProgram with trace output. Trying to omit prelude traces reduces most trace output significantly,  and I think it'll scale better as the prelude size increases.

The basic mechanics here are:

- In order to consistently track whether tracing is on, I've added a TraceStream class, explorer/interpreter/trace_stream.h.
- The AST now has a num_prelude_declarations field, so that it's provided where the boundary is.
- In order to mark where we try to skip prelude output, I've added calls to set_in_prelude in type_checker.
- In exec_program, I just use num_prelude_declarations directly to skip over.
- Everywhere checks TraceStream::is_enabled before printing, similar to the std::optional check that was previously used.

This does add some timing output in order to better diagnose where slowness is coming from, when tracing. It also adds "verbose" targets to make it easier to get the trace output.

So for example, here's a timing for zero.carbon:

```
Timings:
- Parse: 13ms
- AddPrelude: 25ms
- AnalyzeProgram: 116ms
- ExecProgram: 12ms
```

If I make a small change to just not set skipping_prelude (essentially getting back to current output):

```
- Parse: 13ms
- AddPrelude: 25ms
- AnalyzeProgram: 2359ms
- ExecProgram: 57ms
```

Thus in this trivial example, I'm eliminating about 95% of the execution time.

Note this approach could still be refined in a few ways:

- We could add a flag to allow overriding in_prelude. It should be a small amount of work after this change. But it's a little consistent with how parser_debug works, that it won't print prelude output by default (unless there's an error).
- Execution could skip messages involving initialization of globals declared in the prelude. This is a little noisy right now, but I don't think it's significant for performance because ExecProgram is tiny.
- Once files are more separated, we should be able to change the num_prelude_declarations/set_in_prelude approach.

Co-authored-by: Richard Smith <richard@metafoo.co.uk>
---
 explorer/BUILD                              |   1 +
 explorer/ast/ast.h                          |   4 +
 explorer/fuzzing/BUILD                      |   1 +
 explorer/fuzzing/fuzzer_util.cpp            |  10 +-
 explorer/interpreter/BUILD                  |  17 +
 explorer/interpreter/exec_program.cpp       |  48 +--
 explorer/interpreter/exec_program.h         |   7 +-
 explorer/interpreter/interpreter.cpp        | 107 +++---
 explorer/interpreter/interpreter.h          |   9 +-
 explorer/interpreter/trace_stream.h         |  62 ++++
 explorer/interpreter/type_checker.cpp       | 375 ++++++++++----------
 explorer/interpreter/type_checker.h         |   5 +-
 explorer/main.cpp                           |  56 ++-
 explorer/syntax/prelude.cpp                 |   4 +-
 explorer/syntax/prelude.h                   |   3 +-
 explorer/testdata/BUILD                     |  11 +
 explorer/testdata/basic_syntax/trace.carbon |   9 +-
 17 files changed, 442 insertions(+), 287 deletions(-)
 create mode 100644 explorer/interpreter/trace_stream.h

diff --git a/explorer/BUILD b/explorer/BUILD
index c3b76ba92f8d..f6ca898cbd2e 100644
--- a/explorer/BUILD
+++ b/explorer/BUILD
@@ -24,6 +24,7 @@ cc_library(
         "//explorer/common:arena",
         "//explorer/common:nonnull",
         "//explorer/interpreter:exec_program",
+        "//explorer/interpreter:trace_stream",
         "//explorer/syntax",
         "//explorer/syntax:prelude",
         "@llvm-project//llvm:Support",
diff --git a/explorer/ast/ast.h b/explorer/ast/ast.h
index c2ed1341446e..1b30d10edaba 100644
--- a/explorer/ast/ast.h
+++ b/explorer/ast/ast.h
@@ -25,6 +25,10 @@ struct AST {
   std::vector<Nonnull<Declaration*>> declarations;
   // Synthesized call to `Main`. Injected after parsing.
   std::optional<Nonnull<CallExpression*>> main_call;
+  // The number of declarations which came from the prelude.
+  // TODO: This should be removed once the prelude AST can be separated from
+  // per-file ASTs.
+  int num_prelude_declarations = 0;
 };
 
 }  // namespace Carbon
diff --git a/explorer/fuzzing/BUILD b/explorer/fuzzing/BUILD
index 85cc148a59f9..db9d64130fd7 100644
--- a/explorer/fuzzing/BUILD
+++ b/explorer/fuzzing/BUILD
@@ -27,6 +27,7 @@ cc_library(
         "//common/fuzzing:carbon_cc_proto",
         "//common/fuzzing:proto_to_carbon_lib",
         "//explorer/interpreter:exec_program",
+        "//explorer/interpreter:trace_stream",
         "//explorer/syntax",
         "//explorer/syntax:prelude",
         "@bazel_tools//tools/cpp/runfiles",
diff --git a/explorer/fuzzing/fuzzer_util.cpp b/explorer/fuzzing/fuzzer_util.cpp
index e35720eb6fdb..49796f3b9688 100644
--- a/explorer/fuzzing/fuzzer_util.cpp
+++ b/explorer/fuzzing/fuzzer_util.cpp
@@ -10,6 +10,7 @@
 #include "common/error.h"
 #include "common/fuzzing/proto_to_carbon.h"
 #include "explorer/interpreter/exec_program.h"
+#include "explorer/interpreter/trace_stream.h"
 #include "explorer/syntax/parse.h"
 #include "explorer/syntax/prelude.h"
 #include "llvm/Support/FileSystem.h"
@@ -82,10 +83,11 @@ auto ParseAndExecute(const Fuzzing::CompilationUnit& compilation_unit)
   // Can't do anything without a prelude, so it's a fatal error.
   CARBON_CHECK(prelude_path.ok()) << prelude_path.error();
 
-  AddPrelude(*prelude_path, &arena, &ast.declarations);
-  CARBON_ASSIGN_OR_RETURN(
-      ast, AnalyzeProgram(&arena, ast, /*trace_stream=*/std::nullopt));
-  return ExecProgram(&arena, ast, /*trace_stream=*/std::nullopt);
+  AddPrelude(*prelude_path, &arena, &ast.declarations,
+             &ast.num_prelude_declarations);
+  TraceStream trace_stream;
+  CARBON_ASSIGN_OR_RETURN(ast, AnalyzeProgram(&arena, ast, &trace_stream));
+  return ExecProgram(&arena, ast, &trace_stream);
 }
 
 }  // namespace Carbon
diff --git a/explorer/interpreter/BUILD b/explorer/interpreter/BUILD
index acdfa10046ec..4183b371bd22 100644
--- a/explorer/interpreter/BUILD
+++ b/explorer/interpreter/BUILD
@@ -82,6 +82,7 @@ cc_library(
         ":resolve_control_flow",
         ":resolve_names",
         ":resolve_unformed",
+        ":trace_stream",
         ":type_checker",
         "//common:check",
         "//common:ostream",
@@ -142,6 +143,7 @@ cc_library(
         ":address",
         ":heap",
         ":stack",
+        ":trace_stream",
         "//common:check",
         "//common:error",
         "//common:ostream",
@@ -203,6 +205,20 @@ cc_library(
     ],
 )
 
+cc_library(
+    name = "trace_stream",
+    hdrs = ["trace_stream.h"],
+    visibility = [
+        "//explorer:__pkg__",
+        "//explorer/fuzzing:__pkg__",
+    ],
+    deps = [
+        "//common:check",
+        "//common:ostream",
+        "//explorer/common:nonnull",
+    ],
+)
+
 cc_library(
     name = "type_checker",
     srcs = [
@@ -222,6 +238,7 @@ cc_library(
         ":dictionary",
         ":interpreter",
         ":pattern_analysis",
+        ":trace_stream",
         "//common:check",
         "//common:error",
         "//common:ostream",
diff --git a/explorer/interpreter/exec_program.cpp b/explorer/interpreter/exec_program.cpp
index 8e1fc45818ee..1f171aa3ce87 100644
--- a/explorer/interpreter/exec_program.cpp
+++ b/explorer/interpreter/exec_program.cpp
@@ -19,12 +19,12 @@
 namespace Carbon {
 
 auto AnalyzeProgram(Nonnull<Arena*> arena, AST ast,
-                    std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
-    -> ErrorOr<AST> {
-  if (trace_stream) {
-    **trace_stream << "********** source program **********\n";
-    for (auto* const decl : ast.declarations) {
-      **trace_stream << *decl;
+                    Nonnull<TraceStream*> trace_stream) -> ErrorOr<AST> {
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** source program **********\n";
+    for (int i = ast.num_prelude_declarations;
+         i < static_cast<int>(ast.declarations.size()); ++i) {
+      *trace_stream << *ast.declarations[i];
     }
   }
   SourceLocation source_loc("<Main()>", 0);
@@ -33,36 +33,40 @@ auto AnalyzeProgram(Nonnull<Arena*> arena, AST ast,
       arena->New<TupleLiteral>(source_loc));
   // Although name resolution is currently done once, generic programming
   // (particularly templates) may require more passes.
-  if (trace_stream) {
-    **trace_stream << "********** resolving names **********\n";
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** resolving names **********\n";
   }
   CARBON_RETURN_IF_ERROR(ResolveNames(ast));
-  if (trace_stream) {
-    **trace_stream << "********** resolving control flow **********\n";
+
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** resolving control flow **********\n";
   }
   CARBON_RETURN_IF_ERROR(ResolveControlFlow(ast));
-  if (trace_stream) {
-    **trace_stream << "********** type checking **********\n";
+
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** type checking **********\n";
   }
   CARBON_RETURN_IF_ERROR(TypeChecker(arena, trace_stream).TypeCheck(ast));
-  if (trace_stream) {
-    **trace_stream << "********** resolving unformed variables **********\n";
+
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** resolving unformed variables **********\n";
   }
   CARBON_RETURN_IF_ERROR(ResolveUnformed(ast));
-  if (trace_stream) {
-    **trace_stream << "********** printing declarations **********\n";
-    for (auto* const decl : ast.declarations) {
-      **trace_stream << *decl;
+
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** printing declarations **********\n";
+    for (int i = ast.num_prelude_declarations;
+         i < static_cast<int>(ast.declarations.size()); ++i) {
+      *trace_stream << *ast.declarations[i];
     }
   }
   return ast;
 }
 
 auto ExecProgram(Nonnull<Arena*> arena, AST ast,
-                 std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
-    -> ErrorOr<int> {
-  if (trace_stream) {
-    **trace_stream << "********** starting execution **********\n";
+                 Nonnull<TraceStream*> trace_stream) -> ErrorOr<int> {
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** starting execution **********\n";
   }
   return InterpProgram(ast, arena, trace_stream);
 }
diff --git a/explorer/interpreter/exec_program.h b/explorer/interpreter/exec_program.h
index 84619f1d8e33..d602a507812d 100644
--- a/explorer/interpreter/exec_program.h
+++ b/explorer/interpreter/exec_program.h
@@ -10,19 +10,18 @@
 #define CARBON_EXPLORER_INTERPRETER_EXEC_PROGRAM_H_
 
 #include "explorer/ast/ast.h"
+#include "explorer/interpreter/trace_stream.h"
 #include "llvm/Support/raw_ostream.h"
 
 namespace Carbon {
 
 // Perform semantic analysis on the AST.
 auto AnalyzeProgram(Nonnull<Arena*> arena, AST ast,
-                    std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
-    -> ErrorOr<AST>;
+                    Nonnull<TraceStream*> trace_stream) -> ErrorOr<AST>;
 
 // Run the program's `Main` function.
 auto ExecProgram(Nonnull<Arena*> arena, AST ast,
-                 std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
-    -> ErrorOr<int>;
+                 Nonnull<TraceStream*> trace_stream) -> ErrorOr<int>;
 
 }  // namespace Carbon
 
diff --git a/explorer/interpreter/interpreter.cpp b/explorer/interpreter/interpreter.cpp
index e3a58d0ad0b7..5c87ba4e03b1 100644
--- a/explorer/interpreter/interpreter.cpp
+++ b/explorer/interpreter/interpreter.cpp
@@ -59,7 +59,7 @@ class Interpreter {
   // traces if `trace` is true. `phase` indicates whether it executes at
   // compile time or run time.
   Interpreter(Phase phase, Nonnull<Arena*> arena,
-              std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
+              Nonnull<TraceStream*> trace_stream)
       : arena_(arena),
         heap_(arena),
         todo_(MakeTodo(phase, &heap_)),
@@ -168,7 +168,7 @@ class Interpreter {
   auto CallDestructor(Nonnull<const DestructorDeclaration*> fun,
                       Nonnull<const Value*> receiver) -> ErrorOr<Success>;
 
-  void PrintState(llvm::raw_ostream& out);
+  void TraceState();
 
   auto phase() const -> Phase { return phase_; }
 
@@ -182,7 +182,7 @@ class Interpreter {
   // contents of any non-completed continuations at the end of execution.
   std::vector<Nonnull<ContinuationValue::StackFragment*>> stack_fragments_;
 
-  std::optional<Nonnull<llvm::raw_ostream*>> trace_stream_;
+  Nonnull<TraceStream*> trace_stream_;
   Phase phase_;
 };
 
@@ -197,11 +197,10 @@ Interpreter::~Interpreter() {
 // State Operations
 //
 
-void Interpreter::PrintState(llvm::raw_ostream& out) {
-  out << "{\nstack: " << todo_;
-  out << "\nmemory: " << heap_;
-  out << "\n}\n";
+void Interpreter::TraceState() {
+  *trace_stream_ << "{\nstack: " << todo_ << "\nmemory: " << heap_ << "\n}\n";
 }
+
 auto Interpreter::EvalPrim(Operator op, Nonnull<const Value*> /*static_type*/,
                            const std::vector<Nonnull<const Value*>>& args,
                            SourceLocation source_loc)
@@ -271,11 +270,10 @@ auto Interpreter::CreateStruct(const std::vector<FieldInitializer>& fields,
 auto PatternMatch(Nonnull<const Value*> p, Nonnull<const Value*> v,
                   SourceLocation source_loc,
                   std::optional<Nonnull<RuntimeScope*>> bindings,
-                  BindingMap& generic_args,
-                  std::optional<Nonnull<llvm::raw_ostream*>> trace_stream,
+                  BindingMap& generic_args, Nonnull<TraceStream*> trace_stream,
                   Nonnull<Arena*> arena) -> bool {
-  if (trace_stream) {
-    **trace_stream << "match pattern " << *p << "\nwith value " << *v << "\n";
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "match pattern " << *p << "\nwith value " << *v << "\n";
   }
   switch (p->kind()) {
     case Value::Kind::BindingPlaceholderValue: {
@@ -398,9 +396,9 @@ auto PatternMatch(Nonnull<const Value*> p, Nonnull<const Value*> v,
 auto Interpreter::StepLvalue() -> ErrorOr<Success> {
   Action& act = todo_.CurrentAction();
   const Expression& exp = cast<LValAction>(act).expression();
-  if (trace_stream_) {
-    **trace_stream_ << "--- step lvalue " << exp << " ." << act.pos() << "."
-                    << " (" << exp.source_loc() << ") --->\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- step lvalue " << exp << " ." << act.pos() << "."
+                   << " (" << exp.source_loc() << ") --->\n";
   }
   switch (exp.kind()) {
     case ExpressionKind::IdentifierExpression: {
@@ -536,9 +534,9 @@ auto Interpreter::StepLvalue() -> ErrorOr<Success> {
 
 auto Interpreter::EvalRecursively(std::unique_ptr<Action> action)
     -> ErrorOr<Nonnull<const Value*>> {
-  if (trace_stream_) {
-    **trace_stream_ << "--- recursive eval\n";
-    PrintState(**trace_stream_);
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- recursive eval\n";
+    TraceState();
   }
   todo_.BeginRecursiveAction();
   CARBON_RETURN_IF_ERROR(todo_.Spawn(std::move(action)));
@@ -547,12 +545,12 @@ auto Interpreter::EvalRecursively(std::unique_ptr<Action> action)
   // action is finished and popped off the queue before returning to us.
   while (!isa<RecursiveAction>(todo_.CurrentAction())) {
     CARBON_RETURN_IF_ERROR(Step());
-    if (trace_stream_) {
-      PrintState(**trace_stream_);
+    if (trace_stream_->is_enabled()) {
+      TraceState();
     }
   }
-  if (trace_stream_) {
-    **trace_stream_ << "--- recursive eval done\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- recursive eval done\n";
   }
   Nonnull<const Value*> result =
       cast<RecursiveAction>(todo_.CurrentAction()).results()[0];
@@ -957,8 +955,8 @@ auto Interpreter::CallFunction(const CallExpression& call,
                                Nonnull<const Value*> fun,
                                Nonnull<const Value*> arg,
                                ImplWitnessMap&& witnesses) -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "calling function: " << *fun << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "calling function: " << *fun << "\n";
   }
   switch (fun->kind()) {
     case Value::Kind::AlternativeConstructorValue: {
@@ -1096,9 +1094,9 @@ auto Interpreter::CallFunction(const CallExpression& call,
 auto Interpreter::StepExp() -> ErrorOr<Success> {
   Action& act = todo_.CurrentAction();
   const Expression& exp = cast<ExpressionAction>(act).expression();
-  if (trace_stream_) {
-    **trace_stream_ << "--- step exp " << exp << " ." << act.pos() << "."
-                    << " (" << exp.source_loc() << ") --->\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- step exp " << exp << " ." << act.pos() << "."
+                   << " (" << exp.source_loc() << ") --->\n";
   }
   switch (exp.kind()) {
     case ExpressionKind::IndexExpression: {
@@ -1698,9 +1696,9 @@ auto Interpreter::StepExp() -> ErrorOr<Success> {
 auto Interpreter::StepWitness() -> ErrorOr<Success> {
   Action& act = todo_.CurrentAction();
   const Witness* witness = cast<WitnessAction>(act).witness();
-  if (trace_stream_) {
-    **trace_stream_ << "--- step witness " << *witness << " ." << act.pos()
-                    << ". --->\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- step witness " << *witness << " ." << act.pos()
+                   << ". --->\n";
   }
   switch (witness->kind()) {
     case Value::Kind::BindingWitness: {
@@ -1764,11 +1762,11 @@ auto Interpreter::StepWitness() -> ErrorOr<Success> {
 auto Interpreter::StepStmt() -> ErrorOr<Success> {
   Action& act = todo_.CurrentAction();
   const Statement& stmt = cast<StatementAction>(act).statement();
-  if (trace_stream_) {
-    **trace_stream_ << "--- step stmt ";
-    stmt.PrintDepth(1, **trace_stream_);
-    **trace_stream_ << " ." << act.pos() << ". "
-                    << "(" << stmt.source_loc() << ") --->\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- step stmt ";
+    stmt.PrintDepth(1, trace_stream_->stream());
+    *trace_stream_ << " ." << act.pos() << ". "
+                   << "(" << stmt.source_loc() << ") --->\n";
   }
   switch (stmt.kind()) {
     case StatementKind::Match: {
@@ -2030,11 +2028,11 @@ auto Interpreter::StepStmt() -> ErrorOr<Success> {
     case StatementKind::ReturnVar: {
       const auto& ret_var = cast<ReturnVar>(stmt);
       const ValueNodeView& value_node = ret_var.value_node();
-      if (trace_stream_) {
-        **trace_stream_ << "--- step returned var "
-                        << cast<BindingPattern>(value_node.base()).name()
-                        << " ." << act.pos() << "."
-                        << " (" << stmt.source_loc() << ") --->\n";
+      if (trace_stream_->is_enabled()) {
+        *trace_stream_ << "--- step returned var "
+                       << cast<BindingPattern>(value_node.base()).name() << " ."
+                       << act.pos() << "."
+                       << " (" << stmt.source_loc() << ") --->\n";
       }
       CARBON_ASSIGN_OR_RETURN(Nonnull<const Value*> value,
                               todo_.ValueOfNode(value_node, stmt.source_loc()));
@@ -2099,11 +2097,11 @@ auto Interpreter::StepStmt() -> ErrorOr<Success> {
 auto Interpreter::StepDeclaration() -> ErrorOr<Success> {
   Action& act = todo_.CurrentAction();
   const Declaration& decl = cast<DeclarationAction>(act).declaration();
-  if (trace_stream_) {
-    **trace_stream_ << "--- step decl ";
-    decl.PrintID(**trace_stream_);
-    **trace_stream_ << " ." << act.pos() << ". "
-                    << "(" << decl.source_loc() << ") --->\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "--- step decl ";
+    decl.PrintID(trace_stream_->stream());
+    *trace_stream_ << " ." << act.pos() << ". "
+                   << "(" << decl.source_loc() << ") --->\n";
   }
   switch (decl.kind()) {
     case DeclarationKind::VariableDeclaration: {
@@ -2288,25 +2286,24 @@ auto Interpreter::Step() -> ErrorOr<Success> {
 
 auto Interpreter::RunAllSteps(std::unique_ptr<Action> action)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    PrintState(**trace_stream_);
+  if (trace_stream_->is_enabled()) {
+    TraceState();
   }
   todo_.Start(std::move(action));
   while (!todo_.IsEmpty()) {
     CARBON_RETURN_IF_ERROR(Step());
-    if (trace_stream_) {
-      PrintState(**trace_stream_);
+    if (trace_stream_->is_enabled()) {
+      TraceState();
     }
   }
   return Success();
 }
 
 auto InterpProgram(const AST& ast, Nonnull<Arena*> arena,
-                   std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
-    -> ErrorOr<int> {
+                   Nonnull<TraceStream*> trace_stream) -> ErrorOr<int> {
   Interpreter interpreter(Phase::RunTime, arena, trace_stream);
-  if (trace_stream) {
-    **trace_stream << "********** initializing globals **********\n";
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** initializing globals **********\n";
   }
 
   for (Nonnull<Declaration*> declaration : ast.declarations) {
@@ -2314,8 +2311,8 @@ auto InterpProgram(const AST& ast, Nonnull<Arena*> arena,
         std::make_unique<DeclarationAction>(declaration)));
   }
 
-  if (trace_stream) {
-    **trace_stream << "********** calling main function **********\n";
+  if (trace_stream->is_enabled()) {
+    *trace_stream << "********** calling main function **********\n";
   }
 
   CARBON_RETURN_IF_ERROR(interpreter.RunAllSteps(
@@ -2325,7 +2322,7 @@ auto InterpProgram(const AST& ast, Nonnull<Arena*> arena,
 }
 
 auto InterpExp(Nonnull<const Expression*> e, Nonnull<Arena*> arena,
-               std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
+               Nonnull<TraceStream*> trace_stream)
     -> ErrorOr<Nonnull<const Value*>> {
   Interpreter interpreter(Phase::CompileTime, arena, trace_stream);
   CARBON_RETURN_IF_ERROR(
diff --git a/explorer/interpreter/interpreter.h b/explorer/interpreter/interpreter.h
index 7b9775c58844..ea3b51d763be 100644
--- a/explorer/interpreter/interpreter.h
+++ b/explorer/interpreter/interpreter.h
@@ -16,6 +16,7 @@
 #include "explorer/ast/pattern.h"
 #include "explorer/interpreter/action.h"
 #include "explorer/interpreter/heap.h"
+#include "explorer/interpreter/trace_stream.h"
 #include "explorer/interpreter/value.h"
 #include "llvm/ADT/ArrayRef.h"
 
@@ -24,14 +25,13 @@ namespace Carbon {
 // Interprets the program defined by `ast`, allocating values on `arena` and
 // printing traces if `trace` is true.
 auto InterpProgram(const AST& ast, Nonnull<Arena*> arena,
-                   std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
-    -> ErrorOr<int>;
+                   Nonnull<TraceStream*> trace_stream) -> ErrorOr<int>;
 
 // Interprets `e` at compile-time, allocating values on `arena` and
 // printing traces if `trace` is true. The caller must ensure that all the
 // code this evaluates has been typechecked.
 auto InterpExp(Nonnull<const Expression*> e, Nonnull<Arena*> arena,
-               std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
+               Nonnull<TraceStream*> trace_stream)
     -> ErrorOr<Nonnull<const Value*>>;
 
 // Attempts to match `v` against the pattern `p`, returning whether matching
@@ -46,8 +46,7 @@ auto InterpExp(Nonnull<const Expression*> e, Nonnull<Arena*> arena,
 [[nodiscard]] auto PatternMatch(
     Nonnull<const Value*> p, Nonnull<const Value*> v, SourceLocation source_loc,
     std::optional<Nonnull<RuntimeScope*>> bindings, BindingMap& generic_args,
-    std::optional<Nonnull<llvm::raw_ostream*>> trace_stream,
-    Nonnull<Arena*> arena) -> bool;
+    Nonnull<TraceStream*> trace_stream, Nonnull<Arena*> arena) -> bool;
 
 }  // namespace Carbon
 
diff --git a/explorer/interpreter/trace_stream.h b/explorer/interpreter/trace_stream.h
new file mode 100644
index 000000000000..a5698fa1d2f7
--- /dev/null
+++ b/explorer/interpreter/trace_stream.h
@@ -0,0 +1,62 @@
+// Part of the Carbon Language project, under the Apache License v2.0 with LLVM
+// Exceptions. See /LICENSE for license information.
+// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
+
+#ifndef CARBON_EXPLORER_INTERPRETER_TRACE_STREAM_H_
+#define CARBON_EXPLORER_INTERPRETER_TRACE_STREAM_H_
+
+#include <optional>
+#include <string>
+
+#include "common/check.h"
+#include "common/ostream.h"
+#include "explorer/common/nonnull.h"
+
+namespace Carbon {
+
+// Encapsulates the trace stream so that we can cleanly disable tracing while
+// the prelude is being processed. The prelude is expected to take a
+// disproprotionate amount of time to log, so we try to avoid it.
+//
+// TODO: While the prelude is combined with the provided program as a single
+// AST, the AST knows which declarations came from the prelude. When the prelude
+// is fully treated as a separate file, we should be able to take a different
+// approach where the caller explicitly toggles tracing when switching file
+// contexts.
+class TraceStream {
+ public:
+  // Returns true if tracing is currently enabled.
+  auto is_enabled() const -> bool {
+    return stream_.has_value() && !in_prelude_;
+  }
+
+  // Sets whether the prelude is being skipped.
+  auto set_in_prelude(bool in_prelude) -> void { in_prelude_ = in_prelude; }
+
+  // Sets the trace stream. This should only be called from the main.
+  auto set_stream(Nonnull<llvm::raw_ostream*> stream) -> void {
+    stream_ = stream;
+  }
+
+  // Returns the internal stream. Requires is_enabled.
+  auto stream() const -> llvm::raw_ostream& {
+    CARBON_CHECK(is_enabled());
+    return **stream_;
+  }
+
+  // Outputs a trace message. Requires is_enabled.
+  template <typename T>
+  auto operator<<(T&& message) const -> llvm::raw_ostream& {
+    CARBON_CHECK(is_enabled());
+    **stream_ << message;
+    return **stream_;
+  }
+
+ private:
+  std::optional<Nonnull<llvm::raw_ostream*>> stream_;
+  bool in_prelude_ = false;
+};
+
+}  // namespace Carbon
+
+#endif  // CARBON_EXPLORER_INTERPRETER_TRACE_STREAM_H_
diff --git a/explorer/interpreter/type_checker.cpp b/explorer/interpreter/type_checker.cpp
index 3fb394df4ca0..1c0304f58d97 100644
--- a/explorer/interpreter/type_checker.cpp
+++ b/explorer/interpreter/type_checker.cpp
@@ -679,11 +679,11 @@ auto TypeChecker::ImplicitlyConvert(std::string_view context,
           ConvertToConstraintType(source->source_loc(), "implicit conversion",
                                   destination));
       destination = destination_constraint;
-      if (trace_stream_) {
-        **trace_stream_ << "converting type " << *converted_value
-                        << " to constraint " << *destination_constraint
-                        << " for " << context << " in scope " << impl_scope
-                        << "\n";
+      if (trace_stream_->is_enabled()) {
+        *trace_stream_ << "converting type " << *converted_value
+                       << " to constraint " << *destination_constraint
+                       << " for " << context << " in scope " << impl_scope
+                       << "\n";
       }
       // Note, we discard the witness. We don't actually need it in order to
       // perform the conversion, but we do want to know it exists.
@@ -864,18 +864,18 @@ class TypeChecker::ArgumentDeduction {
   ArgumentDeduction(
       SourceLocation source_loc, std::string_view context,
       llvm::ArrayRef<Nonnull<const GenericBinding*>> bindings_to_deduce,
-      std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
+      Nonnull<TraceStream*> trace_stream)
       : source_loc_(source_loc),
         context_(context),
         deduced_bindings_in_order_(bindings_to_deduce),
         trace_stream_(trace_stream) {
-    if (trace_stream_) {
-      **trace_stream_ << "performing argument deduction for bindings: ";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "performing argument deduction for bindings: ";
       llvm::ListSeparator sep;
       for (const auto* binding : bindings_to_deduce) {
-        **trace_stream_ << sep << *binding;
+        *trace_stream_ << sep << *binding;
       }
-      **trace_stream_ << "\n";
+      *trace_stream_ << "\n";
     }
     for (const auto* binding : bindings_to_deduce) {
       deduced_values_.insert({binding, {}});
@@ -918,7 +918,7 @@ class TypeChecker::ArgumentDeduction {
   SourceLocation source_loc_;
   std::string_view context_;
   llvm::ArrayRef<Nonnull<const GenericBinding*>> deduced_bindings_in_order_;
-  std::optional<Nonnull<llvm::raw_ostream*>> trace_stream_;
+  Nonnull<TraceStream*> trace_stream_;
 
   // Values for deduced bindings.
   std::map<Nonnull<const GenericBinding*>,
@@ -943,8 +943,8 @@ auto TypeChecker::ArgumentDeduction::Deduce(Nonnull<const Value*> param,
                                             Nonnull<const Value*> arg,
                                             bool allow_implicit_conversion)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "deducing " << *param << " from " << *arg << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "deducing " << *param << " from " << *arg << "\n";
   }
 
   // If param is the name of a variable we're deducing, then deduce it.
@@ -1279,9 +1279,9 @@ auto TypeChecker::ArgumentDeduction::Finish(
     // Evaluate the argument to get the value.
     CARBON_ASSIGN_OR_RETURN(Nonnull<const Value*> value,
                             InterpExp(arg, type_checker.arena_, trace_stream_));
-    if (trace_stream_) {
-      **trace_stream_ << "evaluated generic parameter " << *binding << " as "
-                      << *value << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "evaluated generic parameter " << *binding << " as "
+                     << *value << "\n";
     }
 
     // Find a witness for the binding if needed.
@@ -1327,16 +1327,16 @@ auto TypeChecker::ArgumentDeduction::Finish(
     }
   }
 
-  if (trace_stream_) {
-    **trace_stream_ << "deduction succeeded with results: {";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "deduction succeeded with results: {";
     llvm::ListSeparator sep;
     for (const auto& [binding, val] : bindings.args()) {
-      **trace_stream_ << sep << *binding << " = " << *val;
+      *trace_stream_ << sep << *binding << " = " << *val;
     }
     for (const auto& [binding, val] : bindings.witnesses()) {
-      **trace_stream_ << sep << *binding << " = " << *val;
+      *trace_stream_ << sep << *binding << " = " << *val;
     }
-    **trace_stream_ << "}\n";
+    *trace_stream_ << "}\n";
   }
 
   return {std::move(bindings)};
@@ -1498,8 +1498,8 @@ class TypeChecker::ConstraintTypeBuilder {
                         Nonnull<const Value*> self,
                         Nonnull<const Witness*> self_witness,
                         const Bindings& bindings, bool add_lookup_contexts) {
-    if (type_checker.trace_stream_) {
-      **type_checker.trace_stream_
+    if (type_checker.trace_stream_->is_enabled()) {
+      *type_checker.trace_stream_
           << "merging " << *constraint << " into constraint with "
           << *constraint->self_binding() << " ~> " << *self << "\n";
     }
@@ -1734,10 +1734,10 @@ class TypeChecker::ConstraintTypeBuilder {
 
     std::deque<Nonnull<RewriteConstraint*>> rewrite_queue;
     for (auto& rewrite : rewrite_constraints_) {
-      if (type_checker.trace_stream_) {
-        **type_checker.trace_stream_ << "initial rewrite of "
-                                     << *rewrite.constant << " is "
-                                     << *rewrite.converted_replacement << "\n";
+      if (type_checker.trace_stream_->is_enabled()) {
+        *type_checker.trace_stream_ << "initial rewrite of "
+                                    << *rewrite.constant << " is "
+                                    << *rewrite.converted_replacement << "\n";
       }
       rewrite_queue.push_back(&rewrite);
     }
@@ -1772,19 +1772,19 @@ class TypeChecker::ConstraintTypeBuilder {
       }
 
       if (!ValueEqual(rebuilt, rewrite->converted_replacement, std::nullopt)) {
-        if (type_checker.trace_stream_) {
-          **type_checker.trace_stream_ << "rewrote rewrite of "
-                                       << *rewrite->constant << " to "
-                                       << *rebuilt << "\n";
+        if (type_checker.trace_stream_->is_enabled()) {
+          *type_checker.trace_stream_ << "rewrote rewrite of "
+                                      << *rewrite->constant << " to "
+                                      << *rebuilt << "\n";
         }
         rewrite->converted_replacement = rebuilt;
         // Now we've rewritten this rewrite, we might find more rewrites apply
         // to the portion we rewrote.
         rewrite_queue.push_back(rewrite);
       } else {
-        if (type_checker.trace_stream_) {
-          **type_checker.trace_stream_ << "rewrite of " << *rewrite->constant
-                                       << " converged to " << *rebuilt << "\n";
+        if (type_checker.trace_stream_->is_enabled()) {
+          *type_checker.trace_stream_ << "rewrite of " << *rewrite->constant
+                                      << " converged to " << *rebuilt << "\n";
         }
       }
     }
@@ -1920,16 +1920,16 @@ auto TypeChecker::Substitute(const Bindings& bindings,
 
   const auto* result = SubstituteImpl(bindings, type);
 
-  if (trace_stream_) {
-    **trace_stream_ << "substitution of {";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "substitution of {";
     llvm::ListSeparator sep;
     for (const auto& [name, value] : bindings.args()) {
-      **trace_stream_ << sep << *name << " -> " << *value;
+      *trace_stream_ << sep << *name << " -> " << *value;
     }
     for (const auto& [name, value] : bindings.witnesses()) {
-      **trace_stream_ << sep << *name << " -> " << *value;
+      *trace_stream_ << sep << *name << " -> " << *value;
     }
-    **trace_stream_ << "}\n  old: " << *type << "\n  new: " << *result << "\n";
+    *trace_stream_ << "}\n  old: " << *type << "\n  new: " << *result << "\n";
   }
   return result;
 }
@@ -1955,9 +1955,10 @@ class TypeChecker::SubstituteTransform
       -> Nonnull<const Value*> {
     auto it = bindings_.args().find(&var_type->binding());
     if (it == bindings_.args().end()) {
-      if (const auto& trace_stream = type_checker_->trace_stream_) {
-        **trace_stream << "substitution: no value for binding " << *var_type
-                       << ", leaving alone\n";
+      if (const auto* trace_stream = type_checker_->trace_stream_;
+          trace_stream->is_enabled()) {
+        *trace_stream << "substitution: no value for binding " << *var_type
+                      << ", leaving alone\n";
       }
       return var_type;
     } else {
@@ -1970,9 +1971,10 @@ class TypeChecker::SubstituteTransform
       -> Nonnull<const Value*> {
     auto it = bindings_.witnesses().find(witness->binding());
     if (it == bindings_.witnesses().end()) {
-      if (const auto& trace_stream = type_checker_->trace_stream_) {
-        **trace_stream << "substitution: no value for binding " << *witness
-                       << ", leaving alone\n";
+      if (const auto* trace_stream = type_checker_->trace_stream_;
+          trace_stream->is_enabled()) {
+        *trace_stream << "substitution: no value for binding " << *witness
+                      << ", leaving alone\n";
       }
       return witness;
     } else {
@@ -2051,10 +2053,11 @@ class TypeChecker::SubstituteTransform
       } else {
         type_of_type = type_checker_->arena_->New<TypeType>();
       }
-      if (const auto& trace_stream = type_checker_->trace_stream_) {
-        **trace_stream << "substitution: self of constraint " << *constraint
-                       << " is substituted, new type of type is "
-                       << *type_of_type << "\n";
+      if (const auto* trace_stream = type_checker_->trace_stream_;
+          trace_stream->is_enabled()) {
+        *trace_stream << "substitution: self of constraint " << *constraint
+                      << " is substituted, new type of type is "
+                      << *type_of_type << "\n";
       }
       // TODO: Should we keep any part of the old constraint -- rewrites,
       // equality constraints, etc?
@@ -2066,9 +2069,10 @@ class TypeChecker::SubstituteTransform
                              builder.GetSelfWitness(), bindings_,
                              /*add_lookup_contexts=*/true);
     Nonnull<const ConstraintType*> new_constraint = std::move(builder).Build();
-    if (const auto& trace_stream = type_checker_->trace_stream_) {
-      **trace_stream << "substitution: " << *constraint << " => "
-                     << *new_constraint << "\n";
+    if (const auto* trace_stream = type_checker_->trace_stream_;
+        trace_stream->is_enabled()) {
+      *trace_stream << "substitution: " << *constraint << " => "
+                    << *new_constraint << "\n";
     }
     return new_constraint;
   }
@@ -2113,9 +2117,9 @@ auto TypeChecker::RefineWitness(Nonnull<const Witness*> witness,
       refined_witness.ok()) {
     return *refined_witness;
   } else {
-    if (trace_stream_) {
-      **trace_stream_ << "could not refine " << *witness << ": "
-                      << refined_witness.error().message() << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "could not refine " << *witness << ": "
+                     << refined_witness.error().message() << "\n";
     }
     return witness;
   }
@@ -2138,11 +2142,11 @@ auto TypeChecker::MatchImpl(const InterfaceType& iface,
   // Track that we're matching this impl.
   MatchingImplSet::Match match(&matching_impl_set_, &impl, impl_type, &iface);
 
-  if (trace_stream_) {
-    **trace_stream_ << "MatchImpl: looking for " << *impl_type << " as "
-                    << iface << "\n";
-    **trace_stream_ << "checking " << *impl.type << " as "
-                    << *impl.interface << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "MatchImpl: looking for " << *impl_type << " as " << iface
+                   << "\n";
+    *trace_stream_ << "checking " << *impl.type << " as "
+                   << *impl.interface << "\n";
   }
 
   ArgumentDeduction deduction(source_loc, "match", impl.deduced, trace_stream_);
@@ -2150,8 +2154,8 @@ auto TypeChecker::MatchImpl(const InterfaceType& iface,
           deduction.Deduce(impl.type, impl_type,
                            /*allow_implicit_conversion=*/false);
       !e.ok()) {
-    if (trace_stream_) {
-      **trace_stream_ << "type does not match: " << e.error() << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "type does not match: " << e.error() << "\n";
     }
     return {std::nullopt};
   }
@@ -2159,8 +2163,8 @@ auto TypeChecker::MatchImpl(const InterfaceType& iface,
   if (ErrorOr<Success> e = deduction.Deduce(
           impl.interface, &iface, /*allow_implicit_conversion=*/false);
       !e.ok()) {
-    if (trace_stream_) {
-      **trace_stream_ << "interface does not match: " << e.error() << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "interface does not match: " << e.error() << "\n";
     }
     return {std::nullopt};
   }
@@ -2175,14 +2179,14 @@ auto TypeChecker::MatchImpl(const InterfaceType& iface,
       deduction.Finish(const_cast<TypeChecker&>(*this), impl_scope,
                        /*diagnose_deduction_failure=*/false));
   if (!bindings_or_error) {
-    if (trace_stream_) {
-      **trace_stream_ << "impl does not match\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "impl does not match\n";
     }
     return {std::nullopt};
   } else {
-    if (trace_stream_) {
-      **trace_stream_ << "matched with " << *impl.type << " as "
-                      << *impl.interface << "\n\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "matched with " << *impl.type << " as "
+                     << *impl.interface << "\n\n";
     }
     return {cast<Witness>(Substitute(*bindings_or_error, impl.witness))};
   }
@@ -2511,14 +2515,13 @@ auto TypeChecker::CheckAddrMeAccess(
 auto TypeChecker::TypeCheckExp(Nonnull<Expression*> e,
                                const ImplScope& impl_scope)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "checking " << ExpressionKindName(e->kind()) << " "
-                    << *e;
-    **trace_stream_ << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "checking " << ExpressionKindName(e->kind()) << " " << *e;
+    *trace_stream_ << "\n";
   }
   if (e->is_type_checked()) {
-    if (trace_stream_) {
-      **trace_stream_ << "expression has already been type-checked\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "expression has already been type-checked\n";
     }
     return Success();
   }
@@ -3311,11 +3314,10 @@ auto TypeChecker::TypeCheckExp(Nonnull<Expression*> e,
       switch (call.function().static_type().kind()) {
         case Value::Kind::FunctionType: {
           const auto& fun_t = cast<FunctionType>(call.function().static_type());
-          if (trace_stream_) {
-            **trace_stream_
-                << "checking call to function of type " << fun_t
-                << "\nwith arguments of type: " << call.argument().static_type()
-                << "\n";
+          if (trace_stream_->is_enabled()) {
+            *trace_stream_ << "checking call to function of type " << fun_t
+                           << "\nwith arguments of type: "
+                           << call.argument().static_type() << "\n";
           }
           CARBON_RETURN_IF_ERROR(DeduceCallBindings(
               call, &fun_t.parameters(), fun_t.generic_parameters(),
@@ -3933,12 +3935,12 @@ auto TypeChecker::TypeCheckPattern(
     Nonnull<Pattern*> p, std::optional<Nonnull<const Value*>> expected,
     ImplScope& impl_scope, ValueCategory enclosing_value_category)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "checking " << PatternKindName(p->kind()) << " " << *p;
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "checking " << PatternKindName(p->kind()) << " " << *p;
     if (expected) {
-      **trace_stream_ << ", expecting " << **expected;
+      *trace_stream_ << ", expecting " << **expected;
     }
-    **trace_stream_ << "\n";
+    *trace_stream_ << "\n";
   }
   switch (p->kind()) {
     case PatternKind::AutoPattern: {
@@ -4037,9 +4039,9 @@ auto TypeChecker::TypeCheckPattern(
         }
         CARBON_RETURN_IF_ERROR(TypeCheckPattern(
             field, expected_field_type, impl_scope, enclosing_value_category));
-        if (trace_stream_) {
-          **trace_stream_ << "finished checking tuple pattern field " << *field
-                          << "\n";
+        if (trace_stream_->is_enabled()) {
+          *trace_stream_ << "finished checking tuple pattern field " << *field
+                         << "\n";
         }
         field_types.push_back(&field->static_type());
         field_patterns.push_back(&field->value());
@@ -4169,15 +4171,15 @@ auto TypeChecker::TypeCheckGenericBinding(GenericBinding& binding,
     ConstraintTypeBuilder builder(arena_, &binding, impl_binding);
     builder.AddAndSubstitute(*this, constraint, symbolic_value, witness,
                              Bindings(), /*add_lookup_contexts=*/true);
-    if (trace_stream_) {
-      **trace_stream_ << "resolving constraint type for " << binding << " from "
-                      << *constraint << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "resolving constraint type for " << binding << " from "
+                     << *constraint << "\n";
     }
     CARBON_RETURN_IF_ERROR(
         builder.Resolve(*this, binding.type().source_loc(), impl_scope));
     type = std::move(builder).Build();
-    if (trace_stream_) {
-      **trace_stream_ << "resolved constraint type is " << *type << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "resolved constraint type is " << *type << "\n";
     }
 
     BringImplIntoScope(impl_binding, impl_scope);
@@ -4220,9 +4222,9 @@ static auto GetBuiltinInterfaceForAssignOperator(AssignOperator op)
 auto TypeChecker::TypeCheckStmt(Nonnull<Statement*> s,
                                 const ImplScope& impl_scope)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "checking " << StatementKindName(s->kind()) << " " << *s
-                    << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "checking " << StatementKindName(s->kind()) << " " << *s
+                   << "\n";
   }
   switch (s->kind()) {
     case StatementKind::Match: {
@@ -4556,8 +4558,8 @@ auto TypeChecker::DeclareCallableDeclaration(Nonnull<CallableDeclaration*> f,
     -> ErrorOr<Success> {
   const auto name = GetName(*f);
   CARBON_CHECK(name) << "Unexpected missing name for `" << *f << "`.";
-  if (trace_stream_) {
-    **trace_stream_ << "** declaring function " << *name << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** declaring function " << *name << "\n";
   }
   ImplScope function_scope;
   function_scope.AddParent(scope_info.innermost_scope);
@@ -4653,9 +4655,9 @@ auto TypeChecker::DeclareCallableDeclaration(Nonnull<CallableDeclaration*> f,
     }
   }
 
-  if (trace_stream_) {
-    **trace_stream_ << "** finished declaring function " << *name << " of type "
-                    << f->static_type() << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished declaring function " << *name << " of type "
+                   << f->static_type() << "\n";
   }
   return Success();
 }
@@ -4665,8 +4667,8 @@ auto TypeChecker::TypeCheckCallableDeclaration(Nonnull<CallableDeclaration*> f,
     -> ErrorOr<Success> {
   auto name = GetName(*f);
   CARBON_CHECK(name) << "Unexpected missing name for `" << *f << "`.";
-  if (trace_stream_) {
-    **trace_stream_ << "** checking function " << *name << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** checking function " << *name << "\n";
   }
   // If f->return_term().is_auto(), the function body was already
   // type checked in DeclareFunctionDeclaration.
@@ -4676,8 +4678,8 @@ auto TypeChecker::TypeCheckCallableDeclaration(Nonnull<CallableDeclaration*> f,
     function_scope.AddParent(&impl_scope);
     BringImplsIntoScope(cast<FunctionType>(f->static_type()).impl_bindings(),
                         function_scope);
-    if (trace_stream_) {
-      **trace_stream_ << function_scope;
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << function_scope;
     }
     CARBON_RETURN_IF_ERROR(TypeCheckStmt(*f->body(), function_scope));
     if (!f->return_term().is_omitted()) {
@@ -4685,8 +4687,8 @@ auto TypeChecker::TypeCheckCallableDeclaration(Nonnull<CallableDeclaration*> f,
           ExpectReturnOnAllPaths(f->body(), f->source_loc()));
     }
   }
-  if (trace_stream_) {
-    **trace_stream_ << "** finished checking function " << *name << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished checking function " << *name << "\n";
   }
   return Success();
 }
@@ -4694,8 +4696,8 @@ auto TypeChecker::TypeCheckCallableDeclaration(Nonnull<CallableDeclaration*> f,
 auto TypeChecker::DeclareClassDeclaration(Nonnull<ClassDeclaration*> class_decl,
                                           const ScopeInfo& scope_info)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "** declaring class " << class_decl->name() << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** declaring class " << class_decl->name() << "\n";
   }
   Nonnull<SelfDeclaration*> self = class_decl->self();
 
@@ -4733,8 +4735,8 @@ auto TypeChecker::DeclareClassDeclaration(Nonnull<ClassDeclaration*> class_decl,
     CARBON_RETURN_IF_ERROR(TypeCheckPattern(type_params, std::nullopt,
                                             class_scope, ValueCategory::Let));
     CollectGenericBindingsInPattern(type_params, bindings);
-    if (trace_stream_) {
-      **trace_stream_ << class_scope;
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << class_scope;
     }
   }
 
@@ -4821,9 +4823,9 @@ auto TypeChecker::DeclareClassDeclaration(Nonnull<ClassDeclaration*> class_decl,
     CARBON_RETURN_IF_ERROR(DeclareDeclaration(m, class_scope_info));
   }
 
-  if (trace_stream_) {
-    **trace_stream_ << "** finished declaring class " << class_decl->name()
-                    << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished declaring class " << class_decl->name()
+                   << "\n";
   }
   return Success();
 }
@@ -4831,16 +4833,16 @@ auto TypeChecker::DeclareClassDeclaration(Nonnull<ClassDeclaration*> class_decl,
 auto TypeChecker::TypeCheckClassDeclaration(
     Nonnull<ClassDeclaration*> class_decl, const ImplScope& impl_scope)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "** checking class " << class_decl->name() << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** checking class " << class_decl->name() << "\n";
   }
   ImplScope class_scope;
   class_scope.AddParent(&impl_scope);
   if (class_decl->type_params().has_value()) {
     BringPatternImplsIntoScope(*class_decl->type_params(), class_scope);
   }
-  if (trace_stream_) {
-    **trace_stream_ << class_scope;
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << class_scope;
   }
   auto [it, inserted] =
       collected_members_.insert({class_decl, CollectedMembersMap()});
@@ -4850,9 +4852,9 @@ auto TypeChecker::TypeCheckClassDeclaration(
     CARBON_RETURN_IF_ERROR(TypeCheckDeclaration(m, class_scope, class_decl));
     CARBON_RETURN_IF_ERROR(CollectMember(class_decl, m));
   }
-  if (trace_stream_) {
-    **trace_stream_ << "** finished checking class " << class_decl->name()
-                    << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished checking class " << class_decl->name()
+                   << "\n";
   }
   return Success();
 }
@@ -4861,8 +4863,8 @@ auto TypeChecker::TypeCheckClassDeclaration(
 auto TypeChecker::DeclareMixinDeclaration(Nonnull<MixinDeclaration*> mixin_decl,
                                           const ScopeInfo& scope_info)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "** declaring mixin " << mixin_decl->name() << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** declaring mixin " << mixin_decl->name() << "\n";
   }
   ImplScope mixin_scope;
   mixin_scope.AddParent(scope_info.innermost_scope);
@@ -4870,8 +4872,8 @@ auto TypeChecker::DeclareMixinDeclaration(Nonnull<MixinDeclaration*> mixin_decl,
   if (mixin_decl->params().has_value()) {
     CARBON_RETURN_IF_ERROR(TypeCheckPattern(*mixin_decl->params(), std::nullopt,
                                             mixin_scope, ValueCategory::Let));
-    if (trace_stream_) {
-      **trace_stream_ << mixin_scope;
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << mixin_scope;
     }
 
     Nonnull<ParameterizedEntityName*> param_name =
@@ -4895,9 +4897,9 @@ auto TypeChecker::DeclareMixinDeclaration(Nonnull<MixinDeclaration*> mixin_decl,
     CARBON_RETURN_IF_ERROR(DeclareDeclaration(m, mixin_scope_info));
   }
 
-  if (trace_stream_) {
-    **trace_stream_ << "** finished declaring mixin " << mixin_decl->name()
-                    << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished declaring mixin " << mixin_decl->name()
+                   << "\n";
   }
   return Success();
 }
@@ -4915,30 +4917,30 @@ auto TypeChecker::TypeCheckMixinDeclaration(
       collected_members_.insert({mixin_decl, CollectedMembersMap()});
   if (!inserted) {
     // This declaration has already been type checked before
-    if (trace_stream_) {
-      **trace_stream_ << "** skipped checking mixin " << mixin_decl->name()
-                      << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "** skipped checking mixin " << mixin_decl->name()
+                     << "\n";
     }
     return Success();
   }
-  if (trace_stream_) {
-    **trace_stream_ << "** checking mixin " << mixin_decl->name() << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** checking mixin " << mixin_decl->name() << "\n";
   }
   ImplScope mixin_scope;
   mixin_scope.AddParent(&impl_scope);
   if (mixin_decl->params().has_value()) {
     BringPatternImplsIntoScope(*mixin_decl->params(), mixin_scope);
   }
-  if (trace_stream_) {
-    **trace_stream_ << mixin_scope;
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << mixin_scope;
   }
   for (Nonnull<Declaration*> m : mixin_decl->members()) {
     CARBON_RETURN_IF_ERROR(TypeCheckDeclaration(m, mixin_scope, mixin_decl));
     CARBON_RETURN_IF_ERROR(CollectMember(mixin_decl, m));
   }
-  if (trace_stream_) {
-    **trace_stream_ << "** finished checking mixin " << mixin_decl->name()
-                    << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished checking mixin " << mixin_decl->name()
+                   << "\n";
   }
   return Success();
 }
@@ -4952,8 +4954,8 @@ auto TypeChecker::TypeCheckMixDeclaration(
     Nonnull<MixDeclaration*> mix_decl, const ImplScope& impl_scope,
     std::optional<Nonnull<const Declaration*>> enclosing_decl)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "** checking " << *mix_decl << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** checking " << *mix_decl << "\n";
   }
   // TODO(darshal): Check if the imports (interface mentioned in the 'for'
   // clause) of the mixin being mixed are being impl'd in the enclosed
@@ -4972,8 +4974,8 @@ auto TypeChecker::TypeCheckMixDeclaration(
     CARBON_RETURN_IF_ERROR(CollectMember(encl_decl, mix_member));
   }
 
-  if (trace_stream_) {
-    **trace_stream_ << "** finished checking " << *mix_decl << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished checking " << *mix_decl << "\n";
   }
 
   return Success();
@@ -4987,10 +4989,10 @@ auto TypeChecker::DeclareConstraintTypeDeclaration(
       << "unexpected kind of constraint type declaration";
   bool is_interface = isa<InterfaceDeclaration>(constraint_decl);
 
-  if (trace_stream_) {
-    **trace_stream_ << "** declaring ";
-    constraint_decl->PrintID(**trace_stream_);
-    **trace_stream_ << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** declaring ";
+    constraint_decl->PrintID(trace_stream_->stream());
+    *trace_stream_ << "\n";
   }
   ImplScope constraint_scope;
   constraint_scope.AddParent(scope_info.innermost_scope);
@@ -5001,8 +5003,8 @@ auto TypeChecker::DeclareConstraintTypeDeclaration(
     CARBON_RETURN_IF_ERROR(TypeCheckPattern(*constraint_decl->params(),
                                             std::nullopt, constraint_scope,
                                             ValueCategory::Let));
-    if (trace_stream_) {
-      **trace_stream_ << constraint_scope;
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << constraint_scope;
     }
     CollectGenericBindingsInPattern(*constraint_decl->params(), bindings);
   }
@@ -5167,10 +5169,10 @@ auto TypeChecker::DeclareConstraintTypeDeclaration(
 
   constraint_decl->set_constraint_type(std::move(builder).Build());
 
-  if (trace_stream_) {
-    **trace_stream_ << "** finished declaring ";
-    constraint_decl->PrintID(**trace_stream_);
-    **trace_stream_ << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished declaring ";
+    constraint_decl->PrintID(trace_stream_->stream());
+    *trace_stream_ << "\n";
   }
   return Success();
 }
@@ -5178,27 +5180,27 @@ auto TypeChecker::DeclareConstraintTypeDeclaration(
 auto TypeChecker::TypeCheckConstraintTypeDeclaration(
     Nonnull<ConstraintTypeDeclaration*> constraint_decl,
     const ImplScope& impl_scope) -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "** checking ";
-    constraint_decl->PrintID(**trace_stream_);
-    **trace_stream_ << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** checking ";
+    constraint_decl->PrintID(trace_stream_->stream());
+    *trace_stream_ << "\n";
   }
   ImplScope constraint_scope;
   constraint_scope.AddParent(&impl_scope);
   if (constraint_decl->params().has_value()) {
     BringPatternImplsIntoScope(*constraint_decl->params(), constraint_scope);
   }
-  if (trace_stream_) {
-    **trace_stream_ << constraint_scope;
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << constraint_scope;
   }
   for (Nonnull<Declaration*> m : constraint_decl->members()) {
     CARBON_RETURN_IF_ERROR(
         TypeCheckDeclaration(m, constraint_scope, constraint_decl));
   }
-  if (trace_stream_) {
-    **trace_stream_ << "** finished checking ";
-    constraint_decl->PrintID(**trace_stream_);
-    **trace_stream_ << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished checking ";
+    constraint_decl->PrintID(trace_stream_->stream());
+    *trace_stream_ << "\n";
   }
   return Success();
 }
@@ -5337,8 +5339,8 @@ auto TypeChecker::CheckAndAddImplBindings(
 auto TypeChecker::DeclareImplDeclaration(Nonnull<ImplDeclaration*> impl_decl,
                                          const ScopeInfo& scope_info)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "declaring " << *impl_decl << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "declaring " << *impl_decl << "\n";
   }
   ImplScope impl_scope;
   impl_scope.AddParent(scope_info.innermost_scope);
@@ -5394,16 +5396,16 @@ auto TypeChecker::DeclareImplDeclaration(Nonnull<ImplDeclaration*> impl_decl,
     builder.AddAndSubstitute(*this, implemented_constraint, impl_type_value,
                              builder.GetSelfWitness(), Bindings(),
                              /*add_lookup_contexts=*/true);
-    if (trace_stream_) {
-      **trace_stream_ << "resolving impl constraint type for " << *impl_decl
-                      << " from " << *implemented_constraint << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "resolving impl constraint type for " << *impl_decl
+                     << " from " << *implemented_constraint << "\n";
     }
     CARBON_RETURN_IF_ERROR(builder.Resolve(
         *this, impl_decl->interface().source_loc(), impl_scope));
     constraint_type = std::move(builder).Build();
-    if (trace_stream_) {
-      **trace_stream_ << "resolving impl constraint type as "
-                      << *constraint_type << "\n";
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "resolving impl constraint type as " << *constraint_type
+                     << "\n";
     }
     impl_decl->set_constraint_type(constraint_type);
   }
@@ -5456,9 +5458,9 @@ auto TypeChecker::DeclareImplDeclaration(Nonnull<ImplDeclaration*> impl_decl,
       CheckAndAddImplBindings(impl_decl, impl_type_value, self_witness,
                               impl_witness, generic_bindings, impl_scope_info));
 
-  if (trace_stream_) {
-    **trace_stream_ << "** finished declaring impl " << *impl_decl->impl_type()
-                    << " as " << impl_decl->interface() << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "** finished declaring impl " << *impl_decl->impl_type()
+                   << " as " << impl_decl->interface() << "\n";
   }
   return Success();
 }
@@ -5494,8 +5496,8 @@ void TypeChecker::BringAssociatedConstantsIntoScope(
 auto TypeChecker::TypeCheckImplDeclaration(Nonnull<ImplDeclaration*> impl_decl,
                                            const ImplScope& enclosing_scope)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "checking " << *impl_decl << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "checking " << *impl_decl << "\n";
   }
 
   Nonnull<const Value*> self = *impl_decl->self()->constant_value();
@@ -5520,8 +5522,8 @@ auto TypeChecker::TypeCheckImplDeclaration(Nonnull<ImplDeclaration*> impl_decl,
 
     CARBON_RETURN_IF_ERROR(TypeCheckDeclaration(m, member_scope, impl_decl));
   }
-  if (trace_stream_) {
-    **trace_stream_ << "finished checking impl\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "finished checking impl\n";
   }
   return Success();
 }
@@ -5537,8 +5539,8 @@ auto TypeChecker::DeclareChoiceDeclaration(Nonnull<ChoiceDeclaration*> choice,
     CARBON_RETURN_IF_ERROR(TypeCheckPattern(type_params, std::nullopt,
                                             choice_scope, ValueCategory::Let));
     CollectGenericBindingsInPattern(type_params, bindings);
-    if (trace_stream_) {
-      **trace_stream_ << choice_scope;
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << choice_scope;
     }
   }
 
@@ -5659,7 +5661,18 @@ auto TypeChecker::TypeCheck(AST& ast) -> ErrorOr<Success> {
   llvm::SaveAndRestore<decltype(top_level_impl_scope_)>
       set_top_level_impl_scope(top_level_impl_scope_, &impl_scope);
 
-  for (Nonnull<Declaration*> declaration : ast.declarations) {
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "Omitting prelude type checking traces...\n";
+    trace_stream_->set_in_prelude(true);
+  }
+  for (int i = 0; i < static_cast<int>(ast.declarations.size()); ++i) {
+    if (i == ast.num_prelude_declarations) {
+      trace_stream_->set_in_prelude(false);
+      if (trace_stream_->is_enabled()) {
+        *trace_stream_ << "Finished prelude, resuming traces...\n";
+      }
+    }
+    auto* declaration = ast.declarations[i];
     CARBON_RETURN_IF_ERROR(
         DeclareDeclaration(declaration, top_level_scope_info));
     CARBON_RETURN_IF_ERROR(
@@ -5676,8 +5689,8 @@ auto TypeChecker::TypeCheckDeclaration(
     Nonnull<Declaration*> d, const ImplScope& impl_scope,
     std::optional<Nonnull<const Declaration*>> enclosing_decl)
     -> ErrorOr<Success> {
-  if (trace_stream_) {
-    **trace_stream_ << "checking " << DeclarationKindName(d->kind()) << "\n";
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "checking " << DeclarationKindName(d->kind()) << "\n";
   }
   switch (d->kind()) {
     case DeclarationKind::NamespaceDeclaration:
diff --git a/explorer/interpreter/type_checker.h b/explorer/interpreter/type_checker.h
index 99a9a6487c6a..06556ecf164e 100644
--- a/explorer/interpreter/type_checker.h
+++ b/explorer/interpreter/type_checker.h
@@ -22,6 +22,7 @@
 #include "explorer/interpreter/impl_scope.h"
 #include "explorer/interpreter/interpreter.h"
 #include "explorer/interpreter/matching_impl_set.h"
+#include "explorer/interpreter/trace_stream.h"
 #include "explorer/interpreter/value.h"
 
 namespace Carbon {
@@ -35,7 +36,7 @@ using GlobalMembersMap =
 class TypeChecker {
  public:
   explicit TypeChecker(Nonnull<Arena*> arena,
-                       std::optional<Nonnull<llvm::raw_ostream*>> trace_stream)
+                       Nonnull<TraceStream*> trace_stream)
       : arena_(arena), trace_stream_(trace_stream) {}
 
   // Type-checks `ast` and sets properties such as `static_type`, as documented
@@ -516,7 +517,7 @@ class TypeChecker {
   // Maps a mixin/class declaration to all of its direct and indirect members.
   GlobalMembersMap collected_members_;
 
-  std::optional<Nonnull<llvm::raw_ostream*>> trace_stream_;
+  Nonnull<TraceStream*> trace_stream_;
 
   // The top-level ImplScope, containing `impl` declarations that should be
   // usable from any context. This is used when we want to try to refine a
diff --git a/explorer/main.cpp b/explorer/main.cpp
index b1dddd3fb97c..adca55e37540 100644
--- a/explorer/main.cpp
+++ b/explorer/main.cpp
@@ -6,6 +6,7 @@
 
 #include <unistd.h>
 
+#include <chrono>
 #include <cstdio>
 #include <cstring>
 #include <iostream>
@@ -17,6 +18,7 @@
 #include "explorer/common/arena.h"
 #include "explorer/common/nonnull.h"
 #include "explorer/interpreter/exec_program.h"
+#include "explorer/interpreter/trace_stream.h"
 #include "explorer/syntax/parse.h"
 #include "explorer/syntax/prelude.h"
 #include "llvm/ADT/SmallString.h"
@@ -67,10 +69,10 @@ auto ExplorerMain(int argc, char** argv, void* static_for_main_addr,
 
   // Set up a stream for trace output.
   std::unique_ptr<llvm::raw_ostream> scoped_trace_stream;
-  std::optional<Nonnull<llvm::raw_ostream*>> trace_stream;
+  TraceStream trace_stream;
   if (!trace_file_name.empty()) {
     if (trace_file_name == "-") {
-      trace_stream = &llvm::outs();
+      trace_stream.set_stream(&llvm::outs());
     } else {
       std::error_code err;
       scoped_trace_stream =
@@ -79,10 +81,12 @@ auto ExplorerMain(int argc, char** argv, void* static_for_main_addr,
         llvm::errs() << err.message() << "\n";
         return EXIT_FAILURE;
       }
-      trace_stream = scoped_trace_stream.get();
+      trace_stream.set_stream(scoped_trace_stream.get());
     }
   }
 
+  auto time_start = std::chrono::system_clock::now();
+
   Arena arena;
   AST ast;
   if (ErrorOr<AST> parse_result = Parse(&arena, input_file_name, parser_debug);
@@ -93,10 +97,15 @@ auto ExplorerMain(int argc, char** argv, void* static_for_main_addr,
     return EXIT_FAILURE;
   }
 
-  AddPrelude(prelude_file_name, &arena, &ast.declarations);
+  auto time_after_parse = std::chrono::system_clock::now();
+
+  AddPrelude(prelude_file_name, &arena, &ast.declarations,
+             &ast.num_prelude_declarations);
+
+  auto time_after_prelude = std::chrono::system_clock::now();
 
   // Semantically analyze the parsed program.
-  if (ErrorOr<AST> analyze_result = AnalyzeProgram(&arena, ast, trace_stream);
+  if (ErrorOr<AST> analyze_result = AnalyzeProgram(&arena, ast, &trace_stream);
       analyze_result.ok()) {
     ast = *std::move(analyze_result);
   } else {
@@ -104,22 +113,51 @@ auto ExplorerMain(int argc, char** argv, void* static_for_main_addr,
     return EXIT_FAILURE;
   }
 
+  auto time_after_analyze = std::chrono::system_clock::now();
+
   // Run the program.
-  if (ErrorOr<int> exec_result = ExecProgram(&arena, ast, trace_stream);
+  auto ret = EXIT_SUCCESS;
+  if (ErrorOr<int> exec_result = ExecProgram(&arena, ast, &trace_stream);
       exec_result.ok()) {
     // Print the return code to stdout.
     llvm::outs() << "result: " << *exec_result << "\n";
 
     // When there's a dedicated trace file, print the return code to it too.
     if (scoped_trace_stream) {
-      **trace_stream << "result: " << *exec_result << "\n";
+      trace_stream << "result: " << *exec_result << "\n";
     }
   } else {
     llvm::errs() << "RUNTIME ERROR: " << exec_result.error() << "\n";
-    return EXIT_FAILURE;
+    ret = EXIT_FAILURE;
   }
 
-  return EXIT_SUCCESS;
+  auto time_after_exec = std::chrono::system_clock::now();
+
+  if (trace_stream.is_enabled()) {
+    trace_stream << "Timings:\n"
+                 << "- Parse: "
+                 << std::chrono::duration_cast<std::chrono::milliseconds>(
+                        time_after_parse - time_start)
+                        .count()
+                 << "ms\n"
+                 << "- AddPrelude: "
+                 << std::chrono::duration_cast<std::chrono::milliseconds>(
+                        time_after_prelude - time_after_parse)
+                        .count()
+                 << "ms\n"
+                 << "- AnalyzeProgram: "
+                 << std::chrono::duration_cast<std::chrono::milliseconds>(
+                        time_after_analyze - time_after_prelude)
+                        .count()
+                 << "ms\n"
+                 << "- ExecProgram: "
+                 << std::chrono::duration_cast<std::chrono::milliseconds>(
+                        time_after_exec - time_after_analyze)
+                        .count()
+                 << "ms\n";
+  }
+
+  return ret;
 }
 
 }  // namespace Carbon
diff --git a/explorer/syntax/prelude.cpp b/explorer/syntax/prelude.cpp
index 8e62c215d289..3a17792263ef 100644
--- a/explorer/syntax/prelude.cpp
+++ b/explorer/syntax/prelude.cpp
@@ -10,7 +10,8 @@ namespace Carbon {
 
 // Adds the Carbon prelude to `declarations`.
 void AddPrelude(std::string_view prelude_file_name, Nonnull<Arena*> arena,
-                std::vector<Nonnull<Declaration*>>* declarations) {
+                std::vector<Nonnull<Declaration*>>* declarations,
+                int* num_prelude_declarations) {
   ErrorOr<AST> parse_result = Parse(arena, prelude_file_name, false);
   if (!parse_result.ok()) {
     // Try again with tracing, to help diagnose the problem.
@@ -21,6 +22,7 @@ void AddPrelude(std::string_view prelude_file_name, Nonnull<Arena*> arena,
   const auto& prelude = *parse_result;
   declarations->insert(declarations->begin(), prelude.declarations.begin(),
                        prelude.declarations.end());
+  *num_prelude_declarations = prelude.declarations.size();
 }
 
 }  // namespace Carbon
diff --git a/explorer/syntax/prelude.h b/explorer/syntax/prelude.h
index 7656466b4ea1..c0c2bfb531d4 100644
--- a/explorer/syntax/prelude.h
+++ b/explorer/syntax/prelude.h
@@ -15,7 +15,8 @@ namespace Carbon {
 
 // Adds the Carbon prelude to `declarations`.
 void AddPrelude(std::string_view prelude_file_name, Nonnull<Arena*> arena,
-                std::vector<Nonnull<Declaration*>>* declarations);
+                std::vector<Nonnull<Declaration*>>* declarations,
+                int* num_prelude_declarations);
 
 }  // namespace Carbon
 
diff --git a/explorer/testdata/BUILD b/explorer/testdata/BUILD
index 2b36b620617a..df7450ee5c84 100644
--- a/explorer/testdata/BUILD
+++ b/explorer/testdata/BUILD
@@ -22,6 +22,17 @@ glob_sh_run(
     file_exts = ["carbon"],
 )
 
+glob_sh_run(
+    args = [
+        "$(location //explorer)",
+        "--parser_debug",
+        "--trace_file=-",
+    ],
+    data = ["//explorer"],
+    file_exts = ["carbon"],
+    run_ext = "verbose",
+)
+
 filegroup(
     name = "carbon_files",
     srcs = glob(["**/*.carbon"]),
diff --git a/explorer/testdata/basic_syntax/trace.carbon b/explorer/testdata/basic_syntax/trace.carbon
index 6cac3175059b..c95abf1946ee 100644
--- a/explorer/testdata/basic_syntax/trace.carbon
+++ b/explorer/testdata/basic_syntax/trace.carbon
@@ -8,12 +8,13 @@
 // NOAUTOUPDATE
 // RUN: %{explorer-run-trace}
 // CHECK:STDOUT: ********** source program **********
-// CHECK:STDOUT: interface ImplicitAs {
+// CHECK-NOT:STDOUT: interface ImplicitAs {
+// CHECK:STDOUT: interface TestInterface {
 // CHECK:STDOUT: ********** type checking **********
-// CHECK:STDOUT: ** declaring interface ImplicitAs
+// CHECK:STDOUT: ** declaring interface TestInterface
 // CHECK:STDOUT: ********** resolving unformed variables **********
 // CHECK:STDOUT: ********** printing declarations **********
-// CHECK:STDOUT: interface ImplicitAs {
+// CHECK:STDOUT: interface TestInterface {
 // CHECK:STDOUT: ********** starting execution **********
 // CHECK:STDOUT: ********** initializing globals **********
 // CHECK:STDOUT: ********** calling main function **********
@@ -22,6 +23,8 @@
 
 package ExplorerTest api;
 
+interface TestInterface {}
+
 fn Main() -> i32 {
   return 0;
 }