[profiler] opt-in tracing setting

CpuProfiler includes logic tracing that is only relevant in
the context of TracingCpuProfiler.
Adds a setting to disable tracing for SamplingCpuProfiler.

Change-Id: Idcac03dd3f368b5fcd48a532d5cfe60966a64003
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/3433219
Auto-Submit: Corentin Pescheloche <cpescheloche@fb.com>
Reviewed-by: Camillo Bruni <cbruni@chromium.org>
Commit-Queue: Camillo Bruni <cbruni@chromium.org>
Cr-Commit-Position: refs/heads/main@{#79190}
This commit is contained in:
Corentin Pescheloche 2022-02-04 13:38:28 -08:00 committed by V8 LUCI CQ
parent 50ccf21d13
commit 38db63b2b8
5 changed files with 135 additions and 30 deletions

View File

@ -306,15 +306,19 @@ class V8_EXPORT CpuProfilingOptions {
* the profiler's sampling interval. * the profiler's sampling interval.
* \param filter_context If specified, profiles will only contain frames * \param filter_context If specified, profiles will only contain frames
* using this context. Other frames will be elided. * using this context. Other frames will be elided.
* \param enable_tracing Controls if profiles will log samples as traces
* events. Defaults to true.
*/ */
CpuProfilingOptions( CpuProfilingOptions(
CpuProfilingMode mode = kLeafNodeLineNumbers, CpuProfilingMode mode = kLeafNodeLineNumbers,
unsigned max_samples = kNoSampleLimit, int sampling_interval_us = 0, unsigned max_samples = kNoSampleLimit, int sampling_interval_us = 0,
MaybeLocal<Context> filter_context = MaybeLocal<Context>()); MaybeLocal<Context> filter_context = MaybeLocal<Context>(),
bool enable_tracing = true);
CpuProfilingMode mode() const { return mode_; } CpuProfilingMode mode() const { return mode_; }
unsigned max_samples() const { return max_samples_; } unsigned max_samples() const { return max_samples_; }
int sampling_interval_us() const { return sampling_interval_us_; } int sampling_interval_us() const { return sampling_interval_us_; }
bool enable_tracing() const { return enable_tracing_; }
private: private:
friend class internal::CpuProfile; friend class internal::CpuProfile;
@ -326,6 +330,7 @@ class V8_EXPORT CpuProfilingOptions {
unsigned max_samples_; unsigned max_samples_;
int sampling_interval_us_; int sampling_interval_us_;
CopyablePersistentTraits<Context>::CopyablePersistent filter_context_; CopyablePersistentTraits<Context>::CopyablePersistent filter_context_;
bool enable_tracing_;
}; };
/** /**

View File

@ -9873,10 +9873,12 @@ CpuProfiler* CpuProfiler::New(Isolate* isolate,
CpuProfilingOptions::CpuProfilingOptions(CpuProfilingMode mode, CpuProfilingOptions::CpuProfilingOptions(CpuProfilingMode mode,
unsigned max_samples, unsigned max_samples,
int sampling_interval_us, int sampling_interval_us,
MaybeLocal<Context> filter_context) MaybeLocal<Context> filter_context,
bool enable_tracing)
: mode_(mode), : mode_(mode),
max_samples_(max_samples), max_samples_(max_samples),
sampling_interval_us_(sampling_interval_us) { sampling_interval_us_(sampling_interval_us),
enable_tracing_(enable_tracing) {
if (!filter_context.IsEmpty()) { if (!filter_context.IsEmpty()) {
Local<Context> local_filter_context = filter_context.ToLocalChecked(); Local<Context> local_filter_context = filter_context.ToLocalChecked();
filter_context_.Reset(local_filter_context->GetIsolate(), filter_context_.Reset(local_filter_context->GetIsolate(),

View File

@ -463,11 +463,14 @@ class DeleteNodesCallback {
void AfterChildTraversed(ProfileNode*, ProfileNode*) { } void AfterChildTraversed(ProfileNode*, ProfileNode*) { }
}; };
ProfileTree::ProfileTree(Isolate* isolate, CodeEntryStorage* storage) ProfileTree::ProfileTree(Isolate* isolate, CodeEntryStorage* storage,
: next_node_id_(1), bool stream_nodes)
: pending_nodes_(0),
next_node_id_(1),
isolate_(isolate), isolate_(isolate),
code_entries_(storage), code_entries_(storage),
root_(new ProfileNode(this, CodeEntry::root_entry(), nullptr)) {} root_(new ProfileNode(this, CodeEntry::root_entry(), nullptr)),
stream_nodes_(stream_nodes) {}
ProfileTree::~ProfileTree() { ProfileTree::~ProfileTree() {
DeleteNodesCallback cb; DeleteNodesCallback cb;
@ -579,19 +582,22 @@ CpuProfile::CpuProfile(CpuProfiler* profiler, const char* title,
options_(options), options_(options),
delegate_(std::move(delegate)), delegate_(std::move(delegate)),
start_time_(base::TimeTicks::Now()), start_time_(base::TimeTicks::Now()),
top_down_(profiler->isolate(), profiler->code_entries()), top_down_(profiler->isolate(), profiler->code_entries(),
options_.enable_tracing()),
profiler_(profiler), profiler_(profiler),
streaming_next_sample_(0), streaming_next_sample_(0),
id_(++last_id_) { id_(++last_id_) {
// The startTime timestamp is not converted to Perfetto's clock domain and if (options.enable_tracing()) {
// will get out of sync with other timestamps Perfetto knows about, including // The startTime timestamp is not converted to Perfetto's clock domain and
// the automatic trace event "ts" timestamp. startTime is included for // will get out of sync with other timestamps Perfetto knows about,
// backward compatibility with the tracing protocol but the value of "ts" // including the automatic trace event "ts" timestamp. startTime is included
// should be used instead (it is recorded nearly immediately after). // for backward compatibility with the tracing protocol but the value of
auto value = TracedValue::Create(); // "ts" should be used instead (it is recorded nearly immediately after).
value->SetDouble("startTime", start_time_.since_origin().InMicroseconds()); auto value = TracedValue::Create();
TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"), value->SetDouble("startTime", start_time_.since_origin().InMicroseconds());
"Profile", id_, "data", std::move(value)); TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"),
"Profile", id_, "data", std::move(value));
}
DisallowHeapAllocation no_gc; DisallowHeapAllocation no_gc;
if (options_.has_filter_context()) { if (options_.has_filter_context()) {
@ -687,6 +693,7 @@ void BuildNodeValue(const ProfileNode* node, TracedValue* value) {
} // namespace } // namespace
void CpuProfile::StreamPendingTraceEvents() { void CpuProfile::StreamPendingTraceEvents() {
if (!options_.enable_tracing()) return;
std::vector<const ProfileNode*> pending_nodes = top_down_.TakePendingNodes(); std::vector<const ProfileNode*> pending_nodes = top_down_.TakePendingNodes();
if (pending_nodes.empty() && samples_.empty()) return; if (pending_nodes.empty() && samples_.empty()) return;
auto value = TracedValue::Create(); auto value = TracedValue::Create();
@ -750,20 +757,23 @@ void CpuProfile::StreamPendingTraceEvents() {
} }
void CpuProfile::FinishProfile() { void CpuProfile::FinishProfile() {
end_time_ = base::TimeTicks::Now();
// Stop tracking context movements after profiling stops. // Stop tracking context movements after profiling stops.
context_filter_.set_native_context_address(kNullAddress); context_filter_.set_native_context_address(kNullAddress);
StreamPendingTraceEvents(); if (options_.enable_tracing()) {
auto value = TracedValue::Create(); end_time_ = base::TimeTicks::Now();
// The endTime timestamp is not converted to Perfetto's clock domain and will StreamPendingTraceEvents();
// get out of sync with other timestamps Perfetto knows about, including the auto value = TracedValue::Create();
// automatic trace event "ts" timestamp. endTime is included for backward // The endTime timestamp is not converted to Perfetto's clock domain and
// compatibility with the tracing protocol: its presence in "data" is used by // will get out of sync with other timestamps Perfetto knows about,
// devtools to identify the last ProfileChunk but the value of "ts" should be // including the automatic trace event "ts" timestamp. endTime is included
// used instead (it is recorded nearly immediately after). // for backward compatibility with the tracing protocol: its presence in
value->SetDouble("endTime", end_time_.since_origin().InMicroseconds()); // "data" is used by devtools to identify the last ProfileChunk but the
TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"), // value of "ts" should be used instead (it is recorded nearly immediately
"ProfileChunk", id_, "data", std::move(value)); // after).
value->SetDouble("endTime", end_time_.since_origin().InMicroseconds());
TRACE_EVENT_SAMPLE_WITH_ID1(TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"),
"ProfileChunk", id_, "data", std::move(value));
}
} }
void CpuProfile::Print() const { void CpuProfile::Print() const {

View File

@ -355,7 +355,8 @@ class CodeEntryStorage;
class V8_EXPORT_PRIVATE ProfileTree { class V8_EXPORT_PRIVATE ProfileTree {
public: public:
explicit ProfileTree(Isolate* isolate, CodeEntryStorage* storage = nullptr); explicit ProfileTree(Isolate* isolate, CodeEntryStorage* storage = nullptr,
bool stream_nodes = true);
~ProfileTree(); ~ProfileTree();
ProfileTree(const ProfileTree&) = delete; ProfileTree(const ProfileTree&) = delete;
ProfileTree& operator=(const ProfileTree&) = delete; ProfileTree& operator=(const ProfileTree&) = delete;
@ -378,7 +379,9 @@ class V8_EXPORT_PRIVATE ProfileTree {
Isolate* isolate() const { return isolate_; } Isolate* isolate() const { return isolate_; }
void EnqueueNode(const ProfileNode* node) { pending_nodes_.push_back(node); } void EnqueueNode(const ProfileNode* node) {
if (stream_nodes_) pending_nodes_.push_back(node);
}
size_t pending_nodes_count() const { return pending_nodes_.size(); } size_t pending_nodes_count() const { return pending_nodes_.size(); }
std::vector<const ProfileNode*> TakePendingNodes() { std::vector<const ProfileNode*> TakePendingNodes() {
return std::move(pending_nodes_); return std::move(pending_nodes_);
@ -396,6 +399,7 @@ class V8_EXPORT_PRIVATE ProfileTree {
Isolate* isolate_; Isolate* isolate_;
CodeEntryStorage* const code_entries_; CodeEntryStorage* const code_entries_;
ProfileNode* root_; ProfileNode* root_;
bool stream_nodes_;
}; };
class CpuProfiler; class CpuProfiler;

View File

@ -2996,6 +2996,90 @@ TEST(TracingCpuProfiler) {
#endif // !V8_USE_PERFETTO #endif // !V8_USE_PERFETTO
} }
TEST(DisableTracing) {
v8::HandleScope scope(CcTest::isolate());
v8::Local<v8::Context> env = CcTest::NewContext({PROFILER_EXTENSION_ID});
v8::Context::Scope context_scope(env);
auto* tracing_controller =
static_cast<v8::platform::tracing::TracingController*>(
i::V8::GetCurrentPlatform()->GetTracingController());
// Event checks throws if events are received from multiple ID
#ifdef V8_USE_PERFETTO
std::ostringstream perfetto_output;
tracing_controller->InitializeForPerfetto(&perfetto_output);
CpuProfilerListener listener;
tracing_controller->SetTraceEventListenerForTesting(&listener);
#else
CpuProfileEventChecker* event_checker = new CpuProfileEventChecker();
TraceBuffer* ring_buffer =
TraceBuffer::CreateTraceBufferRingBuffer(1, event_checker);
tracing_controller->Initialize(ring_buffer);
#endif
i::Isolate* isolate = CcTest::i_isolate();
CodeEntryStorage storage;
CpuProfilesCollection* profiles = new CpuProfilesCollection(isolate);
ProfilerCodeObserver* code_observer =
new ProfilerCodeObserver(isolate, storage);
CpuProfiler profiler(isolate, kDebugNaming, kEagerLogging, profiles, nullptr,
nullptr, code_observer);
TraceConfig* trace_config = new TraceConfig();
trace_config->AddIncludedCategory(
TRACE_DISABLED_BY_DEFAULT("v8.cpu_profiler"));
tracing_controller->StartTracing(trace_config);
#ifdef V8_USE_PERFETTO
TrackEvent::Flush();
#endif
// Start Non tracing profiler configured no to log events in tracing system
CpuProfilingOptions options(kLeafNodeLineNumbers, 0, 0,
MaybeLocal<v8::Context>(), false);
profiler.StartProfiling("test", options);
CompileRun(
"function some_func() {}"
"some_func();");
profiler.StopProfiling("test");
#ifdef V8_USE_PERFETTO
std::string profile_json = listener.result_json();
listener.Reset();
#else
tracing_controller->StopTracing();
std::string profile_json = event_checker->result_json();
event_checker->Reset();
#endif
CHECK_LT(0u, profile_json.length());
printf("Profile JSON: %s\n", profile_json.c_str());
std::string profile_checker_code = R"(
function checkProfile(json) {
const profile_header = json[0];
if (typeof profile_header['startTime'] !== 'number')
return false;
return json.some(event => (event.lines || []).some(line => line)) &&
json.filter(e => e.cpuProfile && e.cpuProfile.nodes)
.some(e => e.cpuProfile.nodes
.some(n => n.callFrame.codeType == "JS"));
}
checkProfile()" + profile_json +
")";
CompileRunChecked(CcTest::isolate(), profile_checker_code.c_str())->IsTrue();
#ifndef V8_USE_PERFETTO
static_cast<v8::platform::tracing::TracingController*>(
i::V8::GetCurrentPlatform()->GetTracingController())
->Initialize(nullptr);
#endif // !V8_USE_PERFETTO
}
TEST(Issue763073) { TEST(Issue763073) {
class AllowNativesSyntax { class AllowNativesSyntax {
public: public: