Trace stack and memory only when there is change in state (#2982)

Add state (stack and heap information) to the trace stream only when
there is a change in state, this would prevent consecutive repetition of
state information in the trace output.

Checks it based on change in size of the stack and heap, added
`std::pair<int, int> stack_heap_sizes` in `Interpreter` to store size of
stack and heap for comparison.

explorer/interpreter/BUILD

@@ -43,6 +43,7 @@ cc_library(
         "//common:error",
         "//common:ostream",
         "//explorer/ast",
+        "//explorer/common:trace_stream",
         "@llvm-project//llvm:Support",
     ],
 )
@@ -87,6 +88,7 @@ cc_library(
         "//explorer/common:error_builders",
         "//explorer/common:nonnull",
         "//explorer/common:source_location",
+        "//explorer/common:trace_stream",
         "@llvm-project//llvm:Support",
     ],
 )

explorer/interpreter/action_stack.cpp

@@ -22,7 +22,7 @@ void ActionStack::Print(llvm::raw_ostream& out) const {
 void ActionStack::Start(std::unique_ptr<Action> action) {
   result_ = std::nullopt;
   CARBON_CHECK(todo_.empty());
-  todo_.Push(std::move(action));
+  Push(std::move(action));
 }
 
 void ActionStack::Initialize(ValueNodeView value_node,
@@ -129,7 +129,7 @@ static auto FinishActionKindFor(Action::Kind kind) -> FinishActionKind {
 
 auto ActionStack::FinishAction() -> ErrorOr<Success> {
   std::stack<std::unique_ptr<Action>> scopes_to_destroy;
-  std::unique_ptr<Action> act = todo_.Pop();
+  std::unique_ptr<Action> act = Pop();
   switch (FinishActionKindFor(act->kind())) {
     case FinishActionKind::Value:
       CARBON_FATAL() << "This kind of action must produce a result: " << *act;
@@ -147,7 +147,7 @@ auto ActionStack::FinishAction() -> ErrorOr<Success> {
 auto ActionStack::FinishAction(Nonnull<const Value*> result)
     -> ErrorOr<Success> {
   std::stack<std::unique_ptr<Action>> scopes_to_destroy;
-  std::unique_ptr<Action> act = todo_.Pop();
+  std::unique_ptr<Action> act = Pop();
   switch (FinishActionKindFor(act->kind())) {
     case FinishActionKind::NoValue:
       CARBON_FATAL() << "This kind of action cannot produce results: " << *act;
@@ -166,7 +166,7 @@ auto ActionStack::FinishAction(Nonnull<const Value*> result)
 auto ActionStack::Spawn(std::unique_ptr<Action> child) -> ErrorOr<Success> {
   Action& action = *todo_.Top();
   action.set_pos(action.pos() + 1);
-  todo_.Push(std::move(child));
+  Push(std::move(child));
   return Success();
 }
 
@@ -174,18 +174,18 @@ auto ActionStack::Spawn(std::unique_ptr<Action> child, RuntimeScope scope)
     -> ErrorOr<Success> {
   Action& action = *todo_.Top();
   action.set_pos(action.pos() + 1);
-  todo_.Push(std::make_unique<ScopeAction>(std::move(scope)));
-  todo_.Push(std::move(child));
+  Push(std::make_unique<ScopeAction>(std::move(scope)));
+  Push(std::move(child));
   return Success();
 }
 
 auto ActionStack::ReplaceWith(std::unique_ptr<Action> replacement)
     -> ErrorOr<Success> {
-  std::unique_ptr<Action> old = todo_.Pop();
+  std::unique_ptr<Action> old = Pop();
   CARBON_CHECK(FinishActionKindFor(old->kind()) ==
                FinishActionKindFor(replacement->kind()))
       << "Can't replace action " << *old << " with " << *replacement;
-  todo_.Push(std::move(replacement));
+  Push(std::move(replacement));
   return Success();
 }
 
@@ -205,7 +205,7 @@ auto ActionStack::UnwindToWithCaptureScopesToDestroy(
         &statement_action->statement() == ast_node) {
       break;
     }
-    auto item = todo_.Pop();
+    auto item = Pop();
     auto& scope = item->scope();
     if (scope && item->kind() != Action::Kind::CleanUpAction) {
       std::unique_ptr<Action> cleanup_action = std::make_unique<CleanUpAction>(
@@ -237,7 +237,7 @@ auto ActionStack::UnwindPastWithCaptureScopesToDestroy(
     Nonnull<const Statement*> ast_node) -> std::stack<std::unique_ptr<Action>> {
   std::stack<std::unique_ptr<Action>> scopes_to_destroy =
       UnwindToWithCaptureScopesToDestroy(ast_node);
-  auto item = todo_.Pop();
+  auto item = Pop();
   scopes_to_destroy.push(std::move(item));
   PopScopes(scopes_to_destroy);
   return scopes_to_destroy;
@@ -255,7 +255,7 @@ auto ActionStack::UnwindPast(Nonnull<const Statement*> ast_node,
 void ActionStack::PopScopes(
     std::stack<std::unique_ptr<Action>>& cleanup_stack) {
   while (!todo_.empty() && llvm::isa<ScopeAction>(*todo_.Top())) {
-    auto act = todo_.Pop();
+    auto act = Pop();
     if (act->scope()) {
       cleanup_stack.push(std::move(act));
     }
@@ -279,7 +279,7 @@ void ActionStack::PushCleanUpActions(
       std::unique_ptr<Action> cleanup_action = std::make_unique<CleanUpAction>(
           std::move(*act->scope()),
           SourceLocation("stack cleanup", 1, FileKind::Unknown));
-      todo_.Push(std::move(cleanup_action));
+      Push(std::move(cleanup_action));
     }
     actions.pop();
   }
@@ -292,7 +292,7 @@ void ActionStack::PushCleanUpAction(std::unique_ptr<Action> act) {
     std::unique_ptr<Action> cleanup_action = std::make_unique<CleanUpAction>(
         std::move(*scope),
         SourceLocation("stack cleanup", 1, FileKind::Unknown));
-    todo_.Push(std::move(cleanup_action));
+    Push(std::move(cleanup_action));
   }
 }
 

explorer/interpreter/action_stack.h

@@ -12,6 +12,7 @@
 #include "common/ostream.h"
 #include "explorer/ast/statement.h"
 #include "explorer/ast/value.h"
+#include "explorer/common/trace_stream.h"
 #include "explorer/interpreter/action.h"
 
 namespace Carbon {
@@ -23,12 +24,16 @@ enum class Phase { CompileTime, RunTime };
 class ActionStack {
  public:
   // Constructs an empty compile-time ActionStack.
-  ActionStack() : phase_(Phase::CompileTime) {}
+  explicit ActionStack(Nonnull<TraceStream*> trace_stream)
+      : phase_(Phase::CompileTime), trace_stream_(trace_stream) {}
 
   // Constructs an empty run-time ActionStack that allocates global variables
   // on `heap`.
-  explicit ActionStack(Nonnull<HeapAllocationInterface*> heap)
-      : globals_(RuntimeScope(heap)), phase_(Phase::RunTime) {}
+  explicit ActionStack(Nonnull<TraceStream*> trace_stream,
+                       Nonnull<HeapAllocationInterface*> heap)
+      : globals_(RuntimeScope(heap)),
+        phase_(Phase::RunTime),
+        trace_stream_(trace_stream) {}
 
   void Print(llvm::raw_ostream& out) const;
   LLVM_DUMP_METHOD void Dump() const { Print(llvm::errs()); }
@@ -104,7 +109,20 @@ class ActionStack {
   auto UnwindPast(Nonnull<const Statement*> ast_node,
                   Nonnull<const Value*> result) -> ErrorOr<Success>;
 
-  void Pop() { todo_.Pop(); }
+  auto Pop() -> std::unique_ptr<Action> {
+    auto popped_action = todo_.Pop();
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "(-) stack-pop: " << *popped_action << "\n";
+    }
+    return popped_action;
+  }
+
+  void Push(std::unique_ptr<Action> action) {
+    if (trace_stream_->is_enabled()) {
+      *trace_stream_ << "(+) stack-push: " << *action << "\n";
+    }
+    todo_.Push(std::move(action));
+  }
 
   auto size() const -> int { return todo_.size(); }
 
@@ -136,6 +154,7 @@ class ActionStack {
   std::optional<Nonnull<const Value*>> result_;
   std::optional<RuntimeScope> globals_;
   Phase phase_;
+  Nonnull<TraceStream*> trace_stream_;
 };
 
 }  // namespace Carbon

explorer/interpreter/heap.cpp

@@ -21,12 +21,21 @@ auto Heap::AllocateValue(Nonnull<const Value*> v) -> AllocationId {
   // to leave it up to the caller.
   AllocationId a(values_.size());
   values_.push_back(v);
+  bool is_uninitialized = false;
+
   if (v->kind() == Carbon::Value::Kind::UninitializedValue) {
     states_.push_back(ValueState::Uninitialized);
+    is_uninitialized = true;
   } else {
     states_.push_back(ValueState::Alive);
   }
   bound_values_.push_back(llvm::DenseMap<const AstNode*, Address>{});
+
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "(+) memory-alloc: #" << a.index_ << " `" << *v << "`"
+                   << (is_uninitialized ? " uninitialized" : "") << "\n";
+  }
+
   return a;
 }
 
@@ -35,7 +44,15 @@ auto Heap::Read(const Address& a, SourceLocation source_loc) const
   CARBON_RETURN_IF_ERROR(this->CheckInit(a.allocation_, source_loc));
   CARBON_RETURN_IF_ERROR(this->CheckAlive(a.allocation_, source_loc));
   Nonnull<const Value*> value = values_[a.allocation_.index_];
-  return value->GetElement(arena_, a.element_path_, source_loc, value);
+  ErrorOr<Nonnull<const Value*>> read_value =
+      value->GetElement(arena_, a.element_path_, source_loc, value);
+
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "+++ memory-read: #" << a.allocation_.index_ << " `"
+                   << **read_value << "`\n";
+  }
+
+  return read_value;
 }
 
 auto Heap::Write(const Address& a, Nonnull<const Value*> v,
@@ -64,6 +81,12 @@ auto Heap::Write(const Address& a, Nonnull<const Value*> v,
       }
     }
   }
+
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "+++ memory-write: #" << a.allocation_.index_ << " `"
+                   << *values_[a.allocation_.index_] << "`\n";
+  }
+
   return Success();
 }
 
@@ -95,6 +118,12 @@ auto Heap::Deallocate(AllocationId allocation) -> ErrorOr<Success> {
     CARBON_FATAL() << "deallocating an already dead value: "
                    << *values_[allocation.index_];
   }
+
+  if (trace_stream_->is_enabled()) {
+    *trace_stream_ << "(-) memory-dealloc: #" << allocation.index_ << " `"
+                   << *values_[allocation.index_] << "`\n";
+  }
+
   return Success();
 }
 

explorer/interpreter/heap.h

@@ -13,6 +13,7 @@
 #include "explorer/ast/value_node.h"
 #include "explorer/common/nonnull.h"
 #include "explorer/common/source_location.h"
+#include "explorer/common/trace_stream.h"
 #include "explorer/interpreter/heap_allocation_interface.h"
 
 namespace Carbon {
@@ -28,7 +29,8 @@ class Heap : public HeapAllocationInterface {
   };
 
   // Constructs an empty Heap.
-  explicit Heap(Nonnull<Arena*> arena) : arena_(arena){};
+  explicit Heap(Nonnull<TraceStream*> trace_stream, Nonnull<Arena*> arena)
+      : arena_(arena), trace_stream_(trace_stream){};
 
   Heap(const Heap&) = delete;
   auto operator=(const Heap&) -> Heap& = delete;
@@ -96,6 +98,7 @@ class Heap : public HeapAllocationInterface {
   std::vector<Nonnull<const Value*>> values_;
   std::vector<ValueState> states_;
   std::vector<llvm::DenseMap<const AstNode*, Address>> bound_values_;
+  Nonnull<TraceStream*> trace_stream_;
 };
 
 }  // namespace Carbon

explorer/interpreter/interpreter.cpp

@@ -48,12 +48,13 @@ static constexpr int64_t MaxStepsTaken = 1e6;
 static constexpr int64_t MaxArenaAllocated = 1e9;
 
 // Constructs an ActionStack suitable for the specified phase.
-static auto MakeTodo(Phase phase, Nonnull<Heap*> heap) -> ActionStack {
+static auto MakeTodo(Phase phase, Nonnull<Heap*> heap,
+                     Nonnull<TraceStream*> trace_stream) -> ActionStack {
   switch (phase) {
     case Phase::CompileTime:
-      return ActionStack();
+      return ActionStack(trace_stream);
     case Phase::RunTime:
-      return ActionStack(heap);
+      return ActionStack(trace_stream, heap);
   }
 }
 
@@ -69,8 +70,8 @@ class Interpreter {
               Nonnull<TraceStream*> trace_stream,
               Nonnull<llvm::raw_ostream*> print_stream)
       : arena_(arena),
-        heap_(arena),
-        todo_(MakeTodo(phase, &heap_)),
+        heap_(trace_stream, arena),
+        todo_(MakeTodo(phase, &heap_, trace_stream)),
         trace_stream_(trace_stream),
         print_stream_(print_stream),
         phase_(phase) {}
@@ -181,8 +182,6 @@ class Interpreter {
   auto CallDestructor(Nonnull<const DestructorDeclaration*> fun,
                       Nonnull<const Value*> receiver) -> ErrorOr<Success>;
 
-  void TraceState();
-
   auto phase() const -> Phase { return phase_; }
 
   Nonnull<Arena*> arena_;
@@ -206,10 +205,6 @@ class Interpreter {
 // State Operations
 //
 
-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)
@@ -651,10 +646,6 @@ auto Interpreter::StepLocation() -> ErrorOr<Success> {
 
 auto Interpreter::EvalRecursively(std::unique_ptr<Action> action)
     -> ErrorOr<Nonnull<const Value*>> {
-  if (trace_stream_->is_enabled()) {
-    TraceState();
-  }
-
   todo_.BeginRecursiveAction();
   CARBON_RETURN_IF_ERROR(todo_.Spawn(std::move(action)));
   // Note that the only `RecursiveAction` we can encounter here is our own --
@@ -662,9 +653,6 @@ 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_->is_enabled()) {
-      TraceState();
-    }
   }
   if (trace_stream_->is_enabled()) {
     *trace_stream_ << "--- recursive eval done\n";
@@ -2766,15 +2754,9 @@ auto Interpreter::Step() -> ErrorOr<Success> {
 
 auto Interpreter::RunAllSteps(std::unique_ptr<Action> action)
     -> ErrorOr<Success> {
-  if (trace_stream_->is_enabled()) {
-    TraceState();
-  }
   todo_.Start(std::move(action));
   while (!todo_.empty()) {
     CARBON_RETURN_IF_ERROR(Step());
-    if (trace_stream_->is_enabled()) {
-      TraceState();
-    }
   }
   return Success();
 }