Make log-based metrics available with diagnostics tooling (#613)

* Add DiagnosticsMetrics class for enhanced metrics recording

This commit introduces the DiagnosticsMetrics class, which provides a high-level API for recording metrics using the `@vtex/diagnostics-nodejs` library. It includes functionality for recording latency, incrementing counters, and setting gauge values while managing attribute limits to prevent high cardinality. The new metrics system is initialized in the startApp function, allowing for backward compatibility with the existing MetricsAccumulator.

* Add unit tests for DiagnosticsMetrics class

This commit introduces a comprehensive test suite for the DiagnosticsMetrics class, covering initialization, latency recording, counter incrementing, and gauge setting functionalities. The tests ensure proper handling of attributes, including limits on the number of attributes, and verify that metrics are recorded correctly under various scenarios, including error handling during initialization.

* Add method to update HTTP agent metrics for diagnostics

This commit introduces the `updateHttpAgentMetrics` method in the HttpAgentSingleton class, which periodically exports the current state of the HTTP agent as diagnostic metrics. It reports the current number of sockets, free sockets, and pending requests as gauges. This stats are used in `MetricsAccumulator` to produce the same metrics in log-based format.

* Integrate HTTP agent metrics update into status tracking

This commit updates the `trackStatus` function to include a call to `HttpAgentSingleton.updateHttpAgentMetrics()`, enhancing the diagnostics metrics by exporting HTTP agent statistics. This addition complements the existing legacy status tracking functionality.

* Add unit tests for HttpAgentSingleton class

This commit introduces a new test suite for the HttpAgentSingleton class, validating the functionality of HTTP agent statistics retrieval and metrics reporting. The tests cover scenarios for both populated and empty agent states, ensuring accurate gauge reporting to diagnostics metrics.

* Enhance total incoming requests reporting in middleware

This commit updates the trackIncomingRequestStats middleware to include detailed metric reporting for total incoming requests. It introduces a cumulative counter for total requests ensuring that metrics are reported to diagnostics if available.

* Enhance closed incoming request metrics reporting in middleware

This commit modifies the requestClosed function to include detailed reporting of closed request metrics to diagnostics. It ensures that metrics are incremented and reported with relevant route and status information, improving the overall monitoring capabilities of the middleware.

* Add diagnostics metrics reporting for aborted requests in middleware

This commit enhances the requestAborted function to report metrics for aborted requests to diagnostics. It includes relevant route and status information, improving monitoring capabilities.

* Add unit tests for requestStats middleware

This commit introduces a comprehensive test suite for the requestStats middleware, validating the functionality of tracking incoming request statistics, including total, aborted, and closed requests. The tests ensure accurate reporting to diagnostics metrics and handle various scenarios, including the absence of global diagnostics metrics.

* Instrument http-client metrics with diagnostics

- Add OpenTelemetry `Attributes` import in `metricsMiddleware` to annotate HTTP client metric dimensions
- Captures elapsed request time and feed it to `global.diagnosticsMetrics.recordLatency`
- Create and increment a request counter

* Add cache state in http-client metrics

- Capture the resolved cache state for each HTTP client response
 - Include `cache_state` on latency histograms and the primary request counter
 - Emit `http_client_cache_total` diagnostics counter to replace legacy extension stats

* Report retries via diagnostics metrics for http-client metrics

- Read retry count from config with safe default so zero attempts are tracked
 - Retain legacy status extension updates while preparing to deprecate them
 - Emit `http_client_requests_retried_total` counter with base attributes for diagnostics

* Add unit tests for metricsMiddleware

This commit introduces a test suite for the metricsMiddleware, validating the functionality of metrics recording for various HTTP client scenarios, including successful requests, cache hits, retries, and error handling.

* Instrument timings middleware with diagnostics metrics

The HTTP timings middleware now takes advantage of DiagnosticsMetrics whenever it is available so we emit request latency and counter telemetry with stable OpenTelemetry-style attributes. This ensure `http-handler` metrics from legacy log-based approach are proper instrumented with diagnostics patterns. Legacy batching remains in place for backwards compatibility, and we log a warning when the diagnostics client is missing to make instrumentation gaps visible.

 - extend context destructuring to capture the route type for tagging
 - record latency histograms for every request and keep legacy batching intact
 - increment the new http_handler_requests_total counter with consistent attributes

* Add unit tests for timings middleware

This commit introduces a test suite for the timings middleware, validating the recording of diagnostics metrics for various HTTP request scenarios, including successful requests, error responses, and legacy compatibility. The tests ensure accurate logging of timing and billing information, as well as proper handling of different status codes and graceful degradation when diagnostics metrics are unavailable.

* Enhance GraphQL metrics with diagnostics support

This commit updates the Metric schema directive to integrate new diagnostics metrics, allowing for the recording of latency histograms and counters with stable attributes. It maintains backward compatibility with legacy metrics while providing warnings when diagnostics metrics are unavailable. Key changes include:

- Refactoring status handling for clarity
- Adding attributes for component, field name, and status in diagnostics metrics
- Recording latency for all requests and incrementing a counter for GraphQL field requests

* Add unit tests for Metric schema directive

This commit introduces a comprehensive test suite for the Metric schema directive, validating the recording of metrics for both successful and failed GraphQL field resolutions. The tests ensure accurate logging of latency and error metrics, while also checking for proper handling when diagnostics metrics are unavailable. Key additions include:

- Tests for successful field resolution metrics
- Tests for failed field resolution metrics
- Warning checks when diagnostics metrics are not present

* Export DiagnosticsMetrics

* Update DiagnosticsMetrics to conditionally log limit warnings

This commit modifies the DiagnosticsMetrics class to log warnings about exceeded attribute limits only if it is in a linked app context

* Add a description explaning unit test that handles intialization errors

* fix: correct mock context and test setup for metrics tests

Add missing mock properties to requestStats tests (`status`, `route`) and enable `LINKED` constant mocking for DiagnosticsMetrics attribute limiting tests

* Release beta version

Author: daniyelnnr

package.json

@@ -1,6 +1,6 @@
 {
   "name": "@vtex/api",
-  "version": "7.2.4",
+  "version": "7.2.5-beta.0",
   "description": "VTEX I/O API client",
   "main": "lib/index.js",
   "typings": "lib/index.d.ts",

src/HttpClient/middlewares/metrics.test.ts

@@ -0,0 +1,335 @@
+// Mock @vtex/diagnostics-nodejs before any imports
+jest.mock('@vtex/diagnostics-nodejs', () => ({
+  Types: {},
+  getMetricClient: jest.fn(),
+  getLogger: jest.fn(),
+}))
+
+jest.mock('../../service/metrics/client', () => ({
+  getMetricClient: jest.fn(),
+}))
+
+jest.mock('../../errors/RequestCancelledError', () => ({
+  RequestCancelledError: class RequestCancelledError extends Error {
+    constructor(message: string) {
+      super(message)
+      this.name = 'RequestCancelledError'
+    }
+  },
+}))
+
+import { DiagnosticsMetrics } from '../../metrics/DiagnosticsMetrics'
+import { MetricsAccumulator } from '../../metrics/MetricsAccumulator'
+import { metricsMiddleware } from './metrics'
+import { MiddlewareContext } from '../typings'
+
+describe('metricsMiddleware', () => {
+  let mockMetrics: jest.Mocked<MetricsAccumulator>
+  let mockDiagnosticsMetrics: jest.Mocked<DiagnosticsMetrics>
+  let mockNext: jest.Mock
+  let mockCtx: MiddlewareContext
+
+  beforeEach(() => {
+    // Mock MetricsAccumulator
+    mockMetrics = {
+      batch: jest.fn(),
+    } as any
+
+    // Mock DiagnosticsMetrics
+    mockDiagnosticsMetrics = {
+      recordLatency: jest.fn(),
+      incrementCounter: jest.fn(),
+      setGauge: jest.fn(),
+    } as any
+
+    // Set up global
+    global.diagnosticsMetrics = mockDiagnosticsMetrics
+
+    // Mock next function
+    mockNext = jest.fn().mockResolvedValue(undefined)
+
+    // Mock context
+    mockCtx = {
+      config: {
+        metric: 'test-client',
+        retryCount: 0,
+      },
+      response: {
+        status: 200,
+      },
+      cacheHit: undefined,
+      inflightHit: undefined,
+      memoizedHit: undefined,
+    } as any
+  })
+
+  afterEach(() => {
+    jest.clearAllMocks()
+    delete (global as any).diagnosticsMetrics
+  })
+
+  describe('successful requests', () => {
+    it('should record metrics for successful request with no cache', async () => {
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      // Legacy metrics
+      const batchCall = mockMetrics.batch.mock.calls[0]
+      expect(batchCall[0]).toBe('http-client-test-client')
+      expect(Array.isArray(batchCall[1])).toBe(true) // hrtime tuple
+      expect(batchCall[2]).toMatchObject({
+        success: 1,
+        'success-miss': 1,
+      })
+
+      // Diagnostics metrics
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(Array.isArray(latencyCall[0])).toBe(true) // hrtime tuple
+      expect(latencyCall[1]).toMatchObject({
+        component: 'http-client',
+        client_metric: 'test-client',
+        status_code: 200,
+        status: 'success',
+        cache_state: 'miss',
+      })
+
+      // Main request counter with status as attribute
+      expect(mockDiagnosticsMetrics.incrementCounter).toHaveBeenCalledWith(
+        'http_client_requests_total',
+        1,
+        expect.objectContaining({
+          component: 'http-client',
+          client_metric: 'test-client',
+          status_code: 200,
+          status: 'success',
+        })
+      )
+
+      // Cache counter with cache_state as attribute
+      expect(mockDiagnosticsMetrics.incrementCounter).toHaveBeenCalledWith(
+        'http_client_cache_total',
+        1,
+        expect.objectContaining({
+          component: 'http-client',
+          client_metric: 'test-client',
+          status: 'success',
+          cache_state: 'miss',
+        })
+      )
+    })
+
+    it('should record metrics with cache hit', async () => {
+      mockCtx.cacheHit = { revalidated: 1 }
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        cache_state: 'hit',
+      })
+
+      // Should have cache counter with cache_state attribute
+      expect(mockDiagnosticsMetrics.incrementCounter).toHaveBeenCalledWith(
+        'http_client_cache_total',
+        1,
+        expect.objectContaining({
+          component: 'http-client',
+          client_metric: 'test-client',
+          cache_state: 'hit',
+        })
+      )
+    })
+
+    it('should record metrics with inflight hit', async () => {
+      mockCtx.inflightHit = true
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        cache_state: 'inflight',
+      })
+    })
+
+    it('should record metrics with memoized hit', async () => {
+      mockCtx.memoizedHit = true
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        cache_state: 'memoized',
+      })
+    })
+
+    it('should include retry count in attributes when retries occurred', async () => {
+      mockCtx.config.retryCount = 2
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      // Histogram should not include retry_count (only in counter)
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        status: 'success',
+        cache_state: 'miss',
+      })
+
+      // Should have retry counter with retry_count attribute
+      expect(mockDiagnosticsMetrics.incrementCounter).toHaveBeenCalledWith(
+        'http_client_requests_retried_total',
+        1,
+        expect.objectContaining({
+          component: 'http-client',
+          client_metric: 'test-client',
+          status: 'success',
+          status_code: 200,
+          retry_count: 2, // Number, not string
+        })
+      )
+    })
+  })
+
+  describe('error handling', () => {
+    it('should record metrics for timeout errors', async () => {
+      mockNext.mockRejectedValueOnce({
+        response: {
+          data: { code: 'ProxyTimeout' }, // TIMEOUT_CODE
+        },
+      })
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await expect(middleware(mockCtx, mockNext)).rejects.toMatchObject({
+        response: expect.any(Object),
+      })
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        status: 'timeout',
+      })
+    })
+
+    it('should record metrics for aborted requests', async () => {
+      mockNext.mockRejectedValueOnce({
+        code: 'ECONNABORTED',
+      })
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await expect(middleware(mockCtx, mockNext)).rejects.toMatchObject({
+        code: 'ECONNABORTED',
+      })
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        status: 'aborted',
+      })
+    })
+
+    it('should record metrics for cancelled requests', async () => {
+      mockNext.mockRejectedValueOnce({
+        message: 'Request cancelled',
+      })
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await expect(middleware(mockCtx, mockNext)).rejects.toThrow('Request cancelled')
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        status: 'cancelled',
+      })
+    })
+
+    it('should record metrics for HTTP error responses', async () => {
+      mockNext.mockRejectedValueOnce({
+        response: {
+          status: 500,
+        },
+      })
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await expect(middleware(mockCtx, mockNext)).rejects.toMatchObject({
+        response: { status: 500 },
+      })
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        status: 'error',
+      })
+    })
+
+    it('should record metrics for generic errors', async () => {
+      mockNext.mockRejectedValueOnce(new Error('Generic error'))
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await expect(middleware(mockCtx, mockNext)).rejects.toThrow('Generic error')
+
+      const latencyCall = mockDiagnosticsMetrics.recordLatency.mock.calls[0]
+      expect(latencyCall[1]).toMatchObject({
+        status: 'error',
+      })
+    })
+  })
+
+  describe('backward compatibility', () => {
+    it('should maintain legacy metrics when config.metric is set', async () => {
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      // Verify legacy metrics still called
+      expect(mockMetrics.batch).toHaveBeenCalledTimes(1)
+      const batchCall = mockMetrics.batch.mock.calls[0]
+      expect(batchCall[0]).toBe('http-client-test-client')
+      expect(Array.isArray(batchCall[1])).toBe(true)
+      expect(batchCall[2]).toBeTruthy()
+    })
+
+    it('should not record metrics when config.metric is not set', async () => {
+      mockCtx.config.metric = undefined
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      expect(mockMetrics.batch).not.toHaveBeenCalled()
+      expect(mockDiagnosticsMetrics.recordLatency).not.toHaveBeenCalled()
+      expect(mockDiagnosticsMetrics.incrementCounter).not.toHaveBeenCalled()
+    })
+  })
+
+  describe('graceful degradation', () => {
+    it('should work without global.diagnosticsMetrics', async () => {
+      delete (global as any).diagnosticsMetrics
+
+      const consoleWarnSpy = jest.spyOn(console, 'warn').mockImplementation()
+
+      const middleware = metricsMiddleware({ metrics: mockMetrics, name: 'test' })
+
+      await middleware(mockCtx, mockNext)
+
+      // Legacy metrics still work
+      expect(mockMetrics.batch).toHaveBeenCalled()
+
+      // Warning logged
+      expect(consoleWarnSpy).toHaveBeenCalledWith(
+        'DiagnosticsMetrics not available. HTTP client metrics not reported.'
+      )
+
+      consoleWarnSpy.mockRestore()
+    })
+  })
+})
+