Skip to content

Commit

Permalink
http: add perf_hooks detail
Browse files Browse the repository at this point in the history
1. http: add perf_hooks detail for http request and client
2. net,dns: move hasObserver out of startPerf and stopPerf
  • Loading branch information
theanarkh committed May 8, 2022
1 parent be1ca70 commit cbe9872
Show file tree
Hide file tree
Showing 9 changed files with 151 additions and 88 deletions.
16 changes: 16 additions & 0 deletions doc/api/perf_hooks.md
Original file line number Diff line number Diff line change
Expand Up @@ -484,6 +484,22 @@ property will be an {Object} with two properties:
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_ALL_EXTERNAL_MEMORY`
* `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_SCHEDULE_IDLE`

### HTTP ('http') Details

When `performanceEntry.type` is equal to `'http'`, the
`performanceEntry.detail` property will be an {Object} containing
additional information.

If `performanceEntry.name` is equal to `HttpClient`, the `detail`
will contain the following properties: `req`, `res`. And the `req` property
will be an {Object} containing `method`, `url`, `headers`, the `res` property
will be an {Object} containing `statusCode`, `statusMessage`, `headers`.

If `performanceEntry.name` is equal to `HttpRequest`, the `detail`
will contain the following properties: `req`, `res`. And the `req` property
will be an {Object} containing `method`, `url`, `headers`, the `res` property
will be an {Object} containing `statusCode`, `statusMessage`, `headers`.

### HTTP/2 ('http2') Details

When `performanceEntry.type` is equal to `'http2'`, the
Expand Down
31 changes: 25 additions & 6 deletions lib/_http_client.js
Original file line number Diff line number Diff line change
Expand Up @@ -57,7 +57,7 @@ const Agent = require('_http_agent');
const { Buffer } = require('buffer');
const { defaultTriggerAsyncIdScope } = require('internal/async_hooks');
const { URL, urlToHttpOptions, searchParamsSymbol } = require('internal/url');
const { kOutHeaders, kNeedDrain, emitStatistics } = require('internal/http');
const { kOutHeaders, kNeedDrain } = require('internal/http');
const { connResetException, codes } = require('internal/errors');
const {
ERR_HTTP_HEADERS_SENT,
Expand All @@ -77,6 +77,8 @@ const {

const {
hasObserver,
startPerf,
stopPerf,
} = require('internal/perf/observe');

const kClientRequestStatistics = Symbol('ClientRequestStatistics');
Expand Down Expand Up @@ -344,10 +346,17 @@ ClientRequest.prototype._finish = function _finish() {
DTRACE_HTTP_CLIENT_REQUEST(this, this.socket);
FunctionPrototypeCall(OutgoingMessage.prototype._finish, this);
if (hasObserver('http')) {
this[kClientRequestStatistics] = {
startTime: process.hrtime(),
type: 'HttpClient',
};
startPerf(this, kClientRequestStatistics, {
type: 'http',
name: 'HttpClient',
detail: {
req: {
method: this.method,
url: `${this.protocol}//${this.host}${this.path}`,
headers: typeof this.getHeaders === 'function' ? this.getHeaders() : {},
},
},
});
}
};

Expand Down Expand Up @@ -616,7 +625,17 @@ function parserOnIncomingClient(res, shouldKeepAlive) {
}

DTRACE_HTTP_CLIENT_RESPONSE(socket, req);
emitStatistics(req[kClientRequestStatistics]);
if (req[kClientRequestStatistics] && hasObserver('http')) {
stopPerf(req, kClientRequestStatistics, {
detail: {
res: {
statusCode: res.statusCode,
statusMessage: res.statusMessage,
headers: res.headers,
},
},
});
}
req.res = res;
res.req = req;

Expand Down
31 changes: 24 additions & 7 deletions lib/_http_server.js
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,6 @@ const { OutgoingMessage } = require('_http_outgoing');
const {
kOutHeaders,
kNeedDrain,
emitStatistics
} = require('internal/http');
const {
defaultTriggerAsyncIdScope,
Expand Down Expand Up @@ -93,6 +92,8 @@ const kServerResponse = Symbol('ServerResponse');
const kServerResponseStatistics = Symbol('ServerResponseStatistics');

const {
startPerf,
stopPerf,
hasObserver,
} = require('internal/perf/observe');

Expand Down Expand Up @@ -191,20 +192,36 @@ function ServerResponse(req) {
req.headers.te);
this.shouldKeepAlive = false;
}

