From 8e5f1a705e39810ddb8dfbc95fa4fd82007e05a2 Mon Sep 17 00:00:00 2001 From: Andreas Madsen Date: Fri, 5 Jan 2018 15:40:47 +0100 Subject: [PATCH 1/3] async_hooks,http: set HTTPParser trigger to socket This allows more easy tracking of where HTTP requests come from. Before this change the HTTPParser would have the HTTPServer as the triggerAsyncId. The HTTPParser will still have the executionAsyncId set to the HTTP Server so that information is still directly available. Indirectly, the TCP socket itself also has its triggerAsyncId set to the TCP Server. --- lib/_http_server.js | 28 +++++++++++----- lib/internal/async_hooks.js | 12 ++++++- test/async-hooks/test-graph.http.js | 52 +++++++++++++++++++++++++++++ 3 files changed, 82 insertions(+), 10 deletions(-) create mode 100644 test/async-hooks/test-graph.http.js diff --git a/lib/_http_server.js b/lib/_http_server.js index 5857e43d79c787..a616f295e1383e 100644 --- a/lib/_http_server.js +++ b/lib/_http_server.js @@ -37,6 +37,10 @@ const { } = require('_http_common'); const { OutgoingMessage } = require('_http_outgoing'); const { outHeadersKey, ondrain } = require('internal/http'); +const { + defaultTriggerAsyncIdScope, + getOrSetAsyncId +} = require('internal/async_hooks'); const errors = require('internal/errors'); const Buffer = require('buffer').Buffer; @@ -292,6 +296,12 @@ Server.prototype.setTimeout = function setTimeout(msecs, callback) { function connectionListener(socket) { + defaultTriggerAsyncIdScope( + getOrSetAsyncId(socket), [this, socket], connectionListenerInternal + ); +} + +function connectionListenerInternal(server, socket) { debug('SERVER new http connection'); httpSocketSetup(socket); @@ -299,13 +309,13 @@ function connectionListener(socket) { // Ensure that the server property of the socket is correctly set. // See https://github.com/nodejs/node/issues/13435 if (socket.server === null) - socket.server = this; + socket.server = server; // If the user has added a listener to the server, // request, or response, then it's their responsibility. // otherwise, destroy on timeout by default - if (this.timeout && typeof socket.setTimeout === 'function') - socket.setTimeout(this.timeout); + if (server.timeout && typeof socket.setTimeout === 'function') + socket.setTimeout(server.timeout); socket.on('timeout', socketOnTimeout); var parser = parsers.alloc(); @@ -315,8 +325,8 @@ function connectionListener(socket) { parser.incoming = null; // Propagate headers limit from server instance to parser - if (typeof this.maxHeadersCount === 'number') { - parser.maxHeaderPairs = this.maxHeadersCount << 1; + if (typeof server.maxHeadersCount === 'number') { + parser.maxHeaderPairs = server.maxHeadersCount << 1; } else { // Set default value because parser may be reused from FreeList parser.maxHeaderPairs = 2000; @@ -336,8 +346,8 @@ function connectionListener(socket) { outgoingData: 0, keepAliveTimeoutSet: false }; - state.onData = socketOnData.bind(undefined, this, socket, parser, state); - state.onEnd = socketOnEnd.bind(undefined, this, socket, parser, state); + state.onData = socketOnData.bind(undefined, server, socket, parser, state); + state.onEnd = socketOnEnd.bind(undefined, server, socket, parser, state); state.onClose = socketOnClose.bind(undefined, socket, state); state.onDrain = socketOnDrain.bind(undefined, socket, state); socket.on('data', state.onData); @@ -345,7 +355,7 @@ function connectionListener(socket) { socket.on('end', state.onEnd); socket.on('close', state.onClose); socket.on('drain', state.onDrain); - parser.onIncoming = parserOnIncoming.bind(undefined, this, socket, state); + parser.onIncoming = parserOnIncoming.bind(undefined, server, socket, state); // We are consuming socket, so it won't get any actual data socket.on('resume', onSocketResume); @@ -364,7 +374,7 @@ function connectionListener(socket) { } } parser[kOnExecute] = - onParserExecute.bind(undefined, this, socket, parser, state); + onParserExecute.bind(undefined, server, socket, parser, state); socket._paused = false; } diff --git a/lib/internal/async_hooks.js b/lib/internal/async_hooks.js index 801d90b7f504e8..f15997e65d3e8f 100644 --- a/lib/internal/async_hooks.js +++ b/lib/internal/async_hooks.js @@ -26,7 +26,7 @@ const async_wrap = process.binding('async_wrap'); * It has a fixed size, so if that is exceeded, calls to the native * side are used instead in pushAsyncIds() and popAsyncIds(). */ -const { async_hook_fields, async_id_fields } = async_wrap; +const { async_id_symbol, async_hook_fields, async_id_fields } = async_wrap; // Store the pair executionAsyncId and triggerAsyncId in a std::stack on // Environment::AsyncHooks::ids_stack_ tracks the resource responsible for the // current execution stack. This is unwound as each resource exits. In the case @@ -248,6 +248,15 @@ function newUid() { return ++async_id_fields[kAsyncIdCounter]; } +function getOrSetAsyncId(object) { + if (object.hasOwnProperty(async_id_symbol)) { + return object[async_id_symbol]; + } + + return object[async_id_symbol] = newUid(); +} + + // Return the triggerAsyncId meant for the constructor calling it. It's up to // the user to safeguard this call and make sure it's zero'd out when the // constructor is complete. @@ -378,6 +387,7 @@ module.exports = { disableHooks, // Internal Embedder API newUid, + getOrSetAsyncId, getDefaultTriggerAsyncId, defaultTriggerAsyncIdScope, emitInit: emitInitScript, diff --git a/test/async-hooks/test-graph.http.js b/test/async-hooks/test-graph.http.js new file mode 100644 index 00000000000000..ab3a77d2e661aa --- /dev/null +++ b/test/async-hooks/test-graph.http.js @@ -0,0 +1,52 @@ +'use strict'; + +const common = require('../common'); +const initHooks = require('./init-hooks'); +const verifyGraph = require('./verify-graph'); +const http = require('http'); + +const hooks = initHooks(); +hooks.enable(); + +const server = http.createServer(common.mustCall(function(req, res) { + res.end(); + this.close(common.mustCall()); +})); +server.listen(0, common.mustCall()); + +http.get(`http://127.0.0.1:${server.address().port}`, common.mustCall()); + +process.on('exit', function() { + hooks.disable(); + + verifyGraph( + hooks, + [ { type: 'TCPSERVERWRAP', + id: 'tcpserver:1', + triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: null }, + { type: 'TCPCONNECTWRAP', + id: 'tcpconnect:1', + triggerAsyncId: 'tcp:1' }, + { type: 'HTTPPARSER', id: 'httpparser:1', triggerAsyncId: null }, + { type: 'HTTPPARSER', id: 'httpparser:2', triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:2', triggerAsyncId: 'tcpserver:1' }, + { type: 'Timeout', id: 'timeout:1', triggerAsyncId: 'tcp:2' }, + { type: 'TIMERWRAP', id: 'timer:1', triggerAsyncId: 'tcp:2' }, + { type: 'HTTPPARSER', + id: 'httpparser:3', + triggerAsyncId: 'tcp:2' }, + { type: 'HTTPPARSER', + id: 'httpparser:4', + triggerAsyncId: 'tcp:2' }, + { type: 'Timeout', + id: 'timeout:2', + triggerAsyncId: 'httpparser:4' }, + { type: 'TIMERWRAP', + id: 'timer:2', + triggerAsyncId: 'httpparser:4' }, + { type: 'SHUTDOWNWRAP', + id: 'shutdown:1', + triggerAsyncId: 'tcp:2' } ] + ); +}); From cb18aa4676dbedd330b080b513c98a131472ba81 Mon Sep 17 00:00:00 2001 From: Andreas Madsen Date: Fri, 5 Jan 2018 23:09:12 +0100 Subject: [PATCH 2/3] [squash] prevent race condition --- test/async-hooks/test-graph.http.js | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/test/async-hooks/test-graph.http.js b/test/async-hooks/test-graph.http.js index ab3a77d2e661aa..5c0c99f408c824 100644 --- a/test/async-hooks/test-graph.http.js +++ b/test/async-hooks/test-graph.http.js @@ -12,9 +12,9 @@ const server = http.createServer(common.mustCall(function(req, res) { res.end(); this.close(common.mustCall()); })); -server.listen(0, common.mustCall()); - -http.get(`http://127.0.0.1:${server.address().port}`, common.mustCall()); +server.listen(0, common.mustCall(function() { + http.get(`http://127.0.0.1:${server.address().port}`, common.mustCall()); +})); process.on('exit', function() { hooks.disable(); @@ -24,12 +24,16 @@ process.on('exit', function() { [ { type: 'TCPSERVERWRAP', id: 'tcpserver:1', triggerAsyncId: null }, - { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: null }, + { type: 'TCPWRAP', id: 'tcp:1', triggerAsyncId: 'tcpserver:1' }, { type: 'TCPCONNECTWRAP', id: 'tcpconnect:1', triggerAsyncId: 'tcp:1' }, - { type: 'HTTPPARSER', id: 'httpparser:1', triggerAsyncId: null }, - { type: 'HTTPPARSER', id: 'httpparser:2', triggerAsyncId: null }, + { type: 'HTTPPARSER', + id: 'httpparser:1', + triggerAsyncId: 'tcpserver:1' }, + { type: 'HTTPPARSER', + id: 'httpparser:2', + triggerAsyncId: 'tcpserver:1' }, { type: 'TCPWRAP', id: 'tcp:2', triggerAsyncId: 'tcpserver:1' }, { type: 'Timeout', id: 'timeout:1', triggerAsyncId: 'tcp:2' }, { type: 'TIMERWRAP', id: 'timer:1', triggerAsyncId: 'tcp:2' }, From 38cc5b2fd3c5285899408422dec3a10dcfcf3807 Mon Sep 17 00:00:00 2001 From: Andreas Madsen Date: Wed, 10 Jan 2018 14:21:27 +0100 Subject: [PATCH 3/3] [squash] rebase fix --- lib/_http_server.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/_http_server.js b/lib/_http_server.js index a616f295e1383e..dee0de74bc75de 100644 --- a/lib/_http_server.js +++ b/lib/_http_server.js @@ -297,7 +297,7 @@ Server.prototype.setTimeout = function setTimeout(msecs, callback) { function connectionListener(socket) { defaultTriggerAsyncIdScope( - getOrSetAsyncId(socket), [this, socket], connectionListenerInternal + getOrSetAsyncId(socket), connectionListenerInternal, this, socket ); }