Add tests for measurement and understand overhead

.github/workflows/ci.yml

@@ -24,6 +24,8 @@ jobs:
         run: node common/scripts/install-run-rush.js install
       - name: Rush validate
         run: node common/scripts/install-run-rush.js validate --verbose
+      - name: Rush test
+        run: node common/scripts/install-run-rush.js test --verbose
       - name: Publish packages
         if: startsWith(github.ref, 'refs/tags/v0.7.')
         env:

common/changes/@hcengineering/measurements-otlp/main_2025-10-10-14-14.json

@@ -0,0 +1,10 @@
+{
+  "changes": [
+    {
+      "packageName": "@hcengineering/measurements-otlp",
+      "comment": "Add tests",
+      "type": "none"
+    }
+  ],
+  "packageName": "@hcengineering/measurements-otlp"
+}

common/changes/@hcengineering/measurements/main_2025-10-10-14-14.json

@@ -0,0 +1,10 @@
+{
+  "changes": [
+    {
+      "packageName": "@hcengineering/measurements",
+      "comment": "Add tests",
+      "type": "none"
+    }
+  ],
+  "packageName": "@hcengineering/measurements"
+}

common/changes/@hcengineering/platform-rig/main_2025-10-10-14-14.json

@@ -0,0 +1,10 @@
+{
+  "changes": [
+    {
+      "packageName": "@hcengineering/platform-rig",
+      "comment": "",
+      "type": "none"
+    }
+  ],
+  "packageName": "@hcengineering/platform-rig"
+}

common/changes/@hcengineering/postgres-base/main_2025-10-10-14-14.json

@@ -0,0 +1,10 @@
+{
+  "changes": [
+    {
+      "packageName": "@hcengineering/postgres-base",
+      "comment": "",
+      "type": "none"
+    }
+  ],
+  "packageName": "@hcengineering/postgres-base"
+}

packages/measurements-otlp/src/__tests__/telemetry.test.ts

