http: add perf_hooks detail for http request and client

PR-URL: #43361
Reviewed-By: Paolo Insogna <paolo@cowtech.it>
Reviewed-By: Matteo Collina <matteo.collina@gmail.com>

doc/api/perf_hooks.md

@@ -521,6 +521,24 @@ property will be an {Object} with two properties:
   * `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_ALL_EXTERNAL_MEMORY`
   * `perf_hooks.constants.NODE_PERFORMANCE_GC_FLAGS_SCHEDULE_IDLE`
 
+### HTTP ('http') Details
+
+When `performanceEntry.type` is equal to `'http'`, the `performanceEntry.detail`
+property will be an {Object} containing additional information.
+
+If `performanceEntry.name` is equal to `HttpClient`, the `detail`
+will contain the following properties: `req`, `res`. And the `req` property
+will be an {Object} containing `method`, `url`, `headers`, the `res` property
+will be an {Object} containing `statusCode`, `statusMessage`, `headers`.
+
+If `performanceEntry.name` is equal to `HttpRequest`, the `detail`
+will contain the following properties: `req`, `res`. And the `req` property
+will be an {Object} containing `method`, `url`, `headers`, the `res` property
+will be an {Object} containing `statusCode`, `statusMessage`, `headers`.
+
+This could add additional memory overhead and should only be used for
+diagnostic purposes, not left turned on in production by default.
+
 ### HTTP/2 ('http2') Details
 
 When `performanceEntry.type` is equal to `'http2'`, the

lib/_http_client.js

@@ -64,7 +64,7 @@ const Agent = require('_http_agent');
 const { Buffer } = require('buffer');
 const { defaultTriggerAsyncIdScope } = require('internal/async_hooks');
 const { URL, urlToHttpOptions, searchParamsSymbol } = require('internal/url');
-const { kOutHeaders, kNeedDrain, emitStatistics } = require('internal/http');
+const { kOutHeaders, kNeedDrain } = require('internal/http');
 const { connResetException, codes } = require('internal/errors');
 const {
   ERR_HTTP_HEADERS_SENT,
@@ -84,10 +84,10 @@ const {
 
 const {
   hasObserver,
+  startPerf,
+  stopPerf,
 } = require('internal/perf/observe');
 
-const { now } = require('internal/perf/utils');
-
 const kClientRequestStatistics = Symbol('ClientRequestStatistics');
 
 const { addAbortSignal, finished } = require('stream');
@@ -355,10 +355,17 @@ ClientRequest.prototype._finish = function _finish() {
   DTRACE_HTTP_CLIENT_REQUEST(this, this.socket);
   FunctionPrototypeCall(OutgoingMessage.prototype._finish, this);
   if (hasObserver('http')) {
-    this[kClientRequestStatistics] = {
-      startTime: now(),
-      type: 'HttpClient',
-    };
+    startPerf(this, kClientRequestStatistics, {
+      type: 'http',
+      name: 'HttpClient',
+      detail: {
+        req: {
+          method: this.method,
+          url: `${this.protocol}//${this.host}${this.path}`,
+          headers: typeof this.getHeaders === 'function' ? this.getHeaders() : {},
+        },
+      },
+    });
   }
 };
 
@@ -627,7 +634,17 @@ function parserOnIncomingClient(res, shouldKeepAlive) {
   }
 
   DTRACE_HTTP_CLIENT_RESPONSE(socket, req);
-  emitStatistics(req[kClientRequestStatistics]);
+  if (req[kClientRequestStatistics] && hasObserver('http')) {
+    stopPerf(req, kClientRequestStatistics, {
+      detail: {
+        res: {
+          statusCode: res.statusCode,
+          statusMessage: res.statusMessage,
+          headers: res.headers,
+        },
+      },
+    });
+  }
   req.res = res;
   res.req = req;
 

lib/_http_server.js

@@ -54,7 +54,6 @@ const {
 const {
   kOutHeaders,
   kNeedDrain,
-  emitStatistics
 } = require('internal/http');
 const {
   defaultTriggerAsyncIdScope,
@@ -98,10 +97,10 @@ const kServerResponseStatistics = Symbol('ServerResponseStatistics');
 
 const {
   hasObserver,
+  startPerf,
+  stopPerf,
 } = require('internal/perf/observe');
 
-const { now } = require('internal/perf/utils');
-
 const STATUS_CODES = {
   100: 'Continue',                   // RFC 7231 6.2.1
   101: 'Switching Protocols',        // RFC 7231 6.2.2
@@ -198,18 +197,35 @@ function ServerResponse(req) {
   }
 
   if (hasObserver('http')) {
-    this[kServerResponseStatistics] = {
-      startTime: now(),
-      type: 'HttpRequest',
-    };
+    startPerf(this, kServerResponseStatistics, {
+      type: 'http',
+      name: 'HttpRequest',
+      detail: {
+        req: {
+          method: req.method,
+          url: req.url,
+          headers: req.headers,
+        },
+      },
+    });
   }
 }
 ObjectSetPrototypeOf(ServerResponse.prototype, OutgoingMessage.prototype);
 ObjectSetPrototypeOf(ServerResponse, OutgoingMessage);
 
 ServerResponse.prototype._finish = function _finish() {
   DTRACE_HTTP_SERVER_RESPONSE(this.socket);
-  emitStatistics(this[kServerResponseStatistics]);
+  if (this[kServerResponseStatistics] && hasObserver('http')) {
+    stopPerf(this, kServerResponseStatistics, {
+      detail: {
+        res: {
+          statusCode: this.statusCode,
+          statusMessage: this.statusMessage,
+          headers: typeof this.getHeaders === 'function' ? this.getHeaders() : {},
+        },
+      },
+    });
+  }
   OutgoingMessage.prototype._finish.call(this);
 };
 

lib/internal/http.js

@@ -9,15 +9,6 @@ const {
 
 const { setUnrefTimeout } = require('internal/timers');
 
-const { InternalPerformanceEntry } = require('internal/perf/performance_entry');
-
-const {
-  enqueue,
-  hasObserver,
-} = require('internal/perf/observe');
-
-const { now } = require('internal/perf/utils');
-
 let utcCache;
 
 function utcDate() {
@@ -35,22 +26,8 @@ function resetCache() {
   utcCache = undefined;
 }
 
-function emitStatistics(statistics) {
-  if (!hasObserver('http') || statistics == null) return;
-  const startTime = statistics.startTime;
-  const entry = new InternalPerformanceEntry(
-    statistics.type,
-    'http',
-    startTime,
-    now() - startTime,
-    undefined,
-  );
-  enqueue(entry);
-}
-
 module.exports = {
   kOutHeaders: Symbol('kOutHeaders'),
   kNeedDrain: Symbol('kNeedDrain'),
   utcDate,
-  emitStatistics,
 };

test/parallel/test-http-perf_hooks.js

@@ -66,6 +66,12 @@ process.on('exit', () => {
     } else if (entry.name === 'HttpRequest') {
       numberOfHttpRequests++;
     }
+    assert.strictEqual(typeof entry.detail.req.method, 'string');
+    assert.strictEqual(typeof entry.detail.req.url, 'string');
+    assert.strictEqual(typeof entry.detail.req.headers, 'object');
+    assert.strictEqual(typeof entry.detail.res.statusCode, 'number');
+    assert.strictEqual(typeof entry.detail.res.statusMessage, 'string');
+    assert.strictEqual(typeof entry.detail.res.headers, 'object');
   });
   assert.strictEqual(numberOfHttpClients, 2);
   assert.strictEqual(numberOfHttpRequests, 2);