Skip to content

Commit 1112e20

Browse files
committed
http: trace http request / response
1 parent 10ee408 commit 1112e20

File tree

5 files changed

+107
-1
lines changed

5 files changed

+107
-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

+18-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+
isTraceHTTPCategory,
71+
traceBegin,
72+
traceEnd,
73+
getNextTraceEventId,
74+
} = require('internal/http');
6875
const { connResetException, codes } = require('internal/errors');
6976
const {
7077
ERR_HTTP_HEADERS_SENT,
@@ -370,6 +377,10 @@ ClientRequest.prototype._finish = function _finish() {
370377
request: this,
371378
});
372379
}
380+
if (isTraceHTTPCategory()) {
381+
this._traceEventId = getNextTraceEventId();
382+
traceBegin('http.client.request', this._traceEventId);
383+
}
373384
};
374385

375386
ClientRequest.prototype._implicitHeader = function _implicitHeader() {
@@ -653,6 +664,12 @@ function parserOnIncomingClient(res, shouldKeepAlive) {
653664
response: res,
654665
});
655666
}
667+
if (isTraceHTTPCategory() && req._traceEventId) {
668+
traceEnd('http.client.request', req._traceEventId, {
669+
path: req.path,
670+
statusCode: res.statusCode,
671+
});
672+
}
656673
req.res = res;
657674
res.req = req;
658675

lib/_http_server.js

+15
Original file line numberDiff line numberDiff line change
@@ -55,6 +55,10 @@ const {
5555
const {
5656
kOutHeaders,
5757
kNeedDrain,
58+
isTraceHTTPCategory,
59+
traceBegin,
60+
traceEnd,
61+
getNextTraceEventId,
5862
} = require('internal/http');
5963
const {
6064
defaultTriggerAsyncIdScope,
@@ -206,6 +210,10 @@ function ServerResponse(req) {
206210
},
207211
});
208212
}
213+
if (isTraceHTTPCategory()) {
214+
this._traceEventId = getNextTraceEventId();
215+
traceBegin('http.server.request', this._traceEventId);
216+
}
209217
}
210218
ObjectSetPrototypeOf(ServerResponse.prototype, OutgoingMessage.prototype);
211219
ObjectSetPrototypeOf(ServerResponse, OutgoingMessage);
@@ -223,6 +231,13 @@ ServerResponse.prototype._finish = function _finish() {
223231
});
224232
}
225233
OutgoingMessage.prototype._finish.call(this);
234+
if (isTraceHTTPCategory() && this._traceEventId) {
235+
const data = {
236+
url: this.req?.url,
237+
statusCode: this.statusCode,
238+
};
239+
traceEnd('http.server.request', this._traceEventId, data);
240+
}
226241
};
227242

228243

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 isTraceHTTPCategory() {
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+
isTraceHTTPCategory,
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)