@@ -0,0 +1,465 @@
+import { OpenTelemetryMetricsContext } from '../telemetry'
+import { newMetrics, type MeasureLogger } from '@hcengineering/measurements'
+import { trace, context, SpanStatusCode } from '@opentelemetry/api'
+import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'
+
+describe('telemetry', () => {
+  let tracer: any
+  let provider: NodeTracerProvider
+
+  beforeAll(() => {
+    provider = new NodeTracerProvider()
+    provider.register()
+    tracer = trace.getTracer('test-tracer')
+  })
+
+  afterAll(() => {
+    provider.shutdown()
+  })
+
+  describe('OpenTelemetryMetricsContext', () => {
+    const mockLogger: MeasureLogger = {
+      info: jest.fn(),
+      error: jest.fn(),
+      warn: jest.fn(),
+      close: jest.fn(async () => {}),
+      logOperation: jest.fn()
+    }
+
+    beforeEach(() => {
+      jest.clearAllMocks()
+    })
+
+    it('should create a new context with tracer', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        undefined,
+        undefined,
+        { op: 'create' },
+        {},
+        metrics,
+        mockLogger
+      )
+
+      expect(ctx).toBeDefined()
+      expect(ctx.metrics).toBe(metrics)
+      expect(ctx.logger).toBe(mockLogger)
+    })
+
+    it('should create child context with span', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'parent',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const child = ctx.newChild('child', { op: 'child' }, { span: true })
+
+      expect(child).toBeDefined()
+      expect(child.parent).toBe(ctx)
+    })
+
+    it('should create child context without span when span is false', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'parent',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const child = ctx.newChild('child', { op: 'child' }, { span: false })
+
+      expect(child).toBeDefined()
+    })
+
+    it('should execute async operation with context', async () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      let executed = false
+      await ctx.with('operation', { op: 'test' }, async () => {
+        executed = true
+        await new Promise(resolve => setTimeout(resolve, 10))
+      })
+
+      expect(executed).toBe(true)
+      expect(metrics.measurements.operation).toBeDefined()
+    })
+
+    it('should execute sync operation with context', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const result = ctx.withSync('operation', { op: 'test' }, () => {
+        return 42
+      })
+
+      expect(result).toBe(42)
+      expect(metrics.measurements.operation).toBeDefined()
+    })
+
+    it('should handle errors in async operations', async () => {
+      const metrics = newMetrics()
+      const span = tracer.startSpan('test-span')
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        span,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      await expect(
+        ctx.with('operation', { op: 'test' }, async () => {
+          throw new Error('Test error')
+        })
+      ).rejects.toThrow('Test error')
+
+      expect(metrics.measurements.operation).toBeDefined()
+    })
+
+    it('should measure custom value with meter', () => {
+      const metrics = newMetrics()
+      const mockMeter = {
+        getCounter: jest.fn(() => ({
+          counter: { record: jest.fn() },
+          value: 0
+        }))
+      }
+
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        undefined,
+        undefined,
+        { op: 'test' },
+        {},
+        metrics,
+        mockLogger,
+        undefined,
+        undefined,
+        undefined,
+        mockMeter as any
+      )
+
+      ctx.measure('custom', 100)
+
+      expect(mockMeter.getCounter).toHaveBeenCalledWith('custom')
+    })
+
+    it('should log info with OTLP logger', () => {
+      const metrics = newMetrics()
+      const mockOtlpLogger = {
+        emit: jest.fn()
+      }
+
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        { op: 'test' },
+        {},
+        metrics,
+        mockLogger,
+        undefined,
+        undefined,
+        mockOtlpLogger as any
+      )
+
+      ctx.info('Test message', { key: 'value' })
+
+      expect(mockOtlpLogger.emit).toHaveBeenCalled()
+      expect(mockLogger.info).toHaveBeenCalled()
+    })
+
+    it('should log error with OTLP logger', () => {
+      const metrics = newMetrics()
+      const mockOtlpLogger = {
+        emit: jest.fn()
+      }
+
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        { op: 'test' },
+        {},
+        metrics,
+        mockLogger,
+        undefined,
+        undefined,
+        mockOtlpLogger as any
+      )
+
+      ctx.error('Error message', { error: 'details' })
+
+      expect(mockOtlpLogger.emit).toHaveBeenCalled()
+      expect(mockLogger.error).toHaveBeenCalled()
+    })
+
+    it('should log warn with OTLP logger', () => {
+      const metrics = newMetrics()
+      const mockOtlpLogger = {
+        emit: jest.fn()
+      }
+
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        { op: 'test' },
+        {},
+        metrics,
+        mockLogger,
+        undefined,
+        undefined,
+        mockOtlpLogger as any
+      )
+
+      ctx.warn('Warning message', { warning: 'info' })
+
+      expect(mockOtlpLogger.emit).toHaveBeenCalled()
+      expect(mockLogger.warn).toHaveBeenCalled()
+    })
+
+    it('should extract metadata from context', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const meta = ctx.extractMeta()
+
+      expect(meta).toBeDefined()
+      expect(typeof meta).toBe('object')
+    })
+
+    it('should get params', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        undefined,
+        undefined,
+        { op: 'test', method: 'GET' },
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const params = ctx.getParams()
+
+      expect(params).toEqual({ op: 'test', method: 'GET' })
+    })
+
+    it('should share contextData with children', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'parent',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+      ctx.contextData = { userId: '123' }
+
+      const child = ctx.newChild('child', {})
+
+      expect(child.contextData).toBe(ctx.contextData)
+    })
+
+    it('should inherit params when inheritParams is true', async () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'parent',
+        tracer,
+        context.active(),
+        undefined,
+        { parentKey: 'parentValue' },
+        {},
+        metrics,
+        mockLogger
+      )
+
+      await ctx.with(
+        'child',
+        { childKey: 'childValue' },
+        async (childCtx) => {
+          expect(childCtx.getParams()).toEqual({ childKey: 'childValue' })
+        },
+        {},
+        { inheritParams: false }
+      )
+
+      await ctx.with(
+        'child',
+        { childKey: 'childValue' },
+        async (childCtx) => {
+          expect(childCtx.getParams()).toEqual({
+            parentKey: 'parentValue',
+            childKey: 'childValue'
+          })
+        },
+        {},
+        { inheritParams: true }
+      )
+    })
+
+    it('should not call end() twice', () => {
+      const metrics = newMetrics()
+      const span = tracer.startSpan('test-span')
+      const spanEndSpy = jest.spyOn(span, 'end')
+
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        span,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      ctx.end()
+      ctx.end() // Second call should be no-op
+
+      expect(spanEndSpy).toHaveBeenCalledTimes(1)
+    })
+
+    it('should handle null return value', async () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const result = await ctx.with('operation', {}, () => null)
+
+      expect(result).toBeUndefined()
+    })
+
+    it('should log operation when log option is true', async () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'test',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      await ctx.with(
+        'operation',
+        { op: 'test' },
+        async () => {
+          await new Promise(resolve => setTimeout(resolve, 10))
+        },
+        {},
+        { log: true }
+      )
+
+      expect(mockLogger.logOperation).toHaveBeenCalledWith(
+        'operation',
+        expect.any(Number),
+        expect.objectContaining({ op: 'test' })
+      )
+    })
+
+    it('should suppress tracing when span is disable', () => {
+      const metrics = newMetrics()
+      const ctx = new OpenTelemetryMetricsContext(
+        'parent',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      const child = ctx.newChild('child', {}, { span: 'disable' })
+
+      expect(child).toBeDefined()
+    })
+
+    it('should set span attributes from params', () => {
+      const metrics = newMetrics()
+      
+      const ctx = new OpenTelemetryMetricsContext(
+        'parent',
+        tracer,
+        context.active(),
+        undefined,
+        {},
+        {},
+        metrics,
+        mockLogger
+      )
+
+      // When creating a child with span: true, attributes are set on the child's span
+      const child = ctx.newChild('child', { key1: 'value1', key2: 'value2' }, { span: true }) as OpenTelemetryMetricsContext
+
+      // The child should have been created successfully
+      expect(child).toBeDefined()
+      expect(child.parent).toBe(ctx)
+    })
+  })
+})

packages/measurements/src/__tests__/context.test.ts

