Skip to content

Commit dd4ec25

Browse files
fix(billing): log + surface root cause when checkout 502s (#3660)
* fix(billing): log + surface root cause when checkout 502s Add logger.error in the checkout and extrasCheckout controller catch blocks (502 path only) and wrap stripe.customers.create / stripe.checkout.sessions.create / stripe.checkout.sessions.create (extras) with explicit try/catch + logger.error so the underlying Stripe error message appears in pod logs before being re-thrown. Without this, production 502s from the billing checkout flow had no stack trace in pod logs — root cause was invisible. Regression tests: billing.checkout.unit.tests.js — three new tests covering stripe.customers.create reject, stripe.checkout.sessions.create reject (subscription), and stripe.checkout.sessions.create reject (extras pack), each asserting logger.error is called with the correct marker + re-thrown. Also adds logger mock to billing.extras.controller and billing.checkout test suites to prevent config-read crash on minimal config objects. * fix(billing): serialize error as message+stack in 502 log payloads Winston format.json() does not serialize Error non-enumerable properties, so logging `error: err` produces `{}` in JSON mode. Switch to `error: err?.message ?? String(err), stack: err?.stack` to match the existing convention in billing.webhook.service.js. Update regression test assertions to verify the extracted message string. * test(billing): mock logger in routes integration test to avoid fileLogger init crash * test(billing): cover main checkout controller 502 path + invalid priceId
1 parent 5a113f9 commit dd4ec25

5 files changed

Lines changed: 218 additions & 12 deletions

File tree

modules/billing/controllers/billing.controller.js

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
import { activeStatuses } from '../lib/constants.js';
55
import config from '../../../config/index.js';
66
import responses from '../../../lib/helpers/responses.js';
7+
import logger from '../../../lib/services/logger.js';
78
import BillingService from '../services/billing.service.js';
89
import BillingUsageService from '../services/billing.usage.service.js';
910
import BillingExtraService from '../services/billing.extra.service.js';
@@ -24,6 +25,15 @@ const checkout = async (req, res) => {
2425
return res.status(409).json({ type: 'error', message: err.message, code: 'subscription_already_active', portalUrl: err.portalUrl });
2526
}
2627
const status = err.message?.startsWith('Invalid') || err.message?.includes('not found') ? 422 : 502;
28+
if (status === 502) {
29+
logger.error('[billing.checkout] createCheckout failed', {
30+
error: err?.message ?? String(err),
31+
stack: err?.stack,
32+
organizationId: req.organization?._id,
33+
priceId: req.body?.priceId,
34+
source: 'web',
35+
});
36+
}
2737
const title = status === 422 ? 'Unprocessable Entity' : 'Bad Gateway';
2838
responses.error(res, status, title, 'Failed to create checkout session')(err);
2939
}
@@ -138,6 +148,15 @@ const extrasCheckout = async (req, res) => {
138148
responses.success(res, 'extras checkout session created')(result);
139149
} catch (err) {
140150
const status = err.message?.startsWith('Invalid') || err.message?.includes('not found') ? 422 : 502;
151+
if (status === 502) {
152+
logger.error('[billing.checkout] createExtrasCheckout failed', {
153+
error: err?.message ?? String(err),
154+
stack: err?.stack,
155+
organizationId: req.organization?._id,
156+
packId: req.body?.packId,
157+
source: 'web',
158+
});
159+
}
141160
const title = status === 422 ? 'Unprocessable Entity' : 'Bad Gateway';
142161
responses.error(res, status, title, 'Failed to create extras checkout session')(err);
143162
}

modules/billing/services/billing.service.js

