diff --git a/README.md b/README.md index 137df66..1934dd2 100644 --- a/README.md +++ b/README.md @@ -38,7 +38,7 @@ Once [installed](#installation), you should be able to submit custom metrics fro Check out the instructions for [submitting custom metrics from AWS Lambda functions](https://docs.datadoghq.com/integrations/amazon_lambda/?tab=java#custom-metrics). -## Tracing +## Distributed Tracing Wrap your outbound HTTP requests with trace headers to see your lambda in context in APM. The Lambda Java Client Library provides instrumented HTTP connection objects as well as helper methods for @@ -168,6 +168,59 @@ public class Handler implements RequestHandler getTraceContext(){ + if (this.tracing == null){ + DDLogger.getLoggerImpl().debug("No tracing context; unable to get Trace ID"); + return null; + } + return this.tracing.getLogCorrelationTraceAndSpanIDsMap(); + } + + /** + * Get the trace context in string form. Inject this into your logs in order to correlate logs with traces. + * @return a string representation of the current trace context + */ + public String getTraceContextString(){ + Map traceInfo = getTraceContext(); + if (traceInfo == null){ + DDLogger.getLoggerImpl().debug("No Trace/Log correlation IDs returned"); + return ""; + } + + String traceID = traceInfo.get(this.tracing.TRACE_ID_KEY); + String spanID = traceInfo.get(this.tracing.SPAN_ID_KEY); + return formatTraceContext(this.tracing.TRACE_ID_KEY, traceID, this.tracing.SPAN_ID_KEY, spanID); + } + + private String formatTraceContext(String traceKey, String trace, String spanKey, String span){ + return String.format("[%s=%s %s=%s]", traceKey, trace, spanKey, span); + } + } diff --git a/src/main/java/com/datadoghq/datadog_lambda_java/Tracing.java b/src/main/java/com/datadoghq/datadog_lambda_java/Tracing.java index 03a12e1..6aac65d 100644 --- a/src/main/java/com/datadoghq/datadog_lambda_java/Tracing.java +++ b/src/main/java/com/datadoghq/datadog_lambda_java/Tracing.java @@ -16,6 +16,9 @@ public class Tracing { protected DDTraceContext cxt; protected XRayTraceContext xrt; + protected String TRACE_ID_KEY = "dd.trace_id"; + protected String SPAN_ID_KEY = "dd.span_id"; + public Tracing(){ this.xrt = new XRayTraceContext(); } @@ -35,6 +38,14 @@ public Tracing(Headerable req){ this.xrt = new XRayTraceContext(); } + /** + * Test constructor that can take a dummy _X_AMZN_TRACE_ID value + * @param xrayTraceInfo + */ + protected Tracing(String xrayTraceInfo){ + this.xrt = new XRayTraceContext(xrayTraceInfo); + } + public DDTraceContext getDDContext() { if (this.cxt == null) { @@ -50,6 +61,31 @@ public XRayTraceContext getXrayContext() { return xrt; } + public Map getLogCorrelationTraceAndSpanIDsMap(){ + if (this.cxt != null){ + String traceID = this.cxt.getTraceID(); + String spanID = this.cxt.getParentID(); + Map out = new HashMap(); + out.put(TRACE_ID_KEY, traceID); + out.put(SPAN_ID_KEY, spanID); + return out; + } + if (this.xrt != null){ + String traceID = this.xrt.getAPMTraceID(); + String spanID = this.xrt.getAPMParentID(); + Map out = new HashMap(); + out.put(TRACE_ID_KEY, traceID); + out.put(SPAN_ID_KEY, spanID); + return out; + } + DDLogger.getLoggerImpl().debug("No DD trace context or XRay trace context set!"); + return null; + } + + private String formatLogCorrelation(String trace, String span){ + return String.format("[dd.trace_id=%s dd.span_id=%s]", trace, span); + } + private static DDTraceContext populateDDContext(Map headers){ DDTraceContext ctx = null; try{ @@ -317,7 +353,7 @@ class XRayTraceContext{ public XRayTraceContext(){ //Root=1-5e41a79d-e6a0db584029dba86a594b7e;Parent=8c34f5ad8f92d510;Sampled=1 String traceId = System.getenv("_X_AMZN_TRACE_ID"); - if (traceId == null){ + if (traceId == null || traceId == ""){ DDLogger.getLoggerImpl().debug("Unable to find _X_AMZN_TRACE_ID"); return; } @@ -337,6 +373,27 @@ public XRayTraceContext(){ this.traceIdHeader = traceId; } + /** + * Test constructor that can take a dummy _X_AMZN_TRACE_ID value rather than reading from env vars + * @param traceId + */ + protected XRayTraceContext(String traceId){ + String[] traceParts = traceId.split(";"); + if(traceParts.length != 3){ + DDLogger.getLoggerImpl().error("Malformed _X_AMZN_TRACE_ID value: "+ traceId); + return; + } + + try { + this.traceId = traceParts[0].split("=")[1]; + parentId = traceParts[1].split("=")[1]; + } catch (Exception e){ + DDLogger.getLoggerImpl().error("Malformed _X_AMZN_TRACE_ID value: "+ traceId); + return; + } + this.traceIdHeader = traceId; + } + public void setTraceIdHeader(String traceIdHeader) { this.traceIdHeader = traceIdHeader; } @@ -375,4 +432,35 @@ public String getAPMParentID(){ return null; } } + + public String getAPMTraceID(){ + //trace ID looks like 1-5e41a79d-e6a0db584029dba86a594b7e + String bigid = ""; + try { + bigid = this.traceId.split("-")[2]; + } + catch (ArrayIndexOutOfBoundsException | NullPointerException ai){ + DDLogger.getLoggerImpl().debug("Unexpected format for the trace ID. Unable to parse it. " + this.traceId); + return ""; + } + + //just to verify + if (bigid.length() != 24){ + DDLogger.getLoggerImpl().debug("Got an unusual traceid from x-ray. Unable to convert that to an APM id. " + this.traceId); + return ""; + } + + String last16 = bigid.substring(bigid.length()-16); // should be the last 16 characters of the big id + + Long parsed = 0L; + try { + parsed = Long.parseUnsignedLong(last16, 16); //unsigned because parseLong throws a numberformatexception at anything greater than 0x7FFFF... + } + catch (NumberFormatException ne){ + DDLogger.getLoggerImpl().debug("Got a NumberFormatException trying to parse the traceID. Unable to convert to an APM id. " + this.traceId); + return ""; + } + parsed = parsed & 0x7FFFFFFFFFFFFFFFL; //take care of that pesky first bit... + return parsed.toString(); + } } diff --git a/src/test/java/com/datadoghq/datadog_lambda_java/TraceLogCorrelationTest.java b/src/test/java/com/datadoghq/datadog_lambda_java/TraceLogCorrelationTest.java new file mode 100644 index 0000000..03b382e --- /dev/null +++ b/src/test/java/com/datadoghq/datadog_lambda_java/TraceLogCorrelationTest.java @@ -0,0 +1,52 @@ +package com.datadoghq.datadog_lambda_java; + +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; +import java.util.Map; +import org.junit.Assert; +import org.junit.Test; +import org.apache.log4j.Logger; +import org.apache.log4j.ConsoleAppender; +import org.apache.log4j.WriterAppender; +import org.apache.log4j.PatternLayout; + + +public class TraceLogCorrelationTest { + private final ByteArrayOutputStream outContent = new ByteArrayOutputStream(); + private final PrintStream originalErr = System.err; + + @Test + public void TestWithLog4J(){ + Logger logger = Logger.getLogger(TraceLogCorrelationTest.class.getName()); + PatternLayout layout = new PatternLayout("%d{ISO8601} %X{dd.trace_context} [%t] %-5p %c %x - %m%n"); + logger.addAppender(new ConsoleAppender((layout))); + + logger.info("Test log message"); + + EnhancedMetricTest.MockContext mc = new EnhancedMetricTest.MockContext(); + + //try to grab the contents of StdErr + logger.addAppender(new WriterAppender(layout, outContent)); + DDLambda ddl = new DDLambda(mc, "Root=1-5fa98677-5dda00b12ec8b1c31f61aa82;Parent=b481b4a6ef3a296c;Sampled=1"); + outContent.reset(); + logger.info("Test log message 2"); + logger.removeAllAppenders(); + + String logOutput = outContent.toString(); + String[] logFields = logOutput.split(" "); + Assert.assertEquals("[dd.trace_id=3371139772690049666", logFields[2]); + Assert.assertEquals("dd.span_id=13006875827893840236]", logFields[3]); + } + + @Test + public void TestGetTraceLogCorrelationId(){ + EnhancedMetricTest.MockContext mc = new EnhancedMetricTest.MockContext(); + DDLambda ddl = new DDLambda(mc, "Root=1-5fa98677-5dda00b12ec8b1c31f61aa82;Parent=b481b4a6ef3a296c;Sampled=1"); + + Map traceInfo = ddl.getTraceContext(); + Assert.assertEquals("3371139772690049666", traceInfo.get("dd.trace_id")); + Assert.assertEquals("13006875827893840236", traceInfo.get("dd.span_id")); + } + +} + diff --git a/src/test/java/com/datadoghq/datadog_lambda_java/XRayTraceContextTest.java b/src/test/java/com/datadoghq/datadog_lambda_java/XRayTraceContextTest.java index 0b85b7f..a6db154 100644 --- a/src/test/java/com/datadoghq/datadog_lambda_java/XRayTraceContextTest.java +++ b/src/test/java/com/datadoghq/datadog_lambda_java/XRayTraceContextTest.java @@ -23,16 +23,48 @@ public void getAPMParentFromXray_happy_path() { @Test - public void getAPMParentFromXray_bad_characters(){ + public void getAPMParentFromXray_bad_characters() { XRayTraceContext xrt = new XRayTraceContext(); xrt.setParentId(";79014b90ce44db5e0;875"); Assert.assertNull(xrt.getAPMParentID()); } @Test - public void getAPMParentFromXray_too_short(){ + public void getAPMParentFromXray_too_short() { XRayTraceContext xrt = new XRayTraceContext(); xrt.setParentId("875"); Assert.assertNull(xrt.getAPMParentID()); } + + @Test + public void getAPMTraceID() { + XRayTraceContext xrt = new XRayTraceContext(); + xrt.setTraceId("1-5ce31dc2-2c779014b90ce44db5e03875"); + String traceId = xrt.getAPMTraceID(); + Assert.assertEquals("4110911582297405557", traceId); + } + + @Test + public void getAPMTraceID_too_short() { + XRayTraceContext xrt = new XRayTraceContext(); + xrt.setTraceId("1-5ce31dc2-5e03875"); + String traceId = xrt.getAPMTraceID(); + Assert.assertEquals("", traceId); + } + + @Test + public void getAPMTraceID_invalid_format() { + XRayTraceContext xrt = new XRayTraceContext(); + xrt.setTraceId("1-2c779014b90ce44db5e03875"); + String traceId = xrt.getAPMTraceID(); + Assert.assertEquals("", traceId); + } + + @Test + public void getAPMTraceID_incorrect_characters() { + XRayTraceContext xrt = new XRayTraceContext(); + xrt.setTraceId("1-5ce31dc2-c779014b90ce44db5e03875;"); + String traceId = xrt.getAPMTraceID(); + Assert.assertEquals("", traceId); + } } \ No newline at end of file