if (hasObserver('http')) {
this[kServerResponseStatistics] = {
startTime: process.hrtime(),
type: 'HttpRequest',
};
startPerf(this, kServerResponseStatistics, {
type: 'http',
name: 'HttpRequest',
detail: {
req: {
method: req.method,
url: req.url,
headers: req.headers,
},
},
});
}
}
ObjectSetPrototypeOf(ServerResponse.prototype, OutgoingMessage.prototype);
ObjectSetPrototypeOf(ServerResponse, OutgoingMessage);

ServerResponse.prototype._finish = function _finish() {
DTRACE_HTTP_SERVER_RESPONSE(this.socket);
emitStatistics(this[kServerResponseStatistics]);
if (this[kServerResponseStatistics] && hasObserver('http')) {
stopPerf(this, kServerResponseStatistics, {
detail: {
res: {
statusCode: this.statusCode,
statusMessage: this.statusMessage,
headers: typeof this.getHeaders === 'function' ? this.getHeaders() : {},
},
},
});
}
OutgoingMessage.prototype._finish.call(this);
};

Expand Down
69 changes: 42 additions & 27 deletions lib/dns.js
Original file line number Diff line number Diff line change
Expand Up @@ -70,6 +70,7 @@ const kPerfHooksDnsLookupServiceContext = Symbol('kPerfHooksDnsLookupServiceCont
const kPerfHooksDnsLookupResolveContext = Symbol('kPerfHooksDnsLookupResolveContext');

const {
hasObserver,
startPerf,
stopPerf,
} = require('internal/perf/observe');
Expand All @@ -83,7 +84,9 @@ function onlookup(err, addresses) {
return this.callback(dnsException(err, 'getaddrinfo', this.hostname));
}
this.callback(null, addresses[0], this.family || isIP(addresses[0]));
stopPerf(this, kPerfHooksDnsLookupContext);
if (this[kPerfHooksDnsLookupContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupContext);
}
}


Expand All @@ -102,7 +105,9 @@ function onlookupall(err, addresses) {
}

this.callback(null, addresses);
stopPerf(this, kPerfHooksDnsLookupContext);
if (this[kPerfHooksDnsLookupContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupContext);
}
}


Expand Down Expand Up @@ -187,13 +192,15 @@ function lookup(hostname, options, callback) {
process.nextTick(callback, dnsException(err, 'getaddrinfo', hostname));
return {};
}
const detail = {
hostname,
family,
hints,
verbatim,
};
startPerf(req, kPerfHooksDnsLookupContext, { type: 'dns', name: 'lookup', detail });
if (hasObserver('dns')) {
const detail = {
hostname,
family,
hints,
verbatim,
};
startPerf(req, kPerfHooksDnsLookupContext, { type: 'dns', name: 'lookup', detail });
}
return req;
}

Expand All @@ -206,7 +213,9 @@ function onlookupservice(err, hostname, service) {
return this.callback(dnsException(err, 'getnameinfo', this.hostname));

this.callback(null, hostname, service);
stopPerf(this, kPerfHooksDnsLookupServiceContext);
if (this[kPerfHooksDnsLookupServiceContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupServiceContext);
}
}


Expand All @@ -231,14 +240,16 @@ function lookupService(address, port, callback) {

const err = cares.getnameinfo(req, address, port);
if (err) throw dnsException(err, 'getnameinfo', address);
startPerf(req, kPerfHooksDnsLookupServiceContext, {
type: 'dns',
name: 'lookupService',
detail: {
host: address,
port
}
});
if (hasObserver('dns')) {
startPerf(req, kPerfHooksDnsLookupServiceContext, {
type: 'dns',
name: 'lookupService',
detail: {
host: address,
port
}
});
}
return req;
}

Expand All @@ -255,7 +266,9 @@ function onresolve(err, result, ttls) {
this.callback(dnsException(err, this.bindingName, this.hostname));
else {
this.callback(null, result);
stopPerf(this, kPerfHooksDnsLookupResolveContext);
if (this[kPerfHooksDnsLookupResolveContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupResolveContext);
}
}
}