Lines changed: 46 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
* Module dependencies
33
*/
44
import config from '../../../config/index.js';
5+
import logger from '../../../lib/services/logger.js';
56
import getStripe from '../lib/stripe.js';
67
import BillingPlansService from './billing.plans.service.js';
78
import SubscriptionRepository from '../repositories/billing.subscription.repository.js';
@@ -46,13 +47,23 @@ const _ensureStripeCustomer = async (stripe, organization) => {
4647
let subscription = await SubscriptionRepository.findByOrganization(organization._id);
4748
if (subscription?.stripeCustomerId) return subscription;
4849

49-
const customer = await stripe.customers.create(
50-
{
51-
name: organization.name,
52-
metadata: { organizationId: String(organization._id) },
53-
},
54-
{ idempotencyKey: `cus_create_${String(organization._id)}` },
55-
);
50+
let customer;
51+
try {
52+
customer = await stripe.customers.create(
53+
{
54+
name: organization.name,
55+
metadata: { organizationId: String(organization._id) },
56+
},
57+
{ idempotencyKey: `cus_create_${String(organization._id)}` },
58+
);
59+
} catch (err) {
60+
logger.error('[billing.service] stripe.customers.create failed', {
61+
error: err?.message ?? String(err),
62+
stack: err?.stack,
63+
organizationId: String(organization._id),
64+
});
65+
throw err;
66+
}
5667

5768
if (subscription) {
5869
subscription = await SubscriptionRepository.update({
@@ -190,7 +201,19 @@ const createCheckout = async (organization, priceId, successUrl, cancelUrl) => {
190201
// the day yields the same expired session URL, silently killing conversion.
191202
// Same-tab double-clicks are prevented in this function by the active-
192203
// subscription guard above (both the DB check and the live Stripe lookup).
193-
const session = await stripe.checkout.sessions.create(checkoutParams);
204+
let session;
205+
try {
206+
session = await stripe.checkout.sessions.create(checkoutParams);
207+
} catch (err) {
208+
logger.error('[billing.service] stripe.checkout.sessions.create failed', {
209+
error: err?.message ?? String(err),
210+
stack: err?.stack,
211+
organizationId: String(organization._id),
212+
priceId,
213+
plan: matchedPlan.planId,
214+
});
215+
throw err;
216+
}
194217

195218
return session.url;
196219
};
@@ -270,10 +293,21 @@ const createExtrasCheckout = async (organization, packId, successUrl, cancelUrl,
270293
extrasCheckoutParams.automatic_tax = { enabled: true };
271294
extrasCheckoutParams.customer_update = { address: 'auto', name: 'auto' };
272295
}
273-
const session = await stripe.checkout.sessions.create(
274-
extrasCheckoutParams,
275-
{ idempotencyKey },
276-
);
296+
let session;
297+
try {
298+
session = await stripe.checkout.sessions.create(
299+
extrasCheckoutParams,
300+
{ idempotencyKey },
301+
);
302+
} catch (err) {
303+
logger.error('[billing.service] stripe.checkout.sessions.create (extras) failed', {
304+
error: err?.message ?? String(err),
305+
stack: err?.stack,
306+
organizationId: orgId,
307+
packId,
308+
});
309+
throw err;
310+
}
277311

278312
return { url: session.url };
279313
};

modules/billing/tests/billing.checkout.unit.tests.js

Lines changed: 115 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -63,6 +63,12 @@ describe('Billing service unit tests:', () => {
6363
jest.unstable_mockModule('../services/billing.plans.service.js', () => ({
6464
default: mockPlansService,
6565
}));
66+
67+
// Mock logger to prevent logger.js from reading config at import time.
68+
// Tests in the "error logging" describe override this with a tracked mock.
69+
jest.unstable_mockModule('../../../lib/services/logger.js', () => ({
70+
default: { error: jest.fn(), warn: jest.fn(), info: jest.fn(), debug: jest.fn() },
71+
}));
6672
});
6773

6874
afterEach(() => {
@@ -829,4 +835,113 @@ describe('Billing service unit tests:', () => {
829835
expect(result.nextRenewalDate).toEqual(new Date(cancelAt * 1000));
830836
});
831837
});
838+
839+
// ── Error logging regression (fix-checkout-502) ──────────────────────────
840+
// Ensures that stripe.customers.create and stripe.checkout.sessions.create
841+
// errors are logged via logger.error before being re-thrown.
842+
// Without this, production 502s have no stack trace in pod logs.
843+
844+
describe('error logging on Stripe failure', () => {
845+
let mockLogger;
846+
847+
beforeEach(() => {
848+
// Re-register logger mock with tracked jest.fn() instances so we can assert on calls.
849+
// The parent beforeEach already registers a silent mock; this overrides it with tracked ones.
850+
mockLogger = { error: jest.fn(), warn: jest.fn(), info: jest.fn(), debug: jest.fn() };
851+
jest.unstable_mockModule('../../../lib/services/logger.js', () => ({
852+
default: mockLogger,
853+
}));
854+
});
855+
856+
test('logs error and re-throws when stripe.customers.create rejects', async () => {
857+
const stripeError = new Error('Stripe Test: customer creation blocked');
858+
jest.unstable_mockModule('../../../config/index.js', () => ({
859+
default: { stripe: { secretKey: 'sk_test_log_cus' } },
860+
}));
861+
862+
mockSubscriptionRepository.findByOrganization
863+
.mockResolvedValueOnce(null) // block guard: no active sub
864+
.mockResolvedValueOnce(null); // _ensureStripeCustomer: no existing sub → create
865+
mockStripeInstance.customers.create.mockRejectedValue(stripeError);
866+
867+
const mod = await import('../services/billing.service.js');
868+
BillingService = mod.default;
869+
870+
await expect(
871+
BillingService.createCheckout(mockOrganization, 'price_starter_m', 'http://ok', 'http://cancel'),
872+
).rejects.toThrow('Stripe Test: customer creation blocked');
873+
874+
expect(mockLogger.error).toHaveBeenCalledWith(
875+
'[billing.service] stripe.customers.create failed',
876+
expect.objectContaining({
877+
organizationId: orgId,
878+
error: 'Stripe Test: customer creation blocked',
879+
}),
880+
);
881+
});
882+
883+
test('logs error and re-throws when stripe.checkout.sessions.create rejects', async () => {
884+
const stripeError = new Error('Stripe Test: session creation blocked');
885+
jest.unstable_mockModule('../../../config/index.js', () => ({
886+
default: { stripe: { secretKey: 'sk_test_log_sess' } },
887+
}));
888+
889+
mockSubscriptionRepository.findByOrganization.mockResolvedValue({
890+
stripeCustomerId: 'cus_existing',
891+
});
892+
mockStripeInstance.checkout.sessions.create.mockRejectedValue(stripeError);
893+
894+
const mod = await import('../services/billing.service.js');
895+
BillingService = mod.default;
896+
897+
await expect(
898+
BillingService.createCheckout(mockOrganization, 'price_starter_m', 'http://ok', 'http://cancel'),
899+
).rejects.toThrow('Stripe Test: session creation blocked');
900+
901+
expect(mockLogger.error).toHaveBeenCalledWith(
902+
'[billing.service] stripe.checkout.sessions.create failed',
903+
expect.objectContaining({
904+
organizationId: orgId,
905+
priceId: 'price_starter_m',
906+
error: 'Stripe Test: session creation blocked',
907+
}),
908+
);
909+
});
910+
911+
test('logs error and re-throws when extras stripe.checkout.sessions.create rejects', async () => {
912+
const stripeError = new Error('Stripe Test: extras session blocked');
913+
jest.unstable_mockModule('../../../config/index.js', () => ({
914+
default: {
915+
stripe: {
916+
secretKey: 'sk_test_log_extras',
917+
prices: { packs: { pack_500k: 'price_pack500' } },
918+
},
919+
billing: {
920+
packs: [{ packId: 'pack_500k', meterUnits: 500000 }],
921+
},
922+
},
923+
}));
924+
925+
mockSubscriptionRepository.findByOrganization.mockResolvedValue({
926+
stripeCustomerId: 'cus_existing',
927+
});
928+
mockStripeInstance.checkout.sessions.create.mockRejectedValue(stripeError);
929+
930+
const mod = await import('../services/billing.service.js');
931+
BillingService = mod.default;
932+
933+
await expect(
934+
BillingService.createExtrasCheckout(mockOrganization, 'pack_500k', 'http://ok', 'http://cancel'),
935+
).rejects.toThrow('Stripe Test: extras session blocked');
936+
937+
expect(mockLogger.error).toHaveBeenCalledWith(
938+
'[billing.service] stripe.checkout.sessions.create (extras) failed',
939+
expect.objectContaining({
940+
organizationId: orgId,
941+
packId: 'pack_500k',
942+
error: 'Stripe Test: extras session blocked',
943+
}),
944+
);
945+
});
946+
});
832947
});

modules/billing/tests/billing.extras.controller.unit.tests.js

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@ describe('Billing extras controller unit tests:', () => {
3131
jest.resetModules();
3232

3333
mockBillingService = {
34+
createCheckout: jest.fn(),
3435
createExtrasCheckout: jest.fn(),
3536
getLocalSubscription: jest.fn(),
3637
getSubscription: jest.fn(),
@@ -77,6 +78,12 @@ describe('Billing extras controller unit tests:', () => {
7778
activeStatuses: ['active', 'trialing'],
7879
}));
7980

81+
// Mock logger: billing.controller.js imports logger, which reads config at module init.
82+
// Without this mock, tests that supply a minimal config object cause logger.js to throw.
83+
jest.unstable_mockModule('../../../lib/services/logger.js', () => ({
84+
default: { error: jest.fn(), warn: jest.fn(), info: jest.fn(), debug: jest.fn() },
85+
}));
86+
8087
const mod = await import('../controllers/billing.controller.js');
8188
BillingController = mod.default;
8289

@@ -141,6 +148,28 @@ describe('Billing extras controller unit tests:', () => {
141148
});
142149
});
143150

151+
// ── checkout (main subscription) ───────────────────────────────────────────
152+
153+
describe('checkout', () => {
154+
test('should return 502 and log the error when Stripe call fails with generic error', async () => {
155+
req.body = { priceId: 'price_growth_m', successUrl: 'http://ok', cancelUrl: 'http://cancel' };
156+
mockBillingService.createCheckout.mockRejectedValue(new Error('Network error'));
157+
158+
await BillingController.checkout(req, res);
159+
160+
expect(res.status).toHaveBeenCalledWith(502);
161+
});
162+
163+
test('should return 422 when priceId is invalid (no logger.error on 422 path)', async () => {
164+
req.body = { priceId: 'price_unknown', successUrl: 'http://ok', cancelUrl: 'http://cancel' };
165+
mockBillingService.createCheckout.mockRejectedValue(new Error('Invalid priceId: price not found'));
166+
167+
await BillingController.checkout(req, res);
168+
169+
expect(res.status).toHaveBeenCalledWith(422);
170+
});
171+
});
172+
144173
// ── extrasBalance ──────────────────────────────────────────────────────────
145174

146175
describe('extrasBalance', () => {

modules/billing/tests/billing.routes.integration.tests.js

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -71,6 +71,15 @@ describe('Billing extras routes integration tests:', () => {
7171
activeStatuses: ['active', 'trialing'],
7272
}));
7373

74+
jest.unstable_mockModule('../../../lib/services/logger.js', () => ({
75+
default: {
76+
error: jest.fn(),
77+
warn: jest.fn(),
78+
info: jest.fn(),
79+
debug: jest.fn(),
80+
},
81+
}));
82+
7483
const mod = await import('../controllers/billing.controller.js');
7584
BillingController = mod.default;
7685

0 commit comments

Comments
 (0)