From 9700a935d348f25295f126beec67a5cf80f4a1c5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E2=80=9Ccaneryy=E2=80=9D?= Date: Tue, 28 Jul 2026 13:24:57 +0300 Subject: [PATCH] feat(horizon): add structured logging for outbound API calls --- src/clients/horizon.client.ts | 24 +++++ src/utils/horizon-api.utils.test.ts | 131 ++++++++++++++++++++++++++++ src/utils/horizon-api.utils.ts | 92 +++++++++++++++++++ 3 files changed, 247 insertions(+) create mode 100644 src/clients/horizon.client.ts create mode 100644 src/utils/horizon-api.utils.test.ts create mode 100644 src/utils/horizon-api.utils.ts diff --git a/src/clients/horizon.client.ts b/src/clients/horizon.client.ts new file mode 100644 index 0000000..7a98489 --- /dev/null +++ b/src/clients/horizon.client.ts @@ -0,0 +1,24 @@ +import { + horizonRequest, + type HorizonRequestInit, +} from '../utils/horizon-api.utils'; + +/** + * Horizon HTTP client. All outbound Horizon traffic must go through these helpers + * so structured request logging is applied consistently. + */ +export async function horizonGet( + endpoint: string, + init: Omit = {} +): Promise { + return horizonRequest(endpoint, { ...init, method: 'GET' }); +} + +export async function horizonPost( + endpoint: string, + init: Omit = {} +): Promise { + return horizonRequest(endpoint, { ...init, method: 'POST' }); +} + +export { horizonRequest }; diff --git a/src/utils/horizon-api.utils.test.ts b/src/utils/horizon-api.utils.test.ts new file mode 100644 index 0000000..a35dc0f --- /dev/null +++ b/src/utils/horizon-api.utils.test.ts @@ -0,0 +1,131 @@ +// Unit tests for #681 — structured logs for outbound Horizon API calls. + +import { + horizonRequest, + normalizeHorizonEndpoint, +} from './horizon-api.utils'; +import { logger } from './logger.utils'; +import { RpcTimeoutError, withRpcTimeout } from './rpc-timeout.utils'; + +jest.mock('./logger.utils', () => ({ + logger: { + info: jest.fn(), + warn: jest.fn(), + error: jest.fn(), + debug: jest.fn(), + }, +})); + +jest.mock('./rpc-timeout.utils', () => { + const actual = jest.requireActual('./rpc-timeout.utils'); + return { + ...actual, + withRpcTimeout: jest.fn( + (_operation: string, fn: () => Promise) => fn() + ), + }; +}); + +const mockLogger = logger as unknown as { + info: jest.Mock; + warn: jest.Mock; +}; + +const mockWithRpcTimeout = withRpcTimeout as jest.MockedFunction< + typeof withRpcTimeout +>; + +describe('#681 Horizon API structured logging', () => { + beforeEach(() => { + jest.clearAllMocks(); + mockWithRpcTimeout.mockImplementation((_op, fn) => fn()); + }); + + describe('normalizeHorizonEndpoint', () => { + it('keeps path-only endpoints', () => { + expect(normalizeHorizonEndpoint('/ledgers?order=desc')).toBe( + '/ledgers?order=desc' + ); + }); + + it('strips the origin from absolute URLs', () => { + expect( + normalizeHorizonEndpoint( + 'https://horizon-testnet.stellar.org/accounts/GABC' + ) + ).toBe('/accounts/GABC'); + }); + }); + + it('emits info log with all five fields after a completed Horizon call', async () => { + const mockResponse = { status: 200 } as Response; + global.fetch = jest.fn().mockResolvedValue(mockResponse); + + await horizonRequest('/ledgers?order=desc&limit=1', { + method: 'GET', + headers: { Authorization: 'Bearer secret-token' }, + }); + + expect(mockLogger.info).toHaveBeenCalledTimes(1); + const [fields] = mockLogger.info.mock.calls[0]; + expect(fields).toMatchObject({ + horizon_endpoint: '/ledgers?order=desc&limit=1', + method: 'GET', + status_code: 200, + }); + expect(fields.response_time_ms).toEqual(expect.any(Number)); + expect(fields.response_time_ms).toBeGreaterThanOrEqual(0); + expect(fields.called_at).toEqual(expect.any(String)); + expect(() => new Date(fields.called_at).toISOString()).not.toThrow(); + expect(JSON.stringify(fields)).not.toContain('secret-token'); + expect(JSON.stringify(fields)).not.toContain('Authorization'); + }); + + it('does not include request body in log fields', async () => { + global.fetch = jest.fn().mockResolvedValue({ status: 201 } as Response); + + await horizonRequest('/transactions', { + method: 'POST', + body: '{"sensitive":"payload"}', + }); + + const [fields] = mockLogger.info.mock.calls[0]; + expect(JSON.stringify(fields)).not.toContain('sensitive'); + expect(JSON.stringify(fields)).not.toContain('payload'); + }); + + it('emits warn log with timed_out and no status_code on timeout', async () => { + mockWithRpcTimeout.mockImplementation(() => + Promise.reject(new RpcTimeoutError('horizon:GET:/ledgers', 50)) + ); + + await expect(horizonRequest('/ledgers')).rejects.toBeInstanceOf( + RpcTimeoutError + ); + + expect(mockLogger.warn).toHaveBeenCalledTimes(1); + expect(mockLogger.info).not.toHaveBeenCalled(); + const [fields] = mockLogger.warn.mock.calls[0]; + expect(fields).toMatchObject({ + horizon_endpoint: '/ledgers', + method: 'GET', + timed_out: true, + }); + expect(fields).not.toHaveProperty('status_code'); + expect(fields.response_time_ms).toBeGreaterThanOrEqual(0); + expect(fields.called_at).toEqual(expect.any(String)); + }); + + it('does not emit timeout warn log for non-timeout failures', async () => { + mockWithRpcTimeout.mockImplementation(() => + Promise.reject(new Error('network down')) + ); + + await expect(horizonRequest('/accounts/GABC')).rejects.toThrow( + 'network down' + ); + + expect(mockLogger.warn).not.toHaveBeenCalled(); + expect(mockLogger.info).not.toHaveBeenCalled(); + }); +}); diff --git a/src/utils/horizon-api.utils.ts b/src/utils/horizon-api.utils.ts new file mode 100644 index 0000000..1f6060f --- /dev/null +++ b/src/utils/horizon-api.utils.ts @@ -0,0 +1,92 @@ +import { envConfig } from '../config'; +import { formatIsoTimestamp } from './iso-timestamp.utils'; +import { logger } from './logger.utils'; +import { elapsedMs, startTimer } from './monotonic-clock.utils'; +import { RpcTimeoutError, withRpcTimeout } from './rpc-timeout.utils'; + +export type HorizonHttpMethod = 'GET' | 'POST' | 'PUT' | 'DELETE' | 'HEAD'; + +export interface HorizonRequestInit { + method?: HorizonHttpMethod; + headers?: Record; + body?: string; + timeoutMs?: number; +} + +/** + * Normalises a Horizon path for logging (pathname + query, no origin). + */ +export function normalizeHorizonEndpoint(endpoint: string): string { + if (endpoint.startsWith('http://') || endpoint.startsWith('https://')) { + const url = new URL(endpoint); + return `${url.pathname}${url.search}`; + } + return endpoint.startsWith('/') ? endpoint : `/${endpoint}`; +} + +function buildHorizonUrl(endpoint: string): string { + const path = normalizeHorizonEndpoint(endpoint); + const base = envConfig.STELLAR_HORIZON_URL.replace(/\/$/, ''); + return `${base}${path}`; +} + +function nonNegativeResponseTimeMs(timer: ReturnType): number { + return Math.max(0, Math.round(elapsedMs(timer))); +} + +/** + * Performs an outbound Horizon API request and emits structured logs after the + * response is received. Request bodies and authorization headers are never logged. + */ +export async function horizonRequest( + endpoint: string, + init: HorizonRequestInit = {} +): Promise { + const method = init.method ?? 'GET'; + const horizonEndpoint = normalizeHorizonEndpoint(endpoint); + const calledAt = formatIsoTimestamp(new Date()); + const timer = startTimer(); + const url = buildHorizonUrl(endpoint); + + const doFetch = () => + fetch(url, { + method, + headers: init.headers, + body: init.body, + }); + + try { + const response = await withRpcTimeout( + `horizon:${method}:${horizonEndpoint}`, + doFetch, + init.timeoutMs + ); + + logger.info( + { + horizon_endpoint: horizonEndpoint, + method, + status_code: response.status, + response_time_ms: nonNegativeResponseTimeMs(timer), + called_at: calledAt, + }, + 'Horizon API call completed' + ); + + return response; + } catch (err) { + if (err instanceof RpcTimeoutError) { + logger.warn( + { + horizon_endpoint: horizonEndpoint, + method, + response_time_ms: nonNegativeResponseTimeMs(timer), + called_at: calledAt, + timed_out: true, + }, + 'Horizon API call timed out' + ); + } + throw err; + } +}