[maglev] Add tracing for graph building

Too often, maglev has an issue during graph building. These are hard to
debug, because failing to build a graph means that no graph can be
printed. This patch adds a tracing printer that dumps out nodes as they
are added to the graph -- it doesn't have the beautiful unicode arrows,
but at least it's something.

Bug: v8:7700
Change-Id: Id6673a9ee2436eac365d6d449dd2fa49bdc354d0
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3780527Reviewed-by: Victor Gomes <victorgomes@chromium.org>
Commit-Queue: Leszek Swirski <leszeks@chromium.org>
Cr-Commit-Position: refs/heads/main@{#81926}

src/flags/flag-definitions.h

@@ -520,6 +520,7 @@ DEFINE_STRING(maglev_filter, "*", "optimization filter for the maglev compiler")
 DEFINE_BOOL(maglev_break_on_entry, false, "insert an int3 on maglev entries")
 DEFINE_BOOL(print_maglev_graph, false, "print maglev graph")
 DEFINE_BOOL(print_maglev_code, false, "print maglev code")
+DEFINE_BOOL(trace_maglev_graph_building, false, "trace maglev graph building")
 DEFINE_BOOL(trace_maglev_regalloc, false, "trace maglev register allocation")
 
 #if ENABLE_SPARKPLUG

src/interpreter/bytecode-array-iterator.h

@@ -103,6 +103,7 @@ class V8_EXPORT_PRIVATE BytecodeArrayIterator {
   int current_offset() const {
     return static_cast<int>(cursor_ - start_ - prefix_size_);
   }
+  uint8_t* current_address() const { return cursor_ - prefix_size_; }
   int next_offset() const { return current_offset() + current_bytecode_size(); }
   Bytecode next_bytecode() const {
     uint8_t* next_cursor = cursor_ + current_bytecode_size_without_prefix();

src/maglev/maglev-compiler.cc

@@ -155,12 +155,12 @@ void MaglevCompiler::Compile(LocalIsolate* local_isolate,
 
   // Build graph.
   if (FLAG_print_maglev_code || FLAG_code_comments || FLAG_print_maglev_graph ||
-      FLAG_trace_maglev_regalloc) {
+      FLAG_trace_maglev_graph_building || FLAG_trace_maglev_regalloc) {
     compilation_info->set_graph_labeller(new MaglevGraphLabeller());
   }
 
   if (FLAG_print_maglev_code || FLAG_print_maglev_graph ||
-      FLAG_trace_maglev_regalloc) {
+      FLAG_trace_maglev_graph_building || FLAG_trace_maglev_regalloc) {
     MaglevCompilationUnit* top_level_unit =
         compilation_info->toplevel_compilation_unit();
     std::cout << "Compiling " << Brief(*top_level_unit->function().object())

src/maglev/maglev-graph-builder.h

@@ -6,6 +6,7 @@
 #define V8_MAGLEV_MAGLEV_GRAPH_BUILDER_H_
 
 #include <cmath>
+#include <iomanip>
 #include <map>
 #include <type_traits>
 
@@ -17,8 +18,10 @@
 #include "src/compiler/js-heap-broker.h"
 #include "src/deoptimizer/deoptimize-reason.h"
 #include "src/interpreter/bytecode-array-iterator.h"
+#include "src/interpreter/bytecode-decoder.h"
 #include "src/interpreter/bytecode-register.h"
 #include "src/maglev/maglev-graph-labeller.h"
+#include "src/maglev/maglev-graph-printer.h"
 #include "src/maglev/maglev-graph.h"
 #include "src/maglev/maglev-ir.h"
 #include "src/utils/memcopy.h"
@@ -117,6 +120,11 @@ class MaglevGraphBuilder {
     if (has_graph_labeller()) {
       for (Phi* phi : *merge_states_[offset]->phis()) {
         graph_labeller()->RegisterNode(phi);
+        if (FLAG_trace_maglev_graph_building) {
+          std::cout << "  " << phi << "  "
+                    << PrintNodeLabel(graph_labeller(), phi) << ": "
+                    << PrintNode(graph_labeller(), phi) << std::endl;
+        }
       }
     }
   }
@@ -183,6 +191,10 @@ class MaglevGraphBuilder {
         merge_state->Merge(*compilation_unit_, current_interpreter_frame_,
                            graph()->last_block(), offset);
       }
+      if (FLAG_trace_maglev_graph_building) {
+        std::cout << "== New block (merge) ==" << std::endl;
+      }
+
       ProcessMergePoint(offset);
       StartNewBlock(offset);
     } else if (V8_UNLIKELY(current_block_ == nullptr)) {
@@ -202,6 +214,12 @@ class MaglevGraphBuilder {
       return;
     }
     DCHECK_NOT_NULL(current_block_);
+    if (FLAG_trace_maglev_graph_building) {
+      std::cout << std::setw(4) << iterator_.current_offset() << " : ";
+      interpreter::BytecodeDecoder::Decode(std::cout,
+                                           iterator_.current_address());
+      std::cout << std::endl;
+    }
 #ifdef DEBUG
     // Clear new nodes for the next VisitFoo
     new_nodes_.clear();
@@ -227,6 +245,11 @@ class MaglevGraphBuilder {
     }
     current_block_->nodes().Add(node);
     if (has_graph_labeller()) graph_labeller()->RegisterNode(node);
+    if (FLAG_trace_maglev_graph_building) {
+      std::cout << "  " << node << "  "
+                << PrintNodeLabel(graph_labeller(), node) << ": "
+                << PrintNode(graph_labeller(), node) << std::endl;
+    }
 #ifdef DEBUG
     new_nodes_.insert(node);
 #endif
@@ -627,6 +650,9 @@ class MaglevGraphBuilder {
     DCHECK_NULL(current_block_);
     if (std::is_base_of<ConditionalControlNode, ControlNodeT>::value) {
       if (NumPredecessors(next_block_offset) == 1) {
+        if (FLAG_trace_maglev_graph_building) {
+          std::cout << "== New block (single fallthrough) ==" << std::endl;
+        }
         StartNewBlock(next_block_offset);
       } else {
         MergeIntoFrameState(block, next_block_offset);

src/maglev/maglev-interpreter-frame-state.h

@@ -11,6 +11,7 @@
 #include "src/compiler/bytecode-liveness-map.h"
 #include "src/interpreter/bytecode-register.h"
 #include "src/maglev/maglev-compilation-unit.h"
+#include "src/maglev/maglev-graph-printer.h"
 #include "src/maglev/maglev-ir.h"
 #include "src/maglev/maglev-regalloc-data.h"
 #include "src/maglev/maglev-register-frame-array.h"
@@ -295,13 +296,29 @@ class MergePointInterpreterFrameState {
     DCHECK_LT(predecessors_so_far_, predecessor_count_);
     predecessors_[predecessors_so_far_] = predecessor;
 
-    frame_state_.ForEachValue(
-        compilation_unit, [&](ValueNode*& value, interpreter::Register reg) {
-          CheckIsLoopPhiIfNeeded(compilation_unit, merge_offset, reg, value);
-
-          value = MergeValue(compilation_unit, reg, value, unmerged.get(reg),
-                             merge_offset);
-        });
+    if (FLAG_trace_maglev_graph_building) {
+      std::cout << "Merging..." << std::endl;
+    }
+    frame_state_.ForEachValue(compilation_unit, [&](ValueNode*& value,
+                                                    interpreter::Register reg) {
+      CheckIsLoopPhiIfNeeded(compilation_unit, merge_offset, reg, value);
+
+      if (FLAG_trace_maglev_graph_building) {
+        std::cout << "  " << reg.ToString() << ": "
+                  << PrintNodeLabel(compilation_unit.graph_labeller(), value)
+                  << " <- "
+                  << PrintNodeLabel(compilation_unit.graph_labeller(),
+                                    unmerged.get(reg));
+      }
+      value = MergeValue(compilation_unit, reg, value, unmerged.get(reg),
+                         merge_offset);
+      if (FLAG_trace_maglev_graph_building) {
+        std::cout << " => "
+                  << PrintNodeLabel(compilation_unit.graph_labeller(), value)
+                  << ": " << PrintNode(compilation_unit.graph_labeller(), value)
+                  << std::endl;
+      }
+    });
     predecessors_so_far_++;
     DCHECK_LE(predecessors_so_far_, predecessor_count_);
   }
@@ -316,13 +333,29 @@ class MergePointInterpreterFrameState {
     DCHECK(is_unmerged_loop());
     predecessors_[predecessor_count_ - 1] = loop_end_block;
 
-    frame_state_.ForEachValue(
-        compilation_unit, [&](ValueNode* value, interpreter::Register reg) {
-          CheckIsLoopPhiIfNeeded(compilation_unit, merge_offset, reg, value);
-
-          MergeLoopValue(compilation_unit, reg, value, loop_end_state.get(reg),
-                         merge_offset);
-        });
+    if (FLAG_trace_maglev_graph_building) {
+      std::cout << "Merging loop backedge..." << std::endl;
+    }
+    frame_state_.ForEachValue(compilation_unit, [&](ValueNode* value,
+                                                    interpreter::Register reg) {
+      CheckIsLoopPhiIfNeeded(compilation_unit, merge_offset, reg, value);
+
+      if (FLAG_trace_maglev_graph_building) {
+        std::cout << "  " << reg.ToString() << ": "
+                  << PrintNodeLabel(compilation_unit.graph_labeller(), value)
+                  << " <- "
+                  << PrintNodeLabel(compilation_unit.graph_labeller(),
+                                    loop_end_state.get(reg));
+      }
+      MergeLoopValue(compilation_unit, reg, value, loop_end_state.get(reg),
+                     merge_offset);
+      if (FLAG_trace_maglev_graph_building) {
+        std::cout << " => "
+                  << PrintNodeLabel(compilation_unit.graph_labeller(), value)
+                  << ": " << PrintNode(compilation_unit.graph_labeller(), value)
+                  << std::endl;
+      }
+    });
     predecessors_so_far_++;
     DCHECK_EQ(predecessors_so_far_, predecessor_count_);
   }
@@ -514,6 +547,11 @@ class MergePointInterpreterFrameState {
 
     for (int i = 0; i < predecessors_so_far_; i++) result->set_input(i, merged);
     result->set_input(predecessors_so_far_, unmerged);
+    if (FLAG_trace_maglev_graph_building) {
+      for (int i = predecessors_so_far_ + 1; i < predecessor_count_; i++) {
+        result->set_input(i, nullptr);
+      }
+    }
 
     phis_.Add(result);
     return result;
@@ -560,6 +598,11 @@ class MergePointInterpreterFrameState {
     DCHECK_EQ(predecessors_so_far_, 0);
     // Create a new loop phi, which for now is empty.
     Phi* result = Node::New<Phi>(zone, predecessor_count_, reg, merge_offset);
+    if (FLAG_trace_maglev_graph_building) {
+      for (int i = 0; i < predecessor_count_; i++) {
+        result->set_input(i, nullptr);
+      }
+    }
     phis_.Add(result);
     return result;
   }