Merge pull request #344 from solarwinds/NH-79062

Response time processor

.yarn/versions/59854bf8.yml

@@ -0,0 +1,2 @@
+releases:
+  solarwinds-apm: minor

packages/solarwinds-apm/package.json

@@ -68,6 +68,7 @@
     "@opentelemetry/semantic-conventions": "~1.23.0",
     "@solarwinds-apm/bindings": "workspace:^",
     "@solarwinds-apm/instrumentations": "workspace:^",
+    "@solarwinds-apm/lazy": "workspace:^",
     "@solarwinds-apm/module": "workspace:^",
     "@solarwinds-apm/proto": "workspace:^",
     "@solarwinds-apm/sampling": "workspace:^",

packages/solarwinds-apm/src/processing/response-time.ts

@@ -0,0 +1,81 @@
+/*
+Copyright 2023-2024 SolarWinds Worldwide, LLC.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+import {
+  type Attributes,
+  metrics,
+  SpanKind,
+  SpanStatusCode,
+  ValueType,
+} from "@opentelemetry/api"
+import { hrTimeToMilliseconds } from "@opentelemetry/core"
+import {
+  NoopSpanProcessor,
+  type ReadableSpan,
+  type SpanProcessor,
+} from "@opentelemetry/sdk-trace-base"
+import {
+  SEMATTRS_HTTP_METHOD,
+  SEMATTRS_HTTP_STATUS_CODE,
+} from "@opentelemetry/semantic-conventions"
+import { lazy } from "@solarwinds-apm/lazy"
+
+import { isRootOrEntry } from "./parent-span.js"
+import { TRANSACTION_NAME_ATTRIBUTE } from "./transaction-name.js"
+
+const RESPONSE_TIME = lazy(() =>
+  metrics
+    .getMeter("sw.apm.request.metrics")
+    .createHistogram("trace.service.response_time", {
+      valueType: ValueType.DOUBLE,
+      unit: "ms",
+    }),
+)
+
+/**
+ * Processor that records response time metrics
+ *
+ * This should be registered after the transaction name processor
+ * as it depends on the final transaction name being set on the span
+ * for the recorded metrics to be correlated with it.
+ */
+export class ResponseTimeProcessor
+  extends NoopSpanProcessor
+  implements SpanProcessor
+{
+  override onEnd(span: ReadableSpan): void {
+    if (!isRootOrEntry(span)) {
+      return
+    }
+
+    const time = hrTimeToMilliseconds(span.duration)
+    const attributes: Attributes = {
+      "sw.is_error": span.status.code === SpanStatusCode.ERROR,
+    }
+
+    const copy = [TRANSACTION_NAME_ATTRIBUTE]
+    if (span.kind === SpanKind.SERVER) {
+      copy.push(SEMATTRS_HTTP_METHOD, SEMATTRS_HTTP_STATUS_CODE)
+    }
+    for (const a of copy) {
+      if (a in span.attributes) {
+        attributes[a] = span.attributes[a]
+      }
+    }
+
+    RESPONSE_TIME.record(time, attributes)
+  }
+}

packages/solarwinds-apm/src/processing/transaction-name.ts

@@ -28,10 +28,11 @@ import { type SwConfiguration } from "@solarwinds-apm/sdk"
 
 import { getRootOrEntry, isRootOrEntry } from "./parent-span.js"
 
+export const TRANSACTION_NAME_ATTRIBUTE = "sw.transaction"
+
 const TRANSACTION_NAME_POOL_TTL = 60 * 1000 // 1 minute
 const TRANSACTION_NAME_POOL_MAX = 200
 const TRANSACTION_NAME_DEFAULT = "other"
