Skip to content

Commit b46bf02

Browse files
committed
http: trace http client by perf_hooks
1 parent 4586ac4 commit b46bf02

File tree

5 files changed

+65
-9
lines changed

5 files changed

+65
-9
lines changed

doc/api/perf_hooks.md

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1276,6 +1276,35 @@ obs.observe({ entryTypes: ['function'], buffered: true });
12761276
require('some-module');
12771277
```
12781278

1279+
### Trace http by perf_hooks
1280+
1281+
The following example traces http client(OutgoingMessage) and http request(IncomingMessage):
1282+
1283+
<!-- eslint-disable no-global-assign -->
1284+
1285+
```js
1286+
'use strict';
1287+
const { PerformanceObserver } = require('perf_hooks');
1288+
const http = require('http');
1289+
1290+
const obs = new PerformanceObserver((items) => {
1291+
items.getEntries().forEach((item) => {
1292+
console.log(item);
1293+
});
1294+
});
1295+
1296+
obs.observe({ entryTypes: ['http'] });
1297+
1298+
const PORT = 8080;
1299+
1300+
http.createServer((req, res) => {
1301+
res.end('ok');
1302+
})
1303+
.listen(PORT, () => {
1304+
http.get(`http://127.0.0.1:${PORT}`);
1305+
});
1306+
```
1307+
12791308
[Async Hooks]: async_hooks.md
12801309
[High Resolution Time]: https://www.w3.org/TR/hr-time-2
12811310
[Performance Timeline]: https://w3c.github.io/performance-timeline/

lib/_http_client.js

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -57,7 +57,7 @@ const Agent = require('_http_agent');
5757
const { Buffer } = require('buffer');
5858
const { defaultTriggerAsyncIdScope } = require('internal/async_hooks');
5959
const { URL, urlToHttpOptions, searchParamsSymbol } = require('internal/url');
60-
const { kOutHeaders, kNeedDrain } = require('internal/http');
60+
const { kOutHeaders, kNeedDrain, emitStatistics } = require('internal/http');
6161
const { connResetException, codes } = require('internal/errors');
6262
const {
6363
ERR_HTTP_HEADERS_SENT,
@@ -75,6 +75,12 @@ const {
7575
DTRACE_HTTP_CLIENT_RESPONSE
7676
} = require('internal/dtrace');
7777

78+
const {
79+
hasObserver,
80+
} = require('internal/perf/observe');
81+
82+
const kClientRequestStatistics = Symbol('ClientRequestStatistics');
83+
7884
const { addAbortSignal, finished } = require('stream');
7985

8086
let debug = require('internal/util/debuglog').debuglog('http', (fn) => {
@@ -337,6 +343,12 @@ ObjectSetPrototypeOf(ClientRequest, OutgoingMessage);
337343
ClientRequest.prototype._finish = function _finish() {
338344
DTRACE_HTTP_CLIENT_REQUEST(this, this.socket);
339345
FunctionPrototypeCall(OutgoingMessage.prototype._finish, this);
346+
if (hasObserver('http')) {
347+
this[kClientRequestStatistics] = {
348+
startTime: process.hrtime(),
349+
type: 'HttpClient',
350+
};
351+
}
340352
};
341353

342354
ClientRequest.prototype._implicitHeader = function _implicitHeader() {
@@ -604,6 +616,7 @@ function parserOnIncomingClient(res, shouldKeepAlive) {
604616
}
605617

606618
DTRACE_HTTP_CLIENT_RESPONSE(socket, req);
619+
emitStatistics(req[kClientRequestStatistics]);
607620
req.res = res;
608621
res.req = req;
609622

lib/_http_server.js

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -193,7 +193,8 @@ function ServerResponse(req) {
193193

194194
if (hasObserver('http')) {
195195
this[kServerResponseStatistics] = {
196-
startTime: process.hrtime()
196+
startTime: process.hrtime(),
197+
type: 'HttpRequest',
197198
};
198199
}
199200
}

lib/internal/http.js

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,7 @@ function emitStatistics(statistics) {
3838
const startTime = statistics.startTime;
3939
const diff = process.hrtime(startTime);
4040
const entry = new InternalPerformanceEntry(
41-
'HttpRequest',
41+
statistics.type,
4242
'http',
4343
startTime[0] * 1000 + startTime[1] / 1e6,
4444
diff[0] * 1000 + diff[1] / 1e6,

test/parallel/test-http-perf_hooks.js

Lines changed: 19 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -5,13 +5,9 @@ const assert = require('assert');
55
const http = require('http');
66

77
const { PerformanceObserver } = require('perf_hooks');
8-
8+
const entris = [];
99
const obs = new PerformanceObserver(common.mustCallAtLeast((items) => {
10-
items.getEntries().forEach((entry) => {
11-
assert.strictEqual(entry.entryType, 'http');
12-
assert.strictEqual(typeof entry.startTime, 'number');
13-
assert.strictEqual(typeof entry.duration, 'number');
14-
});
10+
entris.push(...items.getEntries());
1511
}));
1612

1713
obs.observe({ type: 'http' });
@@ -57,3 +53,20 @@ server.listen(0, common.mustCall(async () => {
5753
]);
5854
server.close();
5955
}));
56+
57+
process.on('exit', () => {
58+
const httpClients = [];
59+
const httpRequests = [];
60+
entris.forEach((entry) => {
61+
assert.strictEqual(entry.entryType, 'http');
62+
assert.strictEqual(typeof entry.startTime, 'number');
63+
assert.strictEqual(typeof entry.duration, 'number');
64+
if (entry.name === 'HttpClient') {
65+
httpClients.push(entry);
66+
} else if (entry.name === 'HttpRequest') {
67+
httpRequests.push(entry);
68+
}
69+
});
70+
assert.strictEqual(httpClients.length, 2);
71+
assert.strictEqual(httpRequests.length, 2);
72+
});

0 commit comments

Comments
 (0)