[turbofan] Improve --trace-turbo-inlining and TRACE_BROKER_MISSING

- Eliminate unconditional heap reads in tracing code.
- Change operator<< on ObjectRef to additionally print
  the Brief() output when the broker is disabled.
- Print line number in TRACE_BROKER_MISSING and make
  some messages more consistent.
- Make PrintCandidates output clearer.
- Be more consistent about dereferencing optionals.

Bug: v8:7790, chromium:990478
Change-Id: I2917529d5138a0d63ad476d3f8fee6a963767b23
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1758311
Commit-Queue: Georg Neis <neis@chromium.org>
Reviewed-by: Maya Lekova <mslekova@chromium.org>
Cr-Commit-Position: refs/heads/master@{#63242}

src/compiler/js-call-reducer.cc

@@ -3247,8 +3247,7 @@ Reduction JSCallReducer::ReduceJSCall(Node* node) {
     if (target_ref.IsJSFunction()) {
       JSFunctionRef function = target_ref.AsJSFunction();
       if (FLAG_concurrent_inlining && !function.serialized()) {
-        TRACE_BROKER_MISSING(broker(),
-                             "function, not serialized: " << function);
+        TRACE_BROKER_MISSING(broker(), "data for function " << function);
         return NoChange();
       }
 
@@ -3261,8 +3260,7 @@ Reduction JSCallReducer::ReduceJSCall(Node* node) {
     } else if (target_ref.IsJSBoundFunction()) {
       JSBoundFunctionRef function = target_ref.AsJSBoundFunction();
       if (FLAG_concurrent_inlining && !function.serialized()) {
-        TRACE_BROKER_MISSING(broker(),
-                             "function, not serialized: " << function);
+        TRACE_BROKER_MISSING(broker(), "data for function " << function);
         return NoChange();
       }
 

src/compiler/js-heap-broker.cc

@@ -4460,7 +4460,13 @@ void ElementAccessFeedback::AddGroup(TransitionGroup&& group) {
 }
 
 std::ostream& operator<<(std::ostream& os, const ObjectRef& ref) {
+  if (ref.broker()->mode() == JSHeapBroker::kDisabled) {
+    // If the broker is disabled we cannot be in a background thread so it's
+    // safe to read the heap.
+    return os << ref.data() << " {" << ref.object() << "}";
+  } else {
     return os << ref.data();
+  }
 }
 
 base::Optional<NameRef> JSHeapBroker::GetNameFeedback(

src/compiler/js-heap-broker.h

@@ -59,7 +59,8 @@ struct FeedbackSource {
 #define TRACE_BROKER_MISSING(broker, x)                        \
   do {                                                         \
     if (broker->tracing_enabled())                             \
-      broker->Trace() << __FUNCTION__ << ": missing " << x << '\n'; \
+      broker->Trace() << __FUNCTION__ << " (line " << __LINE__ \
+                      << "): missing " << x << std::endl;      \
   } while (false)
 
 struct PropertyAccessTarget {

src/compiler/js-inlining-heuristic.cc

@@ -114,8 +114,8 @@ Reduction JSInliningHeuristic::Reduce(Node* node) {
   Handle<SharedFunctionInfo> frame_shared_info;
   for (int i = 0; i < candidate.num_functions; ++i) {
     if (!candidate.bytecode[i].has_value()) {
-      // We're already missing critical data which wouldn't allow us to
-      // continue the inlining checks. Log a warning and continue.
+      // Can't inline without bytecode.
+      // TODO(neis): Should this even be a broker message?
       if (candidate.functions[i].has_value()) {
         TRACE_BROKER(broker(),
                      "Missing bytecode array trying to inline JSFunction "
@@ -205,6 +205,8 @@ Reduction JSInliningHeuristic::Reduce(Node* node) {
 }
 
 void JSInliningHeuristic::Finalize() {
+  DisallowHeapAccessIf no_heap_acess(FLAG_concurrent_inlining);
+
   if (candidates_.empty()) return;  // Nothing to do without candidates.
   if (FLAG_trace_turbo_inlining) PrintCandidates();
 
@@ -730,22 +732,22 @@ bool JSInliningHeuristic::CandidateCompare::operator()(
 
 void JSInliningHeuristic::PrintCandidates() {
   StdoutStream os;
-  os << "Candidates for inlining (size=" << candidates_.size() << "):\n";
+  os << candidates_.size() << " candidate(s) for inlining:" << std::endl;
   for (const Candidate& candidate : candidates_) {
-    os << "  #" << candidate.node->id() << ":"
-       << candidate.node->op()->mnemonic()
-       << ", frequency: " << candidate.frequency << std::endl;
+    os << "- candidate: " << candidate.node->op()->mnemonic() << " node #"
+       << candidate.node->id() << " with frequency " << candidate.frequency
+       << ", " << candidate.num_functions << " target(s):" << std::endl;
     for (int i = 0; i < candidate.num_functions; ++i) {
+      SharedFunctionInfoRef shared = candidate.functions[i].has_value()
+                                         ? candidate.functions[i]->shared()
+                                         : candidate.shared_info.value();
+      os << "  - target: " << shared;
       if (candidate.bytecode[i].has_value()) {
-        PrintF("  - size:%d,", candidate.bytecode[i].value().length());
+        os << ", bytecode size: " << candidate.bytecode[i]->length();
       } else {
-        PrintF("  - no bytecode,");
+        os << ", no bytecode";
       }
-      SharedFunctionInfoRef shared =
-          candidate.functions[i].has_value()
-              ? candidate.functions[i].value().shared()
-              : candidate.shared_info.value();
-      PrintF(" name: %s\n", shared.object()->DebugName().ToCString().get());
+      os << std::endl;
     }
   }
 }

src/compiler/js-inlining.cc

@@ -373,13 +373,14 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
   // Determine the call target.
   base::Optional<SharedFunctionInfoRef> shared_info(DetermineCallTarget(node));
   if (!shared_info.has_value()) return NoChange();
-
   DCHECK(shared_info->IsInlineable());
 
+  SharedFunctionInfoRef outer_shared_info(broker(), info_->shared_info());
+
   // Constructor must be constructable.
   if (node->opcode() == IrOpcode::kJSConstruct &&
       !IsConstructable(shared_info->kind())) {
-    TRACE("Not inlining " << *shared_info << " into " << info_->shared_info()
+    TRACE("Not inlining " << *shared_info << " into " << outer_shared_info
                           << " because constructor is not constructable.");
     return NoChange();
   }
@@ -388,7 +389,7 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
   // See ES6 section 9.2.1 [[Call]] ( thisArgument, argumentsList ).
   if (node->opcode() == IrOpcode::kJSCall &&
       IsClassConstructor(shared_info->kind())) {
-    TRACE("Not inlining " << *shared_info << " into " << info_->shared_info()
+    TRACE("Not inlining " << *shared_info << " into " << outer_shared_info
                           << " because callee is a class constructor.");
     return NoChange();
   }
@@ -402,7 +403,7 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
     nesting_level++;
     if (nesting_level > kMaxDepthForInlining) {
       TRACE("Not inlining "
-            << *shared_info << " into " << info_->shared_info()
+            << *shared_info << " into " << outer_shared_info
             << " because call has exceeded the maximum depth for function "
                "inlining.");
       return NoChange();
@@ -417,14 +418,14 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
   // passing the IsInlineable check, The broker holds a reference to the
   // bytecode array, which prevents it from getting flushed.
   // Therefore, the following check should always hold true.
-  CHECK(shared_info.value().is_compiled());
+  CHECK(shared_info->is_compiled());
 
   if (!FLAG_concurrent_inlining && info_->is_source_positions_enabled()) {
     SharedFunctionInfo::EnsureSourcePositionsAvailable(isolate(),
                                                        shared_info->object());
   }
 
-  TRACE("Inlining " << *shared_info << " into " << info_->shared_info()
+  TRACE("Inlining " << *shared_info << " into " << outer_shared_info
                     << ((exception_target != nullptr) ? " (inside try-block)"
                                                       : ""));
   // Determine the targets feedback vector and its context.
@@ -432,7 +433,8 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
   FeedbackVectorRef feedback_vector = DetermineCallContext(node, &context);
 
   if (FLAG_concurrent_inlining &&
-      !shared_info.value().IsSerializedForCompilation(feedback_vector)) {
+      !shared_info->IsSerializedForCompilation(feedback_vector)) {
+    // TODO(neis): Should this be a broker message?
     TRACE("Missed opportunity to inline a function ("
           << *shared_info << " with " << feedback_vector << ")");
     return NoChange();
@@ -442,11 +444,11 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
   // After this point, we've made a decision to inline this function.
   // We shall not bailout from inlining if we got here.
 
-  BytecodeArrayRef bytecode_array = shared_info.value().GetBytecodeArray();
+  BytecodeArrayRef bytecode_array = shared_info->GetBytecodeArray();
 
   // Remember that we inlined this function.
-  int inlining_id = info_->AddInlinedFunction(
-      shared_info.value().object(), bytecode_array.object(),
+  int inlining_id =
+      info_->AddInlinedFunction(shared_info->object(), bytecode_array.object(),
                                 source_positions_->GetSourcePosition(node));
 
   // Create the subgraph for the inlinee.
@@ -473,11 +475,11 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
       AllowCodeDependencyChange allow_code_dep_change;
       CallFrequency frequency = call.frequency();
       Handle<NativeContext> native_context(info_->native_context(), isolate());
-      BuildGraphFromBytecode(
-          broker(), zone(), bytecode_array.object(),
-          shared_info.value().object(), feedback_vector.object(),
-          BailoutId::None(), jsgraph(), frequency, source_positions_,
-          native_context, inlining_id, flags, &info_->tick_counter());
+      BuildGraphFromBytecode(broker(), zone(), bytecode_array.object(),
+                             shared_info->object(), feedback_vector.object(),
+                             BailoutId::None(), jsgraph(), frequency,
+                             source_positions_, native_context, inlining_id,
+                             flags, &info_->tick_counter());
     }
 
     // Extract the inlinee start/end nodes.
@@ -525,13 +527,13 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
     // where execution continues at {construct_stub_create_deopt_pc_offset}).
     Node* receiver = jsgraph()->TheHoleConstant();  // Implicit receiver.
     Node* context = NodeProperties::GetContextInput(node);
-    if (NeedsImplicitReceiver(shared_info.value())) {
+    if (NeedsImplicitReceiver(*shared_info)) {
       Node* effect = NodeProperties::GetEffectInput(node);
       Node* control = NodeProperties::GetControlInput(node);
       Node* frame_state_inside = CreateArtificialFrameState(
           node, frame_state, call.formal_arguments(),
           BailoutId::ConstructStubCreate(), FrameStateType::kConstructStub,
-          shared_info.value(), context);
+          *shared_info, context);
       Node* create =
           graph()->NewNode(javascript()->Create(), call.target(), new_target,
                            context, frame_state_inside, effect, control);
@@ -586,7 +588,7 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
     frame_state = CreateArtificialFrameState(
         node, frame_state, call.formal_arguments(),
         BailoutId::ConstructStubInvoke(), FrameStateType::kConstructStub,
-        shared_info.value(), context);
+        *shared_info, context);
   }
 
   // Insert a JSConvertReceiver node for sloppy callees. Note that the context
@@ -615,7 +617,7 @@ Reduction JSInliner::ReduceJSCall(Node* node) {
   if (call.formal_arguments() != parameter_count) {
     frame_state = CreateArtificialFrameState(
         node, frame_state, call.formal_arguments(), BailoutId::None(),
-        FrameStateType::kArgumentsAdaptor, shared_info.value());
+        FrameStateType::kArgumentsAdaptor, *shared_info);
   }
 
   return InlineCall(node, new_target, context, frame_state, start, end,