Commit 872a5fce authored by Toon Verwaest's avatar Toon Verwaest Committed by Commit Bot

Reimplement TraceIC using the logger

BUG=

Change-Id: Ib7cc2a04a7c8e314e1f4a8720eef569a6a4a3b18
Reviewed-on: https://chromium-review.googlesource.com/444406Reviewed-by: 's avatarJakob Kummerow <jkummerow@chromium.org>
Reviewed-by: 's avatarToon Verwaest <verwaest@chromium.org>
Commit-Queue: Toon Verwaest <verwaest@chromium.org>
Cr-Commit-Position: refs/heads/master@{#43307}
parent 40b74d04
......@@ -4619,9 +4619,8 @@ void InlineSmiCheckInfo::Emit(MacroAssembler* masm, const Register& reg,
}
}
InlineSmiCheckInfo::InlineSmiCheckInfo(Address info)
: reg_(NoReg), smi_check_(NULL) {
: reg_(NoReg), smi_check_delta_(0), smi_check_(NULL) {
InstructionSequence* inline_data = InstructionSequence::At(info);
DCHECK(inline_data->IsInlineData());
if (inline_data->IsInlineData()) {
......@@ -4633,9 +4632,9 @@ InlineSmiCheckInfo::InlineSmiCheckInfo(Address info)
uint32_t payload32 = static_cast<uint32_t>(payload);
int reg_code = RegisterBits::decode(payload32);
reg_ = Register::XRegFromCode(reg_code);
int smi_check_delta = DeltaBits::decode(payload32);
DCHECK(smi_check_delta != 0);
smi_check_ = inline_data->preceding(smi_check_delta);
smi_check_delta_ = DeltaBits::decode(payload32);
DCHECK_NE(0, smi_check_delta_);
smi_check_ = inline_data->preceding(smi_check_delta_);
}
}
}
......
......@@ -2149,6 +2149,8 @@ class InlineSmiCheckInfo {
return smi_check_;
}
int SmiCheckDelta() const { return smi_check_delta_; }
// Use MacroAssembler::InlineData to emit information about patchable inline
// SMI checks. The caller may specify 'reg' as NoReg and an unbound 'site' to
// indicate that there is no inline SMI check. Note that 'reg' cannot be csp.
......@@ -2166,6 +2168,7 @@ class InlineSmiCheckInfo {
private:
Register reg_;
int smi_check_delta_;
Instruction* smi_check_;
// Fields in the data encoded by InlineData.
......
......@@ -1703,30 +1703,6 @@ void LoadIndexedInterceptorStub::GenerateAssembly(
slot, vector);
}
template<class StateType>
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 (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);
os << ": " << from << "=>" << to << "]" << std::endl;
}
void CallICStub::PrintState(std::ostream& os) const { // NOLINT
os << convert_mode() << ", " << tail_call_mode();
}
......@@ -2134,7 +2110,7 @@ bool ToBooleanICStub::UpdateStatus(Handle<Object> object) {
UNREACHABLE();
to_boolean_value = true;
}
TraceTransition(old_hints, new_hints);
set_sub_minor_key(HintsBits::update(sub_minor_key(), new_hints));
return to_boolean_value;
}
......
......@@ -878,6 +878,7 @@ 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_IMPLICATION(trace_ic, log_code)
DEFINE_INT(ic_stats, 0, "inline cache state transitions statistics")
DEFINE_VALUE_IMPLICATION(trace_ic, ic_stats, 1)
DEFINE_BOOL_READONLY(track_constant_fields, false,
......
......@@ -68,9 +68,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
}
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, cmp=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(cmp_instruction_address), delta);
LOG(isolate, PatchIC(address, cmp_instruction_address, delta));
}
Address patch_address =
......
......@@ -60,9 +60,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
}
if (FLAG_trace_ic) {
PrintF("[ Patching ic at %p, marker=%p, SMI check=%p\n",
static_cast<void*>(address), static_cast<void*>(info_address),
static_cast<void*>(info.SmiCheck()));
LOG(isolate, PatchIC(address, info_address, info.SmiCheckDelta()));
}
// Patch and activate code generated by JumpPatchSite::EmitJumpIfNotSmi()
......
......@@ -62,9 +62,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
// condition code uses at the patched jump.
uint8_t delta = *reinterpret_cast<uint8_t*>(delta_address);
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, test=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(test_instruction_address), delta);
LOG(isolate, PatchIC(address, test_instruction_address, delta));
}
// Patch with a short conditional jump. Enabling means switching from a short
......
......@@ -66,30 +66,7 @@ const char* GetTransitionMarkModifier(KeyedAccessStoreMode mode) {
return "";
}
#ifdef DEBUG
#define TRACE_GENERIC_IC(isolate, type, reason) \
do { \
if (FLAG_trace_ic) { \
PrintF("[%s patching generic stub in ", type); \
JavaScriptFrame::PrintTop(isolate, stdout, false, true); \
PrintF(" (%s)]\n", reason); \
} \
} while (false)
#else
#define TRACE_GENERIC_IC(isolate, type, reason) \
do { \
if (FLAG_trace_ic) { \
PrintF("[%s patching generic stub in ", type); \
PrintF("(see below) (%s)]\n", reason); \
} \
} while (false)
#endif // DEBUG
#define TRACE_GENERIC_IC(reason) set_slow_stub_reason(reason);
void IC::TraceIC(const char* type, Handle<Object> name) {
if (FLAG_ic_stats) {
......@@ -100,30 +77,72 @@ void IC::TraceIC(const char* type, Handle<Object> name) {
}
}
Address IC::GetAbstractPC(int* line, int* column) const {
JavaScriptFrameIterator it(isolate());
JavaScriptFrame* frame = it.frame();
DCHECK(!frame->is_builtin());
int position = frame->position();
Object* maybe_script = frame->function()->shared()->script();
if (maybe_script->IsScript()) {
Handle<Script> script(Script::cast(maybe_script), isolate());
Script::PositionInfo info;
Script::GetPositionInfo(script, position, &info, Script::WITH_OFFSET);
*line = info.line + 1;
*column = info.column + 1;
} else {
*line = position;
*column = -1;
}
if (frame->is_interpreted()) {
InterpretedFrame* iframe = static_cast<InterpretedFrame*>(frame);
Address bytecode_start =
reinterpret_cast<Address>(iframe->GetBytecodeArray()) - kHeapObjectTag +
BytecodeArray::kHeaderSize;
return bytecode_start + iframe->GetBytecodeOffset();
}
return frame->pc();
}
void IC::TraceIC(const char* type, Handle<Object> name, State old_state,
State new_state) {
if (V8_LIKELY(!FLAG_ic_stats)) return;
if (FLAG_ic_stats &
v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING) {
Map* map = nullptr;
if (!receiver_map().is_null()) {
map = *receiver_map();
}
const char* modifier = "";
if (IsKeyedStoreIC()) {
KeyedAccessStoreMode mode =
casted_nexus<KeyedStoreICNexus>()->GetKeyedAccessStoreMode();
modifier = GetTransitionMarkModifier(mode);
}
if (!(FLAG_ic_stats &
v8::tracing::TracingCategoryObserver::ENABLED_BY_TRACING)) {
int line;
int column;
Address pc = GetAbstractPC(&line, &column);
LOG(isolate(), ICEvent(type, is_keyed(), pc, line, column, map, *name,
TransitionMarkFromState(old_state),
TransitionMarkFromState(new_state), modifier,
slow_stub_reason_));
return;
}
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];
// 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()) {
DCHECK(maybe_function->IsJSFunction());
JSFunction* function = JSFunction::cast(maybe_function);
int code_offset = 0;
if (function->IsInterpreted()) {
......@@ -132,30 +151,10 @@ void IC::TraceIC(const char* type, Handle<Object> name, State old_state,
code_offset =
static_cast<int>(pc() - function->code()->instruction_start());
}
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 = "";
if (IsKeyedStoreIC()) {
KeyedAccessStoreMode mode =
casted_nexus<KeyedStoreICNexus>()->GetKeyedAccessStoreMode();
modifier = GetTransitionMarkModifier(mode);
}
Map* map = nullptr;
if (!receiver_map().is_null()) {
map = *receiver_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.
// Reserve 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);
......@@ -164,33 +163,13 @@ void IC::TraceIC(const char* type, Handle<Object> name, State old_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) {
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");
}
}
......@@ -201,6 +180,7 @@ IC::IC(FrameDepth depth, Isolate* isolate, FeedbackNexus* nexus)
vector_set_(false),
kind_(FeedbackSlotKind::kInvalid),
target_maps_set_(false),
slow_stub_reason_(nullptr),
nexus_(nexus) {
// To improve the performance of the (much used) IC code, we unfold a few
// levels of the stack frame iteration code. This yields a ~35% speedup when
......@@ -1135,7 +1115,7 @@ void LoadIC::UpdateCaches(LookupIterator* lookup) {
return;
} else if (lookup->state() == LookupIterator::ACCESSOR) {
if (!IsCompatibleReceiver(lookup, receiver_map())) {
TRACE_GENERIC_IC(isolate(), "LoadIC", "incompatible receiver type");
TRACE_GENERIC_IC("incompatible receiver type");
code = slow_stub();
}
} else if (lookup->state() == LookupIterator::INTERCEPTOR) {
......@@ -1146,7 +1126,7 @@ void LoadIC::UpdateCaches(LookupIterator* lookup) {
LookupForRead(&it);
if (it.state() == LookupIterator::ACCESSOR &&
!IsCompatibleReceiver(&it, receiver_map())) {
TRACE_GENERIC_IC(isolate(), "LoadIC", "incompatible receiver type");
TRACE_GENERIC_IC("incompatible receiver type");
code = slow_stub();
}
}
......@@ -1593,11 +1573,11 @@ void KeyedLoadIC::UpdateLoadElement(Handle<HeapObject> receiver) {
Handle<Map> map = target_receiver_maps.at(i);
if (map.is_null()) continue;
if (map->instance_type() == JS_VALUE_TYPE) {
TRACE_GENERIC_IC(isolate(), "KeyedLoadIC", "JSValue");
TRACE_GENERIC_IC("JSValue");
return;
}
if (map->instance_type() == JS_PROXY_TYPE) {
TRACE_GENERIC_IC(isolate(), "KeyedLoadIC", "JSProxy");
TRACE_GENERIC_IC("JSProxy");
return;
}
}
......@@ -1625,14 +1605,14 @@ void KeyedLoadIC::UpdateLoadElement(Handle<HeapObject> receiver) {
if (!AddOneReceiverMapIfMissing(&target_receiver_maps, receiver_map)) {
// If the miss wasn't due to an unseen map, a polymorphic stub
// won't help, use the generic stub.
TRACE_GENERIC_IC(isolate(), "KeyedLoadIC", "same map added twice");
TRACE_GENERIC_IC("same map added twice");
return;
}
// If the maximum number of receiver maps has been exceeded, use the generic
// version of the IC.
if (target_receiver_maps.length() > kMaxKeyedPolymorphism) {
TRACE_GENERIC_IC(isolate(), "KeyedLoadIC", "max polymorph exceeded");
TRACE_GENERIC_IC("max polymorph exceeded");
return;
}
......@@ -1679,7 +1659,6 @@ MaybeHandle<Object> KeyedLoadIC::Load(Handle<Object> object,
if (!is_vector_set()) {
ConfigureVectorState(MEGAMORPHIC, key);
TRACE_GENERIC_IC(isolate(), "KeyedLoadIC", "set generic");
TRACE_IC("LoadIC", key);
}
......@@ -1845,12 +1824,13 @@ void StoreIC::UpdateCaches(LookupIterator* lookup, Handle<Object> value,
return;
}
bool use_ic = LookupForWrite(lookup, value, store_mode);
if (!use_ic) {
TRACE_GENERIC_IC(isolate(), "StoreIC", "LookupForWrite said 'false'");
Handle<Object> handler;
if (LookupForWrite(lookup, value, store_mode)) {
handler = ComputeHandler(lookup, value);
} else {
TRACE_GENERIC_IC("LookupForWrite said 'false'");
handler = slow_stub();
}
Handle<Object> handler = use_ic ? ComputeHandler(lookup, value)
: Handle<Object>::cast(slow_stub());
PatchCache(lookup->name(), handler);
TRACE_IC("StoreIC", lookup->name());
......@@ -1948,7 +1928,7 @@ Handle<Object> StoreIC::GetMapIndependentHandler(LookupIterator* lookup) {
}
// Currently not handled by CompileStoreTransition.
if (!holder->HasFastProperties()) {
TRACE_GENERIC_IC(isolate(), "StoreIC", "transition from slow");
TRACE_GENERIC_IC("transition from slow");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
......@@ -1968,7 +1948,7 @@ Handle<Object> StoreIC::GetMapIndependentHandler(LookupIterator* lookup) {
case LookupIterator::ACCESSOR: {
if (!holder->HasFastProperties()) {
TRACE_GENERIC_IC(isolate(), "StoreIC", "accessor on slow map");
TRACE_GENERIC_IC("accessor on slow map");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
......@@ -1976,20 +1956,19 @@ Handle<Object> StoreIC::GetMapIndependentHandler(LookupIterator* lookup) {
if (accessors->IsAccessorInfo()) {
Handle<AccessorInfo> info = Handle<AccessorInfo>::cast(accessors);
if (v8::ToCData<Address>(info->setter()) == nullptr) {
TRACE_GENERIC_IC(isolate(), "StoreIC", "setter == nullptr");
TRACE_GENERIC_IC("setter == nullptr");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
if (AccessorInfo::cast(*accessors)->is_special_data_property() &&
!lookup->HolderIsReceiverOrHiddenPrototype()) {
TRACE_GENERIC_IC(isolate(), "StoreIC",
"special data property in prototype chain");
TRACE_GENERIC_IC("special data property in prototype chain");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
if (!AccessorInfo::IsCompatibleReceiverMap(isolate(), info,
receiver_map())) {
TRACE_GENERIC_IC(isolate(), "StoreIC", "incompatible receiver type");
TRACE_GENERIC_IC("incompatible receiver type");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
......@@ -2002,7 +1981,7 @@ Handle<Object> StoreIC::GetMapIndependentHandler(LookupIterator* lookup) {
Handle<Object> setter(Handle<AccessorPair>::cast(accessors)->setter(),
isolate());
if (!setter->IsJSFunction() && !setter->IsFunctionTemplateInfo()) {
TRACE_GENERIC_IC(isolate(), "StoreIC", "setter not a function");
TRACE_GENERIC_IC("setter not a function");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
......@@ -2011,7 +1990,7 @@ Handle<Object> StoreIC::GetMapIndependentHandler(LookupIterator* lookup) {
if (call_optimization.IsCompatibleReceiver(receiver, holder)) {
break; // Custom-compiled handler.
}
TRACE_GENERIC_IC(isolate(), "StoreIC", "incompatible receiver");
TRACE_GENERIC_IC("incompatible receiver");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
......@@ -2044,7 +2023,7 @@ Handle<Object> StoreIC::GetMapIndependentHandler(LookupIterator* lookup) {
// -------------- Constant properties --------------
DCHECK_EQ(kDescriptor, lookup->property_details().location());
TRACE_GENERIC_IC(isolate(), "StoreIC", "constant property");
TRACE_GENERIC_IC("constant property");
TRACE_HANDLER_STATS(isolate(), StoreIC_SlowStub);
return slow_stub();
}
......@@ -2175,7 +2154,7 @@ void KeyedStoreIC::UpdateStoreElement(Handle<Map> receiver_map,
for (int i = 0; i < target_receiver_maps.length(); i++) {
if (!target_receiver_maps.at(i).is_null() &&
target_receiver_maps.at(i)->instance_type() == JS_VALUE_TYPE) {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "JSValue");
TRACE_GENERIC_IC("JSValue");
return;
}
}
......@@ -2236,7 +2215,7 @@ void KeyedStoreIC::UpdateStoreElement(Handle<Map> receiver_map,
if (!map_added) {
// If the miss wasn't due to an unseen map, a polymorphic stub
// won't help, use the megamorphic stub which can handle everything.
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "same map added twice");
TRACE_GENERIC_IC("same map added twice");
return;
}
......@@ -2251,7 +2230,7 @@ void KeyedStoreIC::UpdateStoreElement(Handle<Map> receiver_map,
if (store_mode == STANDARD_STORE) {
store_mode = old_store_mode;
} else if (store_mode != old_store_mode) {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "store mode mismatch");
TRACE_GENERIC_IC("store mode mismatch");
return;
}
}
......@@ -2268,8 +2247,7 @@ void KeyedStoreIC::UpdateStoreElement(Handle<Map> receiver_map,
}
if (external_arrays != 0 &&
external_arrays != target_receiver_maps.length()) {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC",
"unsupported combination of external and normal arrays");
TRACE_GENERIC_IC("unsupported combination of external and normal arrays");
return;
}
}
......@@ -2403,8 +2381,7 @@ MaybeHandle<Object> KeyedStoreIC::Store(Handle<Object> object,
Object);
if (!is_vector_set()) {
ConfigureVectorState(MEGAMORPHIC, key);
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC",
"unhandled internalized string key");
TRACE_GENERIC_IC("unhandled internalized string key");
TRACE_IC("StoreIC", key);
}
return store_handle;
......@@ -2418,7 +2395,7 @@ MaybeHandle<Object> KeyedStoreIC::Store(Handle<Object> object,
// the runtime to enable optimization of element hole access.
Handle<HeapObject> heap_object = Handle<HeapObject>::cast(object);
if (heap_object->map()->IsMapInArrayPrototypeChain()) {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "map in array prototype");
TRACE_GENERIC_IC("map in array prototype");
use_ic = false;
}
}
......@@ -2449,7 +2426,7 @@ MaybeHandle<Object> KeyedStoreIC::Store(Handle<Object> object,
if (use_ic) {
if (!old_receiver_map.is_null()) {
if (is_arguments) {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "arguments receiver");
TRACE_GENERIC_IC("arguments receiver");
} else if (key_is_valid_index) {
// We should go generic if receiver isn't a dictionary, but our
// prototype chain does have dictionary elements. This ensures that
......@@ -2458,20 +2435,18 @@ MaybeHandle<Object> KeyedStoreIC::Store(Handle<Object> object,
if (!old_receiver_map->DictionaryElementsInPrototypeChainOnly()) {
UpdateStoreElement(old_receiver_map, store_mode);
} else {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC",
"dictionary or proxy prototype");
TRACE_GENERIC_IC("dictionary or proxy prototype");
}
} else {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "non-smi-like key");
TRACE_GENERIC_IC("non-smi-like key");
}
} else {
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "non-JSObject receiver");
TRACE_GENERIC_IC("non-JSObject receiver");
}
}
if (!is_vector_set()) {
ConfigureVectorState(MEGAMORPHIC, key);
TRACE_GENERIC_IC(isolate(), "KeyedStoreIC", "set generic");
}
TRACE_IC("StoreIC", key);
......@@ -2791,15 +2766,13 @@ MaybeHandle<Object> BinaryOpIC::Transition(
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;
int line;
int column;
Address pc = GetAbstractPC(&line, &column);
LOG(isolate(),
BinaryOpIC(pc, line, column, *new_target, old_state.ToString().c_str(),
state.ToString().c_str(),
allocation_site.is_null() ? nullptr : *allocation_site));
}
// Patch the inlined smi code as necessary.
......@@ -2888,17 +2861,17 @@ Code* CompareIC::UpdateCaches(Handle<Object> x, Handle<Object> y) {
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",
int line;
int column;
Address pc = GetAbstractPC(&line, &column);
LOG(isolate(),
CompareIC(pc, line, column, *stub.GetCode(), Token::Name(op_),
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()));
CompareICState::GetStateName(state)));
}
// Activate inlined smi code.
......@@ -2928,9 +2901,36 @@ RUNTIME_FUNCTION(Runtime_Unreachable) {
Handle<Object> ToBooleanIC::ToBoolean(Handle<Object> object) {
ToBooleanICStub stub(isolate(), extra_ic_state());
ToBooleanHints old_hints = stub.hints();
bool to_boolean_value = stub.UpdateStatus(object);
ToBooleanHints new_hints = stub.hints();
Handle<Code> code = stub.GetCode();
set_target(*code);
// Note: Although a no-op transition is semantically OK, it is hinting at a
// bug somewhere in our state transition machinery.
DCHECK_NE(old_hints, new_hints);
if (V8_UNLIKELY(FLAG_ic_stats)) {
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 = "ToBooleanIC";
ic_info.state = ToString(old_hints);
ic_info.state += "=>";
ic_info.state += ToString(new_hints);
ic_stats->End();
} else {
int line;
int column;
Address pc = GetAbstractPC(&line, &column);
LOG(isolate(),
ToBooleanIC(pc, line, column, *code, ToString(old_hints).c_str(),
ToString(new_hints).c_str()));
}
}
return isolate()->factory()->ToBoolean(to_boolean_value);
}
......
......@@ -85,6 +85,10 @@ class IC {
protected:
Address fp() const { return fp_; }
Address pc() const { return *pc_address_; }
void set_slow_stub_reason(const char* reason) { slow_stub_reason_ = reason; }
Address GetAbstractPC(int* line, int* column) const;
Isolate* isolate() const { return isolate_; }
// Get the caller function object.
......@@ -249,6 +253,8 @@ class IC {
MapHandleList target_maps_;
bool target_maps_set_;
const char* slow_stub_reason_;
FeedbackNexus* nexus_;
DISALLOW_IMPLICIT_CONSTRUCTORS(IC);
......
......@@ -70,9 +70,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
}
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, andi=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(andi_instruction_address), delta);
LOG(isolate, PatchIC(address, andi_instruction_address, delta));
}
Address patch_address =
......
......@@ -70,9 +70,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
}
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, andi=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(andi_instruction_address), delta);
LOG(isolate, PatchIC(address, andi_instruction_address, delta));
}
Address patch_address =
......
......@@ -71,9 +71,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
}
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, cmp=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(cmp_instruction_address), delta);
LOG(isolate, PatchIC(address, cmp_instruction_address, delta));
}
Address patch_address =
......
......@@ -71,9 +71,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
}
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, cmp=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(cmp_instruction_address), delta);
LOG(isolate, PatchIC(address, cmp_instruction_address, delta));
}
// Expected sequence to enable by changing the following
......
......@@ -62,9 +62,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
// condition code uses at the patched jump.
uint8_t delta = *reinterpret_cast<uint8_t*>(delta_address);
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, test=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(test_instruction_address), delta);
LOG(isolate, PatchIC(address, test_instruction_address, delta));
}
// Patch with a short conditional jump. Enabling means switching from a short
......
......@@ -62,9 +62,7 @@ void PatchInlinedSmiCode(Isolate* isolate, Address address,
// condition code uses at the patched jump.
uint8_t delta = *reinterpret_cast<uint8_t*>(delta_address);
if (FLAG_trace_ic) {
PrintF("[ patching ic at %p, test=%p, delta=%d\n",
static_cast<void*>(address),
static_cast<void*>(test_instruction_address), delta);
LOG(isolate, PatchIC(address, test_instruction_address, delta));
}
// Patch with a short conditional jump. Enabling means switching from a short
......
......@@ -32,7 +32,7 @@ class Log {
return FLAG_log || FLAG_log_api || FLAG_log_code || FLAG_log_gc ||
FLAG_log_handles || FLAG_log_suspect || FLAG_ll_prof ||
FLAG_perf_basic_prof || FLAG_perf_prof ||
FLAG_log_internal_timer_events || FLAG_prof_cpp;
FLAG_log_internal_timer_events || FLAG_prof_cpp || FLAG_trace_ic;
}
// Frees all resources acquired in Initialize and Open... functions.
......
......@@ -1290,6 +1290,93 @@ void Logger::TickEvent(v8::TickSample* sample, bool overflow) {
msg.WriteToLogFile();
}
void Logger::ICEvent(const char* type, bool keyed, const Address pc, int line,
int column, Map* map, Object* key, char old_state,
char new_state, const char* modifier,
const char* slow_stub_reason) {
if (!log_->IsEnabled() || !FLAG_trace_ic) return;
Log::MessageBuilder msg(log_);
if (keyed) msg.Append("Keyed");
msg.Append("%s,", type);
msg.AppendAddress(pc);
msg.Append(",%d,%d,", line, column);
msg.Append(old_state);
msg.Append(",");
msg.Append(new_state);
msg.Append(",");
msg.AppendAddress(reinterpret_cast<Address>(map));
msg.Append(",");
if (key->IsSmi()) {
msg.Append("%d", Smi::cast(key)->value());
} else if (key->IsNumber()) {
msg.Append("%lf", key->Number());
} else if (key->IsString()) {
msg.AppendDetailed(String::cast(key), false);
} else if (key->IsSymbol()) {
msg.AppendSymbolName(Symbol::cast(key));
}
msg.Append(",%s,", modifier);
if (slow_stub_reason != nullptr) {
msg.AppendDoubleQuotedString(slow_stub_reason);
}
msg.WriteToLogFile();
}
void Logger::CompareIC(const Address pc, int line, int column, Code* stub,
const char* op, const char* old_left,
const char* old_right, const char* old_state,
const char* new_left, const char* new_right,
const char* new_state) {
if (!log_->IsEnabled() || !FLAG_trace_ic) return;
Log::MessageBuilder msg(log_);
msg.Append("CompareIC,");
msg.AppendAddress(pc);
msg.Append(",%d,%d,", line, column);
msg.AppendAddress(reinterpret_cast<Address>(stub));
msg.Append(",%s,%s,%s,%s,%s,%s,%s", op, old_left, old_right, old_state,
new_left, new_right, new_state);
msg.WriteToLogFile();
}
void Logger::BinaryOpIC(const Address pc, int line, int column, Code* stub,
const char* old_state, const char* new_state,
AllocationSite* allocation_site) {
if (!log_->IsEnabled() || !FLAG_trace_ic) return;
Log::MessageBuilder msg(log_);
msg.Append("BinaryOpIC,");
msg.AppendAddress(pc);
msg.Append(",%d,%d,", line, column);
msg.AppendAddress(reinterpret_cast<Address>(stub));
msg.Append(",%s,%s,", old_state, new_state);
if (allocation_site != nullptr) {
msg.AppendAddress(reinterpret_cast<Address>(allocation_site));
}
msg.WriteToLogFile();
}
void Logger::ToBooleanIC(const Address pc, int line, int column, Code* stub,
const char* old_state, const char* new_state) {
if (!log_->IsEnabled() || !FLAG_trace_ic) return;
Log::MessageBuilder msg(log_);
msg.Append("ToBooleanIC,");
msg.AppendAddress(pc);
msg.Append(",%d,%d,", line, column);
msg.AppendAddress(reinterpret_cast<Address>(stub));
msg.Append(",%s,%s,", old_state, new_state);
msg.WriteToLogFile();
}
void Logger::PatchIC(const Address pc, const Address test, int delta) {
if (!log_->IsEnabled() || !FLAG_trace_ic) return;
Log::MessageBuilder msg(log_);
msg.Append("PatchIC,");
msg.AppendAddress(pc);
msg.Append(",");
msg.AppendAddress(test);
msg.Append(",");
msg.Append("%d,", delta);
msg.WriteToLogFile();
}
void Logger::StopProfiler() {
if (!log_->IsEnabled()) return;
......
......@@ -183,6 +183,21 @@ class Logger : public CodeEventListener {
void CodeDeoptEvent(Code* code, Address pc, int fp_to_sp_delta);
void ICEvent(const char* type, bool keyed, const Address pc, int line,
int column, Map* map, Object* key, char old_state,
char new_state, const char* modifier,
const char* slow_stub_reason);
void CompareIC(const Address pc, int line, int column, Code* stub,
const char* op, const char* old_left, const char* old_right,
const char* old_state, const char* new_left,
const char* new_right, const char* new_state);
void BinaryOpIC(const Address pc, int line, int column, Code* stub,
const char* old_state, const char* new_state,
AllocationSite* allocation_site);
void ToBooleanIC(const Address pc, int line, int column, Code* stub,
const char* old_state, const char* new_state);
void PatchIC(const Address pc, const Address test, int delta);
// ==== Events logged by --log-gc. ====
// Heap sampling events: start, end, and individual types.
void HeapSampleBeginEvent(const char* space, const char* kind);
......
#!/bin/sh
# find the name of the log file to process, it must not start with a dash.
log_file="v8.log"
for arg in "$@"
do
if ! expr "X${arg}" : "^X-" > /dev/null; then
log_file=${arg}
fi
done
tools_path=`cd $(dirname "$0");pwd`
if [ ! "$D8_PATH" ]; then
d8_public=`which d8`
if [ -x "$d8_public" ]; then D8_PATH=$(dirname "$d8_public"); fi
fi
[ -n "$D8_PATH" ] || D8_PATH=$tools_path/..
d8_exec=$D8_PATH/d8
if [ ! -x "$d8_exec" ]; then
D8_PATH=`pwd`/out/native
d8_exec=$D8_PATH/d8
fi
if [ ! -x "$d8_exec" ]; then
d8_exec=`grep -m 1 -o '".*/d8"' $log_file | sed 's/"//g'`
fi
if [ ! -x "$d8_exec" ]; then
echo "d8 shell not found in $D8_PATH"
echo "To build, execute 'make native' from the V8 directory"
exit 1
fi
# nm spits out 'no symbols found' messages to stderr.
cat $log_file | $d8_exec $tools_path/splaytree.js $tools_path/codemap.js \
$tools_path/csvparser.js $tools_path/consarray.js \
$tools_path/profile.js $tools_path/profile_view.js \
$tools_path/logreader.js $tools_path/ic-processor.js \
$tools_path/SourceMap.js \
$tools_path/ic-processor-driver.js -- $@ 2>/dev/null
// Copyright 2017 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.
function processArguments(args) {
var processor = new ArgumentsProcessor(args);
if (processor.parse()) {
return processor.result();
} else {
processor.printUsageAndExit();
}
}
function initSourceMapSupport() {
// Pull dev tools source maps into our name space.
SourceMap = WebInspector.SourceMap;
// Overwrite the load function to load scripts synchronously.
SourceMap.load = function(sourceMapURL) {
var content = readFile(sourceMapURL);
var sourceMapObject = (JSON.parse(content));
return new SourceMap(sourceMapURL, sourceMapObject);
};
}
var params = processArguments(arguments);
var sourceMap = null;
if (params.sourceMap) {
initSourceMapSupport();
sourceMap = SourceMap.load(params.sourceMap);
}
var icProcessor = new IcProcessor();
icProcessor.processLogFile(params.logFileName);
// Copyright 2017 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.
function inherits(childCtor, parentCtor) {
childCtor.prototype.__proto__ = parentCtor.prototype;
};
/**
* A thin wrapper around shell's 'read' function showing a file name on error.
*/
function readFile(fileName) {
try {
return read(fileName);
} catch (e) {
print(fileName + ': ' + (e.message || e));
throw e;
}
}
/**
* Parser for dynamic code optimization state.
*/
function parseState(s) {
switch (s) {
case "": return Profile.CodeState.COMPILED;
case "~": return Profile.CodeState.OPTIMIZABLE;
case "*": return Profile.CodeState.OPTIMIZED;
}
throw new Error("unknown code state: " + s);
}
function IcProcessor() {
var propertyICParser = [parseInt, parseInt, parseInt, null, null, parseInt,
null, null, null];
LogReader.call(this, {
'code-creation': {
parsers: [null, parseInt, parseInt, parseInt, null, 'var-args'],
processor: this.processCodeCreation },
'code-move': { parsers: [parseInt, parseInt],
processor: this.processCodeMove },
'code-delete': { parsers: [parseInt],
processor: this.processCodeDelete },
'sfi-move': { parsers: [parseInt, parseInt],
processor: this.processFunctionMove },
'LoadIC': {
parsers : propertyICParser,
processor: this.processPropertyIC.bind(this, "LoadIC") },
'StoreIC': {
parsers : propertyICParser,
processor: this.processPropertyIC.bind(this, "StoreIC") },
'KeyedLoadIC': {
parsers : propertyICParser,
processor: this.processPropertyIC.bind(this, "KeyedLoadIC") },
'KeyedStoreIC': {
parsers : propertyICParser,
processor: this.processPropertyIC.bind(this, "KeyedStoreIC") },
'CompareIC': {
parsers : [parseInt, parseInt, parseInt, parseInt, null, null, null,
null, null, null, null],
processor: this.processCompareIC },
'BinaryOpIC': {
parsers : [parseInt, parseInt, parseInt, parseInt, null, null,
parseInt],
processor: this.processBinaryOpIC },
'ToBooleanIC': {
parsers : [parseInt, parseInt, parseInt, parseInt, null, null],
processor: this.processToBooleanIC },
'PatchIC': {
parsers : [parseInt, parseInt, parseInt],
processor: this.processPatchIC },
});
this.deserializedEntriesNames_ = [];
this.profile_ = new Profile();
this.LoadIC = 0;
this.StoreIC = 0;
this.KeyedLoadIC = 0;
this.KeyedStoreIC = 0;
this.CompareIC = 0;
this.BinaryOpIC = 0;
this.ToBooleanIC = 0;
this.PatchIC = 0;
}
inherits(IcProcessor, LogReader);
/**
* @override
*/
IcProcessor.prototype.printError = function(str) {
print(str);
};
IcProcessor.prototype.processLogFile = function(fileName) {
this.lastLogFileName_ = fileName;
var line;
while (line = readline()) {
this.processLogLine(line);
}
print();
print("=====================");
print("Load: " + this.LoadIC);
print("Store: " + this.StoreIC);
print("KeyedLoad: " + this.KeyedLoadIC);
print("KeyedStore: " + this.KeyedStoreIC);
print("CompareIC: " + this.CompareIC);
print("BinaryOpIC: " + this.BinaryOpIC);
print("ToBooleanIC: " + this.ToBooleanIC);
print("PatchIC: " + this.PatchIC);
};
IcProcessor.prototype.processCodeCreation = function(
type, kind, start, size, name, maybe_func) {
name = this.deserializedEntriesNames_[start] || name;
if (maybe_func.length) {
var funcAddr = parseInt(maybe_func[0]);
var state = parseState(maybe_func[1]);
this.profile_.addFuncCode(type, name, start, size, funcAddr, state);
} else {
this.profile_.addCode(type, name, start, size);
}
};
IcProcessor.prototype.processCodeMove = function(from, to) {
this.profile_.moveCode(from, to);
};
IcProcessor.prototype.processCodeDelete = function(start) {
this.profile_.deleteCode(start);
};
IcProcessor.prototype.processFunctionMove = function(from, to) {
this.profile_.moveFunc(from, to);
};
IcProcessor.prototype.formatName = function(entry) {
if (!entry) return "<unknown>"
var name = entry.func.getName();
var re = /(.*):[0-9]+:[0-9]+$/;
var array = re.exec(name);
if (!array) return name;
return array[1];
}
IcProcessor.prototype.processPropertyIC = function (
type, pc, line, column, old_state, new_state, map, name, modifier,
slow_reason) {
this[type]++;
var entry = this.profile_.findEntry(pc);
print(type + " (" + old_state + "->" + new_state + modifier + ") at " +
this.formatName(entry) + ":" + line + ":" + column + " " + name +
" (map 0x" + map.toString(16) + ")");
}
IcProcessor.prototype.processCompareIC = function (
pc, line, column, stub, op, old_left, old_right, old_state, new_left,
new_right, new_state) {
var entry = this.profile_.findEntry(pc);
this.CompareIC++;
print("CompareIC[" + op + "] ((" +
old_left + "+" + old_right + "=" + old_state + ")->(" +
new_left + "+" + new_right + "=" + new_state + ")) at " +
this.formatName(entry) + ":" + line + ":" + column);
}
IcProcessor.prototype.processBinaryOpIC = function (
pc, line, column, stub, old_state, new_state, allocation_site) {
var entry = this.profile_.findEntry(pc);
this.BinaryOpIC++;
print("BinaryOpIC (" + old_state + "->" + new_state + ") at " +
this.formatName(entry) + ":" + line + ":" + column);
}
IcProcessor.prototype.processToBooleanIC = function (
pc, line, column, stub, old_state, new_state) {
var entry = this.profile_.findEntry(pc);
this.ToBooleanIC++;
print("ToBooleanIC (" + old_state + "->" + new_state + ") at " +
this.formatName(entry) + ":" + line + ":" + column);
}
IcProcessor.prototype.processPatchIC = function (pc, test, delta) {
var entry = this.profile_.findEntry(pc);
this.PatchIC++;
print("PatchIC (0x" + test.toString(16) + ", " + delta + ") at " +
this.formatName(entry));
}
function padLeft(s, len) {
s = s.toString();
if (s.length < len) {
var padLength = len - s.length;
if (!(padLength in padLeft)) {
padLeft[padLength] = new Array(padLength + 1).join(' ');
}
s = padLeft[padLength] + s;
}
return s;
};
function ArgumentsProcessor(args) {
this.args_ = args;
this.result_ = ArgumentsProcessor.DEFAULTS;
this.argsDispatch_ = {
'--range': ['range', 'auto,auto',
'Specify the range limit as [start],[end]'],
'--source-map': ['sourceMap', null,
'Specify the source map that should be used for output']
};
};
ArgumentsProcessor.DEFAULTS = {
logFileName: 'v8.log',
range: 'auto,auto',
};
ArgumentsProcessor.prototype.parse = function() {
while (this.args_.length) {
var arg = this.args_.shift();
if (arg.charAt(0) != '-') {
this.result_.logFileName = arg;
continue;
}
var userValue = null;
var eqPos = arg.indexOf('=');
if (eqPos != -1) {
userValue = arg.substr(eqPos + 1);
arg = arg.substr(0, eqPos);
}
if (arg in this.argsDispatch_) {
var dispatch = this.argsDispatch_[arg];
this.result_[dispatch[0]] = userValue == null ? dispatch[1] : userValue;
} else {
return false;
}
}
return true;
};
ArgumentsProcessor.prototype.result = function() {
return this.result_;
};
ArgumentsProcessor.prototype.printUsageAndExit = function() {
function padRight(s, len) {
s = s.toString();
if (s.length < len) {
s = s + (new Array(len - s.length + 1).join(' '));
}
return s;
}
print('Cmdline args: [options] [log-file-name]\n' +
'Default log file name is "' +
ArgumentsProcessor.DEFAULTS.logFileName + '".\n');
print('Options:');
for (var arg in this.argsDispatch_) {
var synonyms = [arg];
var dispatch = this.argsDispatch_[arg];
for (var synArg in this.argsDispatch_) {
if (arg !== synArg && dispatch === this.argsDispatch_[synArg]) {
synonyms.push(synArg);
delete this.argsDispatch_[synArg];
}
}
print(' ' + padRight(synonyms.join(', '), 20) + " " + dispatch[2]);
}
quit(2);
};
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