@@ -0,0 +1,451 @@
+import {
+  MeasureMetricsContext,
+  NoMetricsContext,
+  consoleLogger,
+  noParamsLogger,
+  withContext,
+  setOperationLogProfiling,
+  registerOperationLog,
+  updateOperationLog,
+  addOperation
+} from '../context'
+import { newMetrics } from '../metrics'
+import type { MeasureLogger, MeasureContext } from '../types'
+
+describe('context', () => {
+  describe('consoleLogger', () => {
+    it('should create a logger with params', () => {
+      const logger = consoleLogger({ service: 'test' })
+      
+      expect(logger).toBeDefined()
+      expect(typeof logger.info).toBe('function')
+      expect(typeof logger.error).toBe('function')
+      expect(typeof logger.warn).toBe('function')
+      expect(typeof logger.close).toBe('function')
+    })
+
+    it('should log info messages', () => {
+      const consoleSpy = jest.spyOn(console, 'info').mockImplementation()
+      const logger = consoleLogger({ service: 'test' })
+      
+      logger.info('Test message', { key: 'value' })
+      
+      expect(consoleSpy).toHaveBeenCalled()
+      consoleSpy.mockRestore()
+    })
+
+    it('should log error messages', () => {
+      const consoleSpy = jest.spyOn(console, 'error').mockImplementation()
+      const logger = consoleLogger({ service: 'test' })
+      
+      logger.error('Error message', { error: 'details' })
+      
+      expect(consoleSpy).toHaveBeenCalled()
+      consoleSpy.mockRestore()
+    })
+
+    it('should log warn messages', () => {
+      const consoleSpy = jest.spyOn(console, 'warn').mockImplementation()
+      const logger = consoleLogger({ service: 'test' })
+      
+      logger.warn('Warning message', { warning: 'info' })
+      
+      expect(consoleSpy).toHaveBeenCalled()
+      consoleSpy.mockRestore()
+    })
+
+    it('should handle errors in params', () => {
+      const consoleSpy = jest.spyOn(console, 'error').mockImplementation()
+      const logger = consoleLogger({})
+      const error = new Error('Test error')
+      
+      logger.error('Error occurred', { error })
+      
+      expect(consoleSpy).toHaveBeenCalled()
+      const call = consoleSpy.mock.calls[0]
+      expect(call[0]).toBe('Error occurred')
+      consoleSpy.mockRestore()
+    })
+  })
+
+  describe('MeasureMetricsContext', () => {
+    let logger: MeasureLogger
+
+    beforeEach(() => {
+      logger = noParamsLogger
+    })
+
+    it('should create a new context', () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', { op: 'create' }, {}, metrics, logger)
+      
+      expect(ctx).toBeDefined()
+      expect(ctx.metrics).toBe(metrics)
+      expect(ctx.logger).toBe(logger)
+    })
+
+    it('should measure operation duration', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', { op: 'create' }, {}, metrics, logger)
+      
+      await new Promise(resolve => setTimeout(resolve, 50))
+      ctx.end()
+      
+      expect(metrics.operations).toBe(1)
+      expect(metrics.value).toBeGreaterThan(40)
+    })
+
+    it('should create child context', () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('parent', { op: 'parent' }, {}, metrics, logger)
+      const child = ctx.newChild('child', { op: 'child' })
+      
+      expect(child).toBeDefined()
+      expect(child.parent).toBe(ctx)
+    })
+
+    it('should execute async operation with context', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, logger)
+      
+      let executed = false
+      await ctx.with('operation', { op: 'test' }, async () => {
+        executed = true
+        await new Promise(resolve => setTimeout(resolve, 10))
+      })
+      
+      expect(executed).toBe(true)
+      expect(metrics.measurements.operation).toBeDefined()
+    })
+
+    it('should execute sync operation with context', () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, logger)
+      
+      const result = ctx.withSync('operation', { op: 'test' }, () => {
+        return 42
+      })
+      
+      expect(result).toBe(42)
+      expect(metrics.measurements.operation).toBeDefined()
+    })
+
+    it('should measure custom value', () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, logger)
+      
+      ctx.measure('custom', 100)
+      
+      expect(metrics.measurements['#custom']).toBeDefined()
+      expect(metrics.measurements['#custom'].value).toBe(100)
+    })
+
+    it('should log info messages', () => {
+      const mockLogger: MeasureLogger = {
+        info: jest.fn(),
+        error: jest.fn(),
+        warn: jest.fn(),
+        close: jest.fn(async () => {}),
+        logOperation: jest.fn()
+      }
+      
+      const ctx = new MeasureMetricsContext('test', { op: 'test' }, {}, newMetrics(), mockLogger)
+      ctx.info('Test message', { key: 'value' })
+      
+      expect(mockLogger.info).toHaveBeenCalledWith('Test message', expect.objectContaining({ key: 'value', op: 'test' }))
+    })
+
+    it('should log error messages', () => {
+      const mockLogger: MeasureLogger = {
+        info: jest.fn(),
+        error: jest.fn(),
+        warn: jest.fn(),
+        close: jest.fn(async () => {}),
+        logOperation: jest.fn()
+      }
+      
+      const ctx = new MeasureMetricsContext('test', { op: 'test' }, {}, newMetrics(), mockLogger)
+      ctx.error('Error message', { error: 'details' })
+      
+      expect(mockLogger.error).toHaveBeenCalledWith('Error message', expect.objectContaining({ error: 'details', op: 'test' }))
+    })
+
+    it('should log warn messages', () => {
+      const mockLogger: MeasureLogger = {
+        info: jest.fn(),
+        error: jest.fn(),
+        warn: jest.fn(),
+        close: jest.fn(async () => {}),
+        logOperation: jest.fn()
+      }
+      
+      const ctx = new MeasureMetricsContext('test', { op: 'test' }, {}, newMetrics(), mockLogger)
+      ctx.warn('Warning message', { warning: 'info' })
+      
+      expect(mockLogger.warn).toHaveBeenCalledWith('Warning message', expect.objectContaining({ warning: 'info', op: 'test' }))
+    })
+
+    it('should get params', () => {
+      const ctx = new MeasureMetricsContext('test', { op: 'test', method: 'GET' }, {}, newMetrics(), logger)
+      const params = ctx.getParams()
+      
+      expect(params).toEqual({ op: 'test', method: 'GET' })
+    })
+
+    it('should share contextData with children', () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('parent', {}, {}, metrics, logger)
+      ctx.contextData = { userId: '123' }
+      
+      const child = ctx.newChild('child', {})
+      
+      expect(child.contextData).toBe(ctx.contextData)
+    })
+
+    it('should handle named parameters', () => {
+      const metrics = newMetrics()
+      new MeasureMetricsContext('test', { method: 'GET' }, {}, metrics, logger)
+      
+      expect(metrics.namedParams.method).toBe('GET')
+    })
+
+    it('should update named parameters on multiple contexts', () => {
+      const metrics = newMetrics()
+      const ctx1 = new MeasureMetricsContext('test1', { method: 'GET' }, {}, metrics, logger)
+      
+      expect(metrics.namedParams.method).toBe('GET')
+      
+      // Create another context with different value for same param
+      const ctx2 = new MeasureMetricsContext('test2', { method: 'POST' }, {}, metrics, logger)
+      
+      // The second context will see existing value is different, so it will update to '*'
+      // But this happens within the constructor logic
+      expect(metrics.namedParams.method).toBe('POST')
+    })
+  })
+
+  describe('NoMetricsContext', () => {
+    it('should create a no-op context', () => {
+      const ctx = new NoMetricsContext()
+      
+      expect(ctx).toBeDefined()
+      expect(ctx.logger).toBeDefined()
+    })
+
+    it('should execute operations without measuring', async () => {
+      const ctx = new NoMetricsContext()
+      
+      let executed = false
+      await ctx.with('operation', {}, async () => {
+        executed = true
+      })
+      
+      expect(executed).toBe(true)
+    })
+
+    it('should create child contexts', () => {
+      const ctx = new NoMetricsContext()
+      const child = ctx.newChild('child', {})
+      
+      expect(child).toBeDefined()
+      expect(child).toBeInstanceOf(NoMetricsContext)
+    })
+
+    it('should handle measure calls without error', () => {
+      const ctx = new NoMetricsContext()
+      
+      expect(() => {
+        ctx.measure('test', 100)
+      }).not.toThrow()
+    })
+
+    it('should handle end calls without error', () => {
+      const ctx = new NoMetricsContext()
+      
+      expect(() => {
+        ctx.end()
+      }).not.toThrow()
+    })
+
+    it('should return empty params', () => {
+      const ctx = new NoMetricsContext()
+      const params = ctx.getParams()
+      
+      expect(params).toEqual({})
+    })
+  })
+
+  describe('withContext decorator', () => {
+    it('should wrap method with context', async () => {
+      class TestClass {
+        @withContext('testOperation', { service: 'test' })
+        async testMethod(ctx: MeasureContext, value: number): Promise<number> {
+          return value * 2
+        }
+      }
+      
+      const instance = new TestClass()
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('root', {}, {}, metrics, noParamsLogger)
+      
+      const result = await instance.testMethod(ctx, 21)
+      
+      expect(result).toBe(42)
+      expect(metrics.measurements.testOperation).toBeDefined()
+    })
+  })
+
+  describe('operation log profiling', () => {
+    beforeEach(() => {
+      setOperationLogProfiling(false)
+    })
+
+    afterEach(() => {
+      setOperationLogProfiling(false)
+    })
+
+    it('should register operation log when profiling enabled', () => {
+      setOperationLogProfiling(true)
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      const { opLogMetrics, op } = registerOperationLog(ctx)
+      
+      expect(opLogMetrics).toBe(metrics)
+      expect(op).toBeDefined()
+      expect(ctx.id).toBeDefined()
+    })
+
+    it('should not register operation log when profiling disabled', () => {
+      setOperationLogProfiling(false)
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      const { opLogMetrics, op } = registerOperationLog(ctx)
+      
+      expect(opLogMetrics).toBeUndefined()
+      expect(op).toBeUndefined()
+    })
+
+    it('should update operation log', () => {
+      setOperationLogProfiling(true)
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      const { opLogMetrics, op } = registerOperationLog(ctx)
+      updateOperationLog(opLogMetrics, op)
+      
+      expect(op?.end).toBeGreaterThan(0)
+    })
+
+    it('should add operation to log', async () => {
+      setOperationLogProfiling(true)
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      registerOperationLog(ctx)
+      
+      let executed = false
+      await addOperation(ctx, 'asyncOp', { op: 'test' }, async () => {
+        executed = true
+      })
+      
+      expect(executed).toBe(true)
+      expect(metrics.opLog).toBeDefined()
+    })
+
+    it('should limit operation log entries', () => {
+      setOperationLogProfiling(true)
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      registerOperationLog(ctx)
+      
+      // Create many operation log entries
+      if (metrics.opLog && ctx.id) {
+        for (let i = 0; i < 50; i++) {
+          metrics.opLog[ctx.id].ops.push({
+            op: `test${i}`,
+            start: i,
+            end: i + 1,
+            params: {}
+          })
+        }
+        
+        const op = metrics.opLog[ctx.id]
+        updateOperationLog(metrics, op)
+        
+        expect(Object.keys(metrics.opLog).length).toBeLessThanOrEqual(31)
+      }
+    })
+  })
+
+  describe('extractMeta', () => {
+    it('should return empty metadata', () => {
+      const ctx = new MeasureMetricsContext('test', {}, {}, newMetrics(), noParamsLogger)
+      const meta = ctx.extractMeta()
+      
+      expect(meta).toEqual({})
+    })
+  })
+
+  describe('async operations', () => {
+    it('should handle promise rejection', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      await expect(
+        ctx.with('operation', { op: 'test' }, async () => {
+          throw new Error('Test error')
+        })
+      ).rejects.toThrow('Test error')
+      
+      expect(metrics.measurements.operation).toBeDefined()
+    })
+
+    it('should return null promise for null sync result', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      const result = await ctx.with('operation', { op: 'test' }, () => {
+        return null
+      })
+      
+      expect(result).toBeUndefined()
+    })
+
+    it('should handle sync return value', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, noParamsLogger)
+      
+      const result = await ctx.with('operation', { op: 'test' }, () => {
+        return 42
+      })
+      
+      expect(result).toBe(42)
+    })
+
+    it('should log operation when log option is true', async () => {
+      const mockLogger: MeasureLogger = {
+        info: jest.fn(),
+        error: jest.fn(),
+        warn: jest.fn(),
+        close: jest.fn(async () => {}),
+        logOperation: jest.fn()
+      }
+      
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('test', {}, {}, metrics, mockLogger)
+      
+      await ctx.with('operation', { op: 'test' }, async () => {
+        await new Promise(resolve => setTimeout(resolve, 10))
+      }, {}, { log: true })
+      
+      expect(mockLogger.logOperation).toHaveBeenCalledWith(
+        'operation',
+        expect.any(Number),
+        expect.objectContaining({ op: 'test' })
+      )
+    })
+  })
+})

