Commit 0a3c8fc3 authored by lpy's avatar lpy Committed by Commit bot

[Tracing] Implement IC statistics in tracing.

This patch introduces:

1. ICStats class to store ic statistics items produced by V8,
2. A disabled by default tracing category v8.ic_stats,
3. An trace event V8.ICStats that contains ic statistics items in args,

We store ic statistics items in an array until the array is full to reduce
the number of trace events.

TBR=jkummerow@chromium.org,ishell@chromium.org

Review-Url: https://codereview.chromium.org/2503183002
Cr-Commit-Position: refs/heads/master@{#41559}
parent ebb1aff1
......@@ -1426,6 +1426,8 @@ v8_source_set("v8_base") {
"src/ic/ic-inl.h",
"src/ic/ic-state.cc",
"src/ic/ic-state.h",
"src/ic/ic-stats.cc",
"src/ic/ic-stats.h",
"src/ic/ic.cc",
"src/ic/ic.h",
"src/ic/keyed-store-generic.cc",
......
......@@ -14,8 +14,10 @@
#include "src/gdb-jit.h"
#include "src/ic/accessor-assembler.h"
#include "src/ic/handler-compiler.h"
#include "src/ic/ic-stats.h"
#include "src/ic/ic.h"
#include "src/macro-assembler.h"
#include "src/tracing/tracing-category-observer.h"
namespace v8 {
namespace internal {
......@@ -2284,7 +2286,19 @@ void HydrogenCodeStub::TraceTransition(StateType from, StateType to) {
// Note: Although a no-op transition is semantically OK, it is hinting at a
// bug somewhere in our state transition machinery.
DCHECK(from != to);
if (!FLAG_trace_ic) return;
if (V8_LIKELY(!FLAG_ic_stats)) return;
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 = MajorName(MajorKey());
ic_info.state = ToString(from);
ic_info.state += "=>";
ic_info.state += ToString(to);
ic_stats->End();
return;
}
OFStream os(stdout);
os << "[";
PrintBaseName(os);
......
......@@ -810,6 +810,8 @@ DEFINE_BOOL(use_idle_notification, true,
// ic.cc
DEFINE_BOOL(use_ic, true, "use inline caching")
DEFINE_BOOL(trace_ic, false, "trace inline cache state transitions")
DEFINE_INT(ic_stats, 0, "inline cache state transitions statistics")
DEFINE_VALUE_IMPLICATION(trace_ic, ic_stats, 1)
DEFINE_BOOL_READONLY(tf_load_ic_stub, true, "use TF LoadIC stub")
DEFINE_BOOL(tf_store_ic_stub, true, "use TF StoreIC stub")
......
......@@ -11,6 +11,7 @@
#include "src/deoptimizer.h"
#include "src/frames-inl.h"
#include "src/full-codegen/full-codegen.h"
#include "src/ic/ic-stats.h"
#include "src/register-configuration.h"
#include "src/safepoint-table.h"
#include "src/string-stream.h"
......@@ -1016,7 +1017,6 @@ void JavaScriptFrame::PrintFunctionAndOffset(JSFunction* function,
}
}
void JavaScriptFrame::PrintTop(Isolate* isolate, FILE* file, bool print_args,
bool print_line_number) {
// constructor calls
......@@ -1056,6 +1056,51 @@ void JavaScriptFrame::PrintTop(Isolate* isolate, FILE* file, bool print_args,
}
}
void JavaScriptFrame::CollectFunctionAndOffsetForICStats(JSFunction* function,
AbstractCode* code,
int code_offset) {
auto ic_stats = ICStats::instance();
ICInfo& ic_info = ic_stats->Current();
SharedFunctionInfo* shared = function->shared();
ic_info.function_name = ic_stats->GetOrCacheFunctionName(function);
ic_info.script_offset = code_offset;
int source_pos = code->SourcePosition(code_offset);
Object* maybe_script = shared->script();
if (maybe_script->IsScript()) {
Script* script = Script::cast(maybe_script);
ic_info.line_num = script->GetLineNumber(source_pos) + 1;
ic_info.script_name = ic_stats->GetOrCacheScriptName(script);
}
}
void JavaScriptFrame::CollectTopFrameForICStats(Isolate* isolate) {
// constructor calls
DisallowHeapAllocation no_allocation;
JavaScriptFrameIterator it(isolate);
ICInfo& ic_info = ICStats::instance()->Current();
while (!it.done()) {
if (it.frame()->is_java_script()) {
JavaScriptFrame* frame = it.frame();
if (frame->IsConstructor()) ic_info.is_constructor = true;
JSFunction* function = frame->function();
int code_offset = 0;
if (frame->is_interpreted()) {
InterpretedFrame* iframe = reinterpret_cast<InterpretedFrame*>(frame);
code_offset = iframe->GetBytecodeOffset();
} else {
Code* code = frame->unchecked_code();
code_offset = static_cast<int>(frame->pc() - code->instruction_start());
}
CollectFunctionAndOffsetForICStats(function, function->abstract_code(),
code_offset);
return;
}
it.Advance();
}
}
Object* JavaScriptFrame::GetParameter(int index) const {
return Memory::Object_at(GetParameterSlot(index));
}
......
......@@ -909,6 +909,11 @@ class JavaScriptFrame : public StandardFrame {
static void PrintTop(Isolate* isolate, FILE* file, bool print_args,
bool print_line_number);
static void CollectFunctionAndOffsetForICStats(JSFunction* function,
AbstractCode* code,
int code_offset);
static void CollectTopFrameForICStats(Isolate* isolate);
protected:
inline explicit JavaScriptFrame(StackFrameIteratorBase* iterator);
......
......@@ -61,6 +61,23 @@ ExtraICState BinaryOpICState::GetExtraICState() const {
return extra_ic_state;
}
std::string BinaryOpICState::ToString() const {
std::string ret = "(";
ret += Token::Name(op_);
if (CouldCreateAllocationMementos()) ret += "_CreateAllocationMementos";
ret += ":";
ret += BinaryOpICState::KindToString(left_kind_);
ret += "*";
if (fixed_right_arg_.IsJust()) {
ret += fixed_right_arg_.FromJust();
} else {
ret += BinaryOpICState::KindToString(right_kind_);
}
ret += "->";
ret += BinaryOpICState::KindToString(result_kind_);
ret += ")";
return ret;
}
// static
void BinaryOpICState::GenerateAheadOfTime(
......
......@@ -82,6 +82,7 @@ class BinaryOpICState final BASE_EMBEDDED {
}
ExtraICState GetExtraICState() const;
std::string ToString() const;
static void GenerateAheadOfTime(Isolate*,
void (*Generate)(Isolate*,
......
// Copyright 2016 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-stats.h"
#include "src/flags.h"
#include "src/objects-inl.h"
#include "src/tracing/trace-event.h"
#include "src/tracing/traced-value.h"
#include "src/v8.h"
namespace v8 {
namespace internal {
base::LazyInstance<ICStats>::type ICStats::instance_ =
LAZY_INSTANCE_INITIALIZER;
ICStats::ICStats() : ic_infos_(MAX_IC_INFO), pos_(0) {
base::NoBarrier_Store(&enabled_, 0);
}
void ICStats::Begin() {
if (V8_LIKELY(!FLAG_ic_stats)) return;
base::NoBarrier_Store(&enabled_, 1);
}
void ICStats::End() {
if (base::NoBarrier_Load(&enabled_) != 1) return;
++pos_;
if (pos_ == MAX_IC_INFO) {
Dump();
}
base::NoBarrier_Store(&enabled_, 0);
}
void ICStats::Reset() {
for (auto ic_info : ic_infos_) {
ic_info.Reset();
}
pos_ = 0;
}
void ICStats::Dump() {
auto value = v8::tracing::TracedValue::Create();
value->BeginArray("data");
for (int i = 0; i < pos_; ++i) {
ic_infos_[i].AppendToTracedValue(value.get());
}
value->EndArray();
TRACE_EVENT_INSTANT1(TRACE_DISABLED_BY_DEFAULT("v8.ic_stats"), "V8.ICStats",
TRACE_EVENT_SCOPE_THREAD, "ic-stats", std::move(value));
Reset();
}
const char* ICStats::GetOrCacheScriptName(Script* script) {
if (script_name_map_.find(script) != script_name_map_.end()) {
return script_name_map_[script].get();
}
Object* script_name_raw = script->name();
if (script_name_raw->IsString()) {
String* script_name = String::cast(script_name_raw);
char* c_script_name =
script_name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL)
.release();
script_name_map_.insert(
std::make_pair(script, std::unique_ptr<char[]>(c_script_name)));
return c_script_name;
} else {
script_name_map_.insert(
std::make_pair(script, std::unique_ptr<char[]>(nullptr)));
return nullptr;
}
return nullptr;
}
const char* ICStats::GetOrCacheFunctionName(JSFunction* function) {
if (function_name_map_.find(function) != function_name_map_.end()) {
return function_name_map_[function].get();
}
SharedFunctionInfo* shared = function->shared();
ic_infos_[pos_].is_optimized = function->IsOptimized();
char* function_name = shared->DebugName()->ToCString().release();
function_name_map_.insert(
std::make_pair(function, std::unique_ptr<char[]>(function_name)));
return function_name;
}
ICInfo::ICInfo()
: function_name(nullptr),
script_offset(0),
script_name(nullptr),
line_num(-1),
is_constructor(false),
is_optimized(false),
map(nullptr),
is_dictionary_map(0),
number_of_own_descriptors(0) {}
void ICInfo::Reset() {
type.clear();
function_name = nullptr;
script_offset = 0;
script_name = nullptr;
line_num = -1;
is_constructor = false;
is_optimized = false;
state.clear();
map = nullptr;
is_dictionary_map = false;
number_of_own_descriptors = 0;
instance_type.clear();
}
void ICInfo::AppendToTracedValue(v8::tracing::TracedValue* value) const {
value->BeginDictionary();
value->SetString("type", type);
if (function_name) {
value->SetString("functionName", function_name);
if (is_optimized) {
value->SetInteger("optimized", is_optimized);
}
}
if (script_offset) value->SetInteger("offset", script_offset);
if (script_name) value->SetString("scriptName", script_name);
if (line_num != -1) value->SetInteger("lineNum", line_num);
if (is_constructor) value->SetInteger("constructor", is_constructor);
if (!state.empty()) value->SetString("state", state);
if (map) {
// V8 cannot represent integer above 2^53 - 1 in JavaScript from JSON,
// thus `map` should be converted to a string rather than an integer.
std::stringstream ss;
ss << map;
value->SetString("map", ss.str());
}
if (map) value->SetInteger("dict", is_dictionary_map);
if (map) value->SetInteger("own", number_of_own_descriptors);
if (!instance_type.empty()) value->SetString("instanceType", instance_type);
value->EndDictionary();
}
} // namespace internal
} // namespace v8
// Copyright 2016 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.
#ifndef V8_IC_IC_STATS_H_
#define V8_IC_IC_STATS_H_
#include <memory>
#include <string>
#include <unordered_map>
#include <vector>
#include "src/base/atomicops.h"
#include "src/base/lazy-instance.h"
namespace v8 {
namespace tracing {
class TracedValue;
}
namespace internal {
class JSFunction;
class Script;
struct ICInfo {
ICInfo();
void Reset();
void AppendToTracedValue(v8::tracing::TracedValue* value) const;
std::string type;
const char* function_name;
int script_offset;
const char* script_name;
int line_num;
bool is_constructor;
bool is_optimized;
std::string state;
// Address of the map.
void* map;
// Whether map is a dictionary map.
bool is_dictionary_map;
// Number of own descriptors.
unsigned number_of_own_descriptors;
std::string instance_type;
};
class ICStats {
public:
const int MAX_IC_INFO = 4096;
ICStats();
void Dump();
void Begin();
void End();
void Reset();
V8_INLINE ICInfo& Current() {
DCHECK(pos_ >= 0 && pos_ < MAX_IC_INFO);
return ic_infos_[pos_];
}
const char* GetOrCacheScriptName(Script* script);
const char* GetOrCacheFunctionName(JSFunction* function);
V8_INLINE static ICStats* instance() { return instance_.Pointer(); }
private:
static base::LazyInstance<ICStats>::type instance_;
base::Atomic32 enabled_;
std::vector<ICInfo> ic_infos_;
std::unordered_map<Script*, std::unique_ptr<char[]>> script_name_map_;
std::unordered_map<JSFunction*, std::unique_ptr<char[]>> function_name_map_;
int pos_;
};
} // namespace internal
} // namespace v8
#endif // V8_IC_IC_STATS_H_
......@@ -21,6 +21,7 @@
#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"
......@@ -29,6 +30,7 @@
#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 {
......@@ -90,7 +92,7 @@ const char* GetTransitionMarkModifier(KeyedAccessStoreMode mode) {
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();
......@@ -101,8 +103,17 @@ void IC::TraceIC(const char* type, Handle<Object> name) {
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 &
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 {
PrintF("[%s%s in ", is_keyed() ? "Keyed" : "", type);
}
// TODO(jkummerow): Add support for "apply". The logic is roughly:
// marker = [fp_ + kMarkerOffset];
......@@ -121,8 +132,14 @@ void IC::TraceIC(const char* type, Handle<Object> name, State old_state,
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 {
JavaScriptFrame::PrintFunctionAndOffset(
function, function->abstract_code(), code_offset, stdout, true);
}
}
const char* modifier = "";
......@@ -135,17 +152,45 @@ void IC::TraceIC(const char* type, Handle<Object> name, State old_state,
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();
// Reverse enough space for IC transition state, the longest length is 17.
ic_info.state.reserve(17);
ic_info.state = "(";
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 {
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.is_dictionary_map = map->is_dictionary_map();
ic_info.number_of_own_descriptors = map->NumberOfOwnDescriptors();
ic_info.instance_type = std::to_string(map->instance_type());
} else {
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) {
// TODO(lpy) Add name as key field in ICStats.
ICStats::instance()->End();
} else {
PrintF(") ");
name->ShortPrint(stdout);
PrintF("]\n");
}
PrintF(") ");
name->ShortPrint(stdout);
PrintF("]\n");
}
......@@ -2912,7 +2957,19 @@ MaybeHandle<Object> BinaryOpIC::Transition(
}
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) << " <- ";
......@@ -2986,7 +3043,30 @@ Code* CompareIC::UpdateCaches(Handle<Object> x, Handle<Object> y) {
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",
......
......@@ -21,6 +21,7 @@ void TracingCategoryObserver::SetUp() {
TRACE_EVENT_WARMUP_CATEGORY(
TRACE_DISABLED_BY_DEFAULT("v8.runtime_stats_sampling"));
TRACE_EVENT_WARMUP_CATEGORY(TRACE_DISABLED_BY_DEFAULT("v8.gc_stats"));
TRACE_EVENT_WARMUP_CATEGORY(TRACE_DISABLED_BY_DEFAULT("v8.ic_stats"));
}
void TracingCategoryObserver::TearDown() {
......@@ -46,12 +47,18 @@ void TracingCategoryObserver::OnTraceEnabled() {
if (enabled) {
v8::internal::FLAG_gc_stats |= ENABLED_BY_TRACING;
}
TRACE_EVENT_CATEGORY_GROUP_ENABLED(TRACE_DISABLED_BY_DEFAULT("v8.ic_stats"),
&enabled);
if (enabled) {
v8::internal::FLAG_ic_stats |= ENABLED_BY_TRACING;
}
}
void TracingCategoryObserver::OnTraceDisabled() {
v8::internal::FLAG_runtime_stats &=
~(ENABLED_BY_TRACING | ENABLED_BY_SAMPLING);
v8::internal::FLAG_gc_stats &= ~ENABLED_BY_TRACING;
v8::internal::FLAG_ic_stats &= ~ENABLED_BY_TRACING;
}
} // namespace tracing
......
......@@ -76,6 +76,37 @@ std::ostream& operator<<(std::ostream& os, ToBooleanHint hint) {
return os;
}
std::string ToString(ToBooleanHint hint) {
switch (hint) {
case ToBooleanHint::kNone:
return "None";
case ToBooleanHint::kUndefined:
return "Undefined";
case ToBooleanHint::kBoolean:
return "Boolean";
case ToBooleanHint::kNull:
return "Null";
case ToBooleanHint::kSmallInteger:
return "SmallInteger";
case ToBooleanHint::kReceiver:
return "Receiver";
case ToBooleanHint::kString:
return "String";
case ToBooleanHint::kSymbol:
return "Symbol";
case ToBooleanHint::kHeapNumber:
return "HeapNumber";
case ToBooleanHint::kSimdValue:
return "SimdValue";
case ToBooleanHint::kAny:
return "Any";
case ToBooleanHint::kNeedsMap:
return "NeedsMap";
}
UNREACHABLE();
return "";
}
std::ostream& operator<<(std::ostream& os, ToBooleanHints hints) {
if (hints == ToBooleanHint::kAny) return os << "Any";
if (hints == ToBooleanHint::kNone) return os << "None";
......@@ -91,6 +122,22 @@ std::ostream& operator<<(std::ostream& os, ToBooleanHints hints) {
return os;
}
std::string ToString(ToBooleanHints hints) {
if (hints == ToBooleanHint::kAny) return "Any";
if (hints == ToBooleanHint::kNone) return "None";
std::string ret;
bool first = true;
for (ToBooleanHints::mask_type i = 0; i < sizeof(i) * 8; ++i) {
ToBooleanHint const hint = static_cast<ToBooleanHint>(1u << i);
if (hints & hint) {
if (!first) ret += "|";
first = false;
ret += ToString(hint);
}
}
return ret;
}
std::ostream& operator<<(std::ostream& os, const StringAddFlags& flags) {
switch (flags) {
case STRING_ADD_CHECK_NONE:
......
......@@ -62,10 +62,12 @@ enum class ToBooleanHint : uint16_t {
};
std::ostream& operator<<(std::ostream&, ToBooleanHint);
std::string ToString(ToBooleanHint);
typedef base::Flags<ToBooleanHint, uint16_t> ToBooleanHints;
std::ostream& operator<<(std::ostream&, ToBooleanHints);
std::string ToString(ToBooleanHints);
DEFINE_OPERATORS_FOR_FLAGS(ToBooleanHints)
......
......@@ -965,6 +965,8 @@
'ic/ic-inl.h',
'ic/ic-state.cc',
'ic/ic-state.h',
'ic/ic-stats.cc',
'ic/ic-stats.h',
'ic/ic.cc',
'ic/ic.h',
'ic/ic-compiler.cc',
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment