FazBrowse GitHub Viewer | Trending |
URL:
| Home
Tools: [Download Repo ZIP]   [Original HTTPS Page]

http2: perf_hooks integration · nodejs/node@dcc7f4d · GitHub

/ node Public

Commit dcc7f4d

Browse files
jasnell
authored and
MylesBorins
committed
http2: perf_hooks integration
Collect and report basic timing information about `Http2Session` and `Http2Stream` instances. Backport-PR-URL: #18050 Backport-PR-URL: #20456 PR-URL: #17906 Refs: #17746 Reviewed-By: Matteo Collina <matteo.collina@gmail.com>
1 parent 72b42de commit dcc7f4d

8 files changed

Lines changed: 344 additions & 13 deletions

File tree

‎doc/api/http2.md‎

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2819,13 +2819,63 @@ given newly created [`Http2Stream`] on `Http2ServerRespose`.
28192819
The callback will be called with an error with code `ERR_HTTP2_STREAM_CLOSED`
28202820
if the stream is closed.
28212821

2822+
## Collecting HTTP/2 Performance Metrics
2823+
2824+
The [Performance Observer][] API can be used to collect basic performance
2825+
metrics for each `Http2Session` and `Http2Stream` instance.
2826+
2827+
```js
2828+
const { PerformanceObserver } = require('perf_hooks');
2829+
2830+
const obs = new PerformanceObserver((items) => {
2831+
const entry = items.getEntries()[0];
2832+
console.log(entry.entryType); // prints 'http2'
2833+
if (entry.name === 'Http2Session') {
2834+
// entry contains statistics about the Http2Session
2835+
} else if (entry.name === 'Http2Stream') {
2836+
// entry contains statistics about the Http2Stream
2837+
}
2838+
});
2839+
obs.observe({ entryTypes: ['http2'] });
2840+
```
2841+
2842+
The `entryType` property of the `PerformanceEntry` will be equal to `'http2'`.
2843+
2844+
The `name` property of the `PerformanceEntry` will be equal to either
2845+
`'Http2Stream'` or `'Http2Session'`.
2846+
2847+
If `name` is equal to `Http2Stream`, the `PerformanceEntry` will contain the
2848+
following additional properties:
2849+
2850+
* `timeToFirstByte` {number} The number of milliseconds elapsed between the
2851+
`PerformanceEntry` `startTime` and the reception of the first `DATA` frame.
2852+
* `timeToFirstHeader` {number} The number of milliseconds elapsed between the
2853+
`PerformanceEntry` `startTime` and the reception of the first header.
2854+
2855+
If `name` is equal to `Http2Session`, the `PerformanceEntry` will contain the
2856+
following additional properties:
2857+
2858+
* `pingRTT` {number} The number of milliseconds elapsed since the transmission
2859+
of a `PING` frame and the reception of its acknowledgement. Only present if
2860+
a `PING` frame has been sent on the `Http2Session`.
2861+
* `streamCount` {number} The number of `Http2Stream` instances processed by
2862+
the `Http2Session`.
2863+
* `streamAverageDuration` {number} The average duration (in milliseconds) for
2864+
all `Http2Stream` instances.
2865+
* `framesReceived` {number} The number of HTTP/2 frames received by the
2866+
`Http2Session`.
2867+
* `type` {string} Either `'server'` or `'client'` to identify the type of
2868+
`Http2Session`.
2869+
2870+
28222871
[ALPN negotiation]: #http2_alpn_negotiation
28232872
[Compatibility API]: #http2_compatibility_api
28242873
[HTTP/1]: http.html
28252874
[HTTP/2]: https://tools.ietf.org/html/rfc7540
28262875
[HTTPS]: https.html
28272876
[Headers Object]: #http2_headers_object
28282877
[Http2Session and Sockets]: #http2_http2session_and_sockets
2878+
[Performance Observer]: perf_hooks.html
28292879
[Readable Stream]: stream.html#stream_class_stream_readable
28302880
[Settings Object]: #http2_settings_object
28312881
[Using options.selectPadding]: #http2_using_options_selectpadding

‎lib/perf_hooks.js‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ const {
1818
NODE_PERFORMANCE_ENTRY_TYPE_MEASURE,
1919
NODE_PERFORMANCE_ENTRY_TYPE_GC,
2020
NODE_PERFORMANCE_ENTRY_TYPE_FUNCTION,
21+
NODE_PERFORMANCE_ENTRY_TYPE_HTTP2,
2122

2223
NODE_PERFORMANCE_MILESTONE_NODE_START,
2324
NODE_PERFORMANCE_MILESTONE_V8_START,
@@ -61,7 +62,8 @@ const observerableTypes = [
6162
'mark',
6263
'measure',
6364
'gc',
64-
'function'
65+
'function',
66+
'http2'
6567
];
6668

6769
let errors;
@@ -504,6 +506,7 @@ function mapTypes(i) {
504506
case 'measure': return NODE_PERFORMANCE_ENTRY_TYPE_MEASURE;
505507
case 'gc': return NODE_PERFORMANCE_ENTRY_TYPE_GC;
506508
case 'function': return NODE_PERFORMANCE_ENTRY_TYPE_FUNCTION;
509+
case 'http2': return NODE_PERFORMANCE_ENTRY_TYPE_HTTP2;
507510
}
508511
}
509512

