Skip to content
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.

Commit 4c5b96b

Browse files
authoredAug 5, 2022
http: trace http request / response
PR-URL: #44102 Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Paolo Insogna <[email protected]>
1 parent 464d1c1 commit 4c5b96b

File tree

5 files changed

+111
-1
lines changed

5 files changed

+111
-1
lines changed
 

‎doc/api/tracing.md

+1
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ The available categories are:
3636
* `node.vm.script`: Enables capture of trace data for the `node:vm` module's
3737
`runInNewContext()`, `runInContext()`, and `runInThisContext()` methods.
3838
* `v8`: The [V8][] events are GC, compiling, and execution related.
39+
* `node.http`: Enables capture of trace data for http request / response.
3940

4041
By default the `node`, `node.async_hooks`, and `v8` categories are enabled.
4142

‎lib/_http_client.js

+20-1
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,14 @@ const Agent = require('_http_agent');
6464
const { Buffer } = require('buffer');
6565
const { defaultTriggerAsyncIdScope } = require('internal/async_hooks');
6666
const { URL, urlToHttpOptions, searchParamsSymbol } = require('internal/url');
67-
const { kOutHeaders, kNeedDrain } = require('internal/http');
67+
const {
68+
kOutHeaders,
69+
kNeedDrain,
70+
isTraceHTTPEnabled,
71+
traceBegin,
72+
traceEnd,
73+
getNextTraceEventId,
74+
} = require('internal/http');
6875
const { connResetException, codes } = require('internal/errors');
6976
const {
7077
ERR_HTTP_HEADERS_SENT,
@@ -101,6 +108,8 @@ const kError = Symbol('kError');
101108
const kLenientAll = HTTPParser.kLenientAll | 0;
102109
const kLenientNone = HTTPParser.kLenientNone | 0;
103110

111+
const HTTP_CLIENT_TRACE_EVENT_NAME = 'http.client.request';
112+
104113
function validateHost(host, name) {
105114
if (host !== null && host !== undefined && typeof host !== 'string') {
106115
throw new ERR_INVALID_ARG_TYPE(`options.${name}`,
@@ -370,6 +379,10 @@ ClientRequest.prototype._finish = function _finish() {
370379
request: this,
371380
});
372381
}
382+
if (isTraceHTTPEnabled()) {
383+
this._traceEventId = getNextTraceEventId();
384+
traceBegin(HTTP_CLIENT_TRACE_EVENT_NAME, this._traceEventId);
385+
}
373386
};
374387

375388
ClientRequest.prototype._implicitHeader = function _implicitHeader() {
@@ -653,6 +666,12 @@ function parserOnIncomingClient(res, shouldKeepAlive) {
653666
response: res,
654667
});
655668
}
669+
if (isTraceHTTPEnabled() && typeof req._traceEventId === 'number') {
670+
traceEnd(HTTP_CLIENT_TRACE_EVENT_NAME, req._traceEventId, {
671+
path: req.path,
672+
statusCode: res.statusCode,
673+
});
674+
}
656675
req.res = res;
657676
res.req = req;
658677

‎lib/_http_server.js

+17
Original file line numberDiff line numberDiff line change
@@ -55,6 +55,10 @@ const {
5555
const {
5656
kOutHeaders,
5757
kNeedDrain,
58+
isTraceHTTPEnabled,
59+
traceBegin,
60+
traceEnd,
61+
getNextTraceEventId,
5862
} = require('internal/http');
5963
const {
6064
defaultTriggerAsyncIdScope,
@@ -170,6 +174,8 @@ const kLenientNone = HTTPParser.kLenientNone | 0;
170174
const kConnections = Symbol('http.server.connections');
171175
const kConnectionsCheckingInterval = Symbol('http.server.connectionsCheckingInterval');
172176

177+
const HTTP_SERVER_TRACE_EVENT_NAME = 'http.server.request';
178+
173179
class HTTPServerAsyncResource {
174180
constructor(type, socket) {
175181
this.type = type;
@@ -206,6 +212,10 @@ function ServerResponse(req) {
206212
},
207213
});
208214
}
215+
if (isTraceHTTPEnabled()) {
216+
this._traceEventId = getNextTraceEventId();
217+
traceBegin(HTTP_SERVER_TRACE_EVENT_NAME, this._traceEventId);
218+
}
209219
}
210220
ObjectSetPrototypeOf(ServerResponse.prototype, OutgoingMessage.prototype);
211221
ObjectSetPrototypeOf(ServerResponse, OutgoingMessage);
@@ -223,6 +233,13 @@ ServerResponse.prototype._finish = function _finish() {
223233
});
224234
}
225235
OutgoingMessage.prototype._finish.call(this);
236+
if (isTraceHTTPEnabled() && typeof this._traceEventId === 'number') {
237+
const data = {
238+
url: this.req?.url,
239+
statusCode: this.statusCode,
240+
};
241+
traceEnd(HTTP_SERVER_TRACE_EVENT_NAME, this._traceEventId, data);
242+
}
226243
};
227244

