[SVLS-4699] Detect exceptions raised outside of the handler (#533)

Author: TalUsvyatsky

src/handler.cjs

@@ -3,6 +3,7 @@ const {
   datadogHandlerEnvVar,
   lambdaTaskRootEnvVar,
   traceExtractorEnvVar,
+  emitTelemetryOnErrorOutsideHandler,
   getEnvValue,
 } = require("./index.js");
 const { logDebug, logError } = require("./utils/index.js");
@@ -32,4 +33,11 @@ if (extractorEnv) {
   }
 }
 
-exports.handler = datadog(loadSync(taskRootEnv, handlerEnv), { traceExtractor });
+try {
+  exports.handler = datadog(loadSync(taskRootEnv, handlerEnv), { traceExtractor });
+} catch (error) {
+  emitTelemetryOnErrorOutsideHandler(error, handlerEnv, Date.now()).catch(
+    logDebug("failed to error telemetry on error outside handler"),
+  );
+  throw error;
+}

src/handler.mjs

@@ -1,4 +1,11 @@
-import { datadog, datadogHandlerEnvVar, lambdaTaskRootEnvVar, traceExtractorEnvVar, getEnvValue } from "./index.js";
+import {
+  datadog,
+  datadogHandlerEnvVar,
+  lambdaTaskRootEnvVar,
+  traceExtractorEnvVar,
+  getEnvValue,
+  emitTelemetryOnErrorOutsideHandler,
+} from "./index.js";
 import { logDebug, logError } from "./utils/index.js";
 import { load } from "./runtime/index.js";
 import { initTracer } from "./runtime/module_importer.js";
@@ -26,4 +33,12 @@ if (extractorEnv) {
   }
 }
 
-export const handler = datadog(await load(taskRootEnv, handlerEnv), { traceExtractor });
+let wrappedHandler;
+try {
+  wrappedHandler = datadog(await load(taskRootEnv, handlerEnv), { traceExtractor });
+} catch (error) {
+  await emitTelemetryOnErrorOutsideHandler(error, handlerEnv, Date.now());
+  throw error;
+}
+
+export const handler = wrappedHandler;

src/index.spec.ts

@@ -8,6 +8,7 @@ import {
   sendDistributionMetric,
   sendDistributionMetricWithDate,
   _metricsQueue,
+  emitTelemetryOnErrorOutsideHandler,
 } from "./index";
 import {
   incrementErrorsMetric,
@@ -21,6 +22,8 @@ import { DatadogTraceHeaders } from "./trace/context/extractor";
 import { SpanContextWrapper } from "./trace/span-context-wrapper";
 import { TraceSource } from "./trace/trace-context-service";
 import { inflateSync } from "zlib";
+import { MetricsListener } from "./metrics/listener";
+import { SpanOptions, TracerWrapper } from "./trace/tracer-wrapper";
 
 jest.mock("./metrics/enhanced-metrics");
 
@@ -536,3 +539,58 @@ describe("sendDistributionMetricWithDate", () => {
     expect(_metricsQueue.length).toBe(1);
   });
 });
+
+describe("emitTelemetryOnErrorOutsideHandler", () => {
+  let mockedStartSpan = jest.spyOn(TracerWrapper.prototype, "startSpan");
+  beforeEach(() => {
+    jest.spyOn(MetricsListener.prototype, "onStartInvocation").mockImplementation();
+    jest.spyOn(TracerWrapper.prototype, "isTracerAvailable", "get").mockImplementation(() => true);
+  });
+  afterEach(() => {
+    mockedIncrementErrors.mockClear();
+    mockedStartSpan.mockClear();
+  });
+  it("emits a metric when enhanced metrics are enabled", async () => {
+    process.env.DD_ENHANCED_METRICS = "true";
+    await emitTelemetryOnErrorOutsideHandler(new ReferenceError("some error"), "myFunction", Date.now());
+    expect(mockedIncrementErrors).toBeCalledTimes(1);
+  });
+
+  it("does not emit a metric when enhanced metrics are disabled", async () => {
+    process.env.DD_ENHANCED_METRICS = "false";
+    await emitTelemetryOnErrorOutsideHandler(new ReferenceError("some error"), "myFunction", Date.now());
+    expect(mockedIncrementErrors).toBeCalledTimes(0);
+  });
+
+  it("creates a span when tracing is enabled", async () => {
+    process.env.DD_TRACE_ENABLED = "true";
+    const functionName = "myFunction";
+    const startTime = Date.now();
+    const fakeError = new ReferenceError("some error");
+    const spanName = "aws.lambda";
+
+    await emitTelemetryOnErrorOutsideHandler(fakeError, functionName, startTime);
+
+    const options: SpanOptions = {
+      tags: {
+        service: spanName,
+        operation_name: spanName,
+        resource_names: functionName,
+        "resource.name": functionName,
+        "span.type": "serverless",
+        "error.status": 500,
+        "error.type": fakeError.name,
+        "error.message": fakeError.message,
+        "error.stack": fakeError.stack,
+      },
+      startTime,
+    };
+    expect(mockedStartSpan).toBeCalledWith(spanName, options);
+  });
+
+  it("does not create a span when tracing is disabled", async () => {
+    process.env.DD_TRACE_ENABLED = "false";
+    await emitTelemetryOnErrorOutsideHandler(new ReferenceError("some error"), "myFunction", Date.now());
+    expect(mockedStartSpan).toBeCalledTimes(0);
+  });
+});

src/index.ts

