http2: trace events for http2 #18809
Conversation
jasnell
added
wip
|
@nodejs/diagnostics ... just a note... in going through this exercise, it becomes fairly obvious that v8 trace event macros are definitely not a replacement for DTrace probes. Specifically, the v8 trace event macros are not expressive enough to capture the same level of detail (e.g. limited to 2 informational arguments while the dtrace/lttng/etc probes allow for more flexibility). |
|
/cc @fmeawad: what technique does chrome use if more than 2 informational arguments are needed? |
|
We put objects in them, I recommend storing a JSON string in the first argument. |
jasnell
force-pushed
the
http2-trace-events
branch
from
2ff1247 to
ee5af23
Compare
jasnell
force-pushed
the
http2-trace-events
branch
3 times, most recently
from
b90518e to
b34d465
Compare
jasnell
force-pushed
the
http2-trace-events
branch
from
b34d465 to
4920453
Compare
jasnell
changed the title
|
Ping @nodejs/http2 @nodejs/diagnostics .... PTAL |
|
A couple of example traces: A simple file server with push streams: test/parallel/test-http2-create-client-session (creates 100 concurrent streams): test/parallel/test-http2-window-size (uses flow control mechanisms): |
| Http2Stream* stream = session->FindStream(id); | ||
| switch (frame->hd.type) { | ||
| case NGHTTP2_HEADERS: | ||
| TRACE_EVENT_NESTABLE_ASYNC_BEGIN1( |
There was a problem hiding this comment.
are there cases where this Send Headers Begin event could not be paired with a corresponding end event (e.g., if OnFrameNotSent is called)?. What are implications of if only a begin event happens w/out corresponding end event? (and vice versa)?
There was a problem hiding this comment.
Potentially yes, and will need to tease those conditions out. It's also not clear when this particular span should begin. There are two separate moments that are important: 1) the moment the user enqueues the headers to be sent and 2) the moment nghttp2 actually begins sending those headers. It's not clear which is going to be the most useful for users. For myself, as the person writing the core http2 code, knowing exactly when nghttp2 begins sending the headers helps with tuning core performance, but it's likely not particularly helpful for end users.
| switch (frame->hd.type) { | ||
| case NGHTTP2_RST_STREAM: | ||
| TRACE_EVENT_NESTABLE_ASYNC_INSTANT2( | ||
| NODE_HTTP2_TRACING, "RST_STREAM", |
There was a problem hiding this comment.
Is RST_STREAM an abbreviation for something more descriptive? e.g., "Reset Stream"?
There was a problem hiding this comment.
Nope, it's literally "RST_STREAM" in the http2 spec.
| stream->statistics_.first_byte_sent = uv_hrtime(); | ||
| TRACE_EVENT_NESTABLE_ASYNC_BEGIN1( | ||
| NODE_HTTP2_TRACING, | ||
| "Send Data", |
There was a problem hiding this comment.
this says "Send Data", but it is in the OnRead method. Is this correct, or should it be "Receive Data"?
There was a problem hiding this comment.
The OnRead is a bit of a misnomer here. This is the function where nghttp reads data from the outbound buffer to send to the connected peer, so "Send Data" is correct here. Again, however, we need to decide what is going to be the most useful bit of data here. Currently, this just gives us the time when nghttp2 begins sending data frames and the moment it stops. What it doesn't tell us is how many chunks of data the usercode actually wrote via the streams API, the latency between those, the size of actual data frames, the latency between data frames, the relationship of that to flow control, and so forth. All of those things are likely going to be far more useful for performance tuning so it's likely that this currently is no where near the level of granularity we need.
|
|
||
| TRACE_EVENT_NESTABLE_ASYNC_END0( | ||
| NODE_HTTP2_TRACING, | ||
| "Send Data", |
That's still entirely up in the air. Core does not currently instrument very much so it's still quite unclear who our target is for this and how these are going to be used. Part of the goal of this exercise is to help identify that. These need to be useful, but useful to whom and in what way :-) |
|
FWIW, it's entirely possible that what we really need for http2 tracing is instrumentation on the javascript side, at the various inflection points in the user-facing API. Instrumentation at the C++ level might not be too useful for the average Node.js developer. |
|
There is another completely different approach we can take to this... which is to design trace events specifically around the http2 protocol specifics. For instance, rather than spans marking the start and stop of It would, however, be arguably more useful in helping to tune specific performance parameters... at the cost of increased complexity and required domain knowledge. |
|
I think there are two separate audiences for traces:
I'm sure core developer working on this will have a deep understanding of protocol details and they are most likely experienced with low level/"complicated" trace tools. On the other hand I expect that a typical application developer will not plan/consider changing core nor has he full understanding how it works internally. Therefore the way how the use of the JS entry points effects actual performance is of primary interest (e.g. how to avoid to get negative impact because of nagle's algorithm,...). So I think the mapping of high level requests to low level HTTP2 packets (or or even TCP packets?) would be most likely of help to find API usage resulting in inefficient framing. From APM point of view we will monitor only the highest level, e.g. Request start/end including data to correlate who is talking to whom. Details of low level framing is out of scope (at least now). Therefore our tools target another aspect of performance. |
|
Here's an example of an alternate approach that focuses on TX/RX of individual frames per session...
|
|
Ping @jasnell |
|
Haven't forgotten. Please leave this open. |
|
Will be revisiting this soonish |
This is a work in progress .
Adds a new
node.http2trace events category intended to provide detailed tracing of http2 flow. This is a work in progress and I'm no where near done with this but want to start getting some detailed feedback before going further down this path.Trace example
Checklist
make -j4 test(UNIX), orvcbuild test(Windows) passesAffected core subsystem(s)