packages/measurements/src/__tests__/index.test.ts

@@ -0,0 +1,47 @@
+import { platformNow, platformNowDiff } from '../index'
+
+describe('index', () => {
+  describe('platformNow', () => {
+    it('should return a positive number', () => {
+      const now = platformNow()
+      expect(typeof now).toBe('number')
+      expect(now).toBeGreaterThan(0)
+    })
+
+    it('should return increasing values over time', async () => {
+      const first = platformNow()
+      await new Promise(resolve => setTimeout(resolve, 10))
+      const second = platformNow()
+      expect(second).toBeGreaterThan(first)
+    })
+  })
+
+  describe('platformNowDiff', () => {
+    it('should calculate the difference between timestamps', async () => {
+      const start = platformNow()
+      await new Promise(resolve => setTimeout(resolve, 50))
+      const diff = platformNowDiff(start)
+      
+      expect(diff).toBeGreaterThan(40)
+      expect(diff).toBeLessThan(100)
+    })
+
+    it('should round to 2 decimal places', async () => {
+      const start = platformNow()
+      await new Promise(resolve => setTimeout(resolve, 10))
+      const diff = platformNowDiff(start)
+      
+      // Check that it has at most 2 decimal places
+      const decimalPlaces = (diff.toString().split('.')[1] || '').length
+      expect(decimalPlaces).toBeLessThanOrEqual(2)
+    })
+
+    it('should handle very small differences', () => {
+      const start = platformNow()
+      const diff = platformNowDiff(start)
+      
+      expect(diff).toBeGreaterThanOrEqual(0)
+      expect(typeof diff).toBe('number')
+    })
+  })
+})

