Skip to content

Commit

Permalink
src: trace_event: secondary storage for metadata
Browse files Browse the repository at this point in the history
Metadata trace-events should be held in secondary storage so that they
can be periodically reemitted. This change establishes the secondary
storage and ensures that events are reemitted on each flush.

Backport-PR-URL: #23700
PR-URL: #20900
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Backport-PR-URL: #23700
  • Loading branch information
ofrobots authored and rvagg committed Nov 28, 2018
1 parent ef72b01 commit 1287c74
Show file tree
Hide file tree
Showing 10 changed files with 98 additions and 37 deletions.
4 changes: 2 additions & 2 deletions src/node.cc
Original file line number Diff line number Diff line change
Expand Up @@ -279,9 +279,9 @@ static struct {
#if NODE_USE_V8_PLATFORM
void Initialize(int thread_pool_size) {
tracing_agent_.reset(new tracing::Agent());
node::tracing::TraceEventHelper::SetAgent(tracing_agent_.get());
auto controller = tracing_agent_->GetTracingController();
controller->AddTraceStateObserver(new NodeTraceStateObserver(controller));
tracing::TraceEventHelper::SetTracingController(controller);
StartTracingAgent();
// Tracing must be initialized before platform threads are created.
platform_ = new NodePlatform(thread_pool_size, controller);
Expand Down Expand Up @@ -2805,7 +2805,7 @@ MultiIsolatePlatform* GetMainThreadMultiIsolatePlatform() {

MultiIsolatePlatform* CreatePlatform(
int thread_pool_size,
TracingController* tracing_controller) {
node::tracing::TracingController* tracing_controller) {
return new NodePlatform(thread_pool_size, tracing_controller);
}

Expand Down
2 changes: 1 addition & 1 deletion src/node_platform.cc
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ using v8::Local;
using v8::Object;
using v8::Platform;
using v8::Task;
using v8::TracingController;
using node::tracing::TracingController;

struct PlatformWorkerData {
TaskQueue<Task>* task_queue;
Expand Down
9 changes: 5 additions & 4 deletions src/node_platform.h
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
#include "libplatform/libplatform.h"
#include "node.h"
#include "node_mutex.h"
#include "tracing/agent.h"
#include "uv.h"

namespace node {
Expand Down Expand Up @@ -126,7 +127,8 @@ class BackgroundTaskRunner : public v8::TaskRunner {

class NodePlatform : public MultiIsolatePlatform {
public:
NodePlatform(int thread_pool_size, v8::TracingController* tracing_controller);
NodePlatform(int thread_pool_size,
node::tracing::TracingController* tracing_controller);
virtual ~NodePlatform() {}

void DrainBackgroundTasks(v8::Isolate* isolate) override;
Expand All @@ -143,7 +145,7 @@ class NodePlatform : public MultiIsolatePlatform {
bool IdleTasksEnabled(v8::Isolate* isolate) override;
double MonotonicallyIncreasingTime() override;
double CurrentClockTimeMillis() override;
v8::TracingController* GetTracingController() override;
node::tracing::TracingController* GetTracingController() override;
bool FlushForegroundTasks(v8::Isolate* isolate) override;

void RegisterIsolate(IsolateData* isolate_data, uv_loop_t* loop) override;
Expand All @@ -161,8 +163,7 @@ class NodePlatform : public MultiIsolatePlatform {
std::unordered_map<v8::Isolate*,
std::shared_ptr<PerIsolatePlatformData>> per_isolate_;


v8::TracingController* tracing_controller_;
node::tracing::TracingController* tracing_controller_;
std::shared_ptr<BackgroundTaskRunner> background_task_runner_;
};

Expand Down
27 changes: 27 additions & 0 deletions src/tracing/agent.cc
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
#include "tracing/agent.h"

#include <string>
#include "trace_event.h"
#include "tracing/node_trace_buffer.h"
#include "debug_utils.h"
#include "env-inl.h"
Expand Down Expand Up @@ -207,9 +208,35 @@ void Agent::AppendTraceEvent(TraceObject* trace_event) {
}

void Agent::Flush(bool blocking) {
for (const auto& event : metadata_events_)
AppendTraceEvent(event.get());

for (const auto& id_writer : writers_)
id_writer.second->Flush(blocking);
}

void TracingController::AddMetadataEvent(
const unsigned char* category_group_enabled,
const char* name,
int num_args,
const char** arg_names,
const unsigned char* arg_types,
const uint64_t* arg_values,
std::unique_ptr<v8::ConvertableToTraceFormat>* convertable_values,
unsigned int flags) {
std::unique_ptr<TraceObject> trace_event(new TraceObject);
trace_event->Initialize(
TRACE_EVENT_PHASE_METADATA, category_group_enabled, name,
node::tracing::kGlobalScope, // scope
node::tracing::kNoId, // id
node::tracing::kNoId, // bind_id
num_args, arg_names, arg_types, arg_values, convertable_values,
TRACE_EVENT_FLAG_NONE,
CurrentTimestampMicroseconds(),
CurrentCpuTimestampMicroseconds());
node::tracing::TraceEventHelper::GetAgent()->AddMetadataEvent(
std::move(trace_event));
}

} // namespace tracing
} // namespace node
15 changes: 15 additions & 0 deletions src/tracing/agent.h
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#include "util.h"
#include "node_mutex.h"

#include <list>
#include <set>
#include <string>
#include <unordered_map>
Expand Down Expand Up @@ -34,6 +35,15 @@ class TracingController : public v8::platform::tracing::TracingController {
int64_t CurrentTimestampMicroseconds() override {
return uv_hrtime() / 1000;
}
void AddMetadataEvent(
const unsigned char* category_group_enabled,
const char* name,
int num_args,
const char** arg_names,
const unsigned char* arg_types,
const uint64_t* arg_values,
std::unique_ptr<v8::ConvertableToTraceFormat>* convertable_values,
unsigned int flags);
};

class AgentWriterHandle {
Expand Down Expand Up @@ -91,6 +101,10 @@ class Agent {

// Writes to all writers registered through AddClient().
void AppendTraceEvent(TraceObject* trace_event);

void AddMetadataEvent(std::unique_ptr<TraceObject> event) {
metadata_events_.push_back(std::move(event));
}
// Flushes all writers registered through AddClient().
void Flush(bool blocking);

Expand Down Expand Up @@ -129,6 +143,7 @@ class Agent {
ConditionVariable initialize_writer_condvar_;
uv_async_t initialize_writer_async_;
std::set<AsyncTraceWriter*> to_be_initialized_;
std::list<std::unique_ptr<TraceObject>> metadata_events_;
};

void AgentWriterHandle::reset() {
Expand Down
14 changes: 9 additions & 5 deletions src/tracing/trace_event.cc
Original file line number Diff line number Diff line change
Expand Up @@ -3,14 +3,18 @@
namespace node {
namespace tracing {

v8::TracingController* g_controller = nullptr;
Agent* g_agent = nullptr;

void TraceEventHelper::SetTracingController(v8::TracingController* controller) {
g_controller = controller;
void TraceEventHelper::SetAgent(Agent* agent) {
g_agent = agent;
}

v8::TracingController* TraceEventHelper::GetTracingController() {
return g_controller;
Agent* TraceEventHelper::GetAgent() {
return g_agent;
}

TracingController* TraceEventHelper::GetTracingController() {
return g_agent->GetTracingController();
}

} // namespace tracing
Expand Down
40 changes: 27 additions & 13 deletions src/tracing/trace_event.h
Original file line number Diff line number Diff line change
Expand Up @@ -310,8 +310,9 @@ const uint64_t kNoId = 0;

class TraceEventHelper {
public:
static v8::TracingController* GetTracingController();
static void SetTracingController(v8::TracingController* controller);
static TracingController* GetTracingController();
static Agent* GetAgent();
static void SetAgent(Agent* agent);
};

// TraceID encapsulates an ID that can either be an integer or pointer. Pointers
Expand Down Expand Up @@ -487,6 +488,26 @@ static V8_INLINE uint64_t AddTraceEventWithTimestampImpl(
arg_names, arg_types, arg_values, arg_convertables, flags, timestamp);
}

static V8_INLINE void AddMetadataEventImpl(
const uint8_t* category_group_enabled, const char* name, int32_t num_args,
const char** arg_names, const uint8_t* arg_types,
const uint64_t* arg_values, unsigned int flags) {
std::unique_ptr<v8::ConvertableToTraceFormat> arg_convertibles[2];
if (num_args > 0 && arg_types[0] == TRACE_VALUE_TYPE_CONVERTABLE) {
arg_convertibles[0].reset(reinterpret_cast<v8::ConvertableToTraceFormat*>(
static_cast<intptr_t>(arg_values[0])));
}
if (num_args > 1 && arg_types[1] == TRACE_VALUE_TYPE_CONVERTABLE) {
arg_convertibles[1].reset(reinterpret_cast<v8::ConvertableToTraceFormat*>(
static_cast<intptr_t>(arg_values[1])));
}
node::tracing::TracingController* controller =
node::tracing::TraceEventHelper::GetTracingController();
return controller->AddMetadataEvent(
category_group_enabled, name, num_args, arg_names, arg_types, arg_values,
arg_convertibles, flags);
}

// Define SetTraceValue for each allowed type. It stores the type and
// value in the return arguments. This allows this API to avoid declaring any
// structures so that it is portable to third_party libraries.
Expand Down Expand Up @@ -632,23 +653,16 @@ static V8_INLINE uint64_t AddTraceEventWithTimestamp(
}

template <class ARG1_TYPE>
static V8_INLINE uint64_t AddMetadataEvent(
static V8_INLINE void AddMetadataEvent(
const uint8_t* category_group_enabled, const char* name,
const char* arg1_name, ARG1_TYPE&& arg1_val) {
const int num_args = 1;
uint8_t arg_type;
uint64_t arg_value;
SetTraceValue(std::forward<ARG1_TYPE>(arg1_val), &arg_type, &arg_value);
// TODO(ofrobots): It would be good to add metadata events to a separate
// buffer so that they can be periodically reemitted. For now, we have a
// single buffer, so we just add them to the main buffer.
return TRACE_EVENT_API_ADD_TRACE_EVENT(
TRACE_EVENT_PHASE_METADATA,
category_group_enabled, name,
node::tracing::kGlobalScope, // scope
node::tracing::kNoId, // id
node::tracing::kNoId, // bind_id
num_args, &arg1_name, &arg_type, &arg_value, TRACE_EVENT_FLAG_NONE);
AddMetadataEventImpl(
category_group_enabled, name, num_args, &arg1_name, &arg_type, &arg_value,
TRACE_EVENT_FLAG_NONE);
}

// Used by TRACE_EVENTx macros. Do not use directly.
Expand Down
2 changes: 1 addition & 1 deletion test/cctest/node_test_fixture.cc
Original file line number Diff line number Diff line change
Expand Up @@ -3,4 +3,4 @@
ArrayBufferUniquePtr NodeTestFixture::allocator{nullptr, nullptr};
uv_loop_t NodeTestFixture::current_loop;
NodePlatformUniquePtr NodeTestFixture::platform;
TracingControllerUniquePtr NodeTestFixture::tracing_controller;
TracingAgentUniquePtr NodeTestFixture::tracing_agent;
12 changes: 6 additions & 6 deletions test/cctest/node_test_fixture.h
Original file line number Diff line number Diff line change
Expand Up @@ -55,22 +55,22 @@ struct Argv {

using ArrayBufferUniquePtr = std::unique_ptr<node::ArrayBufferAllocator,
decltype(&node::FreeArrayBufferAllocator)>;
using TracingControllerUniquePtr = std::unique_ptr<v8::TracingController>;
using TracingAgentUniquePtr = std::unique_ptr<node::tracing::Agent>;
using NodePlatformUniquePtr = std::unique_ptr<node::NodePlatform>;

class NodeTestFixture : public ::testing::Test {
protected:
static ArrayBufferUniquePtr allocator;
static TracingControllerUniquePtr tracing_controller;
static TracingAgentUniquePtr tracing_agent;
static NodePlatformUniquePtr platform;
static uv_loop_t current_loop;
v8::Isolate* isolate_;

static void SetUpTestCase() {
tracing_controller.reset(new v8::TracingController());
node::tracing::TraceEventHelper::SetTracingController(
tracing_controller.get());
platform.reset(new node::NodePlatform(4, nullptr));
tracing_agent.reset(new node::tracing::Agent());
node::tracing::TraceEventHelper::SetAgent(tracing_agent.get());
platform.reset(
new node::NodePlatform(4, tracing_agent->GetTracingController()));
CHECK_EQ(0, uv_loop_init(&current_loop));
v8::V8::InitializePlatform(platform.get());
v8::V8::Initialize();
Expand Down
10 changes: 5 additions & 5 deletions test/parallel/test-trace-events-dynamic-enable.js
Original file line number Diff line number Diff line change
Expand Up @@ -25,9 +25,12 @@ function post(message, data) {
async function test() {
session.connect();

let traceNotification = null;
const events = [];
let tracingComplete = false;
session.on('NodeTracing.dataCollected', (n) => traceNotification = n);
session.on('NodeTracing.dataCollected', (n) => {
assert.ok(n && n.data && n.data.value);
events.push(...n.data.value); // append the events.
});
session.on('NodeTracing.tracingComplete', () => tracingComplete = true);

// Generate a node.perf event before tracing is enabled.
Expand All @@ -47,10 +50,7 @@ async function test() {
session.disconnect();

assert.ok(tracingComplete);
assert.ok(traceNotification);
assert.ok(traceNotification.data && traceNotification.data.value);

const events = traceNotification.data.value;
const marks = events.filter((t) => null !== /node\.perf\.usertim/.exec(t.cat));
assert.strictEqual(marks.length, 1);
assert.strictEqual(marks[0].name, 'mark2');
Expand Down

0 comments on commit 1287c74

Please sign in to comment.