import { MonitoringService, withToolMonitoring, withHttpMonitoring, monitoringService, type MonitoringLogger } from '../MonitoringService.js'; describe('MonitoringService', () => { // Mock logger const mockLogger: MonitoringLogger = { info: jest.fn(), warn: jest.fn(), error: jest.fn(), debug: jest.fn() }; beforeEach(() => { jest.clearAllMocks(); }); afterAll(async () => { // Shut down the singleton to stop timers and prevent Jest from hanging await monitoringService.shutdown(); }); describe('Initialization', () => { test('initializes with enabled configuration', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, // Disable for testing without GCP credentials logger: mockLogger }); const stats = service.getStats(); expect(stats.projectId).toBe('test-project'); expect(stats.enabled).toBe(false); }); test('initializes with disabled configuration', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(false); }); test('uses default configuration when not provided', () => { const service = new MonitoringService({ enabled: false, logger: mockLogger }); const stats = service.getStats(); expect(stats).toHaveProperty('enabled'); expect(stats).toHaveProperty('pendingMetrics'); expect(stats).toHaveProperty('projectId'); }); }); describe('Metric Recording (Disabled Mode)', () => { test('records latency metrics without errors when disabled', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); // Should not throw even when disabled await expect( service.recordLatency('http_request_latency', 150, { domain: 'api.example.com', operation: 'GET', status_code: '200' }) ).resolves.not.toThrow(); const stats = service.getStats(); expect(stats.pendingMetrics).toBe(0); // Disabled mode doesn't queue metrics }); test('increments counter metrics without errors when disabled', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); await expect( service.incrementCounter('tool_call_count', { tool_name: 'anthropic', operation: 'call' }) ).resolves.not.toThrow(); }); test('records gauge metrics without errors when disabled', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); await expect( service.recordGauge('active_requests', 5, { endpoint: '/mcp' }) ).resolves.not.toThrow(); }); test('never throws errors from recordMetric', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); // This should not throw even with invalid data await expect( service.recordMetric('invalid_type' as any, NaN, {}) ).resolves.not.toThrow(); }); }); describe('Helper Functions', () => { test('withToolMonitoring records latency and success', async () => { const testFn = jest.fn(); (testFn as any).mockResolvedValue({ result: 'success' }); const result = await withToolMonitoring('test-tool', 'call', testFn as any, { logger: mockLogger }); expect(result).toEqual({ result: 'success' }); expect(testFn).toHaveBeenCalled(); }); test('withToolMonitoring records errors', async () => { const testError = new Error('Test error'); const testFn = jest.fn(); (testFn as any).mockRejectedValue(testError); await expect( withToolMonitoring('test-tool', 'call', testFn as any, { logger: mockLogger }) ).rejects.toThrow('Test error'); expect(testFn).toHaveBeenCalled(); }); test('withHttpMonitoring records HTTP metrics', async () => { const testFn = jest.fn(); (testFn as any).mockResolvedValue({ status: 200 }); const getStatusCode = jest.fn(); (getStatusCode as any).mockReturnValue('200'); const result = await withHttpMonitoring( 'api.example.com', 'GET', testFn as any, getStatusCode as any, mockLogger ); expect(result).toEqual({ status: 200 }); expect(testFn).toHaveBeenCalled(); expect(getStatusCode).toHaveBeenCalled(); }); test('withHttpMonitoring handles errors', async () => { const testError = new Error('Network error'); const testFn = jest.fn(); (testFn as any).mockRejectedValue(testError); const getStatusCode = jest.fn(); (getStatusCode as any).mockReturnValue('500'); await expect( withHttpMonitoring('api.example.com', 'GET', testFn as any, getStatusCode as any, mockLogger) ).rejects.toThrow('Network error'); expect(testFn).toHaveBeenCalled(); }); }); describe('Unified Counter Metrics (Issue #3 Fix)', () => { let incrementCounterSpy: jest.SpyInstance; beforeEach(() => { // Spy on the singleton monitoringService incrementCounterSpy = jest.spyOn(monitoringService, 'incrementCounter'); }); afterEach(() => { incrementCounterSpy.mockRestore(); }); test('withToolMonitoring records success to main counter with status=success', async () => { const testFn = jest.fn().mockResolvedValue({ result: 'ok' }); await withToolMonitoring('test-tool', 'call', testFn, { logger: mockLogger }); // Should record to tool_call_count with status='success' expect(incrementCounterSpy).toHaveBeenCalledWith( 'tool_call_count', expect.objectContaining({ tool_name: 'test-tool', operation: 'call', status: 'success' }) ); }); test('withToolMonitoring records error to BOTH main counter and error metric', async () => { const testError = new Error('Test failure'); const testFn = jest.fn().mockRejectedValue(testError); await expect(withToolMonitoring('test-tool', 'call', testFn, { logger: mockLogger })) .rejects.toThrow('Test failure'); // Should record to tool_call_count with status='error' (unified counter) expect(incrementCounterSpy).toHaveBeenCalledWith( 'tool_call_count', expect.objectContaining({ tool_name: 'test-tool', operation: 'call', status: 'error', error_type: 'Error' }) ); // Should ALSO record to tool_call_errors for backward compatibility expect(incrementCounterSpy).toHaveBeenCalledWith( 'tool_call_errors', expect.objectContaining({ tool_name: 'test-tool', operation: 'call', error_type: 'Error' }) ); // Total of 2 incrementCounter calls for errors (both metrics) expect(incrementCounterSpy).toHaveBeenCalledTimes(2); }); test('withHttpMonitoring records success to main counter with status=success', async () => { const testFn = jest.fn().mockResolvedValue({ status: 200 }); const getStatusCode = jest.fn().mockReturnValue('200'); await withHttpMonitoring('api.test.com', 'GET', testFn, getStatusCode, mockLogger); // Should record to http_request_count with status='success' expect(incrementCounterSpy).toHaveBeenCalledWith( 'http_request_count', expect.objectContaining({ domain: 'api.test.com', operation: 'GET', status: 'success', status_code: '200' }) ); }); test('withHttpMonitoring records error to BOTH main counter and error metric', async () => { const testError = new Error('Network failure'); const testFn = jest.fn().mockRejectedValue(testError); const getStatusCode = jest.fn().mockReturnValue('500'); await expect(withHttpMonitoring('api.test.com', 'POST', testFn, getStatusCode, mockLogger)) .rejects.toThrow('Network failure'); // Should record to http_request_count with status='error' (unified counter) expect(incrementCounterSpy).toHaveBeenCalledWith( 'http_request_count', expect.objectContaining({ domain: 'api.test.com', operation: 'POST', status: 'error', status_code: '500' }) ); // Should ALSO record to http_request_errors for backward compatibility expect(incrementCounterSpy).toHaveBeenCalledWith( 'http_request_errors', expect.objectContaining({ domain: 'api.test.com', operation: 'POST', status_code: '500' }) ); // Total of 2 incrementCounter calls for errors (both metrics) expect(incrementCounterSpy).toHaveBeenCalledTimes(2); }); test('error metrics include error_type for debugging', async () => { class CustomError extends Error { constructor(message: string) { super(message); this.name = 'CustomError'; } } const testFn = jest.fn().mockRejectedValue(new CustomError('Custom failure')); await expect(withToolMonitoring('test-tool', 'call', testFn, { logger: mockLogger })) .rejects.toThrow('Custom failure'); // Should capture custom error type expect(incrementCounterSpy).toHaveBeenCalledWith( 'tool_call_count', expect.objectContaining({ status: 'error', error_type: 'CustomError' }) ); expect(incrementCounterSpy).toHaveBeenCalledWith( 'tool_call_errors', expect.objectContaining({ error_type: 'CustomError' }) ); }); test('unified counter enables error rate calculations', async () => { // Simulate success const successFn = jest.fn().mockResolvedValue({ ok: true }); await withToolMonitoring('api', 'call', successFn, { logger: mockLogger }); // Simulate error const errorFn = jest.fn().mockRejectedValue(new Error('Failure')); await expect(withToolMonitoring('api', 'call', errorFn, { logger: mockLogger })) .rejects.toThrow('Failure'); // Verify both success and error recorded to tool_call_count const mainCounterCalls = incrementCounterSpy.mock.calls.filter( call => call[0] === 'tool_call_count' ); expect(mainCounterCalls).toHaveLength(2); expect(mainCounterCalls[0][1]).toMatchObject({ status: 'success' }); expect(mainCounterCalls[1][1]).toMatchObject({ status: 'error' }); // This enables queries like: sum(tool_call_count{status='error'}) / sum(tool_call_count) }); }); describe('Shutdown', () => { test('handles shutdown when disabled', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); await expect(service.shutdown()).resolves.not.toThrow(); }); test('flushes pending metrics on shutdown when disabled', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); await service.recordMetric('tool_call_count', 1, { tool_name: 'test' }); await expect(service.shutdown()).resolves.not.toThrow(); }); }); describe('Stats', () => { test('returns current statistics', async () => { const service = new MonitoringService({ projectId: 'test-project-stats', enabled: false, logger: mockLogger }); await service.recordMetric('tool_call_count', 1, { tool_name: 'test1' }); await service.recordMetric('tool_call_count', 1, { tool_name: 'test2' }); const stats = service.getStats(); expect(stats).toEqual({ enabled: false, pendingMetrics: 0, // Disabled mode doesn't queue projectId: 'test-project-stats' }); }); test('returns stats when disabled', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); const stats = service.getStats(); expect(stats).toEqual({ enabled: false, pendingMetrics: 0, projectId: 'test-project' }); }); }); describe('Configuration', () => { test('respects custom write interval', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, writeInterval: 5000, logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(false); }); test('respects custom batch size', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxBatchSize: 50, logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(false); }); test('uses custom metric prefix', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, metricPrefix: 'custom.googleapis.com/my_app', logger: mockLogger }); const stats = service.getStats(); expect(stats.projectId).toBe('test-project'); }); }); describe('Async Helpers', () => { test('measureAsync records execution time', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); const testFn = jest.fn(); (testFn as any).mockResolvedValue('success'); const result = await service.measureAsync( 'tool_call_latency', { tool_name: 'test' }, testFn as any ); expect(result).toBe('success'); expect(testFn).toHaveBeenCalled(); }); test('measureAsync records errors', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); const testError = new Error('Test error'); const testFn = jest.fn(); (testFn as any).mockRejectedValue(testError); await expect( service.measureAsync('tool_call_latency', { tool_name: 'test' }, testFn as any) ).rejects.toThrow('Test error'); expect(testFn).toHaveBeenCalled(); }); test('measure records sync execution time', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); const testFn = jest.fn(); (testFn as any).mockReturnValue('success'); const result = service.measure( 'tool_call_latency', { tool_name: 'test' }, testFn as any ); expect(result).toBe('success'); expect(testFn).toHaveBeenCalled(); }); test('measure records sync errors', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); const testError = new Error('Test error'); const testFn = jest.fn(); (testFn as any).mockImplementation(() => { throw testError; }); expect(() => service.measure('tool_call_latency', { tool_name: 'test' }, testFn as any) ).toThrow('Test error'); expect(testFn).toHaveBeenCalled(); }); }); describe('ADC Detection', () => { let originalEnv: NodeJS.ProcessEnv; beforeEach(() => { // Save original environment originalEnv = { ...process.env }; }); afterEach(() => { // Restore original environment process.env = originalEnv; }); test('detects GOOGLE_APPLICATION_CREDENTIALS', () => { process.env.GOOGLE_APPLICATION_CREDENTIALS = '/path/to/key.json'; delete process.env.GOOGLE_CLOUD_PROJECT; delete process.env.K_SERVICE; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(true); }); test('detects GOOGLE_CLOUD_PROJECT (Cloud Run Workload Identity)', () => { delete process.env.GOOGLE_APPLICATION_CREDENTIALS; process.env.GOOGLE_CLOUD_PROJECT = 'my-project'; delete process.env.K_SERVICE; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(true); }); test('detects K_SERVICE (Cloud Run environment)', () => { delete process.env.GOOGLE_APPLICATION_CREDENTIALS; delete process.env.GOOGLE_CLOUD_PROJECT; process.env.K_SERVICE = 'my-cloud-run-service'; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(true); }); test('detects GCP_PROJECT (alternative environment variable)', () => { delete process.env.GOOGLE_APPLICATION_CREDENTIALS; delete process.env.GOOGLE_CLOUD_PROJECT; delete process.env.K_SERVICE; process.env.GCP_PROJECT = 'my-project'; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(true); }); test('detects KUBERNETES_SERVICE_HOST (GKE environment)', () => { delete process.env.GOOGLE_APPLICATION_CREDENTIALS; delete process.env.GOOGLE_CLOUD_PROJECT; delete process.env.K_SERVICE; delete process.env.GCP_PROJECT; process.env.KUBERNETES_SERVICE_HOST = '10.0.0.1'; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(true); }); test('disables when no ADC detected', () => { delete process.env.GOOGLE_APPLICATION_CREDENTIALS; delete process.env.GOOGLE_CLOUD_PROJECT; delete process.env.K_SERVICE; delete process.env.GCP_PROJECT; delete process.env.KUBERNETES_SERVICE_HOST; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(false); }); test('explicit enabled config overrides ADC detection', () => { delete process.env.GOOGLE_APPLICATION_CREDENTIALS; delete process.env.GOOGLE_CLOUD_PROJECT; delete process.env.K_SERVICE; // Explicitly enable even without ADC const service = new MonitoringService({ enabled: true, logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(true); }); test('explicit disabled config overrides ADC detection', () => { process.env.GOOGLE_APPLICATION_CREDENTIALS = '/path/to/key.json'; // Explicitly disable even with ADC const service = new MonitoringService({ enabled: false, logger: mockLogger }); const stats = service.getStats(); expect(stats.enabled).toBe(false); }); test('uses GOOGLE_CLOUD_PROJECT for projectId when available', () => { process.env.GOOGLE_CLOUD_PROJECT = 'my-gcp-project'; delete process.env.GCP_PROJECT_ID; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.projectId).toBe('my-gcp-project'); }); test('prefers GCP_PROJECT_ID over GOOGLE_CLOUD_PROJECT for projectId', () => { process.env.GCP_PROJECT_ID = 'preferred-project'; process.env.GOOGLE_CLOUD_PROJECT = 'fallback-project'; const service = new MonitoringService({ logger: mockLogger }); const stats = service.getStats(); expect(stats.projectId).toBe('preferred-project'); }); }); describe('Retry Logic', () => { test('supports custom maxRetries configuration', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxRetries: 5, logger: mockLogger }); // Configuration is private, but we can verify it works through behavior expect(service).toBeInstanceOf(MonitoringService); }); test('supports custom retryDelay configuration', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, retryDelay: 500, logger: mockLogger }); expect(service).toBeInstanceOf(MonitoringService); }); test('default maxRetries is 3', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); // Verify service can be created with defaults expect(service.getStats()).toHaveProperty('enabled'); }); test('default retryDelay is 1000ms', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); expect(service.getStats()).toHaveProperty('enabled'); }); }); describe('Duplicate Timestamp Prevention', () => { test('roundTimestampToBucket rounds to nearest second by default', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); // Test rounding down const timestamp1 = new Date('2025-11-20T07:10:31.584Z'); const rounded1 = (service as any).roundTimestampToBucket(timestamp1); expect(rounded1.getTime()).toBe(new Date('2025-11-20T07:10:31.000Z').getTime()); // Test rounding down again (within same second) const timestamp2 = new Date('2025-11-20T07:10:31.939Z'); const rounded2 = (service as any).roundTimestampToBucket(timestamp2); expect(rounded2.getTime()).toBe(new Date('2025-11-20T07:10:31.000Z').getTime()); // Verify both round to the same bucket expect(rounded1.getTime()).toBe(rounded2.getTime()); }); test('roundTimestampToBucket respects custom sampling period', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, minSamplingPeriodMs: 5000, // 5 seconds logger: mockLogger }); const timestamp1 = new Date('2025-11-20T07:10:31.584Z'); const rounded1 = (service as any).roundTimestampToBucket(timestamp1); // Should round to nearest 5-second bucket expect(rounded1.getTime()).toBe(new Date('2025-11-20T07:10:30.000Z').getTime()); const timestamp2 = new Date('2025-11-20T07:10:33.939Z'); const rounded2 = (service as any).roundTimestampToBucket(timestamp2); // Both should round to same 5-second bucket expect(rounded2.getTime()).toBe(new Date('2025-11-20T07:10:30.000Z').getTime()); expect(rounded1.getTime()).toBe(rounded2.getTime()); }); test('aggregates metrics with timestamps within same sampling period', async () => { const mockClient = { projectPath: jest.fn().mockReturnValue('projects/test-project'), createTimeSeries: jest.fn().mockResolvedValue({}), close: jest.fn().mockResolvedValue(undefined) }; const service = new MonitoringService({ projectId: 'test-project', enabled: true, minSamplingPeriodMs: 1000, logger: mockLogger }); // Override client and mark as initialized (service as any).client = mockClient; (service as any).initialized = true; // Use fixed timestamp to ensure all metrics fall in the same second bucket // This matches the actual error case: 23:09:31.584 and 23:09:31.939 const baseTime = new Date('2025-11-20T07:10:31.000Z').getTime(); const metrics = [ { type: 'tool_call_count' as const, value: 1, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date(baseTime + 584) }, // 31.584 { type: 'tool_call_count' as const, value: 1, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date(baseTime + 939) }, // 31.939 { type: 'tool_call_count' as const, value: 1, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date(baseTime + 200) } // 31.200 ]; // Add metrics to pending queue directly for (const metric of metrics) { (service as any).pendingMetrics.push(metric); } expect((service as any).pendingMetrics.length).toBe(3); // Flush should aggregate them into one await service.flushMetrics(); // Pending metrics should be cleared after flush expect((service as any).pendingMetrics.length).toBe(0); // Should have called createTimeSeries with aggregated metric expect(mockClient.createTimeSeries).toHaveBeenCalledTimes(1); // Verify the aggregated value const call = mockClient.createTimeSeries.mock.calls[0][0]; expect(call.timeSeries).toHaveLength(1); expect(call.timeSeries[0].points[0].value.doubleValue).toBe(3); // Sum of 1+1+1 }); test('aggregates values correctly for cumulative metrics', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, minSamplingPeriodMs: 1000, logger: mockLogger }); // Verify that tool_call_count is a cumulative metric const metricKind = (service as any).getMetricKind('tool_call_count'); expect(metricKind).toBe('CUMULATIVE'); }); test('does NOT aggregate distribution metrics - keeps first value', async () => { const mockClient = { projectPath: jest.fn().mockReturnValue('projects/test-project'), createTimeSeries: jest.fn().mockResolvedValue({}), close: jest.fn().mockResolvedValue(undefined) }; const service = new MonitoringService({ projectId: 'test-project', enabled: true, minSamplingPeriodMs: 1000, logger: mockLogger }); (service as any).client = mockClient; (service as any).initialized = true; // Use fixed timestamp - all in same bucket const baseTime = new Date('2025-11-20T07:10:31.000Z').getTime(); const metrics = [ { type: 'tool_call_latency' as const, value: 100, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date(baseTime + 200) }, // First: 100ms { type: 'tool_call_latency' as const, value: 250, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date(baseTime + 584) }, // Second: 250ms { type: 'tool_call_latency' as const, value: 500, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date(baseTime + 939) } // Third: 500ms ]; for (const metric of metrics) { (service as any).pendingMetrics.push(metric); } await service.flushMetrics(); expect(mockClient.createTimeSeries).toHaveBeenCalledTimes(1); const call = mockClient.createTimeSeries.mock.calls[0][0]; expect(call.timeSeries).toHaveLength(1); // Should keep the FIRST distribution value (100ms), not sum or use latest const distributionValue = call.timeSeries[0].points[0].value.distributionValue; expect(distributionValue.mean).toBe(100); // First value, not 250 or 500 expect(distributionValue.count).toBe(1); // Single observation }); test('aggregates gauge metrics using LATEST value', async () => { const mockClient = { projectPath: jest.fn().mockReturnValue('projects/test-project'), createTimeSeries: jest.fn().mockResolvedValue({}), close: jest.fn().mockResolvedValue(undefined) }; const service = new MonitoringService({ projectId: 'test-project', enabled: true, minSamplingPeriodMs: 1000, logger: mockLogger }); (service as any).client = mockClient; (service as any).initialized = true; // Use fixed timestamp - all in same bucket const baseTime = new Date('2025-11-20T07:10:31.000Z').getTime(); const metrics = [ { type: 'active_requests' as const, value: 5, labels: { endpoint: '/mcp' }, timestamp: new Date(baseTime + 200) }, // First: 5 { type: 'active_requests' as const, value: 12, labels: { endpoint: '/mcp' }, timestamp: new Date(baseTime + 584) }, // Second: 12 { type: 'active_requests' as const, value: 8, labels: { endpoint: '/mcp' }, timestamp: new Date(baseTime + 939) } // Latest: 8 ]; for (const metric of metrics) { (service as any).pendingMetrics.push(metric); } await service.flushMetrics(); expect(mockClient.createTimeSeries).toHaveBeenCalledTimes(1); const call = mockClient.createTimeSeries.mock.calls[0][0]; expect(call.timeSeries).toHaveLength(1); // Should use the LATEST value (timestamp 939), not sum or first expect(call.timeSeries[0].points[0].value.doubleValue).toBe(8); // Latest, not 5 or 12 or sum(25) }); test('does not aggregate metrics with different labels', async () => { const mockClient = { projectPath: jest.fn().mockReturnValue('projects/test-project'), createTimeSeries: jest.fn().mockResolvedValue({}), close: jest.fn().mockResolvedValue(undefined) }; const service = new MonitoringService({ projectId: 'test-project', enabled: true, minSamplingPeriodMs: 1000, logger: mockLogger }); // Override client and mark as initialized (service as any).client = mockClient; (service as any).initialized = true; const baseTime = Date.now(); const metrics = [ { type: 'tool_call_count' as const, value: 1, labels: { tool_name: 'test1', status: 'success' }, timestamp: new Date(baseTime) }, { type: 'tool_call_count' as const, value: 1, labels: { tool_name: 'test2', status: 'success' }, timestamp: new Date(baseTime + 100) } ]; for (const metric of metrics) { (service as any).pendingMetrics.push(metric); } expect((service as any).pendingMetrics.length).toBe(2); await service.flushMetrics(); // Pending metrics should be cleared expect((service as any).pendingMetrics.length).toBe(0); // Should have called createTimeSeries expect(mockClient.createTimeSeries).toHaveBeenCalledTimes(1); // Verify we have 2 separate timeSeries (different labels) const call = mockClient.createTimeSeries.mock.calls[0][0]; expect(call.timeSeries).toHaveLength(2); expect(call.timeSeries[0].points[0].value.doubleValue).toBe(1); expect(call.timeSeries[1].points[0].value.doubleValue).toBe(1); }); test('handles INVALID_ARGUMENT errors gracefully without crashing', async () => { const mockClient = { projectPath: jest.fn().mockReturnValue('projects/test-project'), createTimeSeries: jest.fn().mockRejectedValue( Object.assign(new Error('3 INVALID_ARGUMENT: One or more TimeSeries could not be written: written more frequently than the maximum sampling period'), { code: 3 }) ), close: jest.fn().mockResolvedValue(undefined) }; const service = new MonitoringService({ projectId: 'test-project', enabled: true, logger: mockLogger }); // Override the client (service as any).client = mockClient; (service as any).initialized = true; // Add a metric (service as any).pendingMetrics.push({ type: 'tool_call_count', value: 1, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date() }); // Should not throw await expect(service.flushMetrics()).resolves.not.toThrow(); // Should log a warning (not an error) for duplicate timestamp issues expect(mockLogger.warn).toHaveBeenCalledWith( 'Monitoring flush skipped duplicate timestamps', expect.objectContaining({ errorCode: 3, metricsCount: 1, hint: expect.any(String) }) ); // Should NOT log an error for this specific case expect(mockLogger.error).not.toHaveBeenCalled(); }); test('logs full error details for non-duplicate-timestamp failures', async () => { const mockClient = { projectPath: jest.fn().mockReturnValue('projects/test-project'), createTimeSeries: jest.fn().mockRejectedValue( Object.assign(new Error('Permission denied'), { code: 7 }) ), close: jest.fn().mockResolvedValue(undefined) }; const service = new MonitoringService({ projectId: 'test-project', enabled: true, logger: mockLogger }); (service as any).client = mockClient; (service as any).initialized = true; (service as any).pendingMetrics.push({ type: 'tool_call_count', value: 1, labels: { tool_name: 'test', status: 'success' }, timestamp: new Date() }); await service.flushMetrics(); // Should log an error (not a warning) for other failures expect(mockLogger.error).toHaveBeenCalledWith( 'Failed to flush metrics to Google Cloud Monitoring', expect.objectContaining({ errorMessage: 'Permission denied', errorCode: 7 }) ); // Should NOT log a warning for non-duplicate errors expect(mockLogger.warn).not.toHaveBeenCalledWith( 'Monitoring flush skipped duplicate timestamps', expect.anything() ); }); }); describe('Clock Skew Handling', () => { test('default maxClockSkewMs is 15 minutes (900000ms)', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, logger: mockLogger }); // Verify service can be created with defaults expect(service).toBeInstanceOf(MonitoringService); }); test('supports custom maxClockSkewMs configuration', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 600000, // 10 minutes logger: mockLogger }); expect(service).toBeInstanceOf(MonitoringService); }); test('adjusts timestamps that are too far in the future', async () => { // Use a real Date object to avoid timing issues const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 60000, // 1 minute for easier testing logger: mockLogger }); // Record a metric with a timestamp 10 minutes in the future const futureTimestamp = new Date(Date.now() + 10 * 60 * 1000); // Use reflection to access private method for testing const adjustTimestamp = (service as any).adjustTimestampForClockSkew.bind(service); const adjusted = adjustTimestamp(futureTimestamp); // Adjusted timestamp should be within the allowed skew (1 minute) const now = Date.now(); const skew = adjusted.getTime() - now; expect(skew).toBeLessThanOrEqual(60000); // Within 1 minute expect(skew).toBeGreaterThanOrEqual(0); // Not in the past }); test('adjusts any future timestamp to now', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 60000, // 1 minute logger: mockLogger }); // Create a timestamp 30 seconds in the future const beforeAdjust = Date.now(); const nearFutureTimestamp = new Date(beforeAdjust + 30000); const adjustTimestamp = (service as any).adjustTimestampForClockSkew.bind(service); const adjusted = adjustTimestamp(nearFutureTimestamp); // Should be adjusted to approximately "now" (within 100ms tolerance) const afterAdjust = Date.now(); expect(adjusted.getTime()).toBeGreaterThanOrEqual(beforeAdjust); expect(adjusted.getTime()).toBeLessThanOrEqual(afterAdjust + 100); }); test('does not adjust past timestamps', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 60000, logger: mockLogger }); // Create a timestamp 1 minute in the past const pastTimestamp = new Date(Date.now() - 60000); const adjustTimestamp = (service as any).adjustTimestampForClockSkew.bind(service); const adjusted = adjustTimestamp(pastTimestamp); // Should return the same timestamp expect(adjusted.getTime()).toBe(pastTimestamp.getTime()); }); test('logs debug message when significant clock skew detected', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 60000, // 1 minute logger: mockLogger }); // Create a timestamp far in the future (>10 seconds to trigger logging) const futureTimestamp = new Date(Date.now() + 10 * 60 * 1000); const adjustTimestamp = (service as any).adjustTimestampForClockSkew.bind(service); adjustTimestamp(futureTimestamp); // Wait for async logging to complete await new Promise(resolve => setImmediate(resolve)); // Verify debug message was logged expect(mockLogger.debug).toHaveBeenCalledWith( 'Clock skew detected: future timestamp adjusted to now', expect.objectContaining({ skewSeconds: expect.any(Number), hint: 'System clock may be ahead - metrics timestamps normalized to GCP server time' }) ); }); test('does not log when timestamp is not adjusted', async () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 60000, logger: mockLogger }); // Create a timestamp within the allowed range const validTimestamp = new Date(Date.now() + 30000); const adjustTimestamp = (service as any).adjustTimestampForClockSkew.bind(service); adjustTimestamp(validTimestamp); // Wait for potential async logging await new Promise(resolve => setImmediate(resolve)); // Verify warning was NOT logged for valid timestamps expect(mockLogger.warn).not.toHaveBeenCalledWith( 'Clock skew detected: timestamp adjusted to prevent GCP rejection', expect.anything() ); }); test('logging is async and does not block timestamp adjustment', () => { const service = new MonitoringService({ projectId: 'test-project', enabled: false, maxClockSkewMs: 60000, logger: mockLogger }); const futureTimestamp = new Date(Date.now() + 10 * 60 * 1000); const startTime = Date.now(); const adjustTimestamp = (service as any).adjustTimestampForClockSkew.bind(service); const adjusted = adjustTimestamp(futureTimestamp); const endTime = Date.now(); // Adjustment should complete in less than 10ms (async logging doesn't block) expect(endTime - startTime).toBeLessThan(10); // Timestamp should be adjusted correctly expect(adjusted.getTime()).toBeLessThanOrEqual(Date.now() + 60000); }); }); });