From 41f51bbdd4502e408240041a33f32fc57a2a4b82 Mon Sep 17 00:00:00 2001 From: DarcyRaynerDD Date: Tue, 21 Jan 2020 13:52:17 -0500 Subject: [PATCH 1/5] Add logic to override X-Ray trace id using env var --- src/trace/constants.ts | 1 + src/trace/context.spec.ts | 50 ++++++++++++++++++++++++++++++++++ src/trace/context.ts | 57 ++++++++++++++++++++++++++++++++++++++- 3 files changed, 107 insertions(+), 1 deletion(-) diff --git a/src/trace/constants.ts b/src/trace/constants.ts index 164f8f02..2878419e 100644 --- a/src/trace/constants.ts +++ b/src/trace/constants.ts @@ -16,3 +16,4 @@ export const xraySubsegmentName = "datadog-metadata"; export const xraySubsegmentKey = "trace"; export const xrayBaggageSubsegmentKey = "root_span_metadata"; export const xraySubsegmentNamespace = "datadog"; +export const xrayTraceEnvVar = "_X_AMZN_TRACE_ID"; diff --git a/src/trace/context.spec.ts b/src/trace/context.spec.ts index 07669fb1..ab3c1184 100644 --- a/src/trace/context.spec.ts +++ b/src/trace/context.spec.ts @@ -9,6 +9,7 @@ import { readTraceContextFromXray, readTraceFromEvent, readStepFunctionContextFromEvent, + readTraceContextFromXrayEnv, } from "./context"; let currentSegment: any; @@ -127,6 +128,9 @@ describe("convertTraceContext", () => { }); describe("readTraceContextFromXray", () => { + afterEach(() => { + process.env["_X_AMZN_TRACE_ID"] = undefined; + }); it("will parse a trace context from the xray", () => { currentSegment = { id: "0b11cc4230d3e09e", @@ -160,6 +164,52 @@ describe("readTraceContextFromXray", () => { const traceContext = readTraceContextFromXray(); expect(traceContext).toBeUndefined(); }); + + it("returns trace context read from env, when traceID mismatches most recent segment from X-Ray sdk", () => { + currentSegment = { + id: "0b11cc4230d3e09e", + trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", + }; + process.env["_X_AMZN_TRACE_ID"] = "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1"; + const traceContext = readTraceContextFromXray(); + expect(traceContext).toEqual({ + parentID: "10713633173203262661", + sampleMode: 2, + source: "xray", + traceID: "3995693151288333088", + }); + }); +}); + +describe("readTraceContextFromXrayEnv", () => { + afterEach(() => { + process.env["_X_AMZN_TRACE_ID"] = undefined; + }); + it("returns a trace context from a valid env var", () => { + process.env["_X_AMZN_TRACE_ID"] = "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1"; + const context = readTraceContextFromXrayEnv(); + expect(context).toEqual({ + parentID: "10713633173203262661", + sampleMode: 2, + source: "xray", + traceID: "3995693151288333088", + }); + }); + it("returns undefined when given an invalid env var", () => { + const badCases = [ + "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5", + "Root=1-5e272390-8c398be037738dc042009320", + "1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1", + "Root=1-5e272390-8c398be037738dc042009320;94ae789b969f1cc5;Sampled=1", + "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;1", + "Root=a;Parent=94ae789b969f1cc5;Sampled=1", + "Root=1-5e272390-8c398be037738dc042009320;Parent=b;Sampled=1", + ]; + for (const badCase of badCases) { + process.env["_X_AMZN_TRACE_ID"] = badCase; + expect(readTraceContextFromXrayEnv()).toBeUndefined(); + } + }); }); describe("readTraceFromEvent", () => { diff --git a/src/trace/context.ts b/src/trace/context.ts index 41c8f79e..01501044 100644 --- a/src/trace/context.ts +++ b/src/trace/context.ts @@ -12,6 +12,7 @@ import { xraySubsegmentKey, xraySubsegmentName, xraySubsegmentNamespace, + xrayTraceEnvVar, } from "./constants"; export interface XRayTraceHeader { @@ -126,13 +127,67 @@ export function readTraceContextFromXray() { sampled: segment.notTraced ? 0 : 1, traceID: segment.trace_id, }; - return convertTraceContext(traceHeader); + const contextFromSegment = convertTraceContext(traceHeader); + const contextFromEnv = readTraceContextFromXrayEnv(); + // Due to a bug with the x-ray sdk's async await support, sometimes the X-Ray SDK will incorrectly report segments from previous traces. + // The x-ray trace environment variable usually has the correct trace id, but might not have the most recent parent segment. If the segment is from + // the wrong trace, we will use the trace context read from the environment instead. + if (contextFromSegment?.traceID != contextFromEnv?.traceID && contextFromEnv !== undefined) { + logDebug( + `Trace ID from X-Ray SDK ${contextFromSegment?.traceID} didn't match traceID from x-ray env var ${contextFromEnv?.traceID}. Using env var trace context instead`, + ); + return contextFromEnv; + } + return contextFromSegment; } catch (error) { logError("couldn't read xray trace header", { innerError: error }); } return undefined; } +export function readTraceContextFromXrayEnv(): TraceContext | undefined { + const header = process.env[xrayTraceEnvVar]; + if (header === undefined) { + return; + } + return parseTraceContextHeader(header); +} + +export function parseTraceContextHeader(header: string): TraceContext | undefined { + // Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1 + const [root, parent, sampled] = header.split(";"); + if (parent === undefined || sampled === undefined) { + return; + } + const [, rawTraceID] = root.split("="); + if (rawTraceID === undefined) { + return; + } + const traceID = convertToAPMTraceID(rawTraceID); + if (traceID === undefined) { + return; + } + const [, rawParentID] = parent.split("="); + if (rawParentID === undefined) { + return; + } + const parentID = convertToAPMParentID(rawParentID); + if (parentID === undefined) { + return; + } + const [, rawSampled] = sampled.split("="); + if (rawSampled === undefined) { + return; + } + const sampleMode = convertToSampleMode(parseInt(rawSampled)); + return { + traceID, + parentID, + sampleMode, + source: Source.Xray, + }; +} + export function readStepFunctionContextFromEvent(event: any): StepFunctionContext | undefined { if (typeof event !== "object") { return; From 397f6300118d9700bfa4f430ba6b7097b3a24ecb Mon Sep 17 00:00:00 2001 From: DarcyRaynerDD Date: Tue, 21 Jan 2020 13:53:57 -0500 Subject: [PATCH 2/5] Add extra debug log --- src/trace/context.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/src/trace/context.ts b/src/trace/context.ts index 01501044..59014221 100644 --- a/src/trace/context.ts +++ b/src/trace/context.ts @@ -155,6 +155,7 @@ export function readTraceContextFromXrayEnv(): TraceContext | undefined { export function parseTraceContextHeader(header: string): TraceContext | undefined { // Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1 + logDebug(`Reading trace context from env var ${header}`); const [root, parent, sampled] = header.split(";"); if (parent === undefined || sampled === undefined) { return; From 9651ba28facbe25fd8f16c0321c3590fd121c7e4 Mon Sep 17 00:00:00 2001 From: DarcyRaynerDD Date: Tue, 21 Jan 2020 13:59:47 -0500 Subject: [PATCH 3/5] Fix linting issues --- src/trace/context.ts | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/src/trace/context.ts b/src/trace/context.ts index 59014221..cc2fb5a7 100644 --- a/src/trace/context.ts +++ b/src/trace/context.ts @@ -129,10 +129,11 @@ export function readTraceContextFromXray() { }; const contextFromSegment = convertTraceContext(traceHeader); const contextFromEnv = readTraceContextFromXrayEnv(); - // Due to a bug with the x-ray sdk's async await support, sometimes the X-Ray SDK will incorrectly report segments from previous traces. - // The x-ray trace environment variable usually has the correct trace id, but might not have the most recent parent segment. If the segment is from - // the wrong trace, we will use the trace context read from the environment instead. - if (contextFromSegment?.traceID != contextFromEnv?.traceID && contextFromEnv !== undefined) { + // Due to a bug with the x-ray sdk's async await support, sometimes the X-Ray SDK will incorrectly report segments + // from previous traces. The x-ray trace environment variable usually has the correct trace id, but might not have + // the most recent parent segment. If the segment is from the wrong trace, we will use the trace context read from + // the environment instead. + if (contextFromSegment?.traceID !== contextFromEnv?.traceID && contextFromEnv !== undefined) { logDebug( `Trace ID from X-Ray SDK ${contextFromSegment?.traceID} didn't match traceID from x-ray env var ${contextFromEnv?.traceID}. Using env var trace context instead`, ); @@ -180,12 +181,12 @@ export function parseTraceContextHeader(header: string): TraceContext | undefine if (rawSampled === undefined) { return; } - const sampleMode = convertToSampleMode(parseInt(rawSampled)); + const sampleMode = convertToSampleMode(parseInt(rawSampled, 10)); return { - traceID, parentID, sampleMode, source: Source.Xray, + traceID, }; } From aca4ad64f17ca120fe102470fe8a8aae927861b7 Mon Sep 17 00:00:00 2001 From: DarcyRaynerDD Date: Tue, 21 Jan 2020 14:13:10 -0500 Subject: [PATCH 4/5] Bump version 0.13.0 --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 966df823..a9657a20 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "datadog-lambda-js", - "version": "0.12.0", + "version": "0.13.0", "description": "Lambda client library that supports hybrid tracing in node js", "main": "dist/index.js", "types": "dist/index.d.ts", From 0fd8f6368ffaeafefff4814fd56e1ce0325ec046 Mon Sep 17 00:00:00 2001 From: DarcyRaynerDD Date: Tue, 21 Jan 2020 14:37:32 -0500 Subject: [PATCH 5/5] Always read current segment from env var instead of X-Ray sdk --- src/trace/context.spec.ts | 84 +++++---------------------------------- src/trace/context.ts | 41 +++++-------------- 2 files changed, 19 insertions(+), 106 deletions(-) diff --git a/src/trace/context.spec.ts b/src/trace/context.spec.ts index ab3c1184..dafa60dd 100644 --- a/src/trace/context.spec.ts +++ b/src/trace/context.spec.ts @@ -9,7 +9,6 @@ import { readTraceContextFromXray, readTraceFromEvent, readStepFunctionContextFromEvent, - readTraceContextFromXrayEnv, } from "./context"; let currentSegment: any; @@ -23,12 +22,6 @@ jest.mock("aws-xray-sdk-core", () => { throw Error("Unimplemented"); } }, - getSegment: () => { - if (currentSegment === undefined) { - throw Error("Empty"); - } - return currentSegment; - }, }; }); @@ -128,66 +121,12 @@ describe("convertTraceContext", () => { }); describe("readTraceContextFromXray", () => { - afterEach(() => { - process.env["_X_AMZN_TRACE_ID"] = undefined; - }); - it("will parse a trace context from the xray", () => { - currentSegment = { - id: "0b11cc4230d3e09e", - trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", - }; - - const traceContext = readTraceContextFromXray(); - expect(traceContext).toEqual({ - parentID: "797643193680388254", - sampleMode: SampleMode.USER_KEEP, - traceID: "4110911582297405557", - source: Source.Xray, - }); - }); - it("will ignore a trace context from the xray, when sampling is turned off", () => { - currentSegment = { - id: "0b11cc4230d3e09e", - notTraced: true, - trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", - }; - - const traceContext = readTraceContextFromXray(); - expect(traceContext).toEqual({ - parentID: "797643193680388254", - sampleMode: SampleMode.USER_REJECT, - traceID: "4110911582297405557", - source: Source.Xray, - }); - }); - it("returns undefined when trace header isn't in environment", () => { - const traceContext = readTraceContextFromXray(); - expect(traceContext).toBeUndefined(); - }); - - it("returns trace context read from env, when traceID mismatches most recent segment from X-Ray sdk", () => { - currentSegment = { - id: "0b11cc4230d3e09e", - trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", - }; - process.env["_X_AMZN_TRACE_ID"] = "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1"; - const traceContext = readTraceContextFromXray(); - expect(traceContext).toEqual({ - parentID: "10713633173203262661", - sampleMode: 2, - source: "xray", - traceID: "3995693151288333088", - }); - }); -}); - -describe("readTraceContextFromXrayEnv", () => { afterEach(() => { process.env["_X_AMZN_TRACE_ID"] = undefined; }); it("returns a trace context from a valid env var", () => { process.env["_X_AMZN_TRACE_ID"] = "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;Sampled=1"; - const context = readTraceContextFromXrayEnv(); + const context = readTraceContextFromXray(); expect(context).toEqual({ parentID: "10713633173203262661", sampleMode: 2, @@ -204,10 +143,11 @@ describe("readTraceContextFromXrayEnv", () => { "Root=1-5e272390-8c398be037738dc042009320;Parent=94ae789b969f1cc5;1", "Root=a;Parent=94ae789b969f1cc5;Sampled=1", "Root=1-5e272390-8c398be037738dc042009320;Parent=b;Sampled=1", + undefined, ]; for (const badCase of badCases) { process.env["_X_AMZN_TRACE_ID"] = badCase; - expect(readTraceContextFromXrayEnv()).toBeUndefined(); + expect(readTraceContextFromXray()).toBeUndefined(); } }); }); @@ -411,11 +351,11 @@ describe("readStepFunctionContextFromEvent", () => { }); describe("extractTraceContext", () => { + afterEach(() => { + process.env["_X_AMZN_TRACE_ID"] = undefined; + }); it("returns trace read from header as highest priority", () => { - currentSegment = { - parent_id: "0b11cc4230d3e09e", - trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", - }; + process.env["_X_AMZN_TRACE_ID"] = "Root=1-5ce31dc2-2c779014b90ce44db5e03875;Parent=0b11cc4230d3e09e;Sampled=1"; const result = extractTraceContext({ headers: { @@ -432,10 +372,7 @@ describe("extractTraceContext", () => { }); }); it("returns trace read from env if no headers present", () => { - currentSegment = { - id: "0b11cc4230d3e09e", - trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", - }; + process.env["_X_AMZN_TRACE_ID"] = "Root=1-5ce31dc2-2c779014b90ce44db5e03875;Parent=0b11cc4230d3e09e;Sampled=1"; const result = extractTraceContext({}); expect(result).toEqual({ @@ -446,10 +383,7 @@ describe("extractTraceContext", () => { }); }); it("returns trace read from env if no headers present", () => { - currentSegment = { - id: "0b11cc4230d3e09e", - trace_id: "1-5ce31dc2-2c779014b90ce44db5e03875", - }; + process.env["_X_AMZN_TRACE_ID"] = "Root=1-5ce31dc2-2c779014b90ce44db5e03875;Parent=0b11cc4230d3e09e;Sampled=1"; const result = extractTraceContext({}); expect(result).toEqual({ diff --git a/src/trace/context.ts b/src/trace/context.ts index cc2fb5a7..2902b7b7 100644 --- a/src/trace/context.ts +++ b/src/trace/context.ts @@ -1,4 +1,4 @@ -import { captureFunc, getSegment } from "aws-xray-sdk-core"; +import { captureFunc } from "aws-xray-sdk-core"; import { BigNumber } from "bignumber.js"; import { logDebug, logError } from "../utils"; @@ -118,40 +118,19 @@ export function readTraceFromEvent(event: any): TraceContext | undefined { }; } -export function readTraceContextFromXray() { - try { - const segment = getSegment(); - logDebug(`Setting X-Ray parent trace to segment with ${segment.id} and trace ${segment.trace_id}`); - const traceHeader = { - parentID: segment.id, - sampled: segment.notTraced ? 0 : 1, - traceID: segment.trace_id, - }; - const contextFromSegment = convertTraceContext(traceHeader); - const contextFromEnv = readTraceContextFromXrayEnv(); - // Due to a bug with the x-ray sdk's async await support, sometimes the X-Ray SDK will incorrectly report segments - // from previous traces. The x-ray trace environment variable usually has the correct trace id, but might not have - // the most recent parent segment. If the segment is from the wrong trace, we will use the trace context read from - // the environment instead. - if (contextFromSegment?.traceID !== contextFromEnv?.traceID && contextFromEnv !== undefined) { - logDebug( - `Trace ID from X-Ray SDK ${contextFromSegment?.traceID} didn't match traceID from x-ray env var ${contextFromEnv?.traceID}. Using env var trace context instead`, - ); - return contextFromEnv; - } - return contextFromSegment; - } catch (error) { - logError("couldn't read xray trace header", { innerError: error }); - } - return undefined; -} - -export function readTraceContextFromXrayEnv(): TraceContext | undefined { +export function readTraceContextFromXray(): TraceContext | undefined { const header = process.env[xrayTraceEnvVar]; if (header === undefined) { + logError("couldn't read xray trace header from env"); return; } - return parseTraceContextHeader(header); + const context = parseTraceContextHeader(header); + if (context === undefined) { + logError("couldn't read xray trace context from env, variable had invalid format"); + } else { + logDebug("read trace context from environment", context); + } + return context; } export function parseTraceContextHeader(header: string): TraceContext | undefined {