lib: add tracing support for http2

PR-URL: #266
Reviewed-By: Juan José Arboleda <[email protected]>
Reviewed-By: Rafael Gonzaga <[email protected]>

Author: santigimeno

lib/internal/nsolid_diag.js

@@ -3,6 +3,7 @@
 const nsolidApi = internalBinding('nsolid_api');
 const {
   nsolid_counts,
+  nsolid_span_id_s,
   nsolid_tracer_s,
   nsolid_consts,
 } = nsolidApi;
@@ -14,6 +15,7 @@ const {
 } = require('internal/otel/core');
 
 const {
+  extractSpanContextFromHttpHeaders,
   generateSpan,
   nsolidTracer,
 } = require('internal/nsolid_trace');
@@ -28,21 +30,34 @@ const {
   kSpanHttpClient,
   kSpanHttpMethod,
   kSpanHttpReqUrl,
+  kSpanHttpServer,
   kSpanHttpStatusCode,
 } = nsolid_consts;
 
 const undiciFetch = dc.tracingChannel('undici:fetch');
+const http2Client = dc.tracingChannel('http2.client');
+const http2Server = dc.tracingChannel('http2.server');
 
 // To lazy load the http2 constants
 let http2Constants;
 
 let tracingEnabled = false;
 
-const fetchSubscribeListener = (message, name) => {};
+const subscribeListener = (message, name) => {};
 
 function disableTracing() {
   undiciFetch.start.unbindStore();
-  dc.unsubscribe('tracing:undici:fetch:start', fetchSubscribeListener);
+  dc.unsubscribe('tracing:undici:fetch:start', subscribeListener);
+  http2Client.start.unbindStore();
+  dc.unsubscribe('tracing:http2.client:start', subscribeListener);
+  http2Server.start.unbindStore();
+  dc.unsubscribe('tracing:http2.server:start', subscribeListener);
+}
+
+function extractHttp2Url(headers, http2Constants) {
+  const { HTTP2_HEADER_SCHEME, HTTP2_HEADER_PATH } = http2Constants;
+  const authority = require('internal/http2/util').getAuthority(headers);
+  return `${headers[HTTP2_HEADER_SCHEME]}://${authority}${headers[HTTP2_HEADER_PATH]}`;
 }
 
 function enableTracing() {
@@ -66,7 +81,52 @@ function enableTracing() {
     return api.trace.setSpan(api.context.active(), span);
   });
 
