Skip to content

Commit

Permalink
windows: generate ETW events to track v8 compiled code positions
Browse files Browse the repository at this point in the history
Patch by Henry Rawas and Scott Blomquist.
  • Loading branch information
sblom authored and piscisaureus committed Nov 1, 2012
1 parent 2f5fa08 commit 66f64ae
Show file tree
Hide file tree
Showing 4 changed files with 306 additions and 13 deletions.
120 changes: 120 additions & 0 deletions src/node_win32_etw_provider-inl.h
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,20 @@ extern int events_enabled;
#define ETW_WRITE_INT32_DATA(data_descriptor, data) \
EventDataDescCreate(data_descriptor, data, sizeof(int32_t));

#define ETW_WRITE_INT64_DATA(data_descriptor, data) \
EventDataDescCreate(data_descriptor, data, sizeof(int64_t));

#define ETW_WRITE_ADDRESS_DATA(data_descriptor, data) \
EventDataDescCreate(data_descriptor, data, sizeof(intptr_t));

#define ETW_WRITE_INT16_DATA(data_descriptor, data) \
EventDataDescCreate(data_descriptor, data, sizeof(int16_t));

#define ETW_WRITE_WSTRING_DATA_LENGTH(data_descriptor, data, data_len_bytes) \
EventDataDescCreate(data_descriptor, \
data, \
data_len_bytes);

#define ETW_WRITE_NET_CONNECTION(descriptors, conn) \
ETW_WRITE_INT32_DATA(descriptors, &conn->fd); \
ETW_WRITE_INT32_DATA(descriptors + 1, &conn->port); \
Expand All @@ -61,6 +75,34 @@ extern int events_enabled;
ETW_WRITE_INT32_DATA(descriptors, &type); \
ETW_WRITE_INT32_DATA(descriptors + 1, &flags);

#define ETW_WRITE_V8ADDRESSCHANGE(descriptors, addr1, addr2) \
ETW_WRITE_ADDRESS_DATA(descriptors, &addr1); \
ETW_WRITE_ADDRESS_DATA(descriptors + 1, &addr2);

#define ETW_WRITE_JSMETHOD_LOADUNLOAD(descriptors, \
context, \
startAddr, \
size, \
id, \
flags, \
rangeId, \
sourceId, \
line, \
col, \
name, \
name_len_bytes) \
ETW_WRITE_ADDRESS_DATA(descriptors, &context); \
ETW_WRITE_ADDRESS_DATA(descriptors + 1, &startAddr); \
ETW_WRITE_INT64_DATA(descriptors + 2, &size); \
ETW_WRITE_INT32_DATA(descriptors + 3, &id); \
ETW_WRITE_INT16_DATA(descriptors + 4, &flags); \
ETW_WRITE_INT16_DATA(descriptors + 5, &rangeId); \
ETW_WRITE_INT64_DATA(descriptors + 6, &sourceId); \
ETW_WRITE_INT32_DATA(descriptors + 7, &line); \
ETW_WRITE_INT32_DATA(descriptors + 8, &col); \
ETW_WRITE_WSTRING_DATA_LENGTH(descriptors + 9, name, name_len_bytes);


