diff --git a/src/util/diplomat.ts b/src/util/diplomat.ts index bfecb4b..a41108b 100644 --- a/src/util/diplomat.ts +++ b/src/util/diplomat.ts @@ -4,6 +4,23 @@ import { rootLogger } from './logger'; const logger = rootLogger.child({ source: 'diplomat-sdk' }); +const FALLBACK_WARN_TTL_MS = 5 * 60 * 1000; +const fallbackWarnLastFiredAt = new Map(); + +function shouldWarnForFallback(installId: string): boolean { + const now = Date.now(); + const lastFiredAt = fallbackWarnLastFiredAt.get(installId); + if (lastFiredAt !== undefined && now - lastFiredAt < FALLBACK_WARN_TTL_MS) { + return false; + } + fallbackWarnLastFiredAt.set(installId, now); + return true; +} + +export function resetDiplomatFallbackWarnCacheForTesting(): void { + fallbackWarnLastFiredAt.clear(); +} + /** * Diplomat Latest Response Format (current) */ @@ -65,9 +82,7 @@ export function isDiplomatV1Response(response: DiplomatServerResponse): response /** * Type guard to check if response is Latest format */ -export function isDiplomatLatestResponse( - response: DiplomatServerResponse, -): response is DiplomatServerResponseLatest { +export function isDiplomatLatestResponse(response: DiplomatServerResponse): response is DiplomatServerResponseLatest { return 'status' in response && 'headers' in response && 'body' in response; } @@ -131,23 +146,25 @@ export async function getDiplomatClientInstall(installId?: string): Promise = { + install_id: installId, + diplomat_version: diplomatVersion, + diplomat_server_url: serverUrl, + }; if (axios.isAxiosError(err)) { - logger.warn('Diplomat server check failed - falling back to direct routing', { - install_id: installId, - diplomat_version: diplomatVersion, - diplomat_server_url: serverUrl, - status_code: err.response?.status, - error_message: err.message, - error_code: err.code, - }); + baseMetadata.status_code = err.response?.status; + baseMetadata.error_message = err.message; + baseMetadata.error_code = err.code; } else { - logger.warn('Diplomat server check failed - falling back to direct routing', { - install_id: installId, - diplomat_version: diplomatVersion, - diplomat_server_url: serverUrl, - error_message: err instanceof Error ? err.message : String(err), - }); + baseMetadata.error_message = err instanceof Error ? err.message : String(err); + } + + logger.debug('Diplomat server check failed - falling back to direct routing', baseMetadata); + if (shouldWarnForFallback(installId)) { + logger.warn('Diplomat server check failed - falling back to direct routing', baseMetadata); } return null; diff --git a/test/util/diplomat.test.ts b/test/util/diplomat.test.ts new file mode 100644 index 0000000..5b2cb00 --- /dev/null +++ b/test/util/diplomat.test.ts @@ -0,0 +1,95 @@ +import axios from 'axios'; +import { resetDiplomatFallbackWarnCacheForTesting, getDiplomatClientInstall } from '../../src/util/diplomat'; + +jest.mock('axios'); +const mockedAxios = axios as jest.Mocked; + +const MS_PER_MINUTE = 60 * 1000; +const FALLBACK_MESSAGE = 'Diplomat server check failed - falling back to direct routing'; + +type LoggedEntry = { level: string; message: string; install_id?: string }; + +function parseLogged(spy: jest.SpyInstance): LoggedEntry[] { + return spy.mock.calls + .map((args) => { + try { + return JSON.parse(args[0] as string) as LoggedEntry; + } catch { + return null; + } + }) + .filter((entry): entry is LoggedEntry => entry !== null); +} + +describe('getDiplomatClientInstall — fallback log behavior', () => { + let consoleLogSpy: jest.SpyInstance; + let consoleWarnSpy: jest.SpyInstance; + let dateNowSpy: jest.SpyInstance; + let now: number; + + beforeEach(() => { + process.env.DIPLOMAT_SERVER_URL = 'https://diplomat.example.com'; + process.env.DIPLOMAT_SERVER_AUTH_USERNAME = 'user'; + process.env.DIPLOMAT_SERVER_AUTH_PASSWORD = 'pass'; + + resetDiplomatFallbackWarnCacheForTesting(); + + consoleLogSpy = jest.spyOn(console, 'log').mockImplementation(() => {}); + consoleWarnSpy = jest.spyOn(console, 'warn').mockImplementation(() => {}); + + now = 1_000_000_000_000; + dateNowSpy = jest.spyOn(Date, 'now').mockImplementation(() => now); + + mockedAxios.create.mockReturnValue({ + get: jest.fn().mockRejectedValue(Object.assign(new Error('boom'), { isAxiosError: true, code: 'ECONNREFUSED' })), + } as unknown as ReturnType); + (mockedAxios.isAxiosError as unknown as jest.Mock).mockImplementation( + (err: unknown) => !!(err && (err as { isAxiosError?: boolean }).isAxiosError), + ); + }); + + afterEach(() => { + consoleLogSpy.mockRestore(); + consoleWarnSpy.mockRestore(); + dateNowSpy.mockRestore(); + }); + + it('logs debug on every fallback and warns only once per installId within 5 minutes', async () => { + await getDiplomatClientInstall('install-1'); + await getDiplomatClientInstall('install-1'); + await getDiplomatClientInstall('install-1'); + + const debugs = parseLogged(consoleLogSpy).filter((e) => e.message === FALLBACK_MESSAGE && e.level === 'debug'); + const warns = parseLogged(consoleWarnSpy).filter((e) => e.message === FALLBACK_MESSAGE); + expect(debugs).toHaveLength(3); + expect(warns).toHaveLength(1); + expect(warns[0].install_id).toBe('install-1'); + }); + + it('warns again for the same installId after the 5-minute window', async () => { + await getDiplomatClientInstall('install-1'); + let warns = parseLogged(consoleWarnSpy).filter((e) => e.message === FALLBACK_MESSAGE); + expect(warns).toHaveLength(1); + + now += 4 * MS_PER_MINUTE + 59_000; + await getDiplomatClientInstall('install-1'); + warns = parseLogged(consoleWarnSpy).filter((e) => e.message === FALLBACK_MESSAGE); + expect(warns).toHaveLength(1); + + now += 2_000; + await getDiplomatClientInstall('install-1'); + warns = parseLogged(consoleWarnSpy).filter((e) => e.message === FALLBACK_MESSAGE); + expect(warns).toHaveLength(2); + }); + + it('warns independently per installId', async () => { + await getDiplomatClientInstall('install-1'); + await getDiplomatClientInstall('install-2'); + await getDiplomatClientInstall('install-1'); + await getDiplomatClientInstall('install-2'); + + const warns = parseLogged(consoleWarnSpy).filter((e) => e.message === FALLBACK_MESSAGE); + expect(warns).toHaveLength(2); + expect(warns.map((w) => w.install_id).sort()).toEqual(['install-1', 'install-2']); + }); +});