-  dc.subscribe('tracing:undici:fetch:start', fetchSubscribeListener);
+  dc.subscribe('tracing:http2.client:start', subscribeListener);
+
+  http2Client.start.bindStore(contextManager._getALS(), (data) => {
+    const api = getApi();
+    const tracer = api.trace.getTracer('http2');
+    http2Constants ||= require('internal/http2/core').constants;
+    const { headers } = data;
+    const method = headers[http2Constants.HTTP2_HEADER_METHOD];
+    const url = extractHttp2Url(headers, http2Constants);
+    const span = tracer.startSpan(`HTTP ${method}`,
+                                  { internal: true,
+                                    kind: api.SpanKind.CLIENT,
+                                    type: kSpanHttpClient });
+    span._pushSpanDataString(kSpanHttpMethod, method);
+    span._pushSpanDataString(kSpanHttpReqUrl, url);
+    const { spanId, traceId } = span.spanContext();
+    if (span._isSampled()) {
+      headers.traceparent = `00-${traceId}-${spanId}-01`;
+    } else {
+      headers.traceparent = `00-${traceId}-${spanId}-00`;
+    }
+
+    return api.trace.setSpan(api.context.active(), span);
+  });
+
+  dc.subscribe('tracing:http2.client:start', subscribeListener);
+
+  http2Server.start.bindStore(contextManager._getALS(), (data) => {
+    const api = getApi();
+    const tracer = api.trace.getTracer('http2');
+    http2Constants ||= require('internal/http2/core').constants;
+    const { headers } = data;
+    const method = headers[http2Constants.HTTP2_HEADER_METHOD];
+    const url = extractHttp2Url(headers, http2Constants);
+    const ctxt = extractSpanContextFromHttpHeaders(api.ROOT_CONTEXT, headers);
+    const span = tracer.startSpan(`HTTP ${method}`,
+                                  { internal: true,
+                                    kind: api.SpanKind.SERVER,
+                                    type: kSpanHttpServer },
+                                  ctxt);
+    span._pushSpanDataString(kSpanHttpMethod, method);
+    span._pushSpanDataString(kSpanHttpReqUrl, url);
+    return api.trace.setSpan(api.context.active(), span);
+  });
+
+  dc.subscribe('tracing:http2.server:start', subscribeListener);
 }
 
 nsolidTracer.on('flagsUpdated', () => {
@@ -130,41 +190,119 @@ dc.subscribe('http2.client.stream.created', ({ stream }) => {
     start: now(),
     response: false,
   };
+
+  if (generateSpan(kSpanHttpClient)) {
+    const api = getApi();
+    const span = api.trace.getSpan(api.context.active());
+    if (span) {
+      stream[nsolid_span_id_s] = span;
+    }
+  }
 });
 
-dc.subscribe('http2.client.stream.finish', ({ stream, flags }) => {
+dc.subscribe('http2.client.stream.finish', ({ stream, headers }) => {
   stream[nsolid_tracer_s].response = true;
+  http2Constants ||= require('internal/http2/core').constants;
+  if (generateSpan(kSpanHttpClient)) {
+    const span = stream[nsolid_span_id_s];
+    if (span) {
+      const status = headers[http2Constants.HTTP2_HEADER_STATUS];
+      span._pushSpanDataUint64(kSpanHttpStatusCode, status);
+      if (status >= 400) {
+        span.setStatus({ code: getApi().SpanStatusCode.ERROR });
+      }
+    }
+  }
+});
+
+dc.subscribe('http2.client.stream.error', ({ stream, error }) => {
+  if (generateSpan(kSpanHttpClient)) {
+    const span = stream[nsolid_span_id_s];
+    if (span) {
+      span.recordException(error);
+      span.setStatus({
+        code: getApi().SpanStatusCode.ERROR,
+        message: error.message,
+      });
+      span.end();
+    }
+  }
 });
 
 dc.subscribe('http2.client.stream.close', ({ stream, code }) => {
   http2Constants ||= require('internal/http2/core').constants;
   const tracingInfo = stream[nsolid_tracer_s];
+  const span = stream[nsolid_span_id_s];
   if (code === http2Constants.NGHTTP2_NO_ERROR && tracingInfo.response) {
     nsolid_counts[kHttpClientCount]++;
     nsolidApi.pushClientBucket(now() - tracingInfo.start);
   } else {
     nsolid_counts[kHttpClientAbortCount]++;
+    if (span) {
+      span.setStatus({
+        code: getApi().SpanStatusCode.ERROR,
+      });
+    }
   }
+
+  span?.end();
 });
 
-dc.subscribe('http2.server.stream.start', ({ stream }) => {
+dc.subscribe('http2.server.stream.start', ({ stream, headers }) => {
   stream[nsolid_tracer_s] = {
     start: now(),
     response: false,
   };
+
+  if (generateSpan(kSpanHttpServer)) {
+    const api = getApi();
+    const span = api.trace.getSpan(api.context.active());
+    if (span) {
+      stream[nsolid_span_id_s] = span;
+    }
+  }
 });
 
-dc.subscribe('http2.server.stream.finish', ({ stream, flags }) => {
+dc.subscribe('http2.server.stream.finish', ({ stream, headers }) => {
   stream[nsolid_tracer_s].response = true;
 });
 
+dc.subscribe('http2.server.stream.error', ({ stream, error }) => {
+  if (generateSpan(kSpanHttpServer)) {
+    const span = stream[nsolid_span_id_s];
+    if (span) {
+      span.recordException(error);
+      span.setStatus({
+        code: getApi().SpanStatusCode.ERROR,
+        message: error.message,
+      });
+      span.end();
+    }
+  }
+});
+
 dc.subscribe('http2.server.stream.close', ({ stream, code }) => {
   http2Constants ||= require('internal/http2/core').constants;
   const tracingInfo = stream[nsolid_tracer_s];
+  const span = stream[nsolid_span_id_s];
   if (code === http2Constants.NGHTTP2_NO_ERROR && tracingInfo.response) {
     nsolid_counts[kHttpServerCount]++;
     nsolidApi.pushServerBucket(now() - tracingInfo.start);
   } else {
     nsolid_counts[kHttpServerAbortCount]++;
+    if (span) {
+      span.setStatus({
+        code: getApi().SpanStatusCode.ERROR,
+      });
+    }
+  }
+
+  if (span) {
+    if (stream.headersSent) {
+      const status = stream.sentHeaders[http2Constants.HTTP2_HEADER_STATUS];
+      span._pushSpanDataUint64(kSpanHttpStatusCode, status);
+    }
+
+    span.end();
   }
 });

test/addons/nsolid-tracing/test-http2-client-destroy-abort-destroyed-signal.js

@@ -0,0 +1,81 @@
+// Flags: --dns-result-order=ipv4first
+'use strict';
+const common = require('../../common');
+if (!common.hasCrypto)
+  common.skip('missing crypto');
+const { checkTracesOnExit } = require('../../common/nsolid-traces');
+const { setupNSolid } = require('./utils');
+const http2 = require('http2');
+const bindingPath = require.resolve(`./build/${common.buildType}/binding`);
+const binding = require(bindingPath);
+
+function setupTracesCheck(port, addresses) {
+  const expectedTraces = [
+    {
+      attributes: {
+        'http.method': 'GET',
+        'http.url': `http://localhost:${port}/`,
+      },
+      end_reason: binding.kSpanEndOk,
+      name: 'HTTP GET',
+      parentId: '0000000000000000',
+      thread_id: 0,
+      kind: binding.kClient,
+      type: binding.kSpanHttpClient,
+      events: [
+        {
+          attributes: {
+            'exception.message': 'The operation was aborted',
+            'exception.type': 'ABORT_ERR',
+          },
+          name: 'exception',
+        },
+      ],
+      status: {
+        code: 2, // ERROR
+        message: 'The operation was aborted',
+      },
+    },
+    {
+      attributes: {
+        'dns.address': [{ address: addresses[0].address,
+                          family: addresses[0].family }],
+        'dns.hostname': 'localhost',
+        'dns.op_type': binding.kDnsLookup,
+      },
+      end_reason: binding.kSpanEndOk,
+      name: 'DNS lookup',
+      thread_id: 0,
+      kind: binding.kClient,
+      type: binding.kSpanDns,
+    },
+  ];
+
+  checkTracesOnExit(binding, expectedTraces);
+}
+
+setupNSolid(common.mustSucceed(({ addresses }) => {
+  const server = http2.createServer();
+  const controller = new AbortController();
+
+  server.on('stream', common.mustNotCall());
+
+  server.listen(0, common.mustCall(() => {
+    const port = server.address().port;
+    setupTracesCheck(port, addresses);
+    const client = http2.connect(`http://localhost:${port}`);
+    client.on('close', common.mustCall());
+
+    const { signal } = controller;
+    controller.abort();
+
+    const req = client.request({}, { signal });
+
+    req.on('error', common.mustCall());
+    req.on('close', common.mustCall(() => {
+      client.close(common.mustCall(() => {
+        server.close();
+      }));
+    }));
+  }));
+}));

test/addons/nsolid-tracing/test-http2-client-destroy-abort-session.js

@@ -0,0 +1,81 @@
+// Flags: --dns-result-order=ipv4first
+'use strict';
+const common = require('../../common');
+if (!common.hasCrypto)
+  common.skip('missing crypto');
+const { checkTracesOnExit } = require('../../common/nsolid-traces');
+const { setupNSolid } = require('./utils');
+const http2 = require('http2');
+const bindingPath = require.resolve(`./build/${common.buildType}/binding`);
+const binding = require(bindingPath);
+
+function setupTracesCheck(port, addresses) {
+  const expectedTraces = [
+    {
+      attributes: {
+        'http.method': 'GET',
+        'http.url': `http://localhost:${port}/`,
+      },
+      end_reason: binding.kSpanEndOk,
+      name: 'HTTP GET',
+      parentId: '0000000000000000',
+      thread_id: 0,
+      kind: binding.kClient,
+      type: binding.kSpanHttpClient,
+      events: [
+        {
+          attributes: {
+            'exception.message': 'The pending stream has been canceled (caused by: The operation was aborted)',
+            'exception.type': 'ERR_HTTP2_STREAM_CANCEL',
+          },
+          name: 'exception',
+        },
+      ],
+      status: {
+        code: 2, // ERROR
+        message: 'The pending stream has been canceled (caused by: The operation was aborted)',
+      },
+    },
+    {
+      attributes: {
+        'dns.address': [{ address: addresses[0].address,
+                          family: addresses[0].family }],
+        'dns.hostname': 'localhost',
+        'dns.op_type': binding.kDnsLookup,
+      },
+      end_reason: binding.kSpanEndOk,
+      name: 'DNS lookup',
+      thread_id: 0,
+      kind: binding.kClient,
+      type: binding.kSpanDns,
+    },
+  ];
+
+  checkTracesOnExit(binding, expectedTraces);
+}
+
+setupNSolid(common.mustSucceed(({ addresses }) => {
+  const server = http2.createServer();
+  const controller = new AbortController();
+
+  server.on('stream', common.mustNotCall());
+
+  server.listen(0, common.mustCall(() => {
+    const port = server.address().port;
+    setupTracesCheck(port, addresses);
+    const { signal } = controller;
+    const client = http2.connect(`http://localhost:${port}`, { signal });
+    client.on('close', common.mustCall());
+
+    client.on('error', common.mustCall());
+
+    const req = client.request({}, {});
+
+    req.on('error', common.mustCall());
+    req.on('close', common.mustCall(() => {
+      server.close();
+    }));
+
+    controller.abort();
+  }));
+}));