#define ETW_WRITE_EVENT(eventDescriptor, dataDescriptors) \
DWORD status = event_write(node_provider, \
&eventDescriptor, \
Expand Down Expand Up @@ -133,6 +175,83 @@ void NODE_GC_DONE(GCType type, GCCallbackFlags flags) {
}


void NODE_V8SYMBOL_REMOVE(const void* addr1, const void* addr2) {
if (events_enabled > 0) {
EVENT_DATA_DESCRIPTOR descriptors[2];
ETW_WRITE_V8ADDRESSCHANGE(descriptors, addr1, addr2);
ETW_WRITE_EVENT(NODE_V8SYMBOL_REMOVE_EVENT, descriptors);
}
}


void NODE_V8SYMBOL_MOVE(const void* addr1, const void* addr2) {
if (events_enabled > 0) {
EVENT_DATA_DESCRIPTOR descriptors[2];
ETW_WRITE_V8ADDRESSCHANGE(descriptors, addr1, addr2);
ETW_WRITE_EVENT(NODE_V8SYMBOL_MOVE_EVENT, descriptors);
}
}


void NODE_V8SYMBOL_RESET() {
if (events_enabled > 0) {
int val = 0;
EVENT_DATA_DESCRIPTOR descriptors[1];
ETW_WRITE_INT32_DATA(descriptors, &val);
ETW_WRITE_EVENT(NODE_V8SYMBOL_RESET_EVENT, descriptors);
}
}

#define SETSYMBUF(s) \
wcscpy(symbuf, s); \
symbol_len = ARRAY_SIZE(s) - 1;

void NODE_V8SYMBOL_ADD(LPCSTR symbol,
int symbol_len,
const void* addr1,
int len) {
if (events_enabled > 0) {
wchar_t symbuf[128];
if (symbol == NULL) {
SETSYMBUF(L"NULL");
} else {
symbol_len = MultiByteToWideChar(CP_ACP, 0, symbol, symbol_len, symbuf, 128);
if (symbol_len == 0) {
SETSYMBUF(L"Invalid");
} else {
if (symbol_len > 127) {
symbol_len = 127;
}
symbuf[symbol_len] = L'\0';
}
}
void* context = NULL;
INT64 size = (INT64)len;
INT32 id = (INT32)addr1;
INT16 flags = 0;
INT16 rangeid = 1;
INT32 col = 1;
INT32 line = 1;
INT64 sourceid = 0;
EVENT_DATA_DESCRIPTOR descriptors[10];
ETW_WRITE_JSMETHOD_LOADUNLOAD(descriptors,
context,
addr1,
size,
id,
flags,
rangeid,
sourceid,
line,
col,
symbuf,
symbol_len * sizeof(symbuf[0]));
ETW_WRITE_EVENT(MethodLoad, descriptors);
}
}
#undef SETSYMBUF


bool NODE_HTTP_SERVER_REQUEST_ENABLED() { return events_enabled > 0; }
bool NODE_HTTP_SERVER_RESPONSE_ENABLED() { return events_enabled > 0; }
bool NODE_HTTP_CLIENT_REQUEST_ENABLED() { return events_enabled > 0; }
Expand All @@ -141,5 +260,6 @@ bool NODE_NET_SERVER_CONNECTION_ENABLED() { return events_enabled > 0; }
bool NODE_NET_STREAM_END_ENABLED() { return events_enabled > 0; }
bool NODE_NET_SOCKET_READ_ENABLED() { return events_enabled > 0; }
bool NODE_NET_SOCKET_WRITE_ENABLED() { return events_enabled > 0; }
bool NODE_V8SYMBOL_ENABLED() { return events_enabled > 0; }
}
#endif // SRC_ETW_INL_H_
114 changes: 114 additions & 0 deletions src/node_win32_etw_provider.cc
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@
#include "node_dtrace.h"
#include "node_win32_etw_provider.h"
#include "node_etw_provider.h"
#include "node_win32_etw_provider-inl.h"