packages/measurements/src/__tests__/metrics.test.ts

@@ -0,0 +1,297 @@
+import {
+  newMetrics,
+  measure,
+  childMetrics,
+  metricsAggregate,
+  metricsToString,
+  metricsToJson,
+  metricsToRows,
+  updateMeasure
+} from '../metrics'
+import { platformNow } from '../index'
+
+describe('metrics', () => {
+  describe('newMetrics', () => {
+    it('should create a new metrics object with default values', () => {
+      const metrics = newMetrics()
+      
+      expect(metrics.operations).toBe(0)
+      expect(metrics.value).toBe(0)
+      expect(metrics.measurements).toEqual({})
+      expect(metrics.params).toEqual({})
+      expect(metrics.namedParams).toEqual({})
+    })
+  })
+
+  describe('measure', () => {
+    it('should measure operation duration', async () => {
+      const metrics = newMetrics()
+      const done = measure(metrics, { operation: 'test' })
+      
+      await new Promise(resolve => setTimeout(resolve, 50))
+      done()
+      
+      expect(metrics.operations).toBe(1)
+      expect(metrics.value).toBeGreaterThan(40)
+    })
+
+    it('should call endOp callback with duration', async () => {
+      const metrics = newMetrics()
+      let capturedSpend = 0
+      const done = measure(metrics, { operation: 'test' }, {}, (spend) => {
+        capturedSpend = spend
+      })
+      
+      await new Promise(resolve => setTimeout(resolve, 50))
+      done()
+      
+      expect(capturedSpend).toBeGreaterThan(40)
+    })
+
+    it('should handle multiple operations', async () => {
+      const metrics = newMetrics()
+      
+      const done1 = measure(metrics, { operation: 'test' })
+      await new Promise(resolve => setTimeout(resolve, 20))
+      done1()
+      
+      const done2 = measure(metrics, { operation: 'test' })
+      await new Promise(resolve => setTimeout(resolve, 20))
+      done2()
+      
+      expect(metrics.operations).toBe(2)
+      expect(metrics.value).toBeGreaterThan(30)
+    })
+  })
+
+  describe('updateMeasure', () => {
+    it('should update metrics with custom value', () => {
+      const metrics = newMetrics()
+      const st = platformNow()
+      
+      updateMeasure(metrics, st, { op: 'test' }, {}, undefined, 100)
+      
+      expect(metrics.operations).toBe(1)
+      expect(metrics.value).toBe(100)
+    })
+
+    it('should override operations when override is true', () => {
+      const metrics = newMetrics()
+      const st = platformNow()
+      
+      // First call without override - accumulates value and increments operations
+      updateMeasure(metrics, st, { op: 'test' }, {}, undefined, 50, false)
+      expect(metrics.value).toBe(50)
+      expect(metrics.operations).toBe(1)
+      
+      // Second call with override - sets operations, doesn't add to value
+      updateMeasure(metrics, st, { op: 'test' }, {}, undefined, 100, true)
+      
+      expect(metrics.operations).toBe(100) // overridden
+      expect(metrics.value).toBe(50) // not changed when override=true
+    })
+
+    it('should track parameters', () => {
+      const metrics = newMetrics()
+      const st = platformNow()
+      
+      updateMeasure(metrics, st, { method: 'GET' }, {}, undefined, 100)
+      updateMeasure(metrics, st, { method: 'POST' }, {}, undefined, 200)
+      
+      expect(metrics.params.method).toBeDefined()
+      expect(metrics.params.method.GET).toBeDefined()
+      expect(metrics.params.method.POST).toBeDefined()
+      expect(metrics.params.method.GET.value).toBe(100)
+      expect(metrics.params.method.POST.value).toBe(200)
+    })
+
+    it('should handle multiple parameters as counters', () => {
+      const metrics = newMetrics()
+      const st = platformNow()
+      
+      updateMeasure(metrics, st, { method: 'GET', status: '200' }, {}, undefined, 100)
+      updateMeasure(metrics, st, { method: 'GET', status: '404' }, {}, undefined, 50)
+      
+      expect(metrics.params.method.GET).toBeDefined()
+      expect(metrics.params.method.GET.topResult).toBeDefined()
+      expect(metrics.params.method.GET.topResult?.length).toBeGreaterThan(0)
+    })
+
+    it('should update top results', () => {
+      const metrics = newMetrics()
+      const st = platformNow()
+      
+      updateMeasure(metrics, st, {}, { request: 'slow' }, undefined, 100)
+      updateMeasure(metrics, st, {}, { request: 'fast' }, undefined, 10)
+      
+      expect(metrics.topResult).toBeDefined()
+      expect(metrics.topResult?.length).toBeGreaterThan(0)
+    })
+  })
+
+  describe('childMetrics', () => {
+    it('should create child metrics in hierarchy', () => {
+      const root = newMetrics()
+      const child = childMetrics(root, ['level1', 'level2'])
+      
+      expect(root.measurements.level1).toBeDefined()
+      expect(root.measurements.level1.measurements.level2).toBeDefined()
+      expect(child).toBe(root.measurements.level1.measurements.level2)
+    })
+
+    it('should reuse existing child metrics', () => {
+      const root = newMetrics()
+      const child1 = childMetrics(root, ['level1'])
+      const child2 = childMetrics(root, ['level1'])
+      
+      expect(child1).toBe(child2)
+    })
+
+    it('should create nested paths', () => {
+      const root = newMetrics()
+      childMetrics(root, ['api', 'users', 'create'])
+      
+      expect(root.measurements.api).toBeDefined()
+      expect(root.measurements.api.measurements.users).toBeDefined()
+      expect(root.measurements.api.measurements.users.measurements.create).toBeDefined()
+    })
+  })
+
+  describe('metricsAggregate', () => {
+    it('should aggregate metrics', () => {
+      const metrics = newMetrics()
+      metrics.value = 100
+      metrics.operations = 10
+      
+      const child1 = childMetrics(metrics, ['child1'])
+      child1.value = 50
+      child1.operations = 5
+      
+      const child2 = childMetrics(metrics, ['child2'])
+      child2.value = 30
+      child2.operations = 3
+      
+      const aggregated = metricsAggregate(metrics)
+      
+      expect(aggregated.value).toBe(80) // child1 + child2
+      expect(aggregated.operations).toBe(10)
+    })
+
+    it('should limit number of child metrics', () => {
+      const metrics = newMetrics()
+      
+      for (let i = 0; i < 10; i++) {
+        const child = childMetrics(metrics, [`child${i}`])
+        child.value = i * 10
+      }
+      
+      const aggregated = metricsAggregate(metrics, 3)
+      
+      expect(Object.keys(aggregated.measurements).length).toBe(3)
+    })
+
+    it('should filter out metrics starting with #', () => {
+      const metrics = newMetrics()
+      
+      const child1 = childMetrics(metrics, ['normal'])
+      child1.value = 50
+      
+      const child2 = childMetrics(metrics, ['#internal'])
+      child2.value = 30
+      
+      const aggregated = metricsAggregate(metrics)
+      
+      expect(aggregated.value).toBe(50) // only 'normal' counted
+    })
+  })
+
+  describe('metricsToString', () => {
+    it('should convert metrics to string', () => {
+      const metrics = newMetrics()
+      metrics.value = 100
+      metrics.operations = 10
+      
+      const str = metricsToString(metrics, 'TestMetrics', 50)
+      
+      expect(str).toContain('TestMetrics')
+      expect(str).toContain('100')
+      expect(str).toContain('10')
+    })
+
+    it('should include child metrics in string', () => {
+      const metrics = newMetrics()
+      const child = childMetrics(metrics, ['operation'])
+      child.value = 50
+      child.operations = 5
+      
+      const str = metricsToString(metrics, 'TestMetrics', 50)
+      
+      expect(str).toContain('operation')
+    })
+  })
+
+  describe('metricsToJson', () => {
+    it('should convert metrics to JSON', () => {
+      const metrics = newMetrics()
+      metrics.value = 100
+      metrics.operations = 10
+      
+      const json = metricsToJson(metrics)
+      
+      // aggregated value is the total value when no children
+      expect(json.$total).toBe(100)
+      expect(json.$ops).toBe(10)
+    })
+
+    it('should include child metrics in JSON', () => {
+      const metrics = newMetrics()
+      const child = childMetrics(metrics, ['operation'])
+      child.value = 50
+      child.operations = 5
+      
+      const json = metricsToJson(metrics)
+      
+      expect(json).toBeDefined()
+      const keys = Object.keys(json)
+      expect(keys.some(k => k.includes('operation'))).toBe(true)
+    })
+  })
+
+  describe('metricsToRows', () => {
+    it('should convert metrics to rows', () => {
+      const metrics = newMetrics()
+      metrics.value = 100
+      metrics.operations = 10
+      
+      const rows = metricsToRows(metrics, 'TestMetrics')
+      
+      expect(Array.isArray(rows)).toBe(true)
+      expect(rows.length).toBeGreaterThan(0)
+      expect(rows[0]).toContain('TestMetrics')
+    })
+
+    it('should include child metrics in rows', () => {
+      const metrics = newMetrics()
+      const child = childMetrics(metrics, ['operation'])
+      child.value = 50
+      child.operations = 5
+      
+      const rows = metricsToRows(metrics, 'TestMetrics')
+      
+      expect(rows.length).toBeGreaterThan(1)
+      expect(rows.some(row => row.includes('operation'))).toBe(true)
+    })
+
+    it('should properly format row values', () => {
+      const metrics = newMetrics()
+      metrics.value = 100
+      metrics.operations = 10
+      
+      const rows = metricsToRows(metrics, 'TestMetrics')
+      
+      expect(rows[0]).toHaveLength(5) // offset, name, avg, total, ops
+      expect(typeof rows[0][0]).toBe('number') // offset
+      expect(typeof rows[0][1]).toBe('string') // name
+    })
+  })
+})

