v8/include/libplatform/v8-tracing.h

Ignoring revisions in .git-blame-ignore-revs. Click here to bypass and see the normal blame view.

335 lines
11 KiB
C
Raw Normal View History

// 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_LIBPLATFORM_V8_TRACING_H_
#define V8_LIBPLATFORM_V8_TRACING_H_
[tracing] Fix races in TracingController implementation The default TracingController (used by d8 and Node) has some concurrency issues. The new test flushes these out, when a second thread logs trace events while the main thread calls StopTracing(). - Use an acquire load in UpdateCategoryGroupEnabledFlags() because this was racing with GetCategoryGroupEnabled() where a new category is added in the slow path. g_category_groups is append-only, but reads/writes to g_category_index need to be correctly ordered so that new categories are added and only then is the change to the index visible. The relaxed load ignored this and caused unsynchronized read/write. - Use a relaxed load in ~ScopedTracer() to access category_group_enabled as this previously used a non-atomic operation which caused a race with UpdateCategoryGroupEnabledFlag() which does a relaxed store. - Replace TracingController::mode_ with an atomic bool as read/writes to mode_ were not synchronized and caused TSAN errors. It only has two states and it doesn't seem like we will extend this so just convert it to bool. - Take the lock around calling trace_object->Initialize in AddTraceEvent(), and around trace_buffer_->Flush() in StopTracing(). These two raced previously as the underlying TraceBufferRingBuffer passes out pointers to TraceObjects in a synchronized way, but the caller (AddTraceEvent) then writes into the object without synchronization. This leads to races when Flush() is called, at which time TraceBufferRingBuffer assumes that all the pointers it handed out are to valid, initialized TraceObjects - which is not true because AddTraceEvent may still be calling Initialize on them. This could be the cause of issues in Node.js where the last line of tracing/logging sometimes gets cut off. This is kind of a band-aid solution - access to the TraceObjects handed out by the ring buffer really needs proper synchronization which at this point would require redesign. It's quite likely we will replace this with Perfetto in the near future so not much point investing in this code right now. - Enable TracingCpuProfiler test which was flaky due to these bugs. Bug: v8:8821 Change-Id: I141296800c6906ac0e7f3f21dd16d861b07dae62 Reviewed-on: https://chromium-review.googlesource.com/c/1477283 Commit-Queue: Peter Marshall <petermarshall@chromium.org> Reviewed-by: Yang Guo <yangguo@chromium.org> Reviewed-by: Ali Ijaz Sheikh <ofrobots@google.com> Cr-Commit-Position: refs/heads/master@{#59752}
2019-02-20 09:02:06 +00:00
#include <atomic>
#include <fstream>
#include <memory>
#include <unordered_set>
#include <vector>
#include "libplatform/libplatform-export.h"
#include "v8-platform.h" // NOLINT(build/include_directory)
namespace perfetto {
namespace trace_processor {
class TraceProcessorStorage;
}
class TracingSession;
}
namespace v8 {
namespace base {
class Mutex;
} // namespace base
namespace platform {
namespace tracing {
[tracing] Add a way to test perfetto traces. Add a new abstract class TraceEventListener which is just an interface for consuming trace events. This separates the V8-specific stuff that an actual perfetto consumer needs to do e.g. handling the has_more flag and signalling back to the controller with a semaphore. This is a change from the previous plan of making the PerfettoConsumer class sub-classable to implement custom consumption of trace events. This will be difficult when the consumer is created outside of the PerfettoTracingController as we can't hook up the consumer_finished_semaphore_ that belongs to the controller. Now the PerfettoTracingController is responsible for the Consumer life- cycle and hides it entirely from callers. We add the AddTraceEventListener() method to allow callers to register a listener either for testing or a JSON listener for real tracing. This lets us write tests that can store all the trace events in memory without first converting them to JSON, letting us write test more easily. There's an example test add to test-tracing - more tests using this style will follow. Cq-Include-Trybots: luci.v8.try:v8_linux64_perfetto_dbg_ng Bug: v8:8339 Change-Id: I2d2b0f408b1c7bed954144163e1968f40d772c1b Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1628789 Commit-Queue: Ulan Degenbaev <ulan@chromium.org> Auto-Submit: Peter Marshall <petermarshall@chromium.org> Reviewed-by: Ulan Degenbaev <ulan@chromium.org> Reviewed-by: Jakob Gruber <jgruber@chromium.org> Cr-Commit-Position: refs/heads/master@{#61854}
2019-05-27 12:46:35 +00:00
class TraceEventListener;
const int kTraceMaxNumArgs = 2;
class V8_PLATFORM_EXPORT TraceObject {
public:
union ArgValue {
V8_DEPRECATED("use as_uint ? true : false") bool as_bool;
uint64_t as_uint;
int64_t as_int;
double as_double;
const void* as_pointer;
const char* as_string;
};
TraceObject() = default;
~TraceObject();
void Initialize(
char phase, const uint8_t* category_enabled_flag, const char* name,
const char* scope, uint64_t id, uint64_t bind_id, int num_args,
const char** arg_names, const uint8_t* arg_types,
const uint64_t* arg_values,
std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables,
unsigned int flags, int64_t timestamp, int64_t cpu_timestamp);
void UpdateDuration(int64_t timestamp, int64_t cpu_timestamp);
void InitializeForTesting(
char phase, const uint8_t* category_enabled_flag, const char* name,
const char* scope, uint64_t id, uint64_t bind_id, int num_args,
const char** arg_names, const uint8_t* arg_types,
const uint64_t* arg_values,
std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables,
unsigned int flags, int pid, int tid, int64_t ts, int64_t tts,
uint64_t duration, uint64_t cpu_duration);
int pid() const { return pid_; }
int tid() const { return tid_; }
char phase() const { return phase_; }
const uint8_t* category_enabled_flag() const {
return category_enabled_flag_;
}
const char* name() const { return name_; }
const char* scope() const { return scope_; }
uint64_t id() const { return id_; }
uint64_t bind_id() const { return bind_id_; }
int num_args() const { return num_args_; }
const char** arg_names() { return arg_names_; }
uint8_t* arg_types() { return arg_types_; }
ArgValue* arg_values() { return arg_values_; }
std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables() {
return arg_convertables_;
}
unsigned int flags() const { return flags_; }
int64_t ts() { return ts_; }
int64_t tts() { return tts_; }
uint64_t duration() { return duration_; }
uint64_t cpu_duration() { return cpu_duration_; }
private:
int pid_;
int tid_;
char phase_;
const char* name_;
const char* scope_;
const uint8_t* category_enabled_flag_;
uint64_t id_;
uint64_t bind_id_;
int num_args_ = 0;
const char* arg_names_[kTraceMaxNumArgs];
uint8_t arg_types_[kTraceMaxNumArgs];
ArgValue arg_values_[kTraceMaxNumArgs];
std::unique_ptr<v8::ConvertableToTraceFormat>
arg_convertables_[kTraceMaxNumArgs];
char* parameter_copy_storage_ = nullptr;
unsigned int flags_;
int64_t ts_;
int64_t tts_;
uint64_t duration_;
uint64_t cpu_duration_;
// Disallow copy and assign
TraceObject(const TraceObject&) = delete;
void operator=(const TraceObject&) = delete;
};
class V8_PLATFORM_EXPORT TraceWriter {
public:
TraceWriter() = default;
virtual ~TraceWriter() = default;
virtual void AppendTraceEvent(TraceObject* trace_event) = 0;
virtual void Flush() = 0;
static TraceWriter* CreateJSONTraceWriter(std::ostream& stream);
static TraceWriter* CreateJSONTraceWriter(std::ostream& stream,
const std::string& tag);
Step 1 (of 3-ish): Basic ETW Instrumentation in V8 Design doc: https://docs.google.com/document/d/1xkXj94iExFgLWc_OszTNyNGi523ARaKMWPZTeomhI4U A lot has changed since the last patchset! I recommend revisiting this design doc and reading the parts in green. I explain the roadmap for what changes to expect from ETW instrumentation as well as the instrumentation of this particular CL. I'll do my best to answer any further questions anyone has about my particular instrumentation or ETW in general :) --- This is the first of a series of changelists to round out ETW instrumentation for V8. This changelist represents the most minimal change needed to instrument ETW in V8. In particular, it: - defines and registers the ETW provider, - interacts minimally with the rest of V8, by hooking into the existing TracingController::AddTraceEvent function, - is designed with a platform-agnostic layer, so that event tracers for other platforms can be instrumented in teh future. Some notes on instrumentation (aka I copied stuff from the design doc): We make heavy use of the TraceLogging API to log events. It differs from previous methods of emitting ETW events in that it doesn<E2><80><99>t require the overhead of a separate manifest file to keep track of metadata; rather, events using this API are self-descriptive. Here are the five major steps to instrument the TraceLogging API: - Forward declare the provider (from provider-win.h) - Define the provider in a .cc file (from provider-win.cc) - Register the provider (called from v8.cc). - Write events (called from libplatform/tracing-controller.cc) - Unregister the provider (called from v8.cc) At the base, we have an abstract provider class that encapsulates the functionality of an event provider. These are things like registering and unregistering the provider, and the actual event-logging. The provider class is split into provider-win and provider-mac (currently not instantiated) classes, with OS-dependent implementations of the above functions. In particular, the TraceLogging API is used only in provider-win. It is here that we forward declare and define the provider, as well as write ETW events. Finally, there is a v8-provider class that serves as a top-level API and is exposed to the rest of V8. It acts as a wrapper for the platform-specific providers. The .wprp file is needed so that Windows Performance Recorder knows how to capture our events. Some considerations: - Is TracingController::AddTraceEvent the best place from which to write my events? - Is src/libplatform/tracing the best place to put my instrumentation? - Right now, I fail the preupload because of this, which tells me my files are probably not in the best location: You added one or more #includes that violate checkdeps rules. src\init\v8.cc Illegal include: "src/libplatform/tracing/v8-provider.h" Because of "-src/libplatform" from src's include_rules. Change-Id: Id53e4a034c9e526524a17000da0a647a95d93edf Bug: v8:11043 Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/2233407 Reviewed-by: Ulan Degenbaev <ulan@chromium.org> Reviewed-by: Peter Marshall <petermarshall@chromium.org> Commit-Queue: Sara Tang <sartang@microsoft.com> Cr-Commit-Position: refs/heads/master@{#71918}
2021-01-05 18:43:34 +00:00
static TraceWriter* CreateSystemInstrumentationTraceWriter();
private:
// Disallow copy and assign
TraceWriter(const TraceWriter&) = delete;
void operator=(const TraceWriter&) = delete;
};
class V8_PLATFORM_EXPORT TraceBufferChunk {
public:
explicit TraceBufferChunk(uint32_t seq);
void Reset(uint32_t new_seq);
bool IsFull() const { return next_free_ == kChunkSize; }
TraceObject* AddTraceEvent(size_t* event_index);
TraceObject* GetEventAt(size_t index) { return &chunk_[index]; }
uint32_t seq() const { return seq_; }
size_t size() const { return next_free_; }
static const size_t kChunkSize = 64;
private:
size_t next_free_ = 0;
TraceObject chunk_[kChunkSize];
uint32_t seq_;
// Disallow copy and assign
TraceBufferChunk(const TraceBufferChunk&) = delete;
void operator=(const TraceBufferChunk&) = delete;
};
class V8_PLATFORM_EXPORT TraceBuffer {
public:
TraceBuffer() = default;
virtual ~TraceBuffer() = default;
virtual TraceObject* AddTraceEvent(uint64_t* handle) = 0;
virtual TraceObject* GetEventByHandle(uint64_t handle) = 0;
virtual bool Flush() = 0;
static const size_t kRingBufferChunks = 1024;
static TraceBuffer* CreateTraceBufferRingBuffer(size_t max_chunks,
TraceWriter* trace_writer);
private:
// Disallow copy and assign
TraceBuffer(const TraceBuffer&) = delete;
void operator=(const TraceBuffer&) = delete;
};
// Options determines how the trace buffer stores data.
enum TraceRecordMode {
// Record until the trace buffer is full.
RECORD_UNTIL_FULL,
// Record until the user ends the trace. The trace buffer is a fixed size
// and we use it as a ring buffer during recording.
RECORD_CONTINUOUSLY,
// Record until the trace buffer is full, but with a huge buffer size.
RECORD_AS_MUCH_AS_POSSIBLE,
// Echo to console. Events are discarded.
ECHO_TO_CONSOLE,
};
class V8_PLATFORM_EXPORT TraceConfig {
public:
typedef std::vector<std::string> StringList;
static TraceConfig* CreateDefaultTraceConfig();
TraceConfig() : enable_systrace_(false), enable_argument_filter_(false) {}
TraceRecordMode GetTraceRecordMode() const { return record_mode_; }
const StringList& GetEnabledCategories() const {
return included_categories_;
}
bool IsSystraceEnabled() const { return enable_systrace_; }
bool IsArgumentFilterEnabled() const { return enable_argument_filter_; }
void SetTraceRecordMode(TraceRecordMode mode) { record_mode_ = mode; }
void EnableSystrace() { enable_systrace_ = true; }
void EnableArgumentFilter() { enable_argument_filter_ = true; }
void AddIncludedCategory(const char* included_category);
bool IsCategoryGroupEnabled(const char* category_group) const;
private:
TraceRecordMode record_mode_;
bool enable_systrace_ : 1;
bool enable_argument_filter_ : 1;
StringList included_categories_;
// Disallow copy and assign
TraceConfig(const TraceConfig&) = delete;
void operator=(const TraceConfig&) = delete;
};
#if defined(_MSC_VER)
#define V8_PLATFORM_NON_EXPORTED_BASE(code) \
__pragma(warning(suppress : 4275)) code
#else
#define V8_PLATFORM_NON_EXPORTED_BASE(code) code
#endif // defined(_MSC_VER)
class V8_PLATFORM_EXPORT TracingController
: public V8_PLATFORM_NON_EXPORTED_BASE(v8::TracingController) {
public:
TracingController();
~TracingController() override;
#if defined(V8_USE_PERFETTO)
// Must be called before StartTracing() if V8_USE_PERFETTO is true. Provides
// the output stream for the JSON trace data.
void InitializeForPerfetto(std::ostream* output_stream);
// Provide an optional listener for testing that will receive trace events.
// Must be called before StartTracing().
void SetTraceEventListenerForTesting(TraceEventListener* listener);
#else // defined(V8_USE_PERFETTO)
// The pointer returned from GetCategoryGroupEnabled() points to a value with
// zero or more of the following bits. Used in this class only. The
// TRACE_EVENT macros should only use the value as a bool. These values must
// be in sync with macro values in TraceEvent.h in Blink.
enum CategoryGroupEnabledFlags {
// Category group enabled for the recording mode.
ENABLED_FOR_RECORDING = 1 << 0,
// Category group enabled by SetEventCallbackEnabled().
ENABLED_FOR_EVENT_CALLBACK = 1 << 2,
// Category group enabled to export events to ETW.
ENABLED_FOR_ETW_EXPORT = 1 << 3
};
// Takes ownership of |trace_buffer|.
void Initialize(TraceBuffer* trace_buffer);
// v8::TracingController implementation.
const uint8_t* GetCategoryGroupEnabled(const char* category_group) override;
uint64_t AddTraceEvent(
char phase, const uint8_t* category_enabled_flag, const char* name,
const char* scope, uint64_t id, uint64_t bind_id, int32_t num_args,
const char** arg_names, const uint8_t* arg_types,
const uint64_t* arg_values,
std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables,
unsigned int flags) override;
uint64_t AddTraceEventWithTimestamp(
char phase, const uint8_t* category_enabled_flag, const char* name,
const char* scope, uint64_t id, uint64_t bind_id, int32_t num_args,
const char** arg_names, const uint8_t* arg_types,
const uint64_t* arg_values,
std::unique_ptr<v8::ConvertableToTraceFormat>* arg_convertables,
unsigned int flags, int64_t timestamp) override;
void UpdateTraceEventDuration(const uint8_t* category_enabled_flag,
const char* name, uint64_t handle) override;
static const char* GetCategoryGroupName(const uint8_t* category_enabled_flag);
#endif // !defined(V8_USE_PERFETTO)
void AddTraceStateObserver(
v8::TracingController::TraceStateObserver* observer) override;
void RemoveTraceStateObserver(
v8::TracingController::TraceStateObserver* observer) override;
void StartTracing(TraceConfig* trace_config);
void StopTracing();
protected:
#if !defined(V8_USE_PERFETTO)
virtual int64_t CurrentTimestampMicroseconds();
virtual int64_t CurrentCpuTimestampMicroseconds();
#endif // !defined(V8_USE_PERFETTO)
private:
#if !defined(V8_USE_PERFETTO)
void UpdateCategoryGroupEnabledFlag(size_t category_index);
void UpdateCategoryGroupEnabledFlags();
#endif // !defined(V8_USE_PERFETTO)
std::unique_ptr<base::Mutex> mutex_;
std::unique_ptr<TraceConfig> trace_config_;
[tracing] Fix races in TracingController implementation The default TracingController (used by d8 and Node) has some concurrency issues. The new test flushes these out, when a second thread logs trace events while the main thread calls StopTracing(). - Use an acquire load in UpdateCategoryGroupEnabledFlags() because this was racing with GetCategoryGroupEnabled() where a new category is added in the slow path. g_category_groups is append-only, but reads/writes to g_category_index need to be correctly ordered so that new categories are added and only then is the change to the index visible. The relaxed load ignored this and caused unsynchronized read/write. - Use a relaxed load in ~ScopedTracer() to access category_group_enabled as this previously used a non-atomic operation which caused a race with UpdateCategoryGroupEnabledFlag() which does a relaxed store. - Replace TracingController::mode_ with an atomic bool as read/writes to mode_ were not synchronized and caused TSAN errors. It only has two states and it doesn't seem like we will extend this so just convert it to bool. - Take the lock around calling trace_object->Initialize in AddTraceEvent(), and around trace_buffer_->Flush() in StopTracing(). These two raced previously as the underlying TraceBufferRingBuffer passes out pointers to TraceObjects in a synchronized way, but the caller (AddTraceEvent) then writes into the object without synchronization. This leads to races when Flush() is called, at which time TraceBufferRingBuffer assumes that all the pointers it handed out are to valid, initialized TraceObjects - which is not true because AddTraceEvent may still be calling Initialize on them. This could be the cause of issues in Node.js where the last line of tracing/logging sometimes gets cut off. This is kind of a band-aid solution - access to the TraceObjects handed out by the ring buffer really needs proper synchronization which at this point would require redesign. It's quite likely we will replace this with Perfetto in the near future so not much point investing in this code right now. - Enable TracingCpuProfiler test which was flaky due to these bugs. Bug: v8:8821 Change-Id: I141296800c6906ac0e7f3f21dd16d861b07dae62 Reviewed-on: https://chromium-review.googlesource.com/c/1477283 Commit-Queue: Peter Marshall <petermarshall@chromium.org> Reviewed-by: Yang Guo <yangguo@chromium.org> Reviewed-by: Ali Ijaz Sheikh <ofrobots@google.com> Cr-Commit-Position: refs/heads/master@{#59752}
2019-02-20 09:02:06 +00:00
std::atomic_bool recording_{false};
std::unordered_set<v8::TracingController::TraceStateObserver*> observers_;
#if defined(V8_USE_PERFETTO)
Reland "[tracing] Add a configurable output stream for perfetto tracing" This is a reland of a03ed626797be8e9424bef58a7dde4415eb9181f Removed the added test which was failing on win32. The test was unrelated to the CL; we can add it later. Original change's description: > [tracing] Add a configurable output stream for perfetto tracing > > Add the ability to provide perfetto with an output stream for the JSON > consumer rather than hardcode it. D8 will use this interface exclusively > once the old trace controller is removed. > > Also add a test for scope-managed trace events and their duration - this > was leftover from a previous CL. > > Cq-Include-Trybots: luci.v8.try:v8_linux64_perfetto_dbg_ng > Bug: v8:8339 > Change-Id: I1c45e17e528b549a4cfdaecabd33c7ac4ab4af77 > Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1611801 > Reviewed-by: Ulan Degenbaev <ulan@chromium.org> > Reviewed-by: Jakob Gruber <jgruber@chromium.org> > Commit-Queue: Peter Marshall <petermarshall@chromium.org> > Cr-Commit-Position: refs/heads/master@{#61753} TBR=jgruber@chromium.org, ulan@chromium.org Bug: v8:8339 Change-Id: I3442a4d111e12947c107e7d0c226ae934acd06e4 Cq-Include-Trybots: luci.v8.try:v8_linux64_perfetto_dbg_ng Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1627334 Reviewed-by: Peter Marshall <petermarshall@chromium.org> Reviewed-by: Ulan Degenbaev <ulan@chromium.org> Commit-Queue: Peter Marshall <petermarshall@chromium.org> Cr-Commit-Position: refs/heads/master@{#61780}
2019-05-23 10:44:11 +00:00
std::ostream* output_stream_ = nullptr;
std::unique_ptr<perfetto::trace_processor::TraceProcessorStorage>
trace_processor_;
[tracing] Add a way to test perfetto traces. Add a new abstract class TraceEventListener which is just an interface for consuming trace events. This separates the V8-specific stuff that an actual perfetto consumer needs to do e.g. handling the has_more flag and signalling back to the controller with a semaphore. This is a change from the previous plan of making the PerfettoConsumer class sub-classable to implement custom consumption of trace events. This will be difficult when the consumer is created outside of the PerfettoTracingController as we can't hook up the consumer_finished_semaphore_ that belongs to the controller. Now the PerfettoTracingController is responsible for the Consumer life- cycle and hides it entirely from callers. We add the AddTraceEventListener() method to allow callers to register a listener either for testing or a JSON listener for real tracing. This lets us write tests that can store all the trace events in memory without first converting them to JSON, letting us write test more easily. There's an example test add to test-tracing - more tests using this style will follow. Cq-Include-Trybots: luci.v8.try:v8_linux64_perfetto_dbg_ng Bug: v8:8339 Change-Id: I2d2b0f408b1c7bed954144163e1968f40d772c1b Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1628789 Commit-Queue: Ulan Degenbaev <ulan@chromium.org> Auto-Submit: Peter Marshall <petermarshall@chromium.org> Reviewed-by: Ulan Degenbaev <ulan@chromium.org> Reviewed-by: Jakob Gruber <jgruber@chromium.org> Cr-Commit-Position: refs/heads/master@{#61854}
2019-05-27 12:46:35 +00:00
TraceEventListener* listener_for_testing_ = nullptr;
std::unique_ptr<perfetto::TracingSession> tracing_session_;
#else // !defined(V8_USE_PERFETTO)
std::unique_ptr<TraceBuffer> trace_buffer_;
#endif // !defined(V8_USE_PERFETTO)
// Disallow copy and assign
TracingController(const TracingController&) = delete;
void operator=(const TracingController&) = delete;
};
#undef V8_PLATFORM_NON_EXPORTED_BASE
} // namespace tracing
} // namespace platform
} // namespace v8
#endif // V8_LIBPLATFORM_V8_TRACING_H_