Expand All @@ -278,14 +291,16 @@ function resolver(bindingName) {
req.ttl = !!(options && options.ttl);
const err = this._handle[bindingName](req, toASCII(name));
if (err) throw dnsException(err, bindingName, name);
startPerf(req, kPerfHooksDnsLookupResolveContext, {
type: 'dns',
name: bindingName,
detail: {
host: name,
ttl: req.ttl
}
});
if (hasObserver('dns')) {
startPerf(req, kPerfHooksDnsLookupResolveContext, {
type: 'dns',
name: bindingName,
detail: {
host: name,
ttl: req.ttl
}
});
}
return req;
}
ObjectDefineProperty(query, 'name', { value: bindingName });
Expand Down
24 changes: 17 additions & 7 deletions lib/internal/dns/promises.js
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@ const kPerfHooksDnsLookupResolveContext = Symbol('kPerfHooksDnsLookupResolveCont
const {
startPerf,
stopPerf,
hasObserver,
} = require('internal/perf/observe');

function onlookup(err, addresses) {
Expand All @@ -58,7 +59,9 @@ function onlookup(err, addresses) {

const family = this.family || isIP(addresses[0]);
this.resolve({ address: addresses[0], family });
stopPerf(this, kPerfHooksDnsLookupContext);
if (this[kPerfHooksDnsLookupContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupContext);
}
}

function onlookupall(err, addresses) {
Expand All @@ -79,7 +82,9 @@ function onlookupall(err, addresses) {
}

this.resolve(addresses);
stopPerf(this, kPerfHooksDnsLookupContext);
if (this[kPerfHooksDnsLookupContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupContext);
}
}

function createLookupPromise(family, hostname, all, hints, verbatim) {
Expand Down Expand Up @@ -110,7 +115,7 @@ function createLookupPromise(family, hostname, all, hints, verbatim) {

if (err) {
reject(dnsException(err, 'getaddrinfo', hostname));
} else {
} else if (hasObserver('dns')) {
const detail = {
hostname,
family,
Expand Down Expand Up @@ -170,7 +175,9 @@ function onlookupservice(err, hostname, service) {
}

this.resolve({ hostname, service });
stopPerf(this, kPerfHooksDnsLookupServiceContext);
if (this[kPerfHooksDnsLookupServiceContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupServiceContext);
}
}

function createLookupServicePromise(hostname, port) {
Expand All @@ -187,7 +194,7 @@ function createLookupServicePromise(hostname, port) {

if (err)
reject(dnsException(err, 'getnameinfo', hostname));
else
else if (hasObserver('dns')) {
startPerf(req, kPerfHooksDnsLookupServiceContext, {
type: 'dns',
name: 'lookupService',
Expand All @@ -196,6 +203,7 @@ function createLookupServicePromise(hostname, port) {
port
}
});
}
});
}

Expand Down Expand Up @@ -223,7 +231,9 @@ function onresolve(err, result, ttls) {
result, (address, index) => ({ address, ttl: ttls[index] }));

this.resolve(result);
stopPerf(this, kPerfHooksDnsLookupResolveContext);
if (this[kPerfHooksDnsLookupResolveContext] && hasObserver('dns')) {
stopPerf(this, kPerfHooksDnsLookupResolveContext);
}
}

function createResolverPromise(resolver, bindingName, hostname, ttl) {
Expand All @@ -241,7 +251,7 @@ function createResolverPromise(resolver, bindingName, hostname, ttl) {

if (err)
reject(dnsException(err, bindingName, hostname));
else {
else if (hasObserver('dns')) {
startPerf(req, kPerfHooksDnsLookupResolveContext, {
type: 'dns',
name: bindingName,
Expand Down
22 changes: 0 additions & 22 deletions lib/internal/http.js
Original file line number Diff line number Diff line change
Expand Up @@ -9,13 +9,6 @@ const {

const { setUnrefTimeout } = require('internal/timers');

const { InternalPerformanceEntry } = require('internal/perf/performance_entry');

const {
enqueue,
hasObserver,
} = require('internal/perf/observe');

let utcCache;

function utcDate() {
Expand All @@ -33,23 +26,8 @@ function resetCache() {
utcCache = undefined;
}

function emitStatistics(statistics) {
if (!hasObserver('http') || statistics == null) return;
const startTime = statistics.startTime;
const diff = process.hrtime(startTime);
const entry = new InternalPerformanceEntry(
statistics.type,
'http',
startTime[0] * 1000 + startTime[1] / 1e6,
diff[0] * 1000 + diff[1] / 1e6,
undefined,
);
enqueue(entry);
}

module.exports = {
kOutHeaders: Symbol('kOutHeaders'),
kNeedDrain: Symbol('kNeedDrain'),
utcDate,
emitStatistics,
};
Loading

0 comments on commit cbe9872

Please sign in to comment.