@@ -24,6 +24,8 @@ import {
 } from "./utils";
 import { getEnhancedMetricTags } from "./metrics/enhanced-metrics";
 import { DatadogTraceHeaders } from "./trace/context/extractor";
+import { SpanWrapper } from "./trace/span-wrapper";
+import { SpanOptions, TracerWrapper } from "./trace/tracer-wrapper";
 
 // Backwards-compatible export, TODO deprecate in next major
 export { DatadogTraceHeaders as TraceHeaders } from "./trace/context/extractor";
@@ -416,3 +418,37 @@ function getRuntimeTag(): string {
   const version = process.version;
   return `dd_lambda_layer:datadog-node${version}`;
 }
+
+export async function emitTelemetryOnErrorOutsideHandler(
+  error: Error,
+  functionName: string,
+  startTime: number,
+): Promise<void> {
+  if (getEnvValue("DD_TRACE_ENABLED", "true").toLowerCase() === "true") {
+    const options: SpanOptions = {
+      tags: {
+        service: "aws.lambda",
+        operation_name: "aws.lambda",
+        resource_names: functionName,
+        "resource.name": functionName,
+        "span.type": "serverless",
+        "error.status": 500,
+        "error.type": error.name,
+        "error.message": error.message,
+        "error.stack": error.stack,
+      },
+      startTime,
+    };
+    const tracerWrapper = new TracerWrapper();
+    const span = new SpanWrapper(tracerWrapper.startSpan("aws.lambda", options), {});
+    span.finish();
+  }
+
+  const config = getConfig();
+  if (config.enhancedMetrics) {
+    const metricsListener = new MetricsListener(new KMSService(), config);
+    await metricsListener.onStartInvocation(undefined);
+    incrementErrorsMetric(metricsListener);
+    await metricsListener.onCompleteInvocation();
+  }
+}

src/metrics/enhanced-metrics.spec.ts

@@ -55,8 +55,8 @@ describe("getEnhancedMetricTags", () => {
       "account_id:123497598159",
       "functionname:my-test-lambda",
       "resource:my-test-lambda",
-      "cold_start:true",
       "memorysize:128",
+      "cold_start:true",
       "datadog_lambda:vX.X.X",
       "runtime:nodejs20.x",
     ]);
@@ -66,8 +66,8 @@ describe("getEnhancedMetricTags", () => {
     mockedGetProcessVersion.mockReturnValue("v20.9.0");
     expect(getEnhancedMetricTags(mockContextLocal)).toStrictEqual([
       "functionname:my-test-lambda",
-      "cold_start:true",
       "memorysize:128",
+      "cold_start:true",
       "datadog_lambda:vX.X.X",
       "runtime:nodejs20.x",
     ]);
@@ -80,9 +80,14 @@ describe("getEnhancedMetricTags", () => {
       "account_id:123497598159",
       "functionname:my-test-lambda",
       "resource:my-test-lambda",
-      "cold_start:true",
       "memorysize:128",
+      "cold_start:true",
       "datadog_lambda:vX.X.X",
     ]);
   });
+
+  it("doesn't add context-based tags when context not provided", () => {
+    mockedGetProcessVersion.mockReturnValue("v20.9.0");
+    expect(getEnhancedMetricTags()).toStrictEqual(["cold_start:true", "datadog_lambda:vX.X.X", "runtime:nodejs20.x"]);
+  });
 });

src/metrics/enhanced-metrics.ts

@@ -49,12 +49,17 @@ export function getRuntimeTag(): string | null {
   return `runtime:${processVersionTagString}`;
 }
 
-export function getEnhancedMetricTags(context: Context): string[] {
-  let arnTags = [`functionname:${context.functionName}`];
-  if (context.invokedFunctionArn) {
-    arnTags = parseTagsFromARN(context.invokedFunctionArn, context.functionVersion);
+export function getEnhancedMetricTags(context?: Context): string[] {
+  const tags: string[] = [];
+  if (context) {
+    let arnTags = [`functionname:${context.functionName}`];
+    if (context.invokedFunctionArn) {
+      arnTags = parseTagsFromARN(context.invokedFunctionArn, context.functionVersion);
+    }
+    tags.push(...arnTags, `memorysize:${context.memoryLimitInMB}`);
   }
-  const tags = [...arnTags, ...getSandboxInitTags(), `memorysize:${context.memoryLimitInMB}`, getVersionTag()];
+
+  tags.push(...getSandboxInitTags(), getVersionTag());
 
   const runtimeTag = getRuntimeTag();
   if (runtimeTag) {
@@ -69,7 +74,7 @@ export function getEnhancedMetricTags(context: Context): string[] {
  * @param context object passed to invocation by AWS
  * @param metricName name of the enhanced metric without namespace prefix, i.e. "invocations" or "errors"
  */
-function incrementEnhancedMetric(listener: MetricsListener, metricName: string, context: Context) {
+function incrementEnhancedMetric(listener: MetricsListener, metricName: string, context?: Context) {
   // Always write enhanced metrics to standard out
   listener.sendDistributionMetric(`aws.lambda.enhanced.${metricName}`, 1, true, ...getEnhancedMetricTags(context));
 }
@@ -78,7 +83,7 @@ export function incrementInvocationsMetric(listener: MetricsListener, context: C
   incrementEnhancedMetric(listener, "invocations", context);
 }
 
-export function incrementErrorsMetric(listener: MetricsListener, context: Context): void {
+export function incrementErrorsMetric(listener: MetricsListener, context?: Context): void {
   incrementEnhancedMetric(listener, "errors", context);
 }