diff --git a/docs/x402-and-rate-limiting.md b/docs/x402-and-rate-limiting.md index c87f09680..d9c0e13c8 100644 --- a/docs/x402-and-rate-limiting.md +++ b/docs/x402-and-rate-limiting.md @@ -12,6 +12,7 @@ traffic management and content monetization. - [x402 Payment Protocol Deep Dive](#x402-payment-protocol-deep-dive) - [Integration Topics](#integration-topics) - [Reference](#reference) +- [Metrics](#metrics) - [Troubleshooting](#troubleshooting) - [Examples](#examples) @@ -2033,6 +2034,53 @@ curl -X POST \ -d '{"tokens": 1000000, "tokenType": "paid"}' ``` +## Metrics + +Payment attempts are counted at `/ar-io/__gateway_metrics`: + +| Metric | Labels | Meaning | +| --- | --- | --- | +| `x402_payment_total` | `outcome`, `target` | Payment attempts by the stage that ended them | +| `x402_payment_settled_usdc_total` | `target` | USDC actually settled (atomic units converted; USDC has 6 decimals) | + +`outcome` values: `no_payment_header`, `invalid_target`, `missing_host`, +`verify_failed`, `unsupported_processor`, `unsupported_payload`, +`settle_failed`, `topup_failed`, `error` (an unexpected throw with no more +specific stage), `settled`. + +`x402_payment_settled_usdc_total` is recorded **at settlement** — the point the +funds move — while `outcome="settled"` also requires the access top-up to have +succeeded. So revenue counts every payment collected, and +`outcome="topup_failed"` counts payments taken where access was not granted. +That second number is worth alerting on: it is money owed back. + +402 responses themselves are already countable without these, via +`http_request_duration_seconds_count{status_code="402"}`. The counters above +cover what happens *after* a 402 — whether anyone pays, and whether their +payments settle. + +That distinction matters in one specific failure: a mainnet deployment with +incomplete CDP credentials silently falls back to `X_402_USDC_FACILITATOR_URL`, +and the commonly configured facilitators there support testnets only. Every +payment then fails verification while the gateway keeps advertising x402 and +serving 402s. Without these metrics that is indistinguishable from a paywall +nobody has paid yet: + +```promql +# paid attempts that never settled +sum by (outcome) (rate(x402_payment_total{outcome!="settled"}[1h])) + +# revenue actually settled +sum(increase(x402_payment_settled_usdc_total[24h])) + +# paid but not granted access — alert on this +sum(increase(x402_payment_total{outcome="topup_failed"}[1h])) + +# conversion: settled payments per 402 served +sum(increase(x402_payment_total{outcome="settled"}[24h])) + / sum(increase(http_request_duration_seconds_count{status_code="402"}[24h])) +``` + ## Troubleshooting ### Rate Limiter Issues diff --git a/src/metrics.ts b/src/metrics.ts index 4f28e414a..bab763278 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1571,6 +1571,39 @@ export const rateLimitTokensConsumedTotal = new promClient.Counter({ labelNames: ['bucket_type', 'token_type', 'domain'], }); +/** + * x402 payment funnel. 402 responses are already countable via + * http_request_duration_seconds_count{status_code="402"}; what was missing is + * everything after one: whether a payment verified, settled, and topped up a + * bucket. Without it an operator cannot tell a paywall nobody pays from one + * whose settlements are failing — which matters because a mainnet deployment + * with incomplete CDP credentials silently falls back to a facilitator that + * cannot settle, and keeps serving 402s while earning nothing. + * + * `outcome` is the stage that ended the attempt: `no_payment_header`, + * `invalid_target`, `missing_host`, `verify_failed`, `unsupported_processor`, + * `unsupported_payload`, `settle_failed`, `topup_failed`, `error` (an + * unexpected throw with no more specific stage), or `settled`. + * + * Note that `x402_payment_settled_usdc_total` is recorded at settlement, which + * is when the funds actually move, while `outcome="settled"` requires the + * access top-up to have succeeded as well. Revenue therefore counts every + * payment collected even when a later step failed, and + * `sum(x402_payment_total{outcome="topup_failed"})` is the count of payments + * taken without access granted — an amount owed back, and worth alerting on. + */ +export const x402PaymentCounter = new promClient.Counter({ + name: 'x402_payment_total', + help: 'x402 payment attempts by outcome and top-up target', + labelNames: ['outcome', 'target'], +}); + +export const x402PaymentSettledUsdcCounter = new promClient.Counter({ + name: 'x402_payment_settled_usdc_total', + help: 'Total USDC settled through x402 (converted from atomic units; USDC has 6 decimals)', + labelNames: ['target'], +}); + // // Root TX Index metrics // diff --git a/src/payments/payment-processor-utils.test.ts b/src/payments/payment-processor-utils.test.ts new file mode 100644 index 000000000..7634098f3 --- /dev/null +++ b/src/payments/payment-processor-utils.test.ts @@ -0,0 +1,200 @@ +/** + * AR.IO Gateway + * Copyright (C) 2022-2025 Permanent Data Solutions, Inc. All Rights Reserved. + * + * SPDX-License-Identifier: AGPL-3.0-or-later + */ +import assert from 'node:assert'; +import { afterEach, describe, it, mock } from 'node:test'; +import { Request } from 'express'; + +import { createTestLogger } from '../../test/test-logger.js'; +import * as metrics from '../metrics.js'; +import { RateLimiter } from '../limiter/types.js'; +import { processPaymentAndTopUp } from './payment-processor-utils.js'; +import { X402UsdcProcessor } from './x402-usdc-processor.js'; + +const log = createTestLogger({ suite: 'processPaymentAndTopUp' }); + +const req = (headers: Record = { host: 'example.com' }) => { + const mockRequest = { + method: 'GET', + originalUrl: '/ar-io/x402/test', + protocol: 'https', + headers, + header: (name: string) => headers[name.toLowerCase()], + }; + return mockRequest as unknown as Request; +}; + +const rateLimiter = { + topOffPaidTokens: async () => undefined, + topOffPaidTokensForResource: async () => undefined, +} as unknown as RateLimiter; + +// A processor that passes the `instanceof X402UsdcProcessor` checks while its +// network calls are stubbed. Payment amounts are USDC atomic units (6 decimals). +function makeProcessor(overrides: Record = {}) { + const processor = new X402UsdcProcessor({ + walletAddress: '0x1234567890123456789012345678901234567890', + network: 'base', + perBytePrice: 0.000001, + minPrice: 0.001, + maxPrice: 1.0, + facilitatorUrl: 'https://facilitator.example.com', + settleTimeoutMs: 5000, + version: 1, + log, + } as any); + Object.assign(processor, { + extractPayment: () => ({ + network: 'base', + scheme: 'exact', + payload: { authorization: { value: '250000' } }, // $0.25 + }), + calculateRequirements: () => ({}) as any, + verifyPayment: async () => ({ isValid: true }), + settlePayment: async () => ({ success: true, responseHeader: 'header' }), + paymentToContentSize: () => 1000, + paymentToTokens: () => 10, + ...overrides, + }); + return processor; +} + +async function outcomeCount(outcome: string, target = 'ip') { + const { values } = await metrics.x402PaymentCounter.get(); + return ( + values.find( + (v: any) => v.labels.outcome === outcome && v.labels.target === target, + )?.value ?? 0 + ); +} + +async function settledUsdc(target = 'ip') { + const { values } = await metrics.x402PaymentSettledUsdcCounter.get(); + return values.find((v: any) => v.labels.target === target)?.value ?? 0; +} + +describe('processPaymentAndTopUp metrics', () => { + afterEach(() => mock.restoreAll()); + + it('counts a settled payment and its USDC amount', async () => { + const before = await outcomeCount('settled'); + const beforeUsdc = await settledUsdc(); + + const result = await processPaymentAndTopUp( + rateLimiter, + makeProcessor() as any, + req(), + log, + { type: 'ip' }, + ); + + assert.equal(result.success, true); + assert.equal(await outcomeCount('settled'), before + 1); + // 250000 atomic units = $0.25 + assert.ok(Math.abs((await settledUsdc()) - (beforeUsdc + 0.25)) < 1e-9); + }); + + // The case that motivated this: a mainnet deployment whose facilitator cannot + // settle keeps serving 402s and earning nothing. 402 counts alone look + // identical to a healthy paywall nobody has paid yet. + it('counts a settlement failure separately from a verification failure', async () => { + const beforeSettle = await outcomeCount('settle_failed'); + const beforeVerify = await outcomeCount('verify_failed'); + + await processPaymentAndTopUp( + rateLimiter, + makeProcessor({ + settlePayment: async () => ({ + success: false, + errorReason: 'facilitator does not support this network', + }), + }) as any, + req(), + log, + { type: 'ip' }, + ); + assert.equal(await outcomeCount('settle_failed'), beforeSettle + 1); + + await processPaymentAndTopUp( + rateLimiter, + makeProcessor({ + verifyPayment: async () => ({ + isValid: false, + invalidReason: 'insufficient_funds', + }), + }) as any, + req(), + log, + { type: 'ip' }, + ); + assert.equal(await outcomeCount('verify_failed'), beforeVerify + 1); + }); + + // A payment that settles on-chain and then fails to grant access is the worst + // case to misreport: the funds moved. It must not be filed as a generic + // error, and the revenue must still be counted. + it('records settled USDC and topup_failed when the top-up throws after settlement', async () => { + const beforeUsdc = await settledUsdc(); + const beforeTopup = await outcomeCount('topup_failed'); + const beforeError = await outcomeCount('error'); + const beforeSettled = await outcomeCount('settled'); + + const failingLimiter = { + topOffPaidTokens: async () => { + throw new Error('redis unavailable'); + }, + topOffPaidTokensForResource: async () => undefined, + } as unknown as RateLimiter; + + const result = await processPaymentAndTopUp( + failingLimiter, + makeProcessor() as any, + req(), + log, + { type: 'ip' }, + ); + + assert.equal(result.success, false); + // The payment settled, so the money is counted... + assert.ok(Math.abs((await settledUsdc()) - (beforeUsdc + 0.25)) < 1e-9); + // ...attributed to the stage that actually failed... + assert.equal(await outcomeCount('topup_failed'), beforeTopup + 1); + // ...and not double-counted as a generic error or a clean success. + assert.equal(await outcomeCount('error'), beforeError); + assert.equal(await outcomeCount('settled'), beforeSettled); + }); + + it('counts a request that carried no payment header', async () => { + const before = await outcomeCount('no_payment_header'); + + const result = await processPaymentAndTopUp( + rateLimiter, + makeProcessor({ extractPayment: () => undefined }) as any, + req(), + log, + { type: 'ip' }, + ); + + assert.equal(result.success, false); + assert.equal(await outcomeCount('no_payment_header'), before + 1); + }); + + it('does not record settled USDC when nothing settled', async () => { + const beforeUsdc = await settledUsdc(); + + await processPaymentAndTopUp( + rateLimiter, + makeProcessor({ + settlePayment: async () => ({ success: false, errorReason: 'nope' }), + }) as any, + req(), + log, + { type: 'ip' }, + ); + + assert.equal(await settledUsdc(), beforeUsdc); + }); +}); diff --git a/src/payments/payment-processor-utils.ts b/src/payments/payment-processor-utils.ts index ff0dea88f..5d2ec1b12 100644 --- a/src/payments/payment-processor-utils.ts +++ b/src/payments/payment-processor-utils.ts @@ -10,6 +10,7 @@ import { PaymentRequirements } from 'x402/types'; import * as config from '../config.js'; import { RateLimiter } from '../limiter/types.js'; import { PaymentProcessor } from './types.js'; +import * as metrics from '../metrics.js'; import { X402UsdcProcessor } from './x402-usdc-processor.js'; export interface PaymentTopUpTarget { @@ -63,11 +64,20 @@ export async function processPaymentAndTopUp( target: PaymentTopUpTarget, contentSizeOverride?: number, ): Promise { + // Records where an attempt ended, so the funnel from 402 -> settled payment is + // visible. Every early return below goes through this, and the outer catch + // only records `error` if nothing more specific was recorded first. + let outcomeRecorded = false; + const countOutcome = (outcome: string) => { + outcomeRecorded = true; + metrics.x402PaymentCounter.inc({ outcome, target: target.type }); + }; try { // Extract payment from headers const payment = paymentProcessor.extractPayment(req); if (payment === undefined) { + countOutcome('no_payment_header'); return { success: false, error: 'No payment found in headers', @@ -81,6 +91,7 @@ export async function processPaymentAndTopUp( target.host === undefined || target.path === undefined ) { + countOutcome('invalid_target'); return { success: false, error: 'Resource top-up requires method, host, and path', @@ -107,6 +118,7 @@ export async function processPaymentAndTopUp( // Validate host header is present const host = req.headers.host; if (host === undefined || host === '') { + countOutcome('missing_host'); return { success: false, error: 'Missing Host header - required for payment processing', @@ -131,6 +143,7 @@ export async function processPaymentAndTopUp( ); if (!verifyResult.isValid) { + countOutcome('verify_failed'); return { success: false, error: `Payment verification failed: ${verifyResult.invalidReason}`, @@ -144,6 +157,7 @@ export async function processPaymentAndTopUp( network: payment.network, scheme: payment.scheme, }); + countOutcome('unsupported_processor'); return { success: false, error: `Unsupported payment processor type: ${paymentProcessor.constructor.name}`, @@ -159,6 +173,7 @@ export async function processPaymentAndTopUp( hasAuthorization: 'authorization' in payment.payload, hasTransaction: 'transaction' in payment.payload, }); + countOutcome('unsupported_payload'); return { success: false, error: @@ -174,12 +189,27 @@ export async function processPaymentAndTopUp( ); if (!settlementResult.success) { + countOutcome('settle_failed'); return { success: false, error: `Payment settlement failed: ${settlementResult.errorReason}`, }; } + // Recorded here rather than after the top-up: settlement is the point the + // funds actually move, so a later failure granting access must not erase + // revenue that was really collected. USDC has 6 decimals; parseInt of a + // non-numeric value would poison the counter, so only a finite result is + // recorded. + const settledUsdc = + parseInt(payment.payload.authorization.value.toString(), 10) / 1_000_000; + if (Number.isFinite(settledUsdc)) { + metrics.x402PaymentSettledUsdcCounter.inc( + { target: target.type }, + settledUsdc, + ); + } + // Convert payment amount to tokens and top up bucket // Payment has been settled successfully and validations passed, now grant access tokens @@ -202,20 +232,33 @@ export async function processPaymentAndTopUp( if (target.type === 'ip') { // For IP bucket, use existing method with request - await rateLimiter.topOffPaidTokens(req, tokens); + try { + await rateLimiter.topOffPaidTokens(req, tokens); + } catch (error: any) { + // The payment settled; only the access grant failed. Attribute it + // precisely instead of letting the outer catch call it an error. + countOutcome('topup_failed'); + throw error; + } tokensAdded = tokens * multiplierApplied; } else if (target.type === 'resource') { // For resource bucket, use new method with explicit params // Note: target validation already done at function entry - await rateLimiter.topOffPaidTokensForResource( - target.method!, - target.host!, - target.path!, - tokens, - ); + try { + await rateLimiter.topOffPaidTokensForResource( + target.method!, + target.host!, + target.path!, + tokens, + ); + } catch (error: any) { + countOutcome('topup_failed'); + throw error; + } tokensAdded = tokens * multiplierApplied; } else { log.error('Invalid target type', { target }); + countOutcome('topup_failed'); return { success: false, error: `Invalid target type: ${target.type}`, @@ -232,6 +275,8 @@ export async function processPaymentAndTopUp( multiplierApplied, }); + countOutcome('settled'); + return { success: true, tokensAdded, @@ -240,6 +285,9 @@ export async function processPaymentAndTopUp( responseHeader: settlementResult.responseHeader, }; } catch (error: any) { + if (!outcomeRecorded) { + countOutcome('error'); + } log.error('Error processing payment and top-up', { error: error.message, stack: error.stack,