http: fix incorrect headersTimeout measurement

For keep-alive connections, the headersTimeout may fire during
subsequent request because the measurement was reset after
a request and not before a request.

Backport-PR-URL: #34131
PR-URL: #32329
Fixes: #27363
Reviewed-By: Anna Henningsen <[email protected]>
Reviewed-By: Matteo Collina <[email protected]>

lib/_http_client.js

@@ -674,7 +674,8 @@ function tickOnSocket(req, socket) {
   parser.initialize(HTTPParser.RESPONSE,
                     new HTTPClientAsyncResource('HTTPINCOMINGMESSAGE', req),
                     req.insecureHTTPParser === undefined ?
-                      isLenient() : req.insecureHTTPParser);
+                      isLenient() : req.insecureHTTPParser,
+                    0);
   parser.socket = socket;
   parser.outgoing = req;
   req.parser = parser;

lib/_http_common.js

@@ -50,6 +50,7 @@ const kOnHeadersComplete = HTTPParser.kOnHeadersComplete | 0;
 const kOnBody = HTTPParser.kOnBody | 0;
 const kOnMessageComplete = HTTPParser.kOnMessageComplete | 0;
 const kOnExecute = HTTPParser.kOnExecute | 0;
+const kOnTimeout = HTTPParser.kOnTimeout | 0;
 
 const MAX_HEADER_PAIRS = 2000;
 
@@ -168,6 +169,7 @@ const parsers = new FreeList('parsers', 1000, function parsersCb() {
   parser[kOnHeadersComplete] = parserOnHeadersComplete;
   parser[kOnBody] = parserOnBody;
   parser[kOnMessageComplete] = parserOnMessageComplete;
+  parser[kOnTimeout] = null;
 
   return parser;
 });

lib/_http_server.js