‎src/node_http2.cc‎

Lines changed: 101 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
#include "node_buffer.h"
44
#include "node_http2.h"
55
#include "node_http2_state.h"
6+
#include "node_perf.h"
67

78
#include <algorithm>
89

@@ -20,6 +21,7 @@ using v8::Uint32;
2021
using v8::Uint32Array;
2122
using v8::Undefined;
2223

24+
using node::performance::PerformanceEntry;
2325
namespace http2 {
2426

2527
namespace {
@@ -468,6 +470,7 @@ Http2Session::Http2Session(Environment* env,
468470
: AsyncWrap(env, wrap, AsyncWrap::PROVIDER_HTTP2SESSION),
469471
session_type_(type) {
470472
MakeWeak<Http2Session>(this);
473+
statistics_.start_time = uv_hrtime();
471474

472475
// Capture the configuration options for this session
473476
Http2Options opts(env);
@@ -527,6 +530,86 @@ Http2Session::~Http2Session() {
527530
nghttp2_session_del(session_);
528531
}
529532

533+
inline bool HasHttp2Observer(Environment* env) {
534+
uint32_t* observers = env->performance_state()->observers;
535+
return observers[performance::NODE_PERFORMANCE_ENTRY_TYPE_HTTP2] != 0;
536+
}
537+
538+
inline void Http2Stream::EmitStatistics() {
539+
if (!HasHttp2Observer(env()))
540+
return;
541+
Http2StreamPerformanceEntry* entry =
542+
new Http2StreamPerformanceEntry(env(), statistics_);
543+
env()->SetImmediate([](Environment* env, void* data) {
544+
Local<Context> context = env->context();
545+
Http2StreamPerformanceEntry* entry =
546+
static_cast<Http2StreamPerformanceEntry*>(data);
547+
if (HasHttp2Observer(env)) {
548+
Local<Object> obj = entry->ToObject();
549+
v8::PropertyAttribute attr =
550+
static_cast<v8::PropertyAttribute>(v8::ReadOnly | v8::DontDelete);
551+
obj->DefineOwnProperty(
552+
context,
553+
FIXED_ONE_BYTE_STRING(env->isolate(), "timeToFirstByte"),
554+
Number::New(env->isolate(),
555+
(entry->first_byte() - entry->startTimeNano()) / 1e6),
556+
attr);
557+
obj->DefineOwnProperty(
558+
context,
559+
FIXED_ONE_BYTE_STRING(env->isolate(), "timeToFirstHeader"),
560+
Number::New(env->isolate(),
561+
(entry->first_header() - entry->startTimeNano()) / 1e6),
562+
attr);
563+
entry->Notify(obj);
564+
}
565+
delete entry;
566+
}, static_cast<void*>(entry));
567+
}
568+
569+
inline void Http2Session::EmitStatistics() {
570+
if (!HasHttp2Observer(env()))
571+
return;
572+
Http2SessionPerformanceEntry* entry =
573+
new Http2SessionPerformanceEntry(env(), statistics_, TypeName());
574+
env()->SetImmediate([](Environment* env, void* data) {
575+
Local<Context> context = env->context();
576+
Http2SessionPerformanceEntry* entry =
577+
static_cast<Http2SessionPerformanceEntry*>(data);
578+
if (HasHttp2Observer(env)) {
579+
Local<Object> obj = entry->ToObject();
580+
v8::PropertyAttribute attr =
581+
static_cast<v8::PropertyAttribute>(v8::ReadOnly | v8::DontDelete);
582+
obj->DefineOwnProperty(
583+
context,
584+
FIXED_ONE_BYTE_STRING(env->isolate(), "type"),
585+
String::NewFromUtf8(env->isolate(),
586+
entry->typeName(),
587+
v8::NewStringType::kInternalized)
588+
.ToLocalChecked(), attr);
589+
if (entry->ping_rtt() != 0) {
590+
obj->DefineOwnProperty(
591+
context,
592+
FIXED_ONE_BYTE_STRING(env->isolate(), "pingRTT"),
593+
Number::New(env->isolate(), entry->ping_rtt() / 1e6), attr);
594+
}
595+
obj->DefineOwnProperty(
596+
context,
597+
FIXED_ONE_BYTE_STRING(env->isolate(), "framesReceived"),
598+
Integer::NewFromUnsigned(env->isolate(), entry->frame_count()), attr);
599+
obj->DefineOwnProperty(
600+
context,
601+
FIXED_ONE_BYTE_STRING(env->isolate(), "streamCount"),
602+
Integer::New(env->isolate(), entry->stream_count()), attr);
603+
obj->DefineOwnProperty(
604+
context,
605+
FIXED_ONE_BYTE_STRING(env->isolate(), "streamAverageDuration"),
606+
Number::New(env->isolate(), entry->stream_average_duration()), attr);
607+
entry->Notify(obj);
608+
}
609+
delete entry;
610+
}, static_cast<void*>(entry));
611+
}
612+
530613
// Closes the session and frees the associated resources
531614
void Http2Session::Close(uint32_t code, bool socket_closed) {
532615
DEBUG_HTTP2SESSION(this, "closing session");
@@ -560,6 +643,9 @@ void Http2Session::Close(uint32_t code, bool socket_closed) {
560643
static_cast<Http2Session::Http2Ping*>(data)->Done(false);
561644
}, static_cast<void*>(ping));
562645
}
646+
647+
statistics_.end_time = uv_hrtime();
648+
EmitStatistics();
563649
}
564650

565651
// Locates an existing known stream by ID. nghttp2 has a similar method
@@ -571,6 +657,7 @@ inline Http2Stream* Http2Session::FindStream(int32_t id) {
571657

572658

573659
inline void Http2Session::AddStream(Http2Stream* stream) {
660+
CHECK_GE(++statistics_.stream_count, 0);
574661
streams_[stream->id()] = stream;
575662
}
576663

@@ -720,6 +807,7 @@ inline int Http2Session::OnFrameReceive(nghttp2_session* handle,
720807
const nghttp2_frame* frame,
721808
void* user_data) {
722809
Http2Session* session = static_cast<Http2Session*>(user_data);
810+
session->statistics_.frame_count++;
723811
DEBUG_HTTP2SESSION2(session, "complete frame received: type: %d",
724812
frame->hd.type);
725813
switch (frame->hd.type) {
@@ -1447,6 +1535,7 @@ Http2Stream::Http2Stream(
14471535
id_(id),
14481536
current_headers_category_(category) {
14491537
MakeWeak<Http2Stream>(this);
1538+
statistics_.start_time = uv_hrtime();
14501539

14511540
// Limit the number of header pairs
14521541
max_header_pairs_ = session->GetMaxHeaderPairs();
@@ -1530,6 +1619,8 @@ inline bool Http2Stream::HasDataChunks(bool ignore_eos) {
15301619
// handles it's internal memory`.
15311620
inline void Http2Stream::AddChunk(const uint8_t* data, size_t len) {
15321621
CHECK(!this->IsDestroyed());
1622+
if (this->statistics_.first_byte == 0)
1623+
this->statistics_.first_byte = uv_hrtime();
15331624
if (flags_ & NGHTTP2_STREAM_FLAG_EOS)
15341625
return;
15351626
char* buf = nullptr;
@@ -1590,7 +1681,6 @@ inline void Http2Stream::Destroy() {
15901681
// may still be some pending operations queued for this stream.
15911682
env()->SetImmediate([](Environment* env, void* data) {
15921683
Http2Stream* stream = static_cast<Http2Stream*>(data);
1593-
15941684
// Free any remaining outgoing data chunks here. This should be done
15951685
// here because it's possible for destroy to have been called while
15961686
// we still have qeueued outbound writes.
@@ -1603,6 +1693,12 @@ inline void Http2Stream::Destroy() {
16031693

16041694
delete stream;
16051695
}, this, this->object());
1696+
1697+
statistics_.end_time = uv_hrtime();
1698+
session_->statistics_.stream_average_duration =
1699+
((statistics_.end_time - statistics_.start_time) /
1700+
session_->statistics_.stream_count) / 1e6;
1701+
EmitStatistics();
16061702
}
16071703

16081704

@@ -1815,6 +1911,8 @@ inline bool Http2Stream::AddHeader(nghttp2_rcbuf* name,
18151911
nghttp2_rcbuf* value,
18161912
uint8_t flags) {
18171913
CHECK(!this->IsDestroyed());
1914+
if (this->statistics_.first_header == 0)
1915+
this->statistics_.first_header = uv_hrtime();
18181916
size_t length = GetBufferLength(name) + GetBufferLength(value) + 32;
18191917
if (current_headers_.size() == max_header_pairs_ ||
18201918
current_headers_length_ + length > max_header_length_) {
@@ -2493,8 +2591,8 @@ void Http2Session::Http2Ping::Send(uint8_t* payload) {
24932591
}
24942592

24952593
void Http2Session::Http2Ping::Done(bool ack, const uint8_t* payload) {
2496-
uint64_t end = uv_hrtime();
2497-
double duration = (end - startTime_) / 1e6;
2594+
session_->statistics_.ping_rtt = (uv_hrtime() - startTime_);
2595+
double duration = (session_->statistics_.ping_rtt - startTime_) / 1e6;
24982596

24992597
Local<Value> buf = Undefined(env()->isolate());
25002598
if (payload != nullptr) {

0 commit comments

Comments
 (0)
Back | FazBrowse Home | New Git URL