AuroraMiddleware/v8
1
0
Fork 0
Code Issues 2 Pull Requests Releases Wiki Activity

[profiler] Tracing-based CPU profiler.

Browse Source 
A new V8 API object v8::TracingCpuProfiler is introduced.
Client can create it on an isolate to enable JS CPU profiles collected
during tracing session.

Once the v8.cpu_profile2 tracing category is enabled the profiler emits
CpuProfile and CpuProfileChunk events with the profile data.

BUG=chromium:406277

Review-Url: https://codereview.chromium.org/2396733002
Cr-Commit-Position: refs/heads/master@{#40054}
This commit is contained in:
alph 2016-10-06 11:14:03 -07:00 committed by Commit bot
parent 549690f2bf
commit 4b575dfcef
8 changed files with 280 additions and 35 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
include/v8-profiler.h
View File

@ -48,7 +48,7 @@ namespace v8 {
/**
* TracingCpuProfiler monitors tracing being enabled/disabled
* and emits CpuProfile trace events once v8.cpu_profile2 tracing category
* and emits CpuProfile trace events once v8.cpu_profiler tracing category
* is enabled. It has no overhead unless the category is enabled.
*/
class V8_EXPORT TracingCpuProfiler {

20
src/profiler/cpu-profiler.cc
View File

@ -326,33 +326,21 @@ void CpuProfiler::StartProcessorIfNotStarted() {
processor_->StartSynchronously();
}
CpuProfile* CpuProfiler::StopProfiling(const char* title) {
if (!is_profiling_) return nullptr;
StopProcessorIfLastProfile(title);
CpuProfile* result = profiles_->StopProfiling(title);
if (result) {
result->Print();
}
return result;
return profiles_->StopProfiling(title);
}
CpuProfile* CpuProfiler::StopProfiling(String* title) {
if (!is_profiling_) return nullptr;
const char* profile_title = profiles_->GetName(title);
StopProcessorIfLastProfile(profile_title);
return profiles_->StopProfiling(profile_title);
return StopProfiling(profiles_->GetName(title));
}
void CpuProfiler::StopProcessorIfLastProfile(const char* title) {
if (profiles_->IsLastProfile(title)) {
StopProcessor();
}
if (!profiles_->IsLastProfile(title)) return;
StopProcessor();
}
void CpuProfiler::StopProcessor() {
Logger* logger = isolate_->logger();
is_profiling_ = false;

10
src/profiler/profile-generator-inl.h
View File

@ -30,20 +30,22 @@ CodeEntry::CodeEntry(CodeEventListener::LogEventsAndTags tag, const char* name,
line_info_(line_info),
instruction_start_(instruction_start) {}
ProfileNode::ProfileNode(ProfileTree* tree, CodeEntry* entry)
ProfileNode::ProfileNode(ProfileTree* tree, CodeEntry* entry,
ProfileNode* parent)
: tree_(tree),
entry_(entry),
self_ticks_(0),
children_(CodeEntriesMatch),
parent_(parent),
id_(tree->next_node_id()),
line_ticks_(LineTickMatch) {}
line_ticks_(LineTickMatch) {
tree_->EnqueueNode(this);
}
inline unsigned ProfileNode::function_id() const {
return tree_->GetFunctionId(this);
}
inline Isolate* ProfileNode::isolate() const { return tree_->isolate(); }
} // namespace internal

109
src/profiler/profile-generator.cc
View File

@ -10,6 +10,8 @@
#include "src/global-handles.h"
#include "src/profiler/cpu-profiler.h"
#include "src/profiler/profile-generator-inl.h"
#include "src/tracing/trace-event.h"
#include "src/tracing/traced-value.h"
#include "src/unicode.h"
namespace v8 {
@ -214,9 +216,8 @@ ProfileNode* ProfileNode::FindOrAddChild(CodeEntry* entry) {
base::HashMap::Entry* map_entry =
children_.LookupOrInsert(entry, CodeEntryHash(entry));
ProfileNode* node = reinterpret_cast<ProfileNode*>(map_entry->value);
if (node == NULL) {
// New node added.
node = new ProfileNode(tree_, entry);
if (!node) {
node = new ProfileNode(tree_, entry, this);
map_entry->value = node;
children_list_.Add(node);
}
@ -305,7 +306,7 @@ class DeleteNodesCallback {
ProfileTree::ProfileTree(Isolate* isolate)
: root_entry_(CodeEventListener::FUNCTION_TAG, "(root)"),
next_node_id_(1),
root_(new ProfileNode(this, &root_entry_)),
root_(new ProfileNode(this, &root_entry_, nullptr)),
isolate_(isolate),
next_function_id_(1),
function_ids_(ProfileNode::CodeEntriesMatch) {}
@ -397,13 +398,22 @@ void ProfileTree::TraverseDepthFirst(Callback* callback) {
}
}
using v8::tracing::TracedValue;
CpuProfile::CpuProfile(CpuProfiler* profiler, const char* title,
bool record_samples)
: title_(title),
record_samples_(record_samples),
start_time_(base::TimeTicks::HighResolutionNow()),
top_down_(profiler->isolate()),
profiler_(profiler) {}
profiler_(profiler),
streaming_next_sample_(0) {
auto value = TracedValue::Create();
value->SetDouble("startTime",
(start_time_ - base::TimeTicks()).InMicroseconds());
TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"),
"CpuProfile", this, "data", std::move(value));
}
void CpuProfile::AddPath(base::TimeTicks timestamp,
const std::vector<CodeEntry*>& path, int src_line,
@ -414,10 +424,91 @@ void CpuProfile::AddPath(base::TimeTicks timestamp,
timestamps_.Add(timestamp);
samples_.Add(top_frame_node);
}
const int kSamplesFlushCount = 100;
const int kNodesFlushCount = 10;
if (samples_.length() - streaming_next_sample_ >= kSamplesFlushCount ||
top_down_.pending_nodes_count() >= kNodesFlushCount) {
StreamPendingTraceEvents();
}
}
void CpuProfile::CalculateTotalTicksAndSamplingRate() {
namespace {
void BuildNodeValue(const ProfileNode* node, TracedValue* value) {
const CodeEntry* entry = node->entry();
value->BeginDictionary("callFrame");
value->SetString("functionName", entry->name());
if (*entry->resource_name()) {
value->SetString("url", entry->resource_name());
}
value->SetInteger("scriptId", entry->script_id());
if (entry->line_number()) {
value->SetInteger("lineNumber", entry->line_number() - 1);
}
if (entry->column_number()) {
value->SetInteger("columnNumber", entry->column_number() - 1);
}
value->EndDictionary();
value->SetInteger("id", node->id());
if (node->parent()) {
value->SetInteger("parent", node->parent()->id());
}
const char* deopt_reason = entry->bailout_reason();
if (deopt_reason && deopt_reason[0] && strcmp(deopt_reason, "no reason")) {
value->SetString("deoptReason", deopt_reason);
}
}
} // namespace
void CpuProfile::StreamPendingTraceEvents() {
std::vector<const ProfileNode*> pending_nodes = top_down_.TakePendingNodes();
if (pending_nodes.empty() && !samples_.length()) return;
auto value = TracedValue::Create();
if (!pending_nodes.empty()) {
value->BeginArray("nodes");
for (auto node : pending_nodes) {
value->BeginDictionary();
BuildNodeValue(node, value.get());
value->EndDictionary();
}
value->EndArray();
}
if (streaming_next_sample_ != samples_.length()) {
value->BeginArray("samples");
for (int i = streaming_next_sample_; i < samples_.length(); ++i) {
value->AppendInteger(samples_[i]->id());
}
value->EndArray();
value->BeginArray("timeDeltas");
base::TimeTicks lastTimestamp =
streaming_next_sample_ ? timestamps_[streaming_next_sample_ - 1]
: start_time();
for (int i = streaming_next_sample_; i < timestamps_.length(); ++i) {
value->AppendInteger(
static_cast<int>((timestamps_[i] - lastTimestamp).InMicroseconds()));
lastTimestamp = timestamps_[i];
}
value->EndArray();
DCHECK(samples_.length() == timestamps_.length());
streaming_next_sample_ = samples_.length();
}
TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"),
"CpuProfileChunk", this, "data",
std::move(value));
}
void CpuProfile::FinishProfile() {
end_time_ = base::TimeTicks::HighResolutionNow();
StreamPendingTraceEvents();
auto value = TracedValue::Create();
value->SetDouble("endTime", (end_time_ - base::TimeTicks()).InMicroseconds());
TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"),
"CpuProfileChunk", this, "data",
std::move(value));
}
void CpuProfile::Print() {
@ -504,7 +595,7 @@ bool CpuProfilesCollection::StartProfiling(const char* title,
CpuProfile* CpuProfilesCollection::StopProfiling(const char* title) {
const int title_len = StrLength(title);
CpuProfile* profile = NULL;
CpuProfile* profile = nullptr;
current_profiles_semaphore_.Wait();
for (int i = current_profiles_.length() - 1; i >= 0; --i) {
if (title_len == 0 || strcmp(current_profiles_[i]->title(), title) == 0) {
@ -514,8 +605,8 @@ CpuProfile* CpuProfilesCollection::StopProfiling(const char* title) {
}
current_profiles_semaphore_.Signal();
if (profile == NULL) return NULL;
profile->CalculateTotalTicksAndSamplingRate();
if (!profile) return nullptr;
profile->FinishProfile();
finished_profiles_.Add(profile);
return profile;
}

17
src/profiler/profile-generator.h
View File

@ -183,7 +183,7 @@ class ProfileTree;
class ProfileNode {
public:
inline ProfileNode(ProfileTree* tree, CodeEntry* entry);
inline ProfileNode(ProfileTree* tree, CodeEntry* entry, ProfileNode* parent);
ProfileNode* FindChild(CodeEntry* entry);
ProfileNode* FindOrAddChild(CodeEntry* entry);
@ -196,6 +196,7 @@ class ProfileNode {
const List<ProfileNode*>* children() const { return &children_list_; }
unsigned id() const { return id_; }
unsigned function_id() const;
ProfileNode* parent() const { return parent_; }
unsigned int GetHitLineCount() const { return line_ticks_.occupancy(); }
bool GetLineTicks(v8::CpuProfileNode::LineTick* entries,
unsigned int length) const;
@ -223,6 +224,7 @@ class ProfileNode {
// Mapping from CodeEntry* to ProfileNode*
base::CustomMatcherHashMap children_;
List<ProfileNode*> children_list_;
ProfileNode* parent_;
unsigned id_;
base::CustomMatcherHashMap line_ticks_;
@ -251,10 +253,18 @@ class ProfileTree {
Isolate* isolate() const { return isolate_; }
void EnqueueNode(const ProfileNode* node) { pending_nodes_.push_back(node); }
size_t pending_nodes_count() const { return pending_nodes_.size(); }
std::vector<const ProfileNode*> TakePendingNodes() {
return std::move(pending_nodes_);
}
private:
template <typename Callback>
void TraverseDepthFirst(Callback* callback);
std::vector<const ProfileNode*> pending_nodes_;
CodeEntry root_entry_;
unsigned next_node_id_;
ProfileNode* root_;
@ -274,7 +284,7 @@ class CpuProfile {
// Add pc -> ... -> main() call path to the profile.
void AddPath(base::TimeTicks timestamp, const std::vector<CodeEntry*>& path,
int src_line, bool update_stats);
void CalculateTotalTicksAndSamplingRate();
void FinishProfile();
const char* title() const { return title_; }
const ProfileTree* top_down() const { return &top_down_; }
@ -294,6 +304,8 @@ class CpuProfile {
void Print();
private:
void StreamPendingTraceEvents();
const char* title_;
bool record_samples_;
base::TimeTicks start_time_;
@ -302,6 +314,7 @@ class CpuProfile {
List<base::TimeTicks> timestamps_;
ProfileTree top_down_;
CpuProfiler* const profiler_;
int streaming_next_sample_;
DISALLOW_COPY_AND_ASSIGN(CpuProfile);
};

57
src/profiler/tracing-cpu-profiler.cc
View File

@ -4,8 +4,13 @@
#include "src/profiler/tracing-cpu-profiler.h"
#include "src/profiler/cpu-profiler.h"
#include "src/tracing/trace-event.h"
#include "src/v8.h"
#define PROFILER_TRACE_CATEGORY_ENABLED(cat) \
(*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(TRACE_DISABLED_BY_DEFAULT(cat)))
namespace v8 {
std::unique_ptr<TracingCpuProfiler> TracingCpuProfiler::Create(
@ -17,9 +22,57 @@ std::unique_ptr<TracingCpuProfiler> TracingCpuProfiler::Create(
namespace internal {
TracingCpuProfilerImpl::TracingCpuProfilerImpl(Isolate* isolate) {}
TracingCpuProfilerImpl::TracingCpuProfilerImpl(Isolate* isolate)
: isolate_(isolate), profiling_enabled_(false) {
// Make sure tracing system notices profiler categories.
PROFILER_TRACE_CATEGORY_ENABLED("v8.cpu_profiler");
PROFILER_TRACE_CATEGORY_ENABLED("v8.cpu_profiler.hires");
V8::GetCurrentPlatform()->AddTraceStateObserver(this);
}
TracingCpuProfilerImpl::~TracingCpuProfilerImpl() {}
TracingCpuProfilerImpl::~TracingCpuProfilerImpl() {
StopProfiling();
V8::GetCurrentPlatform()->RemoveTraceStateObserver(this);
}
void TracingCpuProfilerImpl::OnTraceEnabled() {
if (!PROFILER_TRACE_CATEGORY_ENABLED("v8.cpu_profiler")) return;
profiling_enabled_ = true;
isolate_->RequestInterrupt(
[](v8::Isolate*, void* data) {
reinterpret_cast<TracingCpuProfilerImpl*>(data)->StartProfiling();
},
this);
}
void TracingCpuProfilerImpl::OnTraceDisabled() {
base::LockGuard<base::Mutex> lock(&mutex_);
if (!profiling_enabled_) return;
profiling_enabled_ = false;
isolate_->RequestInterrupt(
[](v8::Isolate*, void* data) {
reinterpret_cast<TracingCpuProfilerImpl*>(data)->StopProfiling();
},
this);
}
void TracingCpuProfilerImpl::StartProfiling() {
base::LockGuard<base::Mutex> lock(&mutex_);
if (!profiling_enabled_ || profiler_) return;
int sampling_interval_us =
PROFILER_TRACE_CATEGORY_ENABLED("v8.cpu_profiler.hires") ? 100 : 1000;
profiler_.reset(new CpuProfiler(isolate_));
profiler_->set_sampling_interval(
base::TimeDelta::FromMicroseconds(sampling_interval_us));
profiler_->StartProfiling("", true);
}
void TracingCpuProfilerImpl::StopProfiling() {
base::LockGuard<base::Mutex> lock(&mutex_);
if (!profiler_) return;
profiler_->StopProfiling("");
profiler_.reset();
}
} // namespace internal
} // namespace v8

21
src/profiler/tracing-cpu-profiler.h
View File

@ -5,18 +5,37 @@
#ifndef V8_PROFILER_TRACING_CPU_PROFILER_H
#define V8_PROFILER_TRACING_CPU_PROFILER_H
#include "include/v8-platform.h"
#include "include/v8-profiler.h"
#include "src/base/atomic-utils.h"
#include "src/base/macros.h"
#include "src/base/platform/mutex.h"
namespace v8 {
namespace internal {
class TracingCpuProfilerImpl final : public TracingCpuProfiler {
class CpuProfiler;
class Isolate;
class TracingCpuProfilerImpl final : public TracingCpuProfiler,
private v8::Platform::TraceStateObserver {
public:
explicit TracingCpuProfilerImpl(Isolate*);
~TracingCpuProfilerImpl();
// v8::Platform::TraceStateObserver
void OnTraceEnabled() final;
void OnTraceDisabled() final;
private:
void StartProfiling();
void StopProfiling();
Isolate* isolate_;
std::unique_ptr<CpuProfiler> profiler_;
bool profiling_enabled_;
base::Mutex mutex_;
DISALLOW_COPY_AND_ASSIGN(TracingCpuProfilerImpl);
};

79
test/cctest/test-cpu-profiler.cc
View File

@ -38,6 +38,9 @@
#include "test/cctest/cctest.h"
#include "test/cctest/profiler-extension.h"
#include "include/libplatform/v8-tracing.h"
#include "src/tracing/trace-event.h"
using i::CodeEntry;
using i::CpuProfile;
using i::CpuProfiler;
@ -2098,3 +2101,79 @@ TEST(DeoptUntrackedFunction) {
iprofiler->DeleteProfile(iprofile);
}
using v8::platform::tracing::TraceBuffer;
using v8::platform::tracing::TraceConfig;
using v8::platform::tracing::TraceObject;
namespace {
class CpuProfileEventChecker : public v8::platform::tracing::TraceWriter {
public:
void AppendTraceEvent(TraceObject* trace_event) override {
if (trace_event->name() != std::string("CpuProfile") &&
trace_event->name() != std::string("CpuProfileChunk"))
return;
CHECK(!profile_id_ || trace_event->id() == profile_id_);
CHECK_EQ(1, trace_event->num_args());
CHECK_EQ(TRACE_VALUE_TYPE_CONVERTABLE, trace_event->arg_types()[0]);
profile_id_ = trace_event->id();
v8::ConvertableToTraceFormat* arg =
trace_event->arg_convertables()[0].get();
arg->AppendAsTraceFormat(&result_json_);
}
void Flush() override {}
std::string result_json() const { return result_json_; }
private:
std::string result_json_;
uint64_t profile_id_ = 0;
};
} // namespace
TEST(TracingCpuProfiler) {
v8::Platform* old_platform = i::V8::GetCurrentPlatform();
v8::Platform* default_platform = v8::platform::CreateDefaultPlatform();
i::V8::SetPlatformForTesting(default_platform);
v8::platform::tracing::TracingController tracing_controller;
v8::platform::SetTracingController(default_platform, &tracing_controller);
CpuProfileEventChecker* event_checker = new CpuProfileEventChecker();
TraceBuffer* ring_buffer =
TraceBuffer::CreateTraceBufferRingBuffer(1, event_checker);
tracing_controller.Initialize(ring_buffer);
TraceConfig* trace_config = new TraceConfig();
trace_config->AddIncludedCategory(
TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"));
LocalContext env;
v8::HandleScope scope(env->GetIsolate());
{
tracing_controller.StartTracing(trace_config);
auto profiler = v8::TracingCpuProfiler::Create(env->GetIsolate());
CompileRun("function foo() { } foo();");
tracing_controller.StopTracing();
CompileRun("function bar() { } bar();");
}
const char* profile_checker =
"function checkProfile(profile) {\n"
" if (typeof profile['startTime'] !== 'number') return 'startTime';\n"
" return '';\n"
"}\n"
"checkProfile(";
std::string profile_json = event_checker->result_json();
CHECK_LT(0u, profile_json.length());
printf("Profile JSON: %s\n", profile_json.c_str());
std::string code = profile_checker + profile_json + ")";
v8::Local<v8::Value> result =
CompileRunChecked(CcTest::isolate(), code.c_str());
v8::String::Utf8Value value(result);
printf("Check result: %*s\n", value.length(), *value);
CHECK_EQ(0, value.length());
i::V8::SetPlatformForTesting(old_platform);
}