@@ -48,7 +48,6 @@ const { OutgoingMessage } = require('_http_outgoing');
 const {
   kOutHeaders,
   kNeedDrain,
-  nowDate,
   emitStatistics
 } = require('internal/http');
 const {
@@ -143,6 +142,7 @@ const STATUS_CODES = {
 };
 
 const kOnExecute = HTTPParser.kOnExecute | 0;
+const kOnTimeout = HTTPParser.kOnTimeout | 0;
 
 class HTTPServerAsyncResource {
   constructor(type, socket) {
@@ -422,11 +422,9 @@ function connectionListenerInternal(server, socket) {
     new HTTPServerAsyncResource('HTTPINCOMINGMESSAGE', socket),
     server.insecureHTTPParser === undefined ?
       isLenient() : server.insecureHTTPParser,
+    server.headersTimeout || 0,
   );
   parser.socket = socket;
-
-  // We are starting to wait for our headers.
-  parser.parsingHeadersStart = nowDate();
   socket.parser = parser;
 
   // Propagate headers limit from server instance to parser
@@ -478,6 +476,9 @@ function connectionListenerInternal(server, socket) {
   parser[kOnExecute] =
     onParserExecute.bind(undefined, server, socket, parser, state);
 
+  parser[kOnTimeout] =
+    onParserTimeout.bind(undefined, server, socket);
+
   socket._paused = false;
 }
 
@@ -566,25 +567,15 @@ function socketOnData(server, socket, parser, state, d) {
 
 function onParserExecute(server, socket, parser, state, ret) {
   socket._unrefTimer();
-  const start = parser.parsingHeadersStart;
   debug('SERVER socketOnParserExecute %d', ret);
+  onParserExecuteCommon(server, socket, parser, state, ret, undefined);
+}
 
-  // If we have not parsed the headers, destroy the socket
-  // after server.headersTimeout to protect from DoS attacks.
-  // start === 0 means that we have parsed headers, while
-  // server.headersTimeout === 0 means user disabled this check.
-  if (
-    start !== 0 && server.headersTimeout &&
-    nowDate() - start > server.headersTimeout
-  ) {
-    const serverTimeout = server.emit('timeout', socket);
-
-    if (!serverTimeout)
-      socket.destroy();
-    return;
-  }
+function onParserTimeout(server, socket) {
+  const serverTimeout = server.emit('timeout', socket);
 
-  onParserExecuteCommon(server, socket, parser, state, ret, undefined);
+  if (!serverTimeout)
+    socket.destroy();
 }
 
 const noop = () => {};
@@ -721,13 +712,6 @@ function emitCloseNT(self) {
 function parserOnIncoming(server, socket, state, req, keepAlive) {
   resetSocketTimeout(server, socket, state);
 
-  if (server.keepAliveTimeout > 0) {
-    req.on('end', resetHeadersTimeoutOnReqEnd);
-  }
-
-  // Set to zero to communicate that we have finished parsing.
-  socket.parser.parsingHeadersStart = 0;
-
   if (req.upgrade) {
     req.upgrade = req.method === 'CONNECT' ||
                   server.listenerCount('upgrade') > 0;
@@ -852,17 +836,6 @@ function generateSocketListenerWrapper(originalFnName) {
   };
 }
 
-function resetHeadersTimeoutOnReqEnd() {
-  debug('resetHeadersTimeoutOnReqEnd');
-
-  const parser = this.socket.parser;
-  // Parser can be null if the socket was destroyed
-  // in that case, there is nothing to do.
-  if (parser) {
-    parser.parsingHeadersStart = nowDate();
-  }
-}
-
 module.exports = {
   STATUS_CODES,
   Server,

src/node_http_parser_impl.h

@@ -78,6 +78,7 @@ const uint32_t kOnHeadersComplete = 1;
 const uint32_t kOnBody = 2;
 const uint32_t kOnMessageComplete = 3;
 const uint32_t kOnExecute = 4;
+const uint32_t kOnTimeout = 5;
 // Any more fields than this will be flushed into JS
 const size_t kMaxHeaderFieldsCount = 32;
 
@@ -185,6 +186,7 @@ class Parser : public AsyncWrap, public StreamListener {
     num_fields_ = num_values_ = 0;
     url_.Reset();
     status_message_.Reset();
+    header_parsing_start_time_ = uv_hrtime();
     return 0;
   }
 
@@ -518,9 +520,16 @@ class Parser : public AsyncWrap, public StreamListener {
     Environment* env = Environment::GetCurrent(args);
     bool lenient = args[2]->IsTrue();
 
+    uint64_t headers_timeout = 0;
+
     CHECK(args[0]->IsInt32());
     CHECK(args[1]->IsObject());
 
+    if (args.Length() > 3) {
+      CHECK(args[3]->IsInt32());
+      headers_timeout = args[3].As<Int32>()->Value();
+    }
+
     parser_type_t type =
         static_cast<parser_type_t>(args[0].As<Int32>()->Value());
 
@@ -537,7 +546,7 @@ class Parser : public AsyncWrap, public StreamListener {
 
     parser->set_provider_type(provider);
     parser->AsyncReset(args[1].As<Object>());
-    parser->Init(type, lenient);
+    parser->Init(type, lenient, headers_timeout);
   }
 
   template <bool should_pause>
@@ -645,6 +654,24 @@ class Parser : public AsyncWrap, public StreamListener {
     if (ret.IsEmpty())
       return;
 
+    // check header parsing time
+    if (header_parsing_start_time_ != 0 && headers_timeout_ != 0) {
+      uint64_t now = uv_hrtime();
+      uint64_t parsing_time = (now - header_parsing_start_time_) / 1e6;
+
+      if (parsing_time > headers_timeout_) {
+        Local<Value> cb =
+            object()->Get(env()->context(), kOnTimeout).ToLocalChecked();
+
+        if (!cb->IsFunction())
+          return;
+
+        MakeCallback(cb.As<Function>(), 0, nullptr);
+
+        return;
+      }
+    }
+
     Local<Value> cb =
         object()->Get(env()->context(), kOnExecute).ToLocalChecked();
 
@@ -821,7 +848,7 @@ class Parser : public AsyncWrap, public StreamListener {
   }
 
 
-  void Init(parser_type_t type, bool lenient) {
+  void Init(parser_type_t type, bool lenient, uint64_t headers_timeout) {
 #ifdef NODE_EXPERIMENTAL_HTTP
     llhttp_init(&parser_, type, &settings);
     llhttp_set_lenient(&parser_, lenient);
@@ -836,6 +863,8 @@ class Parser : public AsyncWrap, public StreamListener {
     num_values_ = 0;
     have_flushed_ = false;
     got_exception_ = false;
+    header_parsing_start_time_ = 0;
+    headers_timeout_ = headers_timeout;
   }
 
 
@@ -884,6 +913,8 @@ class Parser : public AsyncWrap, public StreamListener {
   bool pending_pause_ = false;
   uint64_t header_nread_ = 0;
 #endif  /* NODE_EXPERIMENTAL_HTTP */
+  uint64_t headers_timeout_;
+  uint64_t header_parsing_start_time_ = 0;
 
   // These are helper functions for filling `http_parser_settings`, which turn
   // a member function of Parser into a C-style HTTP parser callback.
@@ -957,6 +988,8 @@ void InitializeHttpParser(Local<Object> target,
          Integer::NewFromUnsigned(env->isolate(), kOnMessageComplete));
   t->Set(FIXED_ONE_BYTE_STRING(env->isolate(), "kOnExecute"),
          Integer::NewFromUnsigned(env->isolate(), kOnExecute));
+  t->Set(FIXED_ONE_BYTE_STRING(env->isolate(), "kOnTimeout"),
+         Integer::NewFromUnsigned(env->isolate(), kOnTimeout));
 
   Local<Array> methods = Array::New(env->isolate());
 #define V(num, name, string)                                                  \

test/async-hooks/test-graph.http.js

@@ -44,8 +44,8 @@ process.on('exit', () => {
         id: 'httpincomingmessage:1',
         triggerAsyncId: 'tcp:2' },
       { type: 'Timeout',
-        id: 'timeout:2',
-        triggerAsyncId: 'tcp:2' },
+        id: 'timeout:1',
+        triggerAsyncId: 'httpincomingmessage:1' },
       { type: 'SHUTDOWNWRAP',
         id: 'shutdown:1',
         triggerAsyncId: 'tcp:2' } ]

test/parallel/test-http-slow-headers-keepalive-multiple-requests.js

@@ -0,0 +1,51 @@
+'use strict';
+
+const common = require('../common');
+const http = require('http');
+const net = require('net');
+const { finished } = require('stream');
+
+const headers =
+  'GET / HTTP/1.1\r\n' +
+  'Host: localhost\r\n' +
+  'Connection: keep-alive\r\n' +
+  'Agent: node\r\n';
+
+const baseTimeout = 1000;
+
+const server = http.createServer(common.mustCall((req, res) => {
+  req.resume();
+  res.writeHead(200);
+  res.end();
+}, 2));
+
+server.keepAliveTimeout = 10 * baseTimeout;
+server.headersTimeout = baseTimeout;
+
+server.once('timeout', common.mustNotCall((socket) => {
+  socket.destroy();
+}));
+
+server.listen(0, () => {
+  const client = net.connect(server.address().port);
+
+  // first request
+  client.write(headers);
+  client.write('\r\n');
+
+  setTimeout(() => {
+    // second request
+    client.write(headers);
+    // `headersTimeout` doesn't seem to fire if request
+    // is sent altogether.
+    setTimeout(() => {
+      client.write('\r\n');
+      client.end();
+    }, 10);
+  }, baseTimeout + 10);
+
+  client.resume();
+  finished(client, common.mustCall((err) => {
+    server.close();
+  }));
+});