GeezerVison is showing github.com — http: report request start and end with diagnostics_channel · nodejs/node@f861733
File treeExpand file treeCollapse file tree Open diff view settings benchmark/diagnostics_channel
Expand file treeCollapse file tree Open diff view settings Collapse file Copy file name to clipboard +96Lines changed: 96 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
| | 1 | +'use strict'; | | 2 | +const common = require('../common.js'); | | 3 | +const dc = require('diagnostics_channel'); | | 4 | +const { AsyncLocalStorage } = require('async_hooks'); | | 5 | +const http = require('http'); | | 6 | + | | 7 | +const bench = common.createBenchmark(main, { | | 8 | + apm: ['none', 'diagnostics_channel', 'patch'], | | 9 | + type: 'buffer', | | 10 | + len: 1024, | | 11 | + chunks: 4, | | 12 | + connections: [50, 500], | | 13 | + chunkedEnc: 1, | | 14 | + duration: 5 | | 15 | +}); | | 16 | + | | 17 | +function main({ apm, connections, duration, type, len, chunks, chunkedEnc }) { | | 18 | + const done = { none, patch, diagnostics_channel }[apm](); | | 19 | + | | 20 | + const server = require('../fixtures/simple-http-server.js') | | 21 | + .listen(common.PORT) | | 22 | + .on('listening', () => { | | 23 | + const path = `/${type}/${len}/${chunks}/normal/${chunkedEnc}`; | | 24 | + bench.http({ | | 25 | + path, | | 26 | + connections, | | 27 | + duration | | 28 | + }, () => { | | 29 | + server.close(); | | 30 | + if (done) done(); | | 31 | + }); | | 32 | + }); | | 33 | +} | | 34 | + | | 35 | +function none() {} | | 36 | + | | 37 | +function patch() { | | 38 | + const als = new AsyncLocalStorage(); | | 39 | + const times = []; | | 40 | + | | 41 | + const { emit } = http.Server.prototype; | | 42 | + function wrappedEmit(...args) { | | 43 | + const [name, req, res] = args; | | 44 | + if (name === 'request') { | | 45 | + als.enterWith({ | | 46 | + url: req.url, | | 47 | + start: process.hrtime.bigint() | | 48 | + }); | | 49 | + | | 50 | + res.on('finish', () => { | | 51 | + times.push({ | | 52 | + ...als.getStore(), | | 53 | + statusCode: res.statusCode, | | 54 | + end: process.hrtime.bigint() | | 55 | + }); | | 56 | + }); | | 57 | + } | | 58 | + return emit.apply(this, args); | | 59 | + } | | 60 | + http.Server.prototype.emit = wrappedEmit; | | 61 | + | | 62 | + return () => { | | 63 | + http.Server.prototype.emit = emit; | | 64 | + }; | | 65 | +} | | 66 | + | | 67 | +function diagnostics_channel() { | | 68 | + const als = new AsyncLocalStorage(); | | 69 | + const times = []; | | 70 | + | | 71 | + const start = dc.channel('http.server.request.start'); | | 72 | + const finish = dc.channel('http.server.response.finish'); | | 73 | + | | 74 | + function onStart(req) { | | 75 | + als.enterWith({ | | 76 | + url: req.url, | | 77 | + start: process.hrtime.bigint() | | 78 | + }); | | 79 | + } | | 80 | + | | 81 | + function onFinish(res) { | | 82 | + times.push({ | | 83 | + ...als.getStore(), | | 84 | + statusCode: res.statusCode, | | 85 | + end: process.hrtime.bigint() | | 86 | + }); | | 87 | + } | | 88 | + | | 89 | + start.subscribe(onStart); | | 90 | + finish.subscribe(onFinish); | | 91 | + | | 92 | + return () => { | | 93 | + start.unsubscribe(onStart); | | 94 | + finish.unsubscribe(onFinish); | | 95 | + }; | | 96 | +} |
Collapse file Copy file name to clipboardExpand all lines: lib/_http_server.js +22Lines changed: 22 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
@@ -84,6 +84,10 @@ const { observerCounts, constants } = internalBinding('performance'); | 84 | 84 | const { setTimeout, clearTimeout } = require('timers'); | 85 | 85 | const { NODE_PERFORMANCE_ENTRY_TYPE_HTTP } = constants; | 86 | 86 |
| | 87 | +const dc = require('diagnostics_channel'); | | 88 | +const onRequestStartChannel = dc.channel('http.server.request.start'); | | 89 | +const onResponseFinishChannel = dc.channel('http.server.response.finish'); | | 90 | + | 87 | 91 | const kServerResponse = Symbol('ServerResponse'); | 88 | 92 | const kServerResponseStatistics = Symbol('ServerResponseStatistics'); | 89 | 93 |
| @@ -775,6 +779,15 @@ function clearRequestTimeout(req) { | 775 | 779 | } | 776 | 780 |
| 777 | 781 | function resOnFinish(req, res, socket, state, server) { | | 782 | + if (onResponseFinishChannel.hasSubscribers) { | | 783 | + onResponseFinishChannel.publish({ | | 784 | + request: req, | | 785 | + response: res, | | 786 | + socket, | | 787 | + server | | 788 | + }); | | 789 | + } | | 790 | + | 778 | 791 | // Usually the first incoming element should be our request. it may | 779 | 792 | // be that in the case abortIncoming() was called that the incoming | 780 | 793 | // array will be empty. | @@ -862,6 +875,15 @@ function parserOnIncoming(server, socket, state, req, keepAlive) { | 862 | 875 | res.shouldKeepAlive = keepAlive; | 863 | 876 | DTRACE_HTTP_SERVER_REQUEST(req, socket); | 864 | 877 |
| | 878 | + if (onRequestStartChannel.hasSubscribers) { | | 879 | + onRequestStartChannel.publish({ | | 880 | + request: req, | | 881 | + response: res, | | 882 | + socket, | | 883 | + server | | 884 | + }); | | 885 | + } | | 886 | + | 865 | 887 | if (socket._httpMessage) { | 866 | 888 | // There are already pending outgoing res, append. | 867 | 889 | state.outgoing.push(res); | |
Collapse file Copy file name to clipboard +65Lines changed: 65 additions & 0 deletions | Original file line number | Diff line number | Diff line change |
|---|
| | 1 | +'use strict'; | | 2 | + | | 3 | +const common = require('../common'); | | 4 | +const { AsyncLocalStorage } = require('async_hooks'); | | 5 | +const dc = require('diagnostics_channel'); | | 6 | +const assert = require('assert'); | | 7 | +const http = require('http'); | | 8 | + | | 9 | +const incomingStartChannel = dc.channel('http.server.request.start'); | | 10 | +const outgoingFinishChannel = dc.channel('http.server.response.finish'); | | 11 | + | | 12 | +const als = new AsyncLocalStorage(); | | 13 | +let context; | | 14 | + | | 15 | +// Bind requests to an AsyncLocalStorage context | | 16 | +incomingStartChannel.subscribe(common.mustCall((message) => { | | 17 | + als.enterWith(message); | | 18 | + context = message; | | 19 | +})); | | 20 | + | | 21 | +// When the request ends, verify the context has been maintained | | 22 | +// and that the messages contain the expected data | | 23 | +outgoingFinishChannel.subscribe(common.mustCall((message) => { | | 24 | + const data = { | | 25 | + request, | | 26 | + response, | | 27 | + server, | | 28 | + socket: request.socket | | 29 | + }; | | 30 | + | | 31 | + // Context is maintained | | 32 | + compare(als.getStore(), context); | | 33 | + | | 34 | + compare(context, data); | | 35 | + compare(message, data); | | 36 | +})); | | 37 | + | | 38 | +let request; | | 39 | +let response; | | 40 | + | | 41 | +const server = http.createServer(common.mustCall((req, res) => { | | 42 | + request = req; | | 43 | + response = res; | | 44 | + | | 45 | + setTimeout(() => { | | 46 | + res.end('done'); | | 47 | + }, 1); | | 48 | +})); | | 49 | + | | 50 | +server.listen(() => { | | 51 | + const { port } = server.address(); | | 52 | + http.get(`http://localhost:${port}`, (res) => { | | 53 | + res.resume(); | | 54 | + res.on('end', () => { | | 55 | + server.close(); | | 56 | + }); | | 57 | + }); | | 58 | +}); | | 59 | + | | 60 | +function compare(a, b) { | | 61 | + assert.strictEqual(a.request, b.request); | | 62 | + assert.strictEqual(a.response, b.response); | | 63 | + assert.strictEqual(a.socket, b.socket); | | 64 | + assert.strictEqual(a.server, b.server); | | 65 | +} |
|