[Tracing] Implement IC statistics in tracing.

src/ic/ic.cc

 // Copyright 2012 the V8 project authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "src/ic/ic.h"
 
 #include <iostream>
 
 #include "src/accessors.h"
 #include "src/api-arguments-inl.h"
 #include "src/api.h"
 #include "src/arguments.h"
 #include "src/base/bits.h"
 #include "src/codegen.h"
 #include "src/conversions.h"
 #include "src/execution.h"
 #include "src/field-type.h"
 #include "src/frames-inl.h"
 #include "src/ic/call-optimization.h"
 #include "src/ic/handler-compiler.h"
 #include "src/ic/handler-configuration-inl.h"
 #include "src/ic/ic-compiler.h"
 #include "src/ic/ic-inl.h"
+#include "src/ic/ic-stats.h"
 #include "src/ic/stub-cache.h"
 #include "src/isolate-inl.h"
 #include "src/macro-assembler.h"
 #include "src/prototype.h"
 #include "src/runtime-profiler.h"
 #include "src/runtime/runtime-utils.h"
 #include "src/runtime/runtime.h"
 #include "src/tracing/trace-event.h"
+#include "src/tracing/tracing-category-observer.h"
 
 namespace v8 {
 namespace internal {
 
 char IC::TransitionMarkFromState(IC::State state) {
   switch (state) {
     case UNINITIALIZED:
       return '0';
     case PREMONOMORPHIC:
       return '.';
@@ skipping 41 matching lines @@
     if (FLAG_trace_ic) {                             \
       PrintF("[%s patching generic stub in ", type); \
       PrintF("(see below) (%s)]\n", reason);         \
     }                                                \
   } while (false)
 
 #endif  // DEBUG
 
 
 void IC::TraceIC(const char* type, Handle<Object> name) {
-  if (FLAG_trace_ic) {
+  if (FLAG_ic_stats) {
     if (AddressIsDeoptimizedCode()) return;
     DCHECK(UseVector());
     State new_state = nexus()->StateFromFeedback();
     TraceIC(type, name, state(), new_state);
   }
 }
 
 
 void IC::TraceIC(const char* type, Handle<Object> name, State old_state,
                  State new_state) {
-  if (!FLAG_trace_ic) return;
-  PrintF("[%s%s in ", is_keyed() ? "Keyed" : "", type);
+  if (V8_LIKELY(!FLAG_ic_stats)) return;
+
+  if (FLAG_ic_stats &

[Camillo Bruni, 2016/12/02 12:12:55]

no need to recheck the flag

[lpy, 2016/12/05 17:49:11]

same here, we want to check whether the flag is enabled by tracing, and if the
flag is set but not enabled by tracing, then it's enabled by command line.

+      v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+    ICStats::instance()->Begin();
+    ICInfo& ic_info = ICStats::instance()->Current();
+    ic_info.type = is_keyed() ? "Keyed" : "";
+    ic_info.type += type;
+  } else if (FLAG_ic_stats) {

[Camillo Bruni, 2016/12/02 12:12:55]

same here.

[lpy, 2016/12/05 17:49:11]

see explanation above

+    PrintF("[%s%s in ", is_keyed() ? "Keyed" : "", type);
+  }
 
   // TODO(jkummerow): Add support for "apply". The logic is roughly:
   // marker = [fp_ + kMarkerOffset];
   // if marker is smi and marker.value == INTERNAL and
   //     the frame's code == builtin(Builtins::kFunctionApply):
   // then print "apply from" and advance one frame
 
   Object* maybe_function =
       Memory::Object_at(fp_ + JavaScriptFrameConstants::kFunctionOffset);
   if (maybe_function->IsJSFunction()) {
     JSFunction* function = JSFunction::cast(maybe_function);
     int code_offset = 0;
     if (function->IsInterpreted()) {
       code_offset = InterpretedFrame::GetBytecodeOffset(fp());
     } else {
       code_offset =
           static_cast<int>(pc() - function->code()->instruction_start());
     }
-    JavaScriptFrame::PrintFunctionAndOffset(function, function->abstract_code(),
-                                            code_offset, stdout, true);
+    if (FLAG_ic_stats &
+        v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+      JavaScriptFrame::CollectFunctionAndOffsetForICStats(
+          function, function->abstract_code(), code_offset);
+    } else if (FLAG_ic_stats) {
+      JavaScriptFrame::PrintFunctionAndOffset(
+          function, function->abstract_code(), code_offset, stdout, true);
+    }
   }
 
   const char* modifier = "";
   if (kind() == Code::KEYED_STORE_IC) {
     KeyedAccessStoreMode mode =
         casted_nexus<KeyedStoreICNexus>()->GetKeyedAccessStoreMode();
     modifier = GetTransitionMarkModifier(mode);
   }
   Map* map = nullptr;
   if (!receiver_map().is_null()) {
     map = *receiver_map();
   }
-  PrintF(" (%c->%c%s) map=(%p", TransitionMarkFromState(old_state),
-         TransitionMarkFromState(new_state), modifier,
-         reinterpret_cast<void*>(map));
+  if (FLAG_ic_stats &
+      v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+    ICInfo& ic_info = ICStats::instance()->Current();
+    ic_info.state = "(";

[Camillo Bruni, 2016/12/02 12:12:55]

I'm not too familiar with the C++ standard library, but maybe it would help to
do std::string::reserve upfront.

[lpy, 2016/12/05 17:49:11]

Done.

+    ic_info.state += TransitionMarkFromState(old_state);
+    ic_info.state += "->";
+    ic_info.state += TransitionMarkFromState(new_state);
+    ic_info.state += modifier;
+    ic_info.state += ")";
+    ic_info.map = reinterpret_cast<void*>(map);
+  } else if (FLAG_ic_stats) {
+    PrintF(" (%c->%c%s) map=(%p", TransitionMarkFromState(old_state),
+           TransitionMarkFromState(new_state), modifier,
+           reinterpret_cast<void*>(map));
+  }
   if (map != nullptr) {
-    PrintF(" dict=%u own=%u type=", map->is_dictionary_map(),
-           map->NumberOfOwnDescriptors());
-    std::cout << map->instance_type();
+    if (FLAG_ic_stats &
+        v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+      ICInfo& ic_info = ICStats::instance()->Current();
+      ic_info.dict = map->is_dictionary_map();
+      ic_info.own = map->NumberOfOwnDescriptors();
+      ic_info.instance_type = std::to_string(map->instance_type());
+    } else if (FLAG_ic_stats) {
+      PrintF(" dict=%u own=%u type=", map->is_dictionary_map(),
+             map->NumberOfOwnDescriptors());
+      std::cout << map->instance_type();
+    }
   }
-  PrintF(") ");
-  name->ShortPrint(stdout);
-  PrintF("]\n");
+  if (FLAG_ic_stats &
+      v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+    // TODO(lpy) Add name as key field in ICStats.
+    ICStats::instance()->End();
+  } else if (FLAG_ic_stats) {
+    PrintF(") ");
+    name->ShortPrint(stdout);
+    PrintF("]\n");
+  }
 }
 
 
 #define TRACE_IC(type, name) TraceIC(type, name)
 
 
 IC::IC(FrameDepth depth, Isolate* isolate, FeedbackNexus* nexus)
     : isolate_(isolate),
       vector_set_(false),
       target_maps_set_(false),
@@ skipping 2746 matching lines @@
   } else {
     // Install the generic stub.
     BinaryOpICStub stub(isolate(), state);
     new_target = stub.GetCode();
 
     // Sanity check the generic stub.
     DCHECK_NULL(new_target->FindFirstAllocationSite());
   }
   set_target(*new_target);
 
-  if (FLAG_trace_ic) {
+  if (FLAG_ic_stats &
+      v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+    auto ic_stats = ICStats::instance();
+    ic_stats->Begin();
+    ICInfo& ic_info = ic_stats->Current();
+    ic_info.type = "BinaryOpIC";
+    ic_info.state = old_state.ToString();
+    ic_info.state += " => ";
+    ic_info.state += state.ToString();
+    JavaScriptFrame::CollectTopFrameForICStats(isolate());
+    ic_stats->End();
+  } else if (FLAG_ic_stats) {
+    // if (FLAG_trace_ic) {
     OFStream os(stdout);
     os << "[BinaryOpIC" << old_state << " => " << state << " @ "
        << static_cast<void*>(*new_target) << " <- ";
     JavaScriptFrame::PrintTop(isolate(), stdout, false, true);
     if (!allocation_site.is_null()) {
       os << " using allocation site " << static_cast<void*>(*allocation_site);
     }
     os << "]" << std::endl;
   }
 
@@ skipping 53 matching lines @@
       isolate(), old_stub.state(), old_stub.left(), old_stub.right(), op_,
       HasInlinedSmiCode(address()), x, y);
   CompareICStub stub(isolate(), op_, new_left, new_right, state);
   if (state == CompareICState::KNOWN_RECEIVER) {
     stub.set_known_map(
         Handle<Map>(Handle<JSReceiver>::cast(x)->map(), isolate()));
   }
   Handle<Code> new_target = stub.GetCode();
   set_target(*new_target);
 
-  if (FLAG_trace_ic) {
+  if (FLAG_ic_stats &
+      v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
+    auto ic_stats = ICStats::instance();
+    ic_stats->Begin();
+    ICInfo& ic_info = ic_stats->Current();
+    ic_info.type = "CompareIC";
+    JavaScriptFrame::CollectTopFrameForICStats(isolate());
+    ic_info.state = "((";
+    ic_info.state += CompareICState::GetStateName(old_stub.left());
+    ic_info.state += "+";
+    ic_info.state += CompareICState::GetStateName(old_stub.right());
+    ic_info.state += "=";
+    ic_info.state += CompareICState::GetStateName(old_stub.state());
+    ic_info.state += ")->(";
+    ic_info.state += CompareICState::GetStateName(new_left);
+    ic_info.state += "+";
+    ic_info.state += CompareICState::GetStateName(new_right);
+    ic_info.state += "=";
+    ic_info.state += CompareICState::GetStateName(state);
+    ic_info.state += "))#";
+    ic_info.state += Token::Name(op_);
+    ic_stats->End();
+  } else if (FLAG_ic_stats) {
+    // if (FLAG_trace_ic) {
     PrintF("[CompareIC in ");
     JavaScriptFrame::PrintTop(isolate(), stdout, false, true);
     PrintF(" ((%s+%s=%s)->(%s+%s=%s))#%s @ %p]\n",
            CompareICState::GetStateName(old_stub.left()),
            CompareICState::GetStateName(old_stub.right()),
            CompareICState::GetStateName(old_stub.state()),
            CompareICState::GetStateName(new_left),
            CompareICState::GetStateName(new_right),
            CompareICState::GetStateName(state), Token::Name(op_),
            static_cast<void*>(*stub.GetCode()));
@@ skipping 237 matching lines @@
     DCHECK_EQ(LookupIterator::INTERCEPTOR, it.state());
     it.Next();
     ASSIGN_RETURN_FAILURE_ON_EXCEPTION(isolate, result,
                                        Object::GetProperty(&it));
   }
 
   return *result;
 }
 }  // namespace internal
 }  // namespace v8