-const TRANSACTION_NAME_ATTRIBUTE = "sw.transaction"
 
 /**
  * Sets a custom name for the current transaction

packages/solarwinds-apm/test/processing/response-time.test.ts

@@ -0,0 +1,129 @@
+/*
+Copyright 2023-2024 SolarWinds Worldwide, LLC.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+import { SpanKind, SpanStatusCode, trace } from "@opentelemetry/api"
+import {
+  DataPointType,
+  type ExponentialHistogramMetricData,
+  type HistogramMetricData,
+} from "@opentelemetry/sdk-metrics"
+import {
+  SEMATTRS_HTTP_METHOD,
+  SEMATTRS_HTTP_ROUTE,
+  SEMATTRS_HTTP_STATUS_CODE,
+  SEMATTRS_HTTP_TARGET,
+} from "@opentelemetry/semantic-conventions"
+import { type SwConfiguration } from "@solarwinds-apm/sdk"
+import { describe, expect, it, otel } from "@solarwinds-apm/test"
+
+import { ParentSpanProcessor } from "../../src/processing/parent-span.js"
+import { ResponseTimeProcessor } from "../../src/processing/response-time.js"
+import { TransactionNameProcessor } from "../../src/processing/transaction-name.js"
+
+const responseTime = async () => {
+  const metrics = await otel.metrics()
+  const histograms = metrics
+    .flatMap(({ scopeMetrics }) => scopeMetrics)
+    .filter(({ scope }) => scope.name === "sw.apm.request.metrics")
+    .flatMap(({ metrics }) => metrics)
+    .filter(
+      (
+        metric,
+      ): metric is HistogramMetricData | ExponentialHistogramMetricData =>
+        metric.descriptor.name === "trace.service.response_time" &&
+        (metric.dataPointType === DataPointType.HISTOGRAM ||
+          metric.dataPointType === DataPointType.EXPONENTIAL_HISTOGRAM),
+    )
+
+  expect(histograms).to.have.lengthOf(1)
+  const { dataPoints } = histograms[0]!
+  expect(dataPoints).to.have.lengthOf(1)
+  const { value, attributes } = dataPoints[0]!
+  expect(value).to.have.property("count", 1)
+  expect(value).to.have.property("sum")
+
+  return { value: value.sum, attributes }
+}
+
+describe("ResponseTimeProcessor", () => {
+  beforeEach(() =>
+    otel.reset({
+      trace: {
+        processors: [
+          new TransactionNameProcessor({} as SwConfiguration),
+          new ResponseTimeProcessor(),
+          new ParentSpanProcessor(),
+        ],
+      },
+    }),
+  )
+
+  it("records response time for server spans", async () => {
+    const tracer = trace.getTracer("test")
+    tracer.startActiveSpan(
+      "GET /hello/:name",
+      {
+        kind: SpanKind.SERVER,
+        attributes: {
+          [SEMATTRS_HTTP_METHOD]: "GET",
+          [SEMATTRS_HTTP_ROUTE]: "/hello/:name",
+          [SEMATTRS_HTTP_TARGET]: "/hello/world",
+        },
+      },
+      (span) => {
+        tracer.startActiveSpan("operation", (span) => {
+          span.end()
+        })
+
+        span.setAttribute(SEMATTRS_HTTP_STATUS_CODE, 200)
+        span.end()
+      },
+    )
+
+    const { value, attributes } = await responseTime()
+    expect(attributes).to.deep.equal({
+      "sw.is_error": false,
+      "sw.transaction": "/hello/:name",
+      [SEMATTRS_HTTP_METHOD]: "GET",
+      [SEMATTRS_HTTP_STATUS_CODE]: 200,
+    })
+    expect(value).to.be.greaterThan(0)
+  })
+
+  it("records response time for other spans", async () => {
+    trace.getTracer("test").startActiveSpan(
+      "GET /foo/bar",
+      {
+        kind: SpanKind.CLIENT,
+        attributes: {
+          [SEMATTRS_HTTP_METHOD]: "GET",
+        },
+      },
+      (span) => {
+        span.setAttribute(SEMATTRS_HTTP_STATUS_CODE, 404)
+        span.setStatus({ code: SpanStatusCode.ERROR })
+        span.end()
+      },
+    )
+
+    const { value, attributes } = await responseTime()
+    expect(attributes).to.deep.equal({
+      "sw.is_error": true,
+      "sw.transaction": "GET /foo/bar",
+    })
+    expect(value).to.be.greaterThan(0)
+  })
+})