packages/measurements/src/__tests__/performance.test.ts

@@ -0,0 +1,259 @@
+import { MeasureMetricsContext, NoMetricsContext } from '../context'
+import { newMetrics, metricsAggregate } from '../metrics'
+import { noParamsLogger } from '../context'
+import type { MeasureContext } from '../types'
+
+describe('performance', () => {
+  describe('overhead measurement', () => {
+    // Reduced iterations to fit within 10 seconds total test time
+    const iterations = 100
+    const depth = 5
+
+    it('should measure overhead of with() vs raw execution', async () => {
+      // Baseline: raw execution without measurement
+      const baselineStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await simulateWork(1)
+      }
+      const baselineTime = performance.now() - baselineStart
+
+      // With measurement context
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('root', {}, {}, metrics, noParamsLogger)
+      
+      const measuredStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await ctx.with('operation', { iteration: i }, async () => {
+          await simulateWork(1)
+        })
+      }
+      const measuredTime = performance.now() - measuredStart
+
+      const overhead = measuredTime - baselineTime
+      const overheadPercentage = (overhead / baselineTime) * 100
+
+      console.log(`\n📊 Overhead Analysis (${iterations} iterations):`)
+      console.log(`  Baseline time: ${baselineTime.toFixed(2)}ms`)
+      console.log(`  Measured time: ${measuredTime.toFixed(2)}ms`)
+      console.log(`  Overhead: ${overhead.toFixed(2)}ms (${overheadPercentage.toFixed(2)}%)`)
+      console.log(`  Per operation: ${(overhead / iterations).toFixed(4)}ms`)
+
+      expect(metrics.measurements.operation).toBeDefined()
+      expect(metrics.measurements.operation.operations).toBe(iterations)
+      
+      // Overhead should be reasonable (typically < 50% for simple operations)
+      // This is informational rather than a strict assertion
+      expect(overheadPercentage).toBeLessThan(200)
+    })
+
+    it('should measure overhead with deep nested contexts', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('root', {}, {}, metrics, noParamsLogger)
+
+      // Baseline: single level
+      const singleLevelStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await ctx.with('shallow', {}, async () => {
+          await simulateWork(1)
+        })
+      }
+      const singleLevelTime = performance.now() - singleLevelStart
+
+      // Deep nesting
+      const deepStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await deepNestedExecution(ctx, depth, 1)
+      }
+      const deepTime = performance.now() - deepStart
+
+      const nestingOverhead = deepTime - singleLevelTime
+      const overheadPerLevel = nestingOverhead / (iterations * depth)
+
+      console.log(`\n📊 Deep Nesting Overhead (${iterations} iterations, depth=${depth}):`)
+      console.log(`  Single level: ${singleLevelTime.toFixed(2)}ms`)
+      console.log(`  Deep nested: ${deepTime.toFixed(2)}ms`)
+      console.log(`  Nesting overhead: ${nestingOverhead.toFixed(2)}ms`)
+      console.log(`  Per level: ${overheadPerLevel.toFixed(4)}ms`)
+
+      expect(metrics.measurements.shallow).toBeDefined()
+      expect(metrics.measurements.level0).toBeDefined()
+    })
+
+    it('should measure overhead with complex parameter tracking', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('root', {}, {}, metrics, noParamsLogger)
+
+      // Simple params
+      const simpleStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await ctx.with('simple', { id: i }, async () => {
+          await simulateWork(1)
+        })
+      }
+      const simpleTime = performance.now() - simpleStart
+
+      // Complex params with multiple tracked values
+      const complexStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await ctx.with('complex', 
+          { 
+            method: i % 3 === 0 ? 'GET' : i % 3 === 1 ? 'POST' : 'PUT',
+            status: i % 2 === 0 ? 200 : 404,
+            cached: i % 4 === 0
+          }, 
+          async () => {
+            await simulateWork(1)
+          },
+          {
+            userId: `user_${i % 10}`,
+            endpoint: `/api/v1/resource/${i % 5}`,
+            timestamp: Date.now()
+          }
+        )
+      }
+      const complexTime = performance.now() - complexStart
+
+      const paramOverhead = complexTime - simpleTime
+
+      console.log(`\n📊 Parameter Tracking Overhead (${iterations} iterations):`)
+      console.log(`  Simple params: ${simpleTime.toFixed(2)}ms`)
+      console.log(`  Complex params: ${complexTime.toFixed(2)}ms`)
+      console.log(`  Param overhead: ${paramOverhead.toFixed(2)}ms`)
+      console.log(`  Per operation: ${(paramOverhead / iterations).toFixed(4)}ms`)
+
+      expect(metrics.measurements.simple).toBeDefined()
+      expect(metrics.measurements.complex).toBeDefined()
+      expect(Object.keys(metrics.measurements.complex.params).length).toBeGreaterThan(0)
+    })
+
+    it('should measure overhead with NoMetricsContext', async () => {
+      // NoMetricsContext should have minimal overhead
+      const noMetricsCtx = new NoMetricsContext(noParamsLogger)
+
+      const start = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await noMetricsCtx.with('operation', { iteration: i }, async () => {
+          await simulateWork(1)
+        })
+      }
+      const noMetricsTime = performance.now() - start
+
+      // Compare with raw execution
+      const rawStart = performance.now()
+      for (let i = 0; i < iterations; i++) {
+        await simulateWork(1)
+      }
+      const rawTime = performance.now() - rawStart
+
+      const overhead = noMetricsTime - rawTime
+      const overheadPercentage = (overhead / rawTime) * 100
+
+      console.log(`\n📊 NoMetricsContext Overhead (${iterations} iterations):`)
+      console.log(`  Raw time: ${rawTime.toFixed(2)}ms`)
+      console.log(`  NoMetrics time: ${noMetricsTime.toFixed(2)}ms`)
+      console.log(`  Overhead: ${overhead.toFixed(2)}ms (${overheadPercentage.toFixed(2)}%)`)
+
+      // NoMetricsContext should have very low overhead
+      expect(overheadPercentage).toBeLessThan(50)
+    })
+  })
+
+  describe('realistic workload simulation', () => {
+    it('should measure overhead in complex realistic scenario', async () => {
+      const metrics = newMetrics()
+      const ctx = new MeasureMetricsContext('app', { service: 'api' }, {}, metrics, noParamsLogger)
+
+      const requests = 50
+      const baselineStart = performance.now()
+      
+      // Simulate without metrics
+      for (let i = 0; i < requests; i++) {
+        await simulateAPIRequest(null, i)
+      }
+      const baselineTime = performance.now() - baselineStart
+
+      // Reset for measured run
+      const measuredStart = performance.now()
+      
+      // Simulate with metrics
+      for (let i = 0; i < requests; i++) {
+        await simulateAPIRequest(ctx, i)
+      }
+      const measuredTime = performance.now() - measuredStart
+
+      const overhead = measuredTime - baselineTime
+      const overheadPercentage = (overhead / baselineTime) * 100
+
+      console.log(`\n📊 Realistic Workload Analysis (${requests} API requests):`)
+      console.log(`  Baseline: ${baselineTime.toFixed(2)}ms`)
+      console.log(`  With metrics: ${measuredTime.toFixed(2)}ms`)
+      console.log(`  Overhead: ${overhead.toFixed(2)}ms (${overheadPercentage.toFixed(2)}%)`)
+      console.log(`  Per request: ${(overhead / requests).toFixed(4)}ms`)
+      
+      // Check metrics structure
+      const aggregated = metricsAggregate(metrics, 10)
+      console.log(`  Collected operations: ${aggregated.measurements.request?.operations || 0}`)
+
+      expect(aggregated.measurements.request).toBeDefined()
+      expect(overheadPercentage).toBeLessThan(100) // Should be less than 100% overhead
+    })
+  })
+})
+
+// Helper functions
+
+async function simulateWork(durationMs: number): Promise<void> {
+  const end = performance.now() + durationMs
+  while (performance.now() < end) {
+    // Busy wait to simulate work
+    Math.random() * Math.random()
+  }
+}
+
+async function deepNestedExecution(
+  ctx: MeasureContext,
+  depth: number,
+  workMs: number,
+  currentLevel: number = 0
+): Promise<void> {
+  if (currentLevel >= depth) {
+    await simulateWork(workMs)
+    return
+  }
+
+  await ctx.with(`level${currentLevel}`, { level: currentLevel }, async (childCtx) => {
+    await deepNestedExecution(childCtx, depth, workMs, currentLevel + 1)
+  })
+}
+
+async function simulateAPIRequest(ctx: MeasureContext | null, requestId: number): Promise<void> {
+  const method = ['GET', 'POST', 'PUT'][requestId % 3]
+  const endpoint = `/api/resource/${requestId % 10}`
+  
+  if (ctx === null) {
+    // No metrics version
+    await simulateWork(1)
+    // Simulate DB query
+    await simulateWork(2)
+    // Simulate processing
+    await simulateWork(1)
+    return
+  }
+
+  // With metrics version
+  await ctx.with('request', { method, endpoint }, async (reqCtx) => {
+    await reqCtx.with('auth', { userId: `user_${requestId % 50}` }, async () => {
+      await simulateWork(1)
+    })
+
+    await reqCtx.with('database', { query: 'SELECT' }, async (dbCtx) => {
+      await dbCtx.with('query_execution', {}, async () => {
+        await simulateWork(2)
+      })
+    })
+
+    await reqCtx.with('processing', { items: requestId % 20 }, async () => {
+      await simulateWork(1)
+    })
+  })
+}