228245

‎lib/internal/http.js

+29
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,11 @@ const {
88
} = primordials;
99

1010
const { setUnrefTimeout } = require('internal/timers');
11+
const { trace, isTraceCategoryEnabled } = internalBinding('trace_events');
12+
const {
13+
CHAR_LOWERCASE_B,
14+
CHAR_LOWERCASE_E,
15+
} = require('internal/constants');
1116

1217
let utcCache;
1318

@@ -26,8 +31,32 @@ function resetCache() {
2631
utcCache = undefined;
2732
}
2833

34+
let traceEventId = 0;
35+
36+
function getNextTraceEventId() {
37+
return ++traceEventId;
38+
}
39+
40+
function isTraceHTTPEnabled() {
41+
return isTraceCategoryEnabled('node.http');
42+
}
43+
44+
const traceEventCategory = 'node,node.http';
45+
46+
function traceBegin(...args) {
47+
trace(CHAR_LOWERCASE_B, traceEventCategory, ...args);
48+
}
49+
50+
function traceEnd(...args) {
51+
trace(CHAR_LOWERCASE_E, traceEventCategory, ...args);
52+
}
53+
2954
module.exports = {
3055
kOutHeaders: Symbol('kOutHeaders'),
3156
kNeedDrain: Symbol('kNeedDrain'),
3257
utcDate,
58+
traceBegin,
59+
traceEnd,
60+
getNextTraceEventId,
61+
isTraceHTTPEnabled,
3362
};
+44
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,44 @@
1+
'use strict';
2+
const common = require('../common');
3+
const assert = require('assert');
4+
const cp = require('child_process');
5+
const fs = require('fs');
6+
const path = require('path');
7+
const tmpdir = require('../common/tmpdir');
8+
9+
const CODE = `
10+
const http = require('http');
11+
const server = http.createServer((req, res) => {
12+
res.end('ok');
13+
server.close();
14+
}).listen(0, () => {
15+
http.get({port: server.address().port});
16+
});
17+
`;
18+
19+
tmpdir.refresh();
20+
const FILE_NAME = path.join(tmpdir.path, 'node_trace.1.log');
21+
22+
const proc = cp.spawn(process.execPath,
23+
[ '--trace-events-enabled',
24+
'--trace-event-categories', 'node.http',
25+
'-e', CODE ],
26+
{ cwd: tmpdir.path });
27+
28+
proc.once('exit', common.mustCall(() => {
29+
assert(fs.existsSync(FILE_NAME));
30+
fs.readFile(FILE_NAME, common.mustCall((err, data) => {
31+
assert(!err);
32+
const traces = JSON.parse(data.toString()).traceEvents;
33+
assert(traces.length > 0);
34+
let count = 0;
35+
traces.forEach((trace) => {
36+
if (trace.cat === 'node,node.http' &&
37+
['http.server.request', 'http.client.request'].includes(trace.name)) {
38+
count++;
39+
}
40+
});
41+
// Two begin, two end
42+
assert.strictEqual(count, 4);
43+
}));
44+
}));

0 commit comments

Comments
 (0)
Please sign in to comment.