namespace node {

Expand All @@ -33,10 +34,110 @@ EventRegisterFunc event_register;
EventUnregisterFunc event_unregister;
EventWriteFunc event_write;
int events_enabled;
static uv_async_t dispatch_etw_events_change_async;

struct v8tags {
char prefix[32 - sizeof(size_t)];
size_t prelen;
};

// The v8 CODE_ADDED event name has a prefix indicating the type of event.
// Many of these are internal to v8.
// The trace_codes array specifies which types are written.
struct v8tags trace_codes[] = {
#define MAKE_V8TAG(s) { s, sizeof(s) - 1 }
MAKE_V8TAG("LazyCompile:"),
MAKE_V8TAG("Script:"),
MAKE_V8TAG("Function:"),
MAKE_V8TAG("RegExp:"),
MAKE_V8TAG("Eval:")
#undef MAKE_V8TAG
};

/* Below are some code prefixes which are not being written.
* "Builtin:"
* "Stub:"
* "CallIC:"
* "LoadIC:"
* "KeyedLoadIC:"
* "StoreIC:"
* "KeyedStoreIC:"
* "CallPreMonomorphic:"
* "CallInitialize:"
* "CallMiss:"
* "CallMegamorphic:"
*/

// v8 sometimes puts a '*' or '~' in front of the name.
#define V8_MARKER1 '*'
#define V8_MARKER2 '~'


// If prefix is not in filtered list return -1,
// else return length of prefix and marker.
int FilterCodeEvents(const char* name, size_t len) {
for (int i = 0; i < ARRAY_SIZE(trace_codes); i++) {
size_t prelen = trace_codes[i].prelen;
if (prelen < len) {
if (strncmp(name, trace_codes[i].prefix, prelen) == 0) {
if (name[prelen] == V8_MARKER1 || name[prelen] == V8_MARKER2)
prelen++;
return prelen;
}
}
}
return -1;
}


// callback from V8 module passes symbol and address info for stack walk
void CodeAddressNotification(const JitCodeEvent* jevent) {
int pre_offset = 0;
if (NODE_V8SYMBOL_ENABLED()) {
switch (jevent->type) {
case JitCodeEvent::CODE_ADDED:
pre_offset = FilterCodeEvents(jevent->name.str, jevent->name.len);
if (pre_offset >= 0) {
// skip over prefix and marker
NODE_V8SYMBOL_ADD(jevent->name.str + pre_offset,
jevent->name.len - pre_offset,
jevent->code_start,
jevent->code_len);
}
break;
case JitCodeEvent::CODE_REMOVED:
NODE_V8SYMBOL_REMOVE(jevent->code_start, 0);
break;
case JitCodeEvent::CODE_MOVED:
NODE_V8SYMBOL_MOVE(jevent->code_start, jevent->new_code_start);
break;
default:
break;
}
}
}


// Call v8 to enable or disable code event callbacks.
// Must be on default thread to do this.
// Note: It is possible to call v8 from ETW thread, but then
// event callbacks are received in the same thread. Attempts
// to write ETW events in this thread will fail.
void etw_events_change_async(uv_async_t* handle, int status) {
if (events_enabled > 0) {
NODE_V8SYMBOL_RESET();
V8::SetJitCodeEventHandler(v8::kJitCodeEventEnumExisting,
CodeAddressNotification);
} else {
V8::SetJitCodeEventHandler(v8::kJitCodeEventDefault, NULL);
}
}


// This callback is called by ETW when consumers of our provider
// are enabled or disabled.
// The callback is dispatched on ETW thread.
// Before calling into V8 to enable code events, switch to default thread.
void NTAPI etw_events_enable_callback(
LPCGUID SourceId,
ULONG IsEnabled,
Expand All @@ -47,8 +148,14 @@ void NTAPI etw_events_enable_callback(
PVOID CallbackContext) {
if (IsEnabled) {
events_enabled++;
if (events_enabled == 1) {
uv_async_send(&dispatch_etw_events_change_async);
}
} else {
events_enabled--;
if (events_enabled == 0) {
uv_async_send(&dispatch_etw_events_change_async);
}
}
}

Expand All @@ -64,6 +171,12 @@ void init_etw() {
GetProcAddress(advapi, "EventUnregister");
event_write = (EventWriteFunc)GetProcAddress(advapi, "EventWrite");

// create async object used to invoke main thread from callback
uv_async_init(uv_default_loop(),
&dispatch_etw_events_change_async,
etw_events_change_async);
uv_unref((uv_handle_t*) &dispatch_etw_events_change_async);

if (event_register) {
DWORD status = event_register(&NODE_ETW_PROVIDER,
etw_events_enable_callback,
Expand All @@ -82,6 +195,7 @@ void shutdown_etw() {
}

events_enabled = 0;
V8::SetJitCodeEventHandler(v8::kJitCodeEventDefault, NULL);

if (advapi) {
FreeLibrary(advapi);
Expand Down
8 changes: 8 additions & 0 deletions src/node_win32_etw_provider.h
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,13 @@ INLINE void NODE_NET_SERVER_CONNECTION(node_dtrace_connection_t* conn);
INLINE void NODE_NET_STREAM_END(node_dtrace_connection_t* conn);
INLINE void NODE_GC_START(GCType type, GCCallbackFlags flags);
INLINE void NODE_GC_DONE(GCType type, GCCallbackFlags flags);
INLINE void NODE_V8SYMBOL_REMOVE(const void* addr1, const void* addr2);
INLINE void NODE_V8SYMBOL_MOVE(const void* addr1, const void* addr2);
INLINE void NODE_V8SYMBOL_RESET();
INLINE void NODE_V8SYMBOL_ADD(LPCSTR symbol,
int symbol_len,
const void* addr1,
int len);

INLINE bool NODE_HTTP_SERVER_REQUEST_ENABLED();
INLINE bool NODE_HTTP_SERVER_RESPONSE_ENABLED();
Expand All @@ -75,6 +82,7 @@ INLINE bool NODE_NET_SERVER_CONNECTION_ENABLED();
INLINE bool NODE_NET_STREAM_END_ENABLED();
INLINE bool NODE_NET_SOCKET_READ_ENABLED();
INLINE bool NODE_NET_SOCKET_WRITE_ENABLED();
INLINE bool NODE_V8SYMBOL_ENABLED();

#define NODE_NET_SOCKET_READ(arg0, arg1)
#define NODE_NET_SOCKET_WRITE(arg0, arg1)
Expand Down
Loading

0 comments on commit 66f64ae

Please sign in to comment.