diff --git a/CHANGELOG.md b/CHANGELOG.md index 0875623f3b..0524e7028f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,7 @@ # Changelog ## Unreleased +- Support for [W3C Trace Context](https://www.w3.org/TR/trace-context/). - Fix: Annotate path templates (Express.js, Koa, Hapi, ...) and error messages (Express.js) on all HTTP entry spans, not only on root spans. ## 1.90.0 diff --git a/packages/collector/test/tracing/misc/w3c_trace_context/app.js b/packages/collector/test/tracing/misc/w3c_trace_context/app.js new file mode 100644 index 0000000000..34a8e6c342 --- /dev/null +++ b/packages/collector/test/tracing/misc/w3c_trace_context/app.js @@ -0,0 +1,225 @@ +'use strict'; + +/** + * This application can either act as a service instrumented by Instana or as a service instrumented by different, W3C + * trace context compliant vendor. In the latter case, it can either forward the trace or participate in it. + * + * In either case, a series of requests is usually started by GET /start?depth=d, which will in turn send a request to + * the downstream service at GET /continue?depth=(d-1). When d reaches 1, the last request will go to GET /end. + */ + +const vendor = process.env.APM_VENDOR; + +let vendorLabel; +if (!vendor) { + throw new Error('APM_VENDOR is mandatory for this app.'); +} +if (vendor === 'instana') { + vendorLabel = 'Instana'; +} else if (vendor === 'other-spec-compliant') { + vendorLabel = 'Other Vendor (compliant)'; +} else if (vendor === 'other-non-spec-compliant') { + vendorLabel = 'Other Vendor (non-compliant)'; +} else { + throw new Error('APM_VENDOR must be either "instana" or "other-spec-compliant" or "other-non-spec-compliant".'); +} + +let cls; +if (isInstana()) { + require('../../../../')(); + cls = require('../../../../../core/src/tracing/cls'); +} + +const rp = require('request-promise'); +const url = require('url'); + +const tracingUtil = require('../../../../../core/src/tracing/tracingUtil'); + +const port = process.env.APP_PORT; +const downstreamPort = process.env.DOWNSTREAM_PORT; + +const otherVendorTraceStateKey = 'other'; +const logPrefix = `${vendorLabel} (${process.pid}):\t`; + +if (!port) { + throw new Error('APP_PORT is mandatory for this app.'); +} + +if (!downstreamPort) { + throw new Error('DOWNSTREAM_PORT is mandatory for this app.'); +} + +let server = require('http') + .createServer() + .listen(port, () => { + log(`Listening on port: ${port}`); + }); + +server.on('request', (req, res) => { + const incomingHeaders = req.headers; + const loggedHeaders = Object.assign({}, incomingHeaders); + delete loggedHeaders.host; + delete loggedHeaders.accept; + delete loggedHeaders.connection; + + if (process.env.WITH_STDOUT) { + log(`-> ${req.method} ${req.url} ${JSON.stringify(loggedHeaders)}`); + } + + const { pathname, query } = url.parse(req.url, true); + + const outgoingHeaders = {}; + + if (isOtherSpecCompliant()) { + const incomingTraceParent = incomingHeaders.traceparent; + const incomingTraceState = incomingHeaders.tracestate; + const newParentId = tracingUtil.generateRandomSpanId(); + const otherMode = query.otherMode || 'participate'; + if (otherMode === 'forward') { + outgoingHeaders.traceparent = incomingTraceParent; + outgoingHeaders.tracestate = incomingTraceState; + } else if (otherMode === 'participate') { + if (incomingTraceParent && incomingTraceState) { + // participate in existing trace by updating traceparent and tracestate + outgoingHeaders.traceparent = `${incomingTraceParent.substring(0, 36)}${newParentId}-01`; + // Not fully spec compliant because we do not remove existing "other" key-value pairs, but that's irrelevant for + // this test. + outgoingHeaders.tracestate = `${otherVendorTraceStateKey}=newParentId,${incomingTraceState}`; + } else { + // start a new trace by creating traceparent and tracestate + const newTraceId = tracingUtil.generateRandomLongTraceId(); + outgoingHeaders.traceparent = `00-${newTraceId}-${newParentId}-01`; + outgoingHeaders.tracestate = `${otherVendorTraceStateKey}=newParentId`; + } + } else if (otherMode === 'soft-restart') { + // soft-restart the trace by creating traceparent with new values but keep tracestate + const newTraceId = tracingUtil.generateRandomLongTraceId(); + outgoingHeaders.traceparent = `00-${newTraceId}-${newParentId}-01`; + outgoingHeaders.tracestate = `${otherVendorTraceStateKey}=newParentId,${incomingTraceState}`; + } else if (otherMode === 'hard-restart') { + // hard-restart the trace by creating traceparent and tracestate and discarding previous tracestate values + const newTraceId = tracingUtil.generateRandomLongTraceId(); + outgoingHeaders.traceparent = `00-${newTraceId}-${newParentId}-01`; + outgoingHeaders.tracestate = `${otherVendorTraceStateKey}=newParentId`; + } else if (otherMode === 'non-compliant') { + // Nothing to do, we do not pass down headers. + } else { + // eslint-disable-next-line no-console + console.error(`Unknown otherMode: ${otherMode}`); + return endWithStatus(req, res, 400); + } + } + + const depth = parseInt(query.depth || '1', 10); + query.depth = depth - 1; + let downstreamPath; + if (pathname === '/') { + if (req.method !== 'GET') { + return endWithStatus(req, res, 405); + } + return endWithStatus(req, res, 200); + } else if (pathname === '/start') { + if (req.method !== 'GET') { + return endWithStatus(req, res, 405); + } + downstreamPath = depth > 1 ? 'continue' : 'end'; + return rp + .get({ + uri: `http://127.0.0.1:${downstreamPort}/${downstreamPath}`, + headers: outgoingHeaders, + qs: query + }) + .then(response => { + return endWithPayload(req, res, response); + }) + .catch(e => { + return endWithError(req, res, e); + }); + } else if (pathname === '/continue') { + if (req.method !== 'GET') { + return endWithStatus(req, res, 405); + } + downstreamPath = depth > 1 ? 'continue' : 'end'; + return rp + .get({ + uri: `http://127.0.0.1:${downstreamPort}/${downstreamPath}`, + headers: outgoingHeaders, + qs: query + }) + .then(response => { + return endWithPayload(req, res, response); + }) + .catch(e => { + return endWithError(req, res, e); + }); + } else if (pathname === '/end') { + if (req.method !== 'GET') { + return endWithStatus(req, res, 405); + } + const payload = { + w3cTaceContext: { + receivedHeaders: { + traceparent: incomingHeaders.traceparent, + tracestate: incomingHeaders.tracestate + } + } + }; + if (incomingHeaders['x-instana-t'] || incomingHeaders['x-instana-s'] || incomingHeaders['x-instana-l']) { + payload.instanaHeaders = { + t: incomingHeaders['x-instana-t'], + s: incomingHeaders['x-instana-s'], + l: incomingHeaders['x-instana-l'] + }; + } + if (isInstana()) { + const activeW3cTraceContext = cls.getW3cTraceContext(); + if (activeW3cTraceContext) { + payload.w3cTaceContext.active = { + instanaTraceId: activeW3cTraceContext.instanaTraceId, + instanaParentId: activeW3cTraceContext.instanaParentId + }; + } + } + return endWithPayload(req, res, JSON.stringify(payload)); + } + + return endWithStatus(req, res, 404); +}); + +function endWithStatus(req, res, statusCode) { + if (process.env.WITH_STDOUT) { + log(`${req.method} ${req.url} -> ${statusCode}`); + } + res.statusCode = statusCode; + res.end(); +} + +function endWithPayload(req, res, payload) { + if (process.env.WITH_STDOUT) { + log(`${req.method} ${req.url} -> 200`); + } + res.end(payload); +} + +function endWithError(req, res, error) { + if (process.env.WITH_STDOUT) { + log(`${req.method} ${req.url} -> 500 – ${error}`); + } + res.statusCode = 500; + res.end(); +} + +function isInstana() { + return vendor === 'instana'; +} + +function isOtherSpecCompliant() { + return vendor === 'other-spec-compliant'; +} + +function log() { + /* eslint-disable no-console */ + const args = Array.prototype.slice.call(arguments); + args[0] = logPrefix + args[0]; + console.log.apply(console, args); +} diff --git a/packages/collector/test/tracing/misc/w3c_trace_context/test.js b/packages/collector/test/tracing/misc/w3c_trace_context/test.js new file mode 100644 index 0000000000..c3db3d5e14 --- /dev/null +++ b/packages/collector/test/tracing/misc/w3c_trace_context/test.js @@ -0,0 +1,766 @@ +'use strict'; + +const path = require('path'); +const { expect } = require('chai'); + +const constants = require('@instana/core').tracing.constants; +const supportedVersion = require('@instana/core').tracing.supportedVersion; +const config = require('../../../../../core/test/config'); +const delay = require('../../../test_util/delay'); +const { retryUntilSpansMatch, expectOneMatching } = require('../../../../../core/test/utils'); +const ProcessControls = require('../../ProcessControls'); + +let agentControls; + +const instanaAppPort = 4200; +const otherVendorAppPort = 4201; + +const foreignTraceId = 'f0e156789012345678901234567bcdea'; +const foreignParentId = '1020304050607080'; +const LEFT_PAD_16 = '0000000000000000'; +const upstreamInstanaTraceId = 'ffeeddccbbaa9988'; +const upstreamInstanaParentId = '7766554433221100'; + +describe('tracing/W3C Trace Context (with processes instrumented by a different vendor)', function() { + if (!supportedVersion(process.versions.node)) { + return; + } + + agentControls = require('../../../apps/agentStubControls'); + + this.timeout(config.getTestTimeout() * 2); + + const allControls = startApps(); + const { instanaAppControls, otherVendorAppControls } = allControls; + + describe('Instana -> Other Vendor', () => { + // First request to Instana does not have spec headers, so we expect a trace to be started. + // We expect correct spec headers to be passed downstream by the Instana service. The trace ID in the spec headers + // should be the one from the trace that Instana starts. + it('Instana should start a spec trace and pass the correct spec headers downstream', () => + startRequest({ app: instanaAppControls, depth: 1 }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + + expect(traceparent).to.match(new RegExp(`00-${LEFT_PAD_16}${instanaTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId}`)); + }); + })); + + // First request to Instana already has spec headers, simulating a (spec) trace in progress. We expect an Instana + // trace to be started. We also expect the correct spec headers to be passed downstream by the Instana/ service. + // In particular, it should keep the same foreign trace ID it received when passing down spec headers, even though + // the Instana trace uses a different one. + it('Instana continues a spec trace and passes the correct spec headers downstream', () => { + return startRequest({ app: instanaAppControls, depth: 1, withSpecHeaders: 'valid' }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', { + t: foreignTraceId, + p: foreignParentId, + lts: 'thing=foo' + }); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId}`)); + expect(instanaTraceId).to.not.equal(foreignTraceId); + }); + }); + }); + + // First request to Instana already has spec headers with sampled=0, simulating a (spec) trace in progress where + // the most recent upstream service did not record tracing data. We still expect an Instana trace to be started. + // We also expect the correct spec headers to be passed downstream by the Instana service. In particular, it + // should keep the same foreign trace ID it received when passing down spec headers, even though the Instana trace + // uses a different one. + it('Instana continues a spec trace with sampled=0', () => { + return startRequest({ app: instanaAppControls, depth: 1, withSpecHeaders: 'not-sampled' }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', { + t: foreignTraceId, + p: foreignParentId, + lts: 'thing=foo' + }); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId}`)); + expect(instanaTraceId).to.not.equal(foreignTraceId); + }); + }); + }); + + // First request to Instana has an invalid traceparent header. We expect the spec trace to be restarted and an + // Instana trace to be started. + it('Instana restarts the trace when receiving an invalid traceparent', () => { + return startRequest({ app: instanaAppControls, depth: 1, withSpecHeaders: 'invalid-traceparent' }).then( + response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${LEFT_PAD_16}${instanaTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId}`)); + }); + } + ); + }); + + // First request to Instana has an traceparent header with a newer version than we support. + // We expect the parts of the headers that we understand (in particular, the foreign trace ID from traceparent + // and the tracestate key-value pairs to be reused. + it('Instana uses the known parts of the traceparent header when the spec version is newer', () => { + return startRequest({ app: instanaAppControls, depth: 1, withSpecHeaders: 'too-new-traceparent' }).then( + response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', { + t: foreignTraceId, + p: foreignParentId, + lts: 'thing=foo' + }); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId},thing=foo,bar=baz`)); + }); + } + ); + }); + + // First request to Instana has a valid traceparent but an invalid tracestate header. We expect the an Instanj + // trace to be started but the trace ID from traceparent needs to be propagated. + it('Instana propagates the trace ID from traceparent when tracestate is invalid', () => { + return startRequest({ app: instanaAppControls, depth: 1, withSpecHeaders: 'invalid-tracestate' }).then( + response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', { + t: foreignTraceId, + p: foreignParentId + }); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId}`)); + expect(instanaTraceId).to.not.equal(foreignTraceId); + }); + } + ); + }); + + // First request to Instana has X-INSTANA-L and no spec headers. We expect no trace to be started and + // X-INSTANA-L and spec headers with sampled=0 to be passed down. + it('Instana should not start a trace when receiving X-INSTANA-L=0 and no spec headers', () => + startRequest({ app: instanaAppControls, depth: 1, withInstanaHeaders: 'suppress' }) + .then(response => { + expect(response.instanaHeaders).to.be.an('object'); + expect(response.instanaHeaders.t).to.not.exist; + expect(response.instanaHeaders.s).to.not.exist; + // X-INSTANA-L: 0 is passed down + expect(response.instanaHeaders.l).to.equal('0'); + expect(response.w3cTaceContext).to.be.an('object'); + expect(response.w3cTaceContext.receivedHeaders).to.be.an('object'); + const traceparent = response.w3cTaceContext.receivedHeaders.traceparent; + expect(traceparent).to.exist; + expect(response.w3cTaceContext.receivedHeaders.tracestate).to.not.exist; + // sampled=0 is passed down + expect(traceparent).to.match(new RegExp(`00-${LEFT_PAD_16}[0-9a-f]{16}-[0-9a-f]{16}-00`)); + }) + // give spans a chance to come in + .then(() => delay(500)) + .then(() => + // verify there are no spans + agentControls.getSpans().then(spans => { + expect(spans).to.have.lengthOf(0); + }) + )); + + describe('with incoming X-INSTANA-T/-S', () => { + it('Instana continues the Instana trace and starts a spec trace', () => + startRequest({ app: instanaAppControls, depth: 1, withInstanaHeaders: 'trace-in-progress' }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry( + spans, + // Pass a dummy parent span to verifyHttpEntry, this verifies that the incoming X-INSTANA- headers + // have been used. + { + t: upstreamInstanaTraceId, + s: upstreamInstanaParentId + }, + '/start', + 'none' + ); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match( + new RegExp(`00-${LEFT_PAD_16}${upstreamInstanaTraceId}-${instanaExitSpanId}-01`) + ); + expect(tracestate).to.match(new RegExp(`in=${upstreamInstanaTraceId};${instanaExitSpanId}`)); + }); + })); + + it('Instana continues the Instana trace and spec trace', () => + startRequest({ + app: instanaAppControls, + depth: 1, + withSpecHeaders: 'valid', + withInstanaHeaders: 'trace-in-progress' + }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry( + spans, + // Pass a dummy parent span to verifyHttpEntry, this verifies that the incoming X-INSTANA- headers + // have been used. + { + t: upstreamInstanaTraceId, + s: upstreamInstanaParentId + }, + '/start', + 'none' + ); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${upstreamInstanaTraceId};${instanaExitSpanId}`)); + }); + })); + + it('Instana continues the Instana trace and spec trace', () => + startRequest({ + app: instanaAppControls, + depth: 1, + withSpecHeaders: 'not-sampled', + withInstanaHeaders: 'trace-in-progress' + }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry( + spans, + // Pass a dummy parent span to verifyHttpEntry, this verifies that the incoming X-INSTANA- headers + // have been used. + { + t: upstreamInstanaTraceId, + s: upstreamInstanaParentId + }, + '/start', + 'none' + ); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + + // The Instana-instrumented process receives sampled=0 but not X-INSTANA-L: 0, so we expect sampled=1 to be + // passed down. + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${upstreamInstanaTraceId};${instanaExitSpanId}`)); + }); + })); + }); + + describe('with incoming X-INSTANA-L: 0', () => { + // First request to Instana has spec headers with sampled=0 and X-INSTANA-L. We expect no trace to be started + // and X-INSTANA-L and spec headers with sampled=0 to be passed down. + it('Instana should not start a trace when receiving spec headers (unsampled) and X-INSTANA-L=0', () => + startRequest({ + app: instanaAppControls, + depth: 1, + withSpecHeaders: 'not-sampled', + withInstanaHeaders: 'suppress' + }) + .then(response => { + expect(response.instanaHeaders).to.be.an('object'); + expect(response.instanaHeaders.t).to.not.exist; + expect(response.instanaHeaders.s).to.not.exist; + // X-INSTANA-L: 0 is passed down + expect(response.instanaHeaders.l).to.equal('0'); + expect(response.w3cTaceContext).to.be.an('object'); + expect(response.w3cTaceContext.receivedHeaders).to.be.an('object'); + const traceparent = response.w3cTaceContext.receivedHeaders.traceparent; + const tracestate = response.w3cTaceContext.receivedHeaders.tracestate; + // given IDs and sampled=0 is passed down + expect(traceparent).to.match(new RegExp(`00-${foreignTraceId}-${foreignParentId}-00`)); + expect(tracestate).to.equal('thing=foo,bar=baz'); + }) + // give spans a chance to come in + .then(() => delay(500)) + .then(() => + // verify there are no spans + agentControls.getSpans().then(spans => { + expect(spans).to.have.lengthOf(0); + }) + )); + + // First request to Instana has spec headers with sampled=1 and X-INSTANA-L. We expect no trace to be started + // and X-INSTANA-L and spec headers with a new parent ID and sampled=0 to be passed down. + it('Instana should not start a trace when receiving spec headers (sampled) and X-INSTANA-L=0', () => + startRequest({ app: instanaAppControls, depth: 1, withSpecHeaders: 'valid', withInstanaHeaders: 'suppress' }) + .then(response => { + expect(response.instanaHeaders).to.be.an('object'); + expect(response.instanaHeaders.t).to.not.exist; + expect(response.instanaHeaders.s).to.not.exist; + // X-INSTANA-L: 0 is passed down + expect(response.instanaHeaders.l).to.equal('0'); + expect(response.w3cTaceContext).to.be.an('object'); + expect(response.w3cTaceContext.receivedHeaders).to.be.an('object'); + const traceparent = response.w3cTaceContext.receivedHeaders.traceparent; + const tracestate = response.w3cTaceContext.receivedHeaders.tracestate; + // The spec says we must create a new parent ID when updating the sampled flag. + const traceParentMatch = new RegExp(`00-${foreignTraceId}-([0-9a-f]{16})-00`).exec(traceparent); + expect(traceParentMatch).to.exist; + expect(traceParentMatch[1]).to.not.equal(foreignParentId); + expect(tracestate).to.equal('thing=foo,bar=baz'); + }) + // give spans a chance to come in + .then(() => delay(500)) + .then(() => + // verify there are no spans + agentControls.getSpans().then(spans => { + expect(spans).to.have.lengthOf(0); + }) + )); + + // First request to Instana has no spec headers and X-INSTANA-L. We expect no trace to be started + // and X-INSTANA-L and spec headers with a new parent ID and sampled=0 to be passed down. + it( + 'Instana should not start an Instana trace but pass down traceparent when receiving X-INSTANA-L=0 and no ' + + 'spec headers', + () => + startRequest({ app: instanaAppControls, depth: 1, withInstanaHeaders: 'suppress' }) + .then(response => { + expect(response.instanaHeaders).to.be.an('object'); + expect(response.instanaHeaders.t).to.not.exist; + expect(response.instanaHeaders.s).to.not.exist; + // X-INSTANA-L: 0 is passed down + expect(response.instanaHeaders.l).to.equal('0'); + expect(response.w3cTaceContext).to.be.an('object'); + expect(response.w3cTaceContext.receivedHeaders).to.be.an('object'); + const traceparent = response.w3cTaceContext.receivedHeaders.traceparent; + const tracestate = response.w3cTaceContext.receivedHeaders.tracestate; + const traceParentMatch = new RegExp(`00-${LEFT_PAD_16}([0-9a-f]{16})-([0-9a-f]{16})-00`).exec( + traceparent + ); + expect(traceParentMatch).to.exist; + expect(traceParentMatch[1]).to.not.equal(foreignTraceId); + expect(traceParentMatch[1]).to.not.equal(upstreamInstanaTraceId); + expect(traceParentMatch[1]).to.not.equal(foreignParentId); + expect(traceParentMatch[1]).to.not.equal(upstreamInstanaParentId); + expect(tracestate).to.not.exist; + }) + // give spans a chance to come in + .then(() => delay(500)) + .then(() => + // verify there are no spans + agentControls.getSpans().then(spans => { + expect(spans).to.have.lengthOf(0); + }) + ) + ); + }); + }); + + describe('Instana -> Other Vendor -> Instana', () => { + // The other vendor participates in the trace.We expect one continuous Instana trace, and the second Instana HTTP + // entry span has foreign parent data. + it('Instana should continue a trace after a detour via a participating service', () => + startRequest({ app: instanaAppControls, depth: 2 }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/continue'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${LEFT_PAD_16}${instanaTraceId}-[0-9a-f]{16}-01`)); + expect(tracestate).to.match(new RegExp(`other=newParentId,in=${instanaTraceId};${instanaExitSpanId}`)); + // The trace ID from the traceparent header should match then Instana trace ID (modulo left padding). + const { traceIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + expect(traceIdFromTraceParent).to.equal(LEFT_PAD_16 + instanaTraceId); + + verifyTraceContextAgainstTerminalSpan(response, spans, instanaHttpExit, instanaTraceId, 'other=newParentId'); + }); + })); + + // Instana -> Other Vendor -> Instana. + // The other vendor only forwards the trace, but does not participate. We expect one continuous Instana trace, and + // the second Instana HTTP entry span has foreign parent data. + it('Instana should continue a trace after a detour via a forwarding service', () => + startRequest({ app: instanaAppControls, depth: 2, otherMode: 'forward' }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/continue'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(traceparent).to.match(new RegExp(`00-${LEFT_PAD_16}${instanaTraceId}-${instanaExitSpanId}-01`)); + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId}`)); + // The trace ID from the traceparent header should match then Instana trace ID (modulo left padding). + const { traceIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + expect(traceIdFromTraceParent).to.equal(LEFT_PAD_16 + instanaTraceId); + + verifyTraceContextAgainstTerminalSpan(response, spans, instanaHttpExit, instanaTraceId, undefined); + }); + })); + + // Instana -> Other -> Instana. + // Other soft-restarts trace, that is, it generates a new trace id and parent id for traceparent, but keeps the + // old tracestate members around (which is an option the spec allows for "front gates into secure networks"). We + // still expect one continuous Instana trace, and the second Instana HTTP entry span has foreign parent data. + it('Instana should continue a trace after a detour when the foreign service has soft-restarted the trace', () => + startRequest({ app: instanaAppControls, depth: 2, otherMode: 'soft-restart' }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/continue'); + + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + expect(tracestate).to.match(new RegExp(`^other=newParentId,in=${instanaTraceId};${instanaExitSpanId}$`)); + // Due to soft-restart, the traceparent's trace ID part shouldn't match the initial trace ID. + const { traceIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + expect(traceIdFromTraceParent).to.not.equal(LEFT_PAD_16 + instanaTraceId); + verifyTraceContextAgainstTerminalSpan(response, spans, instanaHttpExit, instanaTraceId, 'other=newParentId'); + }); + })); + + // Instana -> Other -> Instana. + // The other vendor hard-restarts the trace, that is, it generates a new trace id and parent id for traceparent, + // and also discards the received tracestate header around. We do not expect one continuous Instana trace, but + // rather two separate traces. + it('The trace will break after a detour when the foreign service has hard-restarted the trace', () => + startRequest({ app: instanaAppControls, depth: 2, otherMode: 'hard-restart' }).then(response => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + verifyHttpExit(spans, instanaHttpEntryRoot, '/continue'); + + const instanaTraceId = instanaHttpEntryRoot.t; + expect(tracestate).to.equal('other=newParentId'); + + // The W3C trace context that was active during processing the last HTTP entry. This is different from + // response.w3cTaceContext.receivedHeaders because we update the trace context (in particular, the parent + // ID) after generating the span ID for this HTTP entry. + expect(response.w3cTaceContext.active).to.be.an('object'); + const instanaTraceIdInActiveTraceContext = response.w3cTaceContext.active.instanaTraceId; + const instanaParentIdInActiveTraceContext = response.w3cTaceContext.active.instanaParentId; + expect(instanaTraceIdInActiveTraceContext).to.exist; + expect(instanaParentIdInActiveTraceContext).to.exist; + + // Find the span for last HTTP entry in to the Instana-instrumented process. + // In this case, the terminal HTTP entry span is not part of the same trace. + const terminalHttpEntry = verifyHttpEntry(spans, null, '/end'); + + expect(instanaTraceIdInActiveTraceContext).to.not.equal(instanaTraceId); + // The span ID we put into the in key-value pair in the active trace context must equal the span ID on the + // span. + const instanaEntrySpanId = terminalHttpEntry.s; + expect(instanaParentIdInActiveTraceContext).to.equal(instanaEntrySpanId); + + const { traceIdFromTraceParent, parentIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + expect(traceIdFromTraceParent).not.contains(instanaTraceId); + verifyForeignParentContext(terminalHttpEntry, parentIdFromTraceParent, instanaTraceId, 'other=newParentId'); + }); + })); + + it('the trace will break after a detour when the foreign service does not implement W3C trace context', () => + startRequest({ app: instanaAppControls, depth: 2, otherMode: 'non-compliant' }).then(response => { + expect(response.w3cTaceContext).to.be.an('object'); + expect(response.w3cTaceContext.receivedHeaders).to.deep.equal({}); + + return retryUntilSpansMatch(agentControls, spans => { + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/start', 'none'); + verifyHttpExit(spans, instanaHttpEntryRoot, '/continue'); + + const instanaTraceId = instanaHttpEntryRoot.t; + + // The W3C trace context that was active during processing the last HTTP entry. This is different from + // response.w3cTaceContext.receivedHeaders because we update the trace context (in particular, the parent + // ID) after generating the span ID for this HTTP entry. + expect(response.w3cTaceContext.active).to.be.an('object'); + const instanaTraceIdInActiveTraceContext = response.w3cTaceContext.active.instanaTraceId; + const instanaParentIdInActiveTraceContext = response.w3cTaceContext.active.instanaParentId; + expect(instanaTraceIdInActiveTraceContext).to.exist; + expect(instanaParentIdInActiveTraceContext).to.exist; + + // Find the span for last HTTP entry in to the Instana-instrumented process. + // In this case, the terminal HTTP entry span is not part of the same trace. + const terminalHttpEntry = verifyHttpEntry(spans, null, '/end', 'none'); + + expect(instanaTraceIdInActiveTraceContext).to.not.equal(instanaTraceId); + // The span ID we put into the in key-value pair in the active trace context must equal the span ID on the + // span. + const instanaEntrySpanId = terminalHttpEntry.s; + expect(instanaParentIdInActiveTraceContext).to.equal(instanaEntrySpanId); + }); + })); + }); + + describe('Other Vendor -> Instana', () => { + it('Instana should start a spec trace and pass the correct spec headers downstream', () => + startRequest({ app: otherVendorAppControls, depth: 1 }).then(response => + retryUntilSpansMatch(agentControls, spans => { + const { traceparent } = verifySpecHeadersExistOnLastHttpRequest(response); + const { traceIdFromTraceParent, parentIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/end'); + expect(instanaHttpEntryRoot.fp).to.be.an('object'); + expect(instanaHttpEntryRoot.fp.t).to.equal(traceIdFromTraceParent); + expect(instanaHttpEntryRoot.fp.t).to.not.contain(instanaHttpEntryRoot.t); + expect(instanaHttpEntryRoot.fp.p).to.equal(parentIdFromTraceParent); + expect(instanaHttpEntryRoot.fp.p).to.not.equal(instanaHttpEntryRoot.s); + expect(instanaHttpEntryRoot.fp.lts).to.equal('other=newParentId'); + }) + )); + }); + + describe('Other Vendor -> Instana -> Other Vendor', () => { + it('Instana should pass down the correct spec headers', () => + startRequest({ app: otherVendorAppControls, depth: 2 }).then(response => + retryUntilSpansMatch(agentControls, spans => { + const { traceparent, tracestate } = verifySpecHeadersExistOnLastHttpRequest(response); + const { traceIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + + const instanaHttpEntryRoot = verifyHttpEntry(spans, null, '/continue'); + expect(instanaHttpEntryRoot.fp.t).to.equal(traceIdFromTraceParent); + expect(instanaHttpEntryRoot.fp.lts).to.equal('other=newParentId'); + + expect(traceparent).to.match(/^00-[0-9a-f]{32}-[0-9a-f]{16}-01$/); + + const instanaHttpExit = verifyHttpExit(spans, instanaHttpEntryRoot, '/end'); + const instanaTraceId = instanaHttpEntryRoot.t; + const instanaExitSpanId = instanaHttpExit.s; + + expect(tracestate).to.match(new RegExp(`in=${instanaTraceId};${instanaExitSpanId},other=newParentId`)); + }) + )); + }); +}); + +function startApps() { + agentControls.registerTestHooks(); + const instanaAppControls = new ProcessControls({ + appPath: path.join(__dirname, 'app'), + port: instanaAppPort, + agentControls, + env: { + APM_VENDOR: 'instana', + DOWNSTREAM_PORT: otherVendorAppPort + } + }).registerTestHooks(); + const otherVendorAppControls = new ProcessControls({ + appPath: path.join(__dirname, 'app'), + port: otherVendorAppPort, + // not passing agent controls because this app will not connect to the agent + env: { + APM_VENDOR: 'other-spec-compliant', + DOWNSTREAM_PORT: instanaAppPort + } + }).registerTestHooks(); + + return { + instanaAppControls, + otherVendorAppControls + }; +} + +function startRequest({ app, depth = 2, withSpecHeaders = null, otherMode = 'participate', withInstanaHeaders }) { + const request = { + path: `/start?depth=${depth}&otherMode=${otherMode}` + }; + if (withSpecHeaders === 'valid') { + request.headers = { + traceparent: `00-${foreignTraceId}-${foreignParentId}-01`, + tracestate: 'thing=foo,bar=baz' + }; + } else if (withSpecHeaders === 'not-sampled') { + request.headers = { + traceparent: `00-${foreignTraceId}-${foreignParentId}-00`, + tracestate: 'thing=foo,bar=baz' + }; + } else if (withSpecHeaders === 'too-new-traceparent') { + request.headers = { + traceparent: `01-${foreignTraceId}-${foreignParentId}-01-wait-there-is-more`, + tracestate: 'thing=foo,bar=baz' + }; + } else if (withSpecHeaders === 'invalid-traceparent') { + request.headers = { + traceparent: `00-${foreignTraceId}-${foreignParentId}-001`, + tracestate: 'thing=foo,bar=baz' + }; + } else if (withSpecHeaders === 'invalid-tracestate') { + request.headers = { + traceparent: `00-${foreignTraceId}-${foreignParentId}-01`, + tracestate: 'this will be discarded' + }; + } else if (withSpecHeaders != null) { + throw new Error(`Invalid withSpecHeaders value: ${withSpecHeaders}.`); + } + + if (withInstanaHeaders === 'trace-in-progress') { + request.headers = request.headers || {}; + request.headers['X-INSTANA-T'] = upstreamInstanaTraceId; + request.headers['X-INSTANA-S'] = upstreamInstanaParentId; + } else if (withInstanaHeaders === 'suppress') { + request.headers = request.headers || {}; + request.headers['X-INSTANA-L'] = '0'; + } else if (withInstanaHeaders != null) { + throw new Error(`Invalid withInstanaHeaders value: ${withInstanaHeaders}.`); + } + return app.sendRequest(request); +} + +/** + * This verification checks for some basic properties on the response, which is returned from the last HTTP response in + * the chain. + */ +function verifySpecHeadersExistOnLastHttpRequest(response) { + expect(response.w3cTaceContext).to.be.an('object'); + expect(response.w3cTaceContext.receivedHeaders).to.be.an('object'); + const traceparent = response.w3cTaceContext.receivedHeaders.traceparent; + const tracestate = response.w3cTaceContext.receivedHeaders.tracestate; + expect(traceparent).to.exist; + expect(tracestate).to.exist; + return { traceparent, tracestate }; +} + +/** + * This verification will only happen for test scenarios where we have a call to the Instana-instrumented service at the + * end. It basically verifies the incoming trace context headers and the internal trace context state that is used + * during processing this last request, comparing it against with the meta data in the span representing this last call. + */ +function verifyTraceContextAgainstTerminalSpan( + response, + spans, + instanaHttpExit, + instanaTraceId, + expectedMostRecentTraceStateMember, + restart +) { + // The incoming HTTP headers for the last request. + const traceparent = response.w3cTaceContext.receivedHeaders.traceparent; + + // The W3C trace context that was active during processing the last HTTP entry. This is different from + // response.w3cTaceContext.receivedHeaders because we update the trace context (in particular, the parent ID) after + // generating the span ID for this HTTP entry. + expect(response.w3cTaceContext.active).to.be.an('object'); + const instanaTraceIdInActiveTraceContext = response.w3cTaceContext.active.instanaTraceId; + const instanaParentIdInActiveTraceContext = response.w3cTaceContext.active.instanaParentId; + expect(instanaTraceIdInActiveTraceContext).to.exist; + expect(instanaParentIdInActiveTraceContext).to.exist; + + // Find the span for last HTTP entry in to the Instana-instrumented process. + const terminalHttpEntry = verifyHttpEntry(spans, instanaHttpExit, '/end'); + + // The trace ID put into the in key-value pair in the active trace context must equal the trace ID on the span. + expect(instanaTraceIdInActiveTraceContext).to.equal(instanaTraceId); + // The span ID we put into the in key-value pair in the active trace context must equal the span ID on the span. + const instanaEntrySpanId = terminalHttpEntry.s; + expect(instanaParentIdInActiveTraceContext).to.equal(instanaEntrySpanId); + + const { parentIdFromTraceParent } = extraceIdsFromTraceParent(traceparent); + + verifyForeignParentContext( + terminalHttpEntry, + parentIdFromTraceParent, + instanaTraceId, + expectedMostRecentTraceStateMember, + restart + ); +} + +function verifyForeignParentContext( + terminalHttpEntry, + parentIdFromTraceParent, + instanaTraceId, + expectedMostRecentTraceStateMember, + restart +) { + const foreignParentContext = terminalHttpEntry.fp; + expect(foreignParentContext).to.be.an('object'); + + if (restart) { + expect(foreignParentContext.t).to.equal(LEFT_PAD_16 + instanaTraceId); + } + expect(foreignParentContext.p).to.equal(parentIdFromTraceParent); + if (expectedMostRecentTraceStateMember) { + expect(foreignParentContext.lts).to.equal(expectedMostRecentTraceStateMember); + } else { + expect(foreignParentContext.lts).to.be.undefined; + } +} + +function extraceIdsFromTraceParent(traceparent) { + const traceParentMatch = /^00-([0-9a-f]{32})-([0-9a-f]{16})-01$/.exec(traceparent); + const traceIdFromTraceParent = traceParentMatch[1]; + const parentIdFromTraceParent = traceParentMatch[2]; + return { traceIdFromTraceParent, parentIdFromTraceParent }; +} + +function verifyHttpEntry(spans, parentSpan, url, foreignParent) { + return expectOneMatching(spans, span => { + expect(span.n).to.equal('node.http.server'); + expect(span.k).to.equal(constants.ENTRY); + expect(span.async).to.equal(false); + expect(span.error).to.equal(false); + expect(span.ec).to.equal(0); + expect(span.t).to.be.a('string'); + expect(span.s).to.be.a('string'); + if (parentSpan) { + expect(span.t).to.equal(parentSpan.t); + expect(span.p).to.equal(parentSpan.s); + } else { + expect(span.p).to.not.exist; + } + expect(span.data.http.method).to.equal('GET'); + expect(span.data.http.url).to.equal(url); + expect(span.data.http.host).to.equal(`127.0.0.1:${instanaAppPort}`); + expect(span.data.http.status).to.equal(200); + + if (typeof foreignParent === 'object') { + expect(span.fp).to.deep.equal(foreignParent); + } else if (foreignParent === 'none') { + expect(span.fp).to.not.exist; + } + }); +} + +function verifyHttpExit(spans, parentSpan, url) { + return expectOneMatching(spans, span => { + expect(span.n).to.equal('node.http.client'); + expect(span.k).to.equal(constants.EXIT); + expect(span.async).to.equal(false); + expect(span.error).to.equal(false); + expect(span.ec).to.equal(0); + expect(span.t).to.be.a('string'); + expect(span.s).to.be.a('string'); + expect(span.p).to.equal(parentSpan.s); + expect(span.data.http.method).to.equal('GET'); + expect(span.data.http.url).to.match(RegExp(`^.*:${otherVendorAppPort}${url}$`)); + expect(span.data.http.status).to.equal(200); + expect(span.fp).to.not.exist; + }); +} diff --git a/packages/core/src/tracing/cls.js b/packages/core/src/tracing/cls.js index 890e186e33..4882f73608 100644 --- a/packages/core/src/tracing/cls.js +++ b/packages/core/src/tracing/cls.js @@ -10,11 +10,12 @@ logger = require('../logger').getLogger('tracing/cls', function(newLogger) { logger = newLogger; }); -var currentEntrySpanKey = (exports.currentEntrySpanKey = 'com.instana.entrySpan'); +var currentEntrySpanKey = (exports.currentEntrySpanKey = 'com.instana.entry'); var currentSpanKey = (exports.currentSpanKey = 'com.instana.span'); var reducedSpanKey = (exports.reducedSpanKey = 'com.instana.reduced'); - var tracingLevelKey = (exports.tracingLevelKey = 'com.instana.tl'); +var w3cTraceContextKey = (exports.w3cTraceContextKey = 'com.instana.w3ctc'); + // eslint-disable-next-line no-undef-init var serviceName = undefined; var processIdentityProvider = null; @@ -39,43 +40,59 @@ exports.init = function init(config, _processIdentityProvider) { /* * Start a new span and set it as the current span. */ -exports.startSpan = function startSpan(spanName, kind, traceId, parentSpanId, modifyAsyncContext) { +exports.startSpan = function startSpan(spanName, kind, traceId, parentSpanId, w3cTraceContext) { tracingMetrics.incrementOpened(); if (!kind || (kind !== constants.ENTRY && kind !== constants.EXIT && kind !== constants.INTERMEDIATE)) { logger.warn('Invalid span (%s) without kind/with invalid kind: %s, assuming EXIT.', spanName, kind); kind = constants.EXIT; } - modifyAsyncContext = modifyAsyncContext !== false; var span = new InstanaSpan(spanName); - var parentSpan = exports.ns.get(currentSpanKey); span.k = kind; - // If specified, use params - if (traceId && parentSpanId) { + var parentSpan = exports.getCurrentSpan(); + var parentW3cTraceContext = exports.getW3cTraceContext(); + + // If the client code has specified a trace ID/parent ID, use the provided IDs. + if (traceId) { span.t = traceId; - span.p = parentSpanId; - // else use pre-existing context (if any) + if (parentSpanId) { + span.p = parentSpanId; + } } else if (parentSpan) { + // Otherwise, use the currently active span (if any) as parent. span.t = parentSpan.t; span.p = parentSpan.s; - // last resort, use newly generated Ids } else { + // If no IDs have been provided, we start a new trace by generating a new trace ID. We do not set a parent ID in + // this case. span.t = tracingUtil.generateRandomTraceId(); } + + // Always generate a new span ID for the new span. span.s = tracingUtil.generateRandomSpanId(); - if (span.k === constants.ENTRY) { - if (modifyAsyncContext) { - // Make the entry span available independently (even if getCurrentSpan would return an intermediate or an exit at - // any given moment). This is used in the error handlers of web frameworks like Express to attach path templates - // and errors messages. - span.addCleanup(exports.ns.set(currentEntrySpanKey, span)); - } + if (!w3cTraceContext && parentW3cTraceContext) { + // If there is no incoming W3C trace context that has been read from HTTP headers, but there is a parent trace + // context associated with a parent span, we will create an updated copy of that parent W3C trace context. We must + // make sure that the parent trace context in the parent cls context is not modified. + w3cTraceContext = parentW3cTraceContext.clone(); } - if (modifyAsyncContext) { - span.addCleanup(exports.ns.set(currentSpanKey, span)); + if (w3cTraceContext) { + w3cTraceContext.updateParent(span.t, span.s); + span.addCleanup(exports.ns.set(w3cTraceContextKey, w3cTraceContext)); + } + + if (span.k === constants.ENTRY) { + // Make the entry span available independently (even if getCurrentSpan would return an intermediate or an exit at + // any given moment). This is used by the instrumentations of web frameworks like Express.js to add path templates + // and error messages to the entry span. + span.addCleanup(exports.ns.set(currentEntrySpanKey, span)); } + + // Set the span object as the currently active span in the active CLS context and also add a cleanup hook for when + // this span is transmitted. + span.addCleanup(exports.ns.set(currentSpanKey, span)); return span; }; @@ -107,6 +124,20 @@ exports.getReducedSpan = function getReducedSpan() { return exports.ns.get(reducedSpanKey); }; +/* + * Stores the W3C trace context object. + */ +exports.setW3cTraceContext = function setW3cTraceContext(traceContext) { + exports.ns.set(w3cTraceContextKey, traceContext); +}; + +/* + * Returns the W3C trace context object. + */ +exports.getW3cTraceContext = function getW3cTraceContext() { + return exports.ns.get(w3cTraceContextKey); +}; + /* * Determine if we're currently tracing or not. */ @@ -133,7 +164,7 @@ exports.tracingLevel = function tracingLevel() { */ exports.tracingSuppressed = function tracingSuppressed() { var tl = exports.tracingLevel(); - return tl && tl === '0'; + return typeof tl === 'string' && tl.indexOf('0') === 0; }; /* diff --git a/packages/core/src/tracing/instrumentation/protocols/httpClient.js b/packages/core/src/tracing/instrumentation/protocols/httpClient.js index bb3a573866..3f5c117551 100644 --- a/packages/core/src/tracing/instrumentation/protocols/httpClient.js +++ b/packages/core/src/tracing/instrumentation/protocols/httpClient.js @@ -74,14 +74,17 @@ function instrument(coreModule) { callbackIndex = 2; } + var w3cTraceContext = cls.getW3cTraceContext(); + if (!isActive || !cls.isTracing()) { var traceLevelHeaderHasBeenAdded = false; if (cls.tracingLevel()) { - traceLevelHeaderHasBeenAdded = tryToAddTraceLevelAddHeaderToOpts(options, cls.tracingLevel()); + traceLevelHeaderHasBeenAdded = tryToAddTraceLevelAddHeaderToOpts(options, cls.tracingLevel(), w3cTraceContext); } clientRequest = originalRequest.apply(coreModule, arguments); if (cls.tracingLevel() && !traceLevelHeaderHasBeenAdded) { clientRequest.setHeader(constants.traceLevelHeaderName, cls.tracingLevel()); + setW3cHeadersOnRequest(clientRequest, w3cTraceContext); } return clientRequest; } @@ -90,11 +93,12 @@ function instrument(coreModule) { if (constants.isExitSpan(parentSpan)) { if (cls.tracingSuppressed()) { - traceLevelHeaderHasBeenAdded = tryToAddTraceLevelAddHeaderToOpts(options, '0'); + traceLevelHeaderHasBeenAdded = tryToAddTraceLevelAddHeaderToOpts(options, '0', w3cTraceContext); } clientRequest = originalRequest.apply(coreModule, arguments); if (cls.tracingSuppressed() && !traceLevelHeaderHasBeenAdded) { clientRequest.setHeader(constants.traceLevelHeaderName, '0'); + setW3cHeadersOnRequest(clientRequest, w3cTraceContext); } return clientRequest; } @@ -102,6 +106,10 @@ function instrument(coreModule) { cls.ns.run(function() { var span = cls.startSpan('node.http.client', constants.EXIT); + // startSpan updates the W3C trace context and writes it back to CLS, so we have to refetch the updated context + // object from CLS. + w3cTraceContext = cls.getW3cTraceContext(); + var completeCallUrl; var params; if (urlArg && typeof urlArg === 'string') { @@ -143,7 +151,7 @@ function instrument(coreModule) { } try { - var instanaHeadersHaveBeenAdded = tryToAddHeadersToOpts(options, span); + var instanaHeadersHaveBeenAdded = tryToAddHeadersToOpts(options, span, w3cTraceContext); clientRequest = originalRequest.apply(coreModule, originalArgs); } catch (e) { // A synchronous exception indicates a failure that is not covered by the listeners. Using a malformed URL for @@ -161,7 +169,7 @@ function instrument(coreModule) { cls.ns.bindEmitter(clientRequest); if (!instanaHeadersHaveBeenAdded) { - instanaHeadersHaveBeenAdded = setHeadersOnRequest(clientRequest, span); + instanaHeadersHaveBeenAdded = setHeadersOnRequest(clientRequest, span, w3cTraceContext); } var isTimeout = false; @@ -245,7 +253,7 @@ function isUrlObject(argument) { return URL && argument instanceof url.URL; } -function tryToAddHeadersToOpts(options, span) { +function tryToAddHeadersToOpts(options, span, w3cTraceContext) { // Some HTTP spec background: If the request has a header Expect: 100-continue, the client will first send the // request headers, without the body. The client is then ought to wait for the server to send a first, preliminary // response with the status code 100 Continue (if all is well). Only then will the client send the actual request @@ -261,8 +269,9 @@ function tryToAddHeadersToOpts(options, span) { // Thus, at the very least, when this header is present in the incoming request options arguments, we need to add our // INSTANA-... HTTP headers to options.headers instead of calling request.setHeader later. In fact, we opt for the // slightly more general solution: If there is an options object parameter with a `headers` object, we just always - // add our headers there. Only when this object is missing do we use request.setHeader on the ClientRequest object + // add our headers there. We use request.setHeader on the ClientRequest object only when the headers object is missing // (see setHeadersOnRequest). + if (hasHeadersOption(options)) { if (!isItSafeToModifiyHeadersInOptions(options)) { return true; @@ -270,33 +279,55 @@ function tryToAddHeadersToOpts(options, span) { options.headers[constants.spanIdHeaderName] = span.s; options.headers[constants.traceIdHeaderName] = span.t; options.headers[constants.traceLevelHeaderName] = '1'; + tryToAddW3cHeaderToOpts(options, w3cTraceContext); return true; } + return false; } -function tryToAddTraceLevelAddHeaderToOpts(options, level) { +function tryToAddTraceLevelAddHeaderToOpts(options, level, w3cTraceContext) { if (hasHeadersOption(options)) { if (!isItSafeToModifiyHeadersInOptions(options)) { return true; } options.headers[constants.traceLevelHeaderName] = level; + tryToAddW3cHeaderToOpts(options, w3cTraceContext); return true; } return false; } +function tryToAddW3cHeaderToOpts(options, w3cTraceContext) { + if (w3cTraceContext) { + options.headers[constants.w3cTraceParent] = w3cTraceContext.renderTraceParent(); + if (w3cTraceContext.hasTraceState()) { + options.headers[constants.w3cTraceState] = w3cTraceContext.renderTraceState(); + } + } +} + function hasHeadersOption(options) { return options && typeof options === 'object' && options.headers && typeof options.headers === 'object'; } -function setHeadersOnRequest(clientRequest, span) { +function setHeadersOnRequest(clientRequest, span, w3cTraceContext) { if (!isItSafeToModifiyHeadersForRequest(clientRequest)) { return; } clientRequest.setHeader(constants.spanIdHeaderName, span.s); clientRequest.setHeader(constants.traceIdHeaderName, span.t); clientRequest.setHeader(constants.traceLevelHeaderName, '1'); + setW3cHeadersOnRequest(clientRequest, w3cTraceContext); +} + +function setW3cHeadersOnRequest(clientRequest, w3cTraceContext) { + if (w3cTraceContext) { + clientRequest.setHeader(constants.w3cTraceParent, w3cTraceContext.renderTraceParent()); + if (w3cTraceContext.hasTraceState()) { + clientRequest.setHeader(constants.w3cTraceState, w3cTraceContext.renderTraceState()); + } + } } function isItSafeToModifiyHeadersInOptions(options) { diff --git a/packages/core/src/tracing/instrumentation/protocols/httpServer.js b/packages/core/src/tracing/instrumentation/protocols/httpServer.js index f5cb73fc93..4764e74d3a 100644 --- a/packages/core/src/tracing/instrumentation/protocols/httpServer.js +++ b/packages/core/src/tracing/instrumentation/protocols/httpServer.js @@ -4,6 +4,7 @@ var coreHttpsModule = require('https'); var coreHttpModule = require('http'); var constants = require('../../constants'); +var tracingHeaders = require('../../tracingHeaders'); var urlUtil = require('../../../util/url'); var httpCommon = require('./_http'); var shimmer = require('shimmer'); @@ -44,22 +45,37 @@ function shimEmit(realEmit) { cls.ns.bindEmitter(res); } - // Respect any incoming tracing level headers - if (req && req.headers && req.headers[constants.traceLevelHeaderNameLowerCase] === '0') { - cls.setTracingLevel(req.headers[constants.traceLevelHeaderNameLowerCase]); + var headers = tracingHeaders.fromHttpRequest(req); + var w3cTraceContext = headers.w3cTraceContext; + + if (typeof headers.level === 'string' && headers.level.indexOf('0') === 0) { + cls.setTracingLevel('0'); + if (w3cTraceContext) { + w3cTraceContext.disableSampling(); + } + } + + if (w3cTraceContext) { + // Ususally we commit the W3C trace context to CLS in start span, but in some cases (e.g. when suppressed), + // we don't call startSpan, so we write to CLS here unconditionally. If we also write an update trace context + // later, the one written here will be overwritten. + cls.setW3cTraceContext(w3cTraceContext); } if (cls.tracingSuppressed()) { + // We still need to forward X-INSTANA-L and the W3C trace context; this happens in exit instrumentations + // (like httpClient.js). return realEmit.apply(originalThis, originalArgs); } - var incomingTraceId = getExistingTraceId(req); - var incomingParentSpanId = getExistingSpanId(req); - var span = cls.startSpan(exports.spanName, constants.ENTRY, incomingTraceId, incomingParentSpanId); + var span = cls.startSpan(exports.spanName, constants.ENTRY, headers.traceId, headers.parentId, w3cTraceContext); + + if (headers.foreignParent) { + span.fp = headers.foreignParent; + } - // Grab the URL before application code gets access to the incoming message. - // We are doing this because libs like express are manipulating req.url when - // using routers. + // Capture the URL before application code gets access to the incoming message. Libraries like express manipulate + // req.url when routers are used. var urlParts = req.url.split('?'); if (urlParts.length >= 1) { urlParts[1] = filterParams(urlParts[1]); @@ -77,8 +93,11 @@ function shimEmit(realEmit) { span.data.service = incomingServiceName; } - // Handle client / backend eum correlation. + // Handle client/back end eum correlation. if (!span.p) { + // We add the trace ID to the incoming request so a customer's app can render it into the EUM snippet, see + // eslint-disable-next-line max-len + // https://docs.instana.io/products/website_monitoring/backendCorrelation/#retrieve-the-backend-trace-id-in-nodejs req.headers['x-instana-t'] = span.t; // support for automatic client/back end EUM correlation @@ -143,22 +162,6 @@ exports.deactivate = function() { isActive = false; }; -function getExistingSpanId(req) { - var spanId = req.headers[constants.spanIdHeaderNameLowerCase]; - if (spanId == null) { - return null; - } - return spanId; -} - -function getExistingTraceId(req) { - var traceId = req.headers[constants.traceIdHeaderNameLowerCase]; - if (traceId == null) { - return null; - } - return traceId; -} - exports.setExtraHttpHeadersToCapture = function setExtraHttpHeadersToCapture(_extraHeaders) { extraHttpHeadersToCapture = _extraHeaders; }; diff --git a/packages/core/src/tracing/tracingHeaders.js b/packages/core/src/tracing/tracingHeaders.js new file mode 100644 index 0000000000..647902d3f0 --- /dev/null +++ b/packages/core/src/tracing/tracingHeaders.js @@ -0,0 +1,169 @@ +'use strict'; + +var constants = require('./constants'); +var tracingUtil = require('./tracingUtil'); +var w3c = require('./w3c_trace_context'); + +/** + * Inspects the headers of an incoming HTTP request for X-INSTANA-T, X-INSTANA-S, X-INSTANA-L, as well as the W3C trace + * context headers traceparent and tracestate. + */ +exports.fromHttpRequest = function fromHttpRequest(req) { + if (!req || !req.headers) { + req = { headers: {} }; + } + + var xInstanaT = readInstanaTraceId(req); + var xInstanaS = readInstanaParentId(req); + var level = readInstanaLevel(req); + var w3cTraceContext = readW3cTraceContext(req); + + if (isSuppressed(level)) { + // Ignore X-INSTANA-T/-S if X-INSTANA-L: 0 is also present. + xInstanaT = null; + xInstanaS = null; + } + + if (xInstanaT && xInstanaS && w3cTraceContext) { + // X-INSTANA- headers *and* W3C trace context headers are present. We use the X-NSTANA- values for tracing and also + // keep the received W3C trace context around. + var result = { + traceId: xInstanaT, + parentId: xInstanaS, + level: level, + w3cTraceContext: w3cTraceContext + }; + if (traceStateHasInstanaKeyValuePair(w3cTraceContext) && w3cTraceContext.traceStateHead) { + result.foreignParent = { + t: w3cTraceContext.foreignTraceId, + p: w3cTraceContext.foreignParentId, + lts: w3cTraceContext.getMostRecentForeignTraceStateMember() + }; + } + return result; + } else if (xInstanaT && xInstanaS) { + // X-INSTANA- headers are present but W3C trace context headers are not. Use the received IDs and also create a W3C + // trace context based on those IDs. + return { + traceId: xInstanaT, + parentId: xInstanaS, + level: level, + w3cTraceContext: w3c.create(xInstanaT, xInstanaS, !isSuppressed(level)) + }; + } else if (w3cTraceContext) { + // X-INSTANA- headers are not present but W3C trace context headers are. + if (traceStateHasInstanaKeyValuePair(w3cTraceContext)) { + // The W3C tracestate header has an in key-value pair. We use the values from it as trace ID and parent ID. + return { + traceId: !isSuppressed(level) ? w3cTraceContext.instanaTraceId : null, + parentId: !isSuppressed(level) ? w3cTraceContext.instanaParentId : null, + level: level, + w3cTraceContext: w3cTraceContext, + foreignParent: { + t: w3cTraceContext.foreignTraceId, + p: w3cTraceContext.foreignParentId, + lts: w3cTraceContext.getMostRecentForeignTraceStateMember() + } + }; + } else { + // The W3C tracestate header has no in key-value pair. We start a new Instana trace by generating a trace ID, + // at the same time, we keep the W3C trace context we received intact and will propagate it further. + // The w3cTraceContext has no instanaTraceId/instanaParentId yet, it will get one as soon as we start a span + // and upate it. In case we received X-INSTANA-L: 0 we will not start a span, but we will make sure to toggle the + // sampled flag in traceparent off. + return { + traceId: !isSuppressed(level) ? tracingUtil.generateRandomTraceId() : null, + parentId: null, + level: level, + w3cTraceContext: w3cTraceContext, + foreignParent: { + t: w3cTraceContext.foreignTraceId, + p: w3cTraceContext.foreignParentId, + lts: w3cTraceContext.getMostRecentForeignTraceStateMember() + } + }; + } + } else { + // Neither X-INSTANA- headers nor W3C trace context headers are present. + // eslint-disable-next-line no-lonely-if + if (isSuppressed(level)) { + // If tracing is suppressed an no headers are incoming, we need to create a new random parent ID (and pass it down + // in the traceparent header); this parent ID is not actually associated with any existing span (Instana or + // foreign). This can't be helped, the spec mandates to always set the traceparent header on outgoing requests, + // even if we didn't sample and it has to have a parent ID field. + return { + level: level, + w3cTraceContext: w3c.createEmptyUnsampled( + tracingUtil.generateRandomTraceId(), + tracingUtil.generateRandomSpanId() + ) + // We do not add foreignParent header here because we didn't receive any W3C trace context spec headers. + }; + } else { + // Neither X-INSTANA- headers nor W3C trace context headers are present and tracing is not suppressed + // via X-INSTANA-L. Start a new trace, that is, generate a trace ID and use it for for our trace ID as well as in + // the W3C trace context. + xInstanaT = tracingUtil.generateRandomTraceId(); + // We create a new dummy W3C trace context with an invalid parent ID, as we have no parent ID yet. Later, in + // cls.startSpan, we will update it so it gets the parent ID of the entry span we create there. The bogus + // parent ID "000..." will never be transmitted to any other service. + w3cTraceContext = w3c.create(xInstanaT, '0000000000000000', true); + return { + traceId: xInstanaT, + parentId: null, + level: level, + w3cTraceContext: w3cTraceContext + // We do not add foreignParent header here because we didn't receive any W3C trace context spec headers. + }; + } + } +}; + +function readInstanaTraceId(req) { + var xInstanaT = req.headers[constants.traceIdHeaderNameLowerCase]; + if (xInstanaT == null) { + return null; + } + return xInstanaT; +} + +function readInstanaParentId(req) { + var xInstanaS = req.headers[constants.spanIdHeaderNameLowerCase]; + if (xInstanaS == null) { + return null; + } + return xInstanaS; +} + +function readInstanaLevel(req) { + return req.headers[constants.traceLevelHeaderNameLowerCase]; +} + +function isSuppressed(level) { + return typeof level === 'string' && level.indexOf('0') === 0; +} + +function traceStateHasInstanaKeyValuePair(w3cTraceContext) { + return w3cTraceContext.instanaTraceId && w3cTraceContext.instanaParentId; +} + +function readW3cTraceContext(req) { + var traceParent = req.headers[constants.w3cTraceParent]; + // The spec mandates that multiple tracestate headers should be treated by concatenating them. Node.js' http core + // library takes care of that already. + var traceState = req.headers[constants.w3cTraceState]; + var traceContext; + if (traceParent) { + traceContext = w3c.parse(traceParent, traceState); + } + + if (traceContext) { + if (!traceContext.traceParentValid) { + traceContext = null; + } else if (!traceContext.traceStateValid) { + traceContext.resetTraceState(); + } + } + + return traceContext; +} diff --git a/packages/core/test/tracing/tracingHeaders_test.js b/packages/core/test/tracing/tracingHeaders_test.js new file mode 100644 index 0000000000..0039d4e527 --- /dev/null +++ b/packages/core/test/tracing/tracingHeaders_test.js @@ -0,0 +1,290 @@ +/* eslint-env mocha */ + +'use strict'; + +const { expect } = require('chai'); +const { fail } = expect; + +const tracingHeaders = require('../../src/tracing/tracingHeaders'); + +// X-INSTANA- values +const instana32CharTraceId = '0123456789abcdeffedcbc9876543210'; +const instana16CharTraceId = '0123456789abcdef'; +const instanaSpanId = '02468acefdb97531'; + +// W3C trace context values +const version00 = '00'; +const foreignTraceId = '0af7651916cd43dd8448eb211c80319c'; +const foreignParentId = 'b7ad6b7169203331'; +const flags = '01'; +const traceParent = `${version00}-${foreignTraceId}-${foreignParentId}-${flags}`; +const traceStateWithoutInstana = 'rojo=00f067aa0ba902b7,congo=t61rcWkgMzE'; +const instanaWideTraceStateValue = `in=${instana32CharTraceId};${instanaSpanId}`; +const instanaNarrowTraceStateValue = `in=${instana16CharTraceId};${instanaSpanId}`; +const traceStateWithInstanaWide = `rojo=00f067aa0ba902b7,congo=t61rcWkgMzE,${instanaWideTraceStateValue}`; +const traceStateWithInstanaNarrow = `rojo=00f067aa0ba902b7,congo=t61rcWkgMzE,${instanaNarrowTraceStateValue}`; +const traceStateWithInstanaLeftMostNarrow = `${instanaNarrowTraceStateValue},rojo=00f067aa0ba902b7,congo=t61rcWkgMzE`; + +describe('tracing/headers', () => { + it('should read X-INSTANA- headers', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: { + 'x-instana-t': instana32CharTraceId, + 'x-instana-s': instanaSpanId + } + }); + + expect(context).to.be.an('object'); + expect(context.traceId).to.equal(instana32CharTraceId); + expect(context.parentId).to.equal(instanaSpanId); + }); + + it('should use X-INSTANA- headers to create a new W3C trace context', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: { + 'x-instana-t': instana32CharTraceId, + 'x-instana-s': instanaSpanId + } + }); + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal(instana32CharTraceId); + expect(w3cTraceContext.foreignParentId).to.equal(instanaSpanId); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.equal(instana32CharTraceId); + expect(w3cTraceContext.instanaParentId).to.equal(instanaSpanId); + }); + + it('should read X-INSTANA-L', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: { + 'x-instana-l': '0' + } + }); + expect(context.level).to.equal('0'); + }); + + it('should read W3C trace context headers without an in key-value pair', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: { + traceparent: traceParent, + tracestate: traceStateWithoutInstana + } + }); + + expect(context).to.be.an('object'); + expect(context.traceId).to.be.a('string'); + expect(context.traceId).to.have.lengthOf(16); + expect(context.parentId).to.not.exist; + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal(foreignTraceId); + expect(context.traceId).to.not.equal(w3cTraceContext.foreignTraceId); + expect(w3cTraceContext.foreignParentId).to.equal(foreignParentId); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.not.exist; + expect(w3cTraceContext.instanaParentId).to.not.exist; + }); + + it('should read W3C trace context headers with an in key-value pair (wide)', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: { + traceparent: traceParent, + tracestate: traceStateWithInstanaWide + } + }); + + expect(context).to.be.an('object'); + expect(context.traceId).to.equal(instana32CharTraceId); + expect(context.parentId).to.equal(instanaSpanId); + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal(foreignTraceId); + expect(w3cTraceContext.foreignParentId).to.equal(foreignParentId); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.equal(instana32CharTraceId); + expect(w3cTraceContext.instanaParentId).to.equal(instanaSpanId); + }); + + it('should read W3C trace context headers with an in key-value pair (narrow)', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: { + traceparent: traceParent, + tracestate: traceStateWithInstanaNarrow + } + }); + + expect(context).to.be.an('object'); + expect(context.traceId).to.equal(instana16CharTraceId); + expect(context.parentId).to.equal(instanaSpanId); + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal(foreignTraceId); + expect(w3cTraceContext.foreignParentId).to.equal(foreignParentId); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.equal(instana16CharTraceId); + expect(w3cTraceContext.instanaParentId).to.equal(instanaSpanId); + }); + + it('should start a new trace if neither X-INSTANA- nor W3C trace context headers are present', () => { + const context = tracingHeaders.fromHttpRequest({ + headers: {} + }); + + expect(context).to.be.an('object'); + expect(context.traceId).to.be.a('string'); + expect(context.traceId).to.have.lengthOf(16); + expect(context.parentId).to.not.exist; + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal('0000000000000000' + context.traceId); + expect(w3cTraceContext.foreignParentId).to.equal('0000000000000000'); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.equal(context.traceId); + expect(w3cTraceContext.instanaParentId).to.equal('0000000000000000'); + }); + + it('should cope with missing headers', () => { + const context = tracingHeaders.fromHttpRequest({}); + + expect(context).to.be.an('object'); + expect(context.traceId).to.be.a('string'); + expect(context.traceId).to.have.lengthOf(16); + expect(context.parentId).to.not.exist; + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal('0000000000000000' + context.traceId); + expect(w3cTraceContext.foreignParentId).to.equal('0000000000000000'); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.equal(context.traceId); + expect(w3cTraceContext.instanaParentId).to.equal('0000000000000000'); + }); + + it('should cope with null', () => { + const context = tracingHeaders.fromHttpRequest(); + + expect(context).to.be.an('object'); + expect(context.traceId).to.be.a('string'); + expect(context.traceId).to.have.lengthOf(16); + expect(context.parentId).to.not.exist; + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + expect(w3cTraceContext.foreignTraceId).to.equal('0000000000000000' + context.traceId); + expect(w3cTraceContext.foreignParentId).to.equal('0000000000000000'); + expect(w3cTraceContext.sampled).to.be.true; + expect(w3cTraceContext.instanaTraceId).to.equal(context.traceId); + expect(w3cTraceContext.instanaParentId).to.equal('0000000000000000'); + }); + + [true, false].forEach(withInstanaHeaders => + [false, '1', '0'].forEach(withInstanaLevel => + [false, 'without-in', 'in-leftmost', 'in-not-leftmost'].forEach(withSpecHeaders => + registerTest(withInstanaHeaders, withInstanaLevel, withSpecHeaders) + ) + ) + ); + + function registerTest(withInstanaHeaders, withInstanaLevel, withSpecHeaders) { + const title = + // + `X-INSTANA-T/-S: ${withInstanaHeaders}, X-INSTANA-L: ${withInstanaLevel}, spec headers: ${withSpecHeaders}`; + const headers = {}; + + if (withInstanaHeaders) { + headers['x-instana-t'] = instana16CharTraceId; + headers['x-instana-s'] = instanaSpanId; + } + if (withSpecHeaders !== false) { + headers.traceparent = traceParent; + if (withSpecHeaders === 'without-in') { + headers.tracestate = traceStateWithoutInstana; + } else if (withSpecHeaders === 'in-leftmost') { + headers.tracestate = traceStateWithInstanaLeftMostNarrow; + } else if (withSpecHeaders === 'in-not-leftmost') { + headers.tracestate = traceStateWithInstanaNarrow; + } else { + throw new Error(`Unknown withSpecHeaders value: ${withSpecHeaders}`); + } + } + + if (withInstanaLevel !== false) { + headers['x-instana-l'] = withInstanaLevel; + } + + it(title, () => { + const context = tracingHeaders.fromHttpRequest({ headers }); + expect(context).to.be.an('object'); + const w3cTraceContext = context.w3cTraceContext; + expect(w3cTraceContext).to.be.an('object'); + + if (withInstanaLevel === '0') { + // We expect no trace to be started and no IDs to be generated. + expect(context.traceId).to.not.exist; + expect(context.parentId).to.not.exist; + } else if (withInstanaHeaders) { + // We expect the Instana headers to be respected. + expect(context.traceId).to.equal(instana16CharTraceId); + expect(context.parentId).to.equal(instanaSpanId); + } else if (withSpecHeaders === false || withSpecHeaders === 'without-in') { + // Neither the X-INSTANA- headers nor tracestate yielded a trace ID/parent ID. We expect a trace to be started + // with a new, generated trace ID. + expect(context.traceId).to.be.a('string'); + expect(context.traceId).to.have.lengthOf(16); + expect(context.traceId).to.not.equal(instana16CharTraceId); + expect(context.parentId).to.not.exist; + } else if (withSpecHeaders === 'in-leftmost' || withSpecHeaders === 'in-not-leftmost') { + expect(context.traceId).to.equal(instana16CharTraceId); + expect(context.parentId).to.equal(instanaSpanId); + } else { + fail('This should never happen, all cases should have been covered above.'); + } + + if (withSpecHeaders) { + expect(w3cTraceContext.foreignTraceId).to.equal(foreignTraceId); + expect(w3cTraceContext.foreignParentId).to.equal(foreignParentId); + } else if (withInstanaHeaders && withInstanaLevel !== '0') { + expect(w3cTraceContext.foreignTraceId).to.equal('0000000000000000' + instana16CharTraceId); + expect(w3cTraceContext.foreignParentId).to.equal(instanaSpanId); + } else { + // No foreign trace/parent ID available, new IDs will be generated. + expect(w3cTraceContext.foreignTraceId).to.be.a('string'); + expect(w3cTraceContext.foreignTraceId).to.have.lengthOf(32); + expect(w3cTraceContext.foreignTraceId).to.not.equal(instana16CharTraceId); + expect(w3cTraceContext.foreignTraceId).to.not.equal(foreignTraceId); + expect(w3cTraceContext.foreignParentId).to.be.a('string'); + expect(w3cTraceContext.foreignParentId).to.have.lengthOf(16); + expect(w3cTraceContext.foreignParentId).to.not.equal(instanaSpanId); + expect(w3cTraceContext.foreignParentId).to.not.equal(foreignParentId); + } + + if (!withSpecHeaders && withInstanaLevel === '0') { + expect(w3cTraceContext.sampled).to.be.false; + } else { + expect(w3cTraceContext.sampled).to.be.true; + } + + if (withInstanaHeaders && withInstanaLevel !== '0' && withSpecHeaders !== 'without-in') { + expect(w3cTraceContext.instanaTraceId).to.equal(instana16CharTraceId); + expect(w3cTraceContext.instanaParentId).to.equal(instanaSpanId); + } else if (withSpecHeaders === 'in-leftmost' || withSpecHeaders === 'in-not-leftmost') { + expect(w3cTraceContext.instanaTraceId).to.equal(instana16CharTraceId); + expect(w3cTraceContext.instanaParentId).to.equal(instanaSpanId); + } else if (withInstanaLevel !== '0' && !withInstanaHeaders && !withSpecHeaders) { + expect(w3cTraceContext.instanaTraceId).to.equal(context.traceId); + expect(w3cTraceContext.instanaParentId).to.equal('0000000000000000'); + } else { + expect(w3cTraceContext.instanaTraceId).to.not.exist; + expect(w3cTraceContext.instanaParentId).to.not.exist; + } + + if ((!withInstanaHeaders && withSpecHeaders) || withSpecHeaders === 'in-not-leftmost') { + expect(context.foreignParent).to.exist; + expect(context.foreignParent.t).to.equal(foreignTraceId); + expect(context.foreignParent.p).to.equal(foreignParentId); + expect(context.foreignParent.lts).to.equal('rojo=00f067aa0ba902b7'); + } else if (withInstanaLevel !== '0') { + expect(context.foreignParent).to.not.exist; + } + }); + } +}); diff --git a/packages/core/test/utils.js b/packages/core/test/utils.js index 214ffad0cd..8f8fdf4839 100644 --- a/packages/core/test/utils.js +++ b/packages/core/test/utils.js @@ -57,6 +57,10 @@ exports.expectOneMatching = function expectOneMatching(arr, fn) { } }; +exports.retryUntilSpansMatch = function retryUntilSpansMatch(agentControls, fn) { + return exports.retry(() => agentControls.getSpans().then(spans => fn(spans))); +}; + exports.stringifySpans = function stringifySpans(spans) { if (spans === null) { return 'null';