Merge pull request #50 from DataDog/stephenf/log-enhanced-metrics-by-default-js

Enable enhanced metrics by default and write enhanced metrics to logs

Author: swfunc

package.json

@@ -1,6 +1,6 @@
 {
   "name": "datadog-lambda-js",
-  "version": "0.14.0",
+  "version": "1.15.0",
   "description": "Lambda client library that supports hybrid tracing in node js",
   "main": "dist/index.js",
   "types": "dist/index.d.ts",

src/index.spec.ts

@@ -225,8 +225,7 @@ describe("datadog", () => {
     expect(spy).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=9101112] Hello");
   });
 
-  it("increments invocations for each function call with env var", async () => {
-    process.env.DD_ENHANCED_METRICS = "true";
+  it("increments invocations for each function call", async () => {
     const wrapped = datadog(handler);
 
     await wrapped({}, mockContext, () => {});
@@ -241,9 +240,7 @@ describe("datadog", () => {
     expect(mockedIncrementInvocations).toBeCalledTimes(4);
   });
 
-  it("increments errors correctly with env var", async () => {
-    process.env.DD_ENHANCED_METRICS = "true";
-
+  it("increments errors enhanced metric", async () => {
     const handlerError: Handler = (event, context, callback) => {
       throw Error("Some error");
     };
@@ -260,24 +257,23 @@ describe("datadog", () => {
     expect(mockedIncrementErrors).toBeCalledWith(mockContext);
   });
 
-  it("increments errors and invocations with config setting", async () => {
+  it("doesn't increment errors or invocations with config false setting", async () => {
     const handlerError: Handler = (event, context, callback) => {
       throw Error("Some error");
     };
 
-    const wrappedHandler = datadog(handlerError, { enhancedMetrics: true });
+    const wrappedHandler = datadog(handlerError, { enhancedMetrics: false });
 
     const result = wrappedHandler({}, mockContext, () => {});
     await expect(result).rejects.toEqual(Error("Some error"));
 
-    expect(mockedIncrementInvocations).toBeCalledTimes(1);
-    expect(mockedIncrementErrors).toBeCalledTimes(1);
-
-    expect(mockedIncrementInvocations).toBeCalledWith(mockContext);
-    expect(mockedIncrementErrors).toBeCalledWith(mockContext);
+    expect(mockedIncrementInvocations).toBeCalledTimes(0);
+    expect(mockedIncrementErrors).toBeCalledTimes(0);
   });
 
-  it("doesn't increment enhanced metrics without env var or config", async () => {
+  it("doesn't increment enhanced metrics with env var set to false", async () => {
+    process.env.DD_ENHANCED_METRICS = "false";
+
     const handlerError: Handler = (event, context, callback) => {
       throw Error("Some error");
     };

src/index.ts

@@ -40,7 +40,7 @@ export const defaultConfig: Config = {
   apiKeyKMS: "",
   autoPatchHTTP: true,
   debugLogging: false,
-  enhancedMetrics: false,
+  enhancedMetrics: true,
   injectLogContext: false,
   logForwarding: false,
   mergeDatadogXrayTraces: false,
@@ -166,7 +166,7 @@ function getConfig(userConfig?: Partial<Config>): Config {
     config.logForwarding = result === "true";
   }
   if (userConfig === undefined || userConfig.enhancedMetrics === undefined) {
-    const result = getEnvValue(enhancedMetricsEnvVar, "false").toLowerCase();
+    const result = getEnvValue(enhancedMetricsEnvVar, "true").toLowerCase();
     config.enhancedMetrics = result === "true";
   }
 

src/metrics/build-metric-log.ts

@@ -28,6 +28,11 @@ describe("getRuntimeTag", () => {
     mockedGetProcessVersion.mockReturnValue("v10.1.0");
     expect(getRuntimeTag()).toBe("runtime:nodejs10.x");
   });
+
+  it("returns the right tag for v12.13.0", () => {
+    mockedGetProcessVersion.mockReturnValue("v12.13.0");
+    expect(getRuntimeTag()).toBe("runtime:nodejs12.x");
+  });
 });
 
 describe("getEnhancedMetricTags", () => {

src/metrics/enhanced-metrics.spec.ts

@@ -1,16 +1,18 @@
-import { getEnvValue, sendDistributionMetric } from "../index";
+import { sendDistributionMetric } from "../index";
 
 import { Context } from "aws-lambda";
 import { parseTagsFromARN } from "../utils/arn";
 import { getColdStartTag } from "../utils/cold-start";
 import { getProcessVersion } from "../utils/process-version";
+import { writeMetricToStdout } from "./metric-log";
 
 const ENHANCED_LAMBDA_METRICS_NAMESPACE = "aws.lambda.enhanced";
 
 // Same tag strings added to normal Lambda integration metrics
 enum RuntimeTagValues {
   Node8 = "nodejs8.10",
   Node10 = "nodejs10.x",
+  Node12 = "nodejs12.x",
 }
 
 /**
@@ -30,6 +32,10 @@ export function getRuntimeTag(): string | null {
     processVersionTagString = RuntimeTagValues.Node10;
   }
 
+  if (processVersion.startsWith("v12")) {
+    processVersionTagString = RuntimeTagValues.Node12;
+  }
+
   if (!processVersionTagString) {
     return null;
   }
@@ -52,10 +58,20 @@ export function getEnhancedMetricTags(context: Context): string[] {
   return tags;
 }
 
+/**
+ * Increments the specified enhanced metric, applying all relevant tags
+ * @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(metricName: string, context: Context) {
+  // Always write enhanced metrics to standard out
+  writeMetricToStdout(`${ENHANCED_LAMBDA_METRICS_NAMESPACE}.${metricName}`, 1, getEnhancedMetricTags(context));
+}
+
 export function incrementInvocationsMetric(context: Context): void {
-  sendDistributionMetric(`${ENHANCED_LAMBDA_METRICS_NAMESPACE}.invocations`, 1, ...getEnhancedMetricTags(context));
+  incrementEnhancedMetric("invocations", context);
 }
 
 export function incrementErrorsMetric(context: Context): void {
-  sendDistributionMetric(`${ENHANCED_LAMBDA_METRICS_NAMESPACE}.errors`, 1, ...getEnhancedMetricTags(context));
+  incrementEnhancedMetric("errors", context);
 }

src/metrics/enhanced-metrics.ts

@@ -2,8 +2,8 @@ import { promisify } from "util";
 
 import { logDebug, logError } from "../utils";
 import { APIClient } from "./api";
-import { buildMetricLog } from "./build-metric-log";
 import { KMSService } from "./kms-service";
+import { writeMetricToStdout } from "./metric-log";
 import { Distribution } from "./model";
 import { Processor } from "./processor";
 
@@ -85,9 +85,7 @@ export class MetricsListener {
 
   public sendDistributionMetric(name: string, value: number, ...tags: string[]) {
     if (this.config.logForwarding) {
-      // We use process.stdout.write, because console.log will prepend metadata to the start
-      // of the log that log forwarder doesn't know how to read.
-      process.stdout.write(buildMetricLog(name, value, tags));
+      writeMetricToStdout(name, value, tags);
       return;
     }
     const dist = new Distribution(name, [{ timestamp: new Date(), value }], ...tags);

src/metrics/listener.ts

@@ -1,4 +1,4 @@
-import { buildMetricLog } from "./build-metric-log";
+import { buildMetricLog } from "./metric-log";
 
 describe("buildMetricLog", () => {
   jest.spyOn(Date, "now").mockImplementation(() => 1487076708123);

src/metrics/build-metric-log.spec.ts renamed to src/metrics/metric-log.spec.ts

@@ -0,0 +1,22 @@
+// Builds the string representation of the metric that will be written to logs
+export function buildMetricLog(name: string, value: number, tags: string[]) {
+  return `${JSON.stringify({
+    // Date.now() returns Unix time in milliseconds, we convert to seconds for DD API submission
+    e: Date.now() / 1000,
+    m: name,
+    t: tags,
+    v: value,
+  })}\n`;
+}
+
+/**
+ * Writes the specified metric to standard output
+ * @param name The name of the metric
+ * @param value Metric datapoint's value
+ * @param tags Tags to apply to the metric
+ */
+export function writeMetricToStdout(name: string, value: number, tags: string[]) {
+  // We use process.stdout.write, because console.log will prepend metadata to the start
+  // of the log that log forwarder doesn't know how to read.
+  process.stdout.write(buildMetricLog(name, value, tags));
+}