Skip to content

Commit 82b5cf0

Browse files
fix(mailer,audit): propagate send and write failures so caller context logging fires (#3973)
* fix(mailer,audit): propagate send/write failures so caller context logging fires lib/helpers/mailer/index.js#sendMail and modules/audit/services/audit.service.js#log each wrapped their failing call in a local try/catch, logged one generic line, and resolved null instead of rejecting. Every caller's own context-rich .catch() (action/userId/orgId/targetType) never ran on a real outage — dead code hidden behind a swallowed rejection. Let both helpers propagate the underlying rejection. The "mail/audit failure never breaks the main flow" invariant now lives at the call sites (their existing .catch()), not centrally in the helper: - auth signup/reset, billing.email.js, invitations.service.js, and the 4 organizations.membership.service.js sites already had context-logging .catch() handlers that were previously unreachable — now they fire. - invitations.service.js#resend already documented "a transport failure surfaces as an error" but the swallow silently defeated that; propagation fixes it to match its own doc comment. - audit.middleware.js's .catch() is enriched with action/userId/organizationId/ targetType/targetId so a write failure now logs full request context, not just message+stack. Closes #3966 Claude-Session: https://claude.ai/code/session_01WfNC8bt1TgL4AsiYgCEGup * fix(mailer): return a generic client message on resend mail-transport failures resendVerification (auth.controller.js) and the invitations resend endpoint now surface propagated mail-transport failures via errors.getMessage(err), which relayed the raw SMTP/Resend provider error string to the client on these two endpoints — a low-severity infra-detail leak flagged by the pre-push critical-review gate on #3966. Both catches now log the real error server-side with context (userId / invitationId) and respond with a stable generic message. invitations.resend still threads deliberate AppError statuses (409 conflict, 404 not found, 422 mailer-not-configured) through unchanged — only the untagged transport rejection (no `.status`) gets the generic treatment. resendVerification's catch is resend-email-scoped end-to-end, so the whole catch goes generic. Claude-Session: https://claude.ai/code/session_01WfNC8bt1TgL4AsiYgCEGup
1 parent b9f4951 commit 82b5cf0

12 files changed

Lines changed: 287 additions & 65 deletions

File tree

ERRORS.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,3 +33,4 @@ Use this file as a compact memory of recurring AI mistakes.
3333
- [2026-07-16] security: `users.repository.js findByIdAndUpdatePopulated()` does `.populate()` with no `.select()`, so `organizations.controller.js switchOrganization` serialized the raw doc (password hash + OAuth tokens + reset/verification tokens) straight to the client; `users.account.controller.js me()` separately forwarded `providerData` (OAuth tokens) verbatim -> any endpoint returning a Mongoose user doc must go through `UserService.removeSensitive()` (whitelist, `modules/users/utils/sanitizeUser.js`) at the response boundary, never serialize `req.user`/a populated doc directly; a local-signup fixture's `providerData` defaults to `{}` so a naive falsy check won't catch this — seed a fake OAuth token in tests to prove the leak is actually closed; see pierreb-devkit/Node#3963
3434
- [2026-07-16] billing/stripe: the #3742 priceId-map fix (`resolvePlan`/`buildPriceIdToPlanMap`) was applied only to the webhook handler; `billing.admin.service.js` `resolveStripePlan` (admin force-sync, a DB WRITE path) and `billing.reconcile.service.js` `resolveStripePlan` (LOG-ONLY divergence check) kept their own copies reading only `metadata.planId` -> a paid org's Stripe subscription (which never carries `metadata.planId`) resolved to `'free'` on admin sync (silently downgrading a paying org) and produced a false `planMismatch` alert on every reconcile run; fix = one shared resolver (`modules/billing/lib/billing.planResolver.js`) used by all three call sites, and a null-unresolved sentinel (never guess `'free'`) so the admin write path ABORTS instead of downgrading and the reconcile log path skips the comparison instead of alerting; see pierreb-devkit/Node#3964
3535
- [2026-07-16] architecture: `users.service.js remove()`'s sole-owner cascade called `OrganizationsRepository.remove()` directly instead of `organizations.crud.service.js#remove()`, silently skipping `runOrganizationRemovedHandlers` (the `onOrganizationRemoved` seam `modules/tasks/tasks.init.js` registers for org-scoped task cleanup) -> deleting an org must always route through the owning module's SERVICE method, never straight to its Repository, even for a "bare" cascade delete from another module — a direct-repository shortcut silently bypasses any registered removal hook; a stale cross-test fixture in `tasks.integration.tests.js` (an orphaned-but-still-existing task reused across unrelated test cases) was inadvertently relying on this bug and needed a properly isolated fixture once the cascade actually cleaned up; see pierreb-devkit/Node#3965
36+
- [2026-07-17] error handling: shared helpers (`lib/helpers/mailer/index.js#sendMail`, `modules/audit/services/audit.service.js#log`) wrapped the failing call in their own try/catch, logged a single generic line, and resolved `null` -> every caller's own context-rich `.catch()` (action/userId/orgId) became dead code on a real outage, since the promise never rejected; a central helper must let the underlying call's rejection propagate and let each CALL SITE own the "never break the main flow" `.catch()` with its own context — never swallow centrally just because most callers currently attach a catch; see pierreb-devkit/Node#3966

lib/helpers/mailer/index.js

Lines changed: 15 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,6 @@ import path from 'path';
22
import handlebars from 'handlebars';
33

44
import config from '../../../config/index.js';
5-
import logger from '../../services/logger.js';
65
import files from '../files.js';
76
import NodemailerProvider from './provider.nodemailer.js';
87
import ResendProvider from './provider.resend.js';
@@ -73,7 +72,12 @@ const validateAttachments = (attachments) => {
7372
* @param {Array} [mail.attachments] - Optional attachments array
7473
* @param {string} mail.attachments[].filename - Attachment filename
7574
* @param {string|Buffer} mail.attachments[].content - Attachment content (string or Buffer)
76-
* @returns {Promise<Object|null>} The send result or null if not configured
75+
* @returns {Promise<Object|null>} The send result, or null if not configured
76+
* @throws {Error} If the provider's send() call fails — propagated so each
77+
* caller's own `.catch()` can log with its flow-specific context
78+
* (action, userId, orgId, ...). Callers that must never let a mail failure
79+
* break their main flow are responsible for attaching that `.catch()`
80+
* themselves; this helper does not swallow errors centrally.
7781
*/
7882
const sendMail = async (mail) => {
7983
if (!isConfigured()) return null;
@@ -83,20 +87,15 @@ const sendMail = async (mail) => {
8387
const file = await files.readFile(path.resolve(`./config/templates/${sanitizedTemplate}.html`));
8488
const template = handlebars.compile(file);
8589
const html = template(mail.params);
86-
try {
87-
const result = await getProvider().send({
88-
from: config.mailer.from,
89-
to: mail.to,
90-
subject: mail.subject,
91-
html,
92-
attachments: mail.attachments,
93-
});
94-
if (!Array.isArray(result?.accepted)) return { ...result, accepted: [mail.to], rejected: [] };
95-
return result;
96-
} catch (err) {
97-
logger.error('Mail send error', err);
98-
return null;
99-
}
90+
const result = await getProvider().send({
91+
from: config.mailer.from,
92+
to: mail.to,
93+
subject: mail.subject,
94+
html,
95+
attachments: mail.attachments,
96+
});
97+
if (!Array.isArray(result?.accepted)) return { ...result, accepted: [mail.to], rejected: [] };
98+
return result;
10099
};
101100

102101
export default { sendMail, isConfigured };

lib/helpers/mailer/tests/mailer.unit.tests.js

Lines changed: 26 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -29,15 +29,6 @@ jest.unstable_mockModule('../provider.nodemailer.js', () => ({
2929
default: jest.fn().mockImplementation(() => ({ send: jest.fn() })),
3030
}));
3131

32-
jest.unstable_mockModule('../../../services/logger.js', () => ({
33-
default: {
34-
error: jest.fn(),
35-
warn: jest.fn(),
36-
info: jest.fn(),
37-
debug: jest.fn(),
38-
},
39-
}));
40-
4132
const { default: mailer } = await import('../index.js');
4233

4334
describe('mailer index with resend provider unit tests:', () => {
@@ -102,17 +93,35 @@ describe('mailer index with resend provider unit tests:', () => {
10293
);
10394
});
10495

105-
test('should return null on send error', async () => {
96+
test('should propagate (reject) when the provider send fails, instead of swallowing to null', async () => {
10697
mockSend.mockRejectedValue(new Error('API failure'));
10798

108-
const result = await mailer.sendMail({
109-
to: 'user@example.com',
110-
subject: 'Test',
111-
template: 'welcome',
112-
params: { name: 'Bob' },
113-
});
99+
await expect(
100+
mailer.sendMail({
101+
to: 'user@example.com',
102+
subject: 'Test',
103+
template: 'welcome',
104+
params: { name: 'Bob' },
105+
}),
106+
).rejects.toThrow('API failure');
107+
});
108+
109+
test('should let a provider rejection reach a caller-attached .catch() with its own context', async () => {
110+
mockSend.mockRejectedValue(new Error('API failure'));
111+
const callerLogger = { warn: jest.fn() };
112+
113+
// Mirrors the call-site pattern used across the codebase: fire-and-forget
114+
// sendMail() with a local .catch() that logs flow-specific context.
115+
await mailer
116+
.sendMail({
117+
to: 'user@example.com',
118+
subject: 'Test',
119+
template: 'welcome',
120+
params: { name: 'Bob' },
121+
})
122+
.catch((err) => callerLogger.warn('caller: mail failed', { message: err?.message, userId: 'u1' }));
114123

115-
expect(result).toBeNull();
124+
expect(callerLogger.warn).toHaveBeenCalledWith('caller: mail failed', { message: 'API failure', userId: 'u1' });
116125
});
117126

118127
test('should throw when attachment is missing content', async () => {

modules/audit/middlewares/audit.middleware.js

Lines changed: 14 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -118,15 +118,26 @@ const createAuditMiddleware = (options = {}) => {
118118
const targetType = deriveTargetType(routePath, req.baseUrl);
119119
const targetId = deriveTargetId(req.params);
120120

121+
const userId = req.user?._id || req.user?.id;
122+
const organizationId = req.organization?._id || req.organization?.id;
123+
121124
AuditService.log({
122125
action,
123-
userId: req.user?._id || req.user?.id,
124-
organizationId: req.organization?._id || req.organization?.id,
126+
userId,
127+
organizationId,
125128
ip: config.audit?.captureIp !== false ? (req.ip || req.connection?.remoteAddress || '') : undefined,
126129
userAgent: config.audit?.captureUserAgent !== false ? (req.headers?.['user-agent'] || '') : undefined,
127130
targetType,
128131
targetId,
129-
}).catch((err) => logger.error('audit.middleware: audit log write failed', { message: err?.message, stack: err?.stack }));
132+
}).catch((err) => logger.error('audit.middleware: audit log write failed', {
133+
message: err?.message,
134+
stack: err?.stack,
135+
action,
136+
userId,
137+
organizationId,
138+
targetType,
139+
targetId,
140+
}));
130141
});
131142

132143
return next();

modules/audit/services/audit.service.js

Lines changed: 7 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,6 @@
22
* Module dependencies
33
*/
44
import config from '../../../config/index.js';
5-
import logger from '../../../lib/services/logger.js';
65
import AuditRepository from '../repositories/audit.repository.js';
76

87
/**
@@ -17,7 +16,12 @@ import AuditRepository from '../repositories/audit.repository.js';
1716
* @param {string} [params.targetType] - Type of the target entity
1817
* @param {string} [params.targetId] - ID of the target entity
1918
* @param {Object} [params.metadata] - Additional metadata
20-
* @returns {Promise<Object|null>} The created audit log entry or null if disabled
19+
* @returns {Promise<Object|null>} The created audit log entry, or null if disabled
20+
* @throws {Error} If `AuditRepository.create` fails — propagated so the caller's
21+
* own `.catch()` can log with its request context (action, userId, orgId,
22+
* targetType, ...). Audit must never break the main flow — that guarantee is
23+
* enforced by the caller's `.catch()` (see `audit.middleware.js`), not by
24+
* swallowing the write failure here.
2125
*/
2226
const log = async ({ action, userId, organizationId, ip, userAgent, targetType, targetId, metadata } = {}) => {
2327
if (!config.audit?.enabled) return null;
@@ -35,13 +39,7 @@ const log = async ({ action, userId, organizationId, ip, userAgent, targetType,
3539
if (ip !== undefined) entry.ip = ip || '';
3640
if (userAgent !== undefined) entry.userAgent = userAgent || '';
3741

38-
try {
39-
return await AuditRepository.create(entry);
40-
} catch (err) {
41-
// Audit must never break the main flow
42-
logger.error('AuditLog write failed:', { message: err.message });
43-
return null;
44-
}
42+
return AuditRepository.create(entry);
4543
};
4644

4745
/**

modules/audit/tests/audit.middleware.unit.tests.js

Lines changed: 11 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -257,7 +257,7 @@ describe('Audit middleware unit tests:', () => {
257257
expect(mockLog).not.toHaveBeenCalled();
258258
});
259259

260-
test('should not throw when AuditService.log rejects and should log the error', async () => {
260+
test('should not throw when AuditService.log rejects and should log the error with request context', async () => {
261261
const dbError = new Error('DB down');
262262
mockLog = jest.fn().mockRejectedValue(dbError);
263263
const middleware = createAuditMiddleware();
@@ -266,13 +266,21 @@ describe('Audit middleware unit tests:', () => {
266266
const next = jest.fn();
267267

268268
middleware(req, res, next);
269-
// Should not throw
269+
// Should not throw — a rejected AuditService.log() must never break the request flow
270270
expect(() => res.emit('finish')).not.toThrow();
271271
// Allow the .catch() handler to run
272272
await new Promise((r) => setTimeout(r, 10));
273273
expect(mockLoggerError).toHaveBeenCalledWith(
274274
'audit.middleware: audit log write failed',
275-
{ message: dbError.message, stack: dbError.stack },
275+
{
276+
message: dbError.message,
277+
stack: dbError.stack,
278+
action: 'auth.signin',
279+
userId: '507f1f77bcf86cd799439011',
280+
organizationId: '507f1f77bcf86cd799439012',
281+
targetType: 'User',
282+
targetId: '',
283+
},
276284
);
277285
});
278286
});

modules/audit/tests/audit.service.unit.tests.js

Lines changed: 20 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -22,15 +22,6 @@ jest.unstable_mockModule('../../../config/index.js', () => ({
2222
default: mockConfig,
2323
}));
2424

25-
// Mock logger to avoid winston config dependency in unit tests
26-
jest.unstable_mockModule('../../../lib/services/logger.js', () => ({
27-
default: {
28-
error: jest.fn(),
29-
warn: jest.fn(),
30-
info: jest.fn(),
31-
},
32-
}));
33-
3425
/**
3526
* Unit tests
3627
*/
@@ -90,11 +81,28 @@ describe('AuditService unit tests:', () => {
9081
expect(arg.userAgent).toBeFalsy();
9182
});
9283

93-
test('should not throw when repository create fails', async () => {
84+
test('should propagate (reject) when repository create fails, instead of swallowing to null', async () => {
9485
mockCreate = jest.fn().mockRejectedValue(new Error('DB down'));
9586

96-
const result = await AuditService.log({ action: 'test.fail' });
97-
expect(result).toBeNull();
87+
await expect(AuditService.log({ action: 'test.fail' })).rejects.toThrow('DB down');
88+
});
89+
90+
test('should let a repository rejection reach a caller-attached .catch() with its own context', async () => {
91+
mockCreate = jest.fn().mockRejectedValue(new Error('DB down'));
92+
const callerLogger = { error: jest.fn() };
93+
94+
// Mirrors audit.middleware.js's pattern: fire-and-forget log() with a
95+
// local .catch() that logs request context (action/userId/orgId).
96+
await AuditService.log({ action: 'test.fail', userId: 'u1', organizationId: 'o1' }).catch((err) =>
97+
callerLogger.error('audit.middleware: audit log write failed', { message: err?.message, action: 'test.fail', userId: 'u1', orgId: 'o1' }),
98+
);
99+
100+
expect(callerLogger.error).toHaveBeenCalledWith('audit.middleware: audit log write failed', {
101+
message: 'DB down',
102+
action: 'test.fail',
103+
userId: 'u1',
104+
orgId: 'o1',
105+
});
98106
});
99107

100108
test('should list audit logs with filters', async () => {

modules/auth/controllers/auth.controller.js

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -850,7 +850,17 @@ const resendVerification = async (req, res) => {
850850
if (!acceptedCount) return responses.error(res, 400, 'Bad Request', 'Failure sending email')();
851851
return responses.success(res, 'Verification email sent')({ status: true });
852852
} catch (err) {
853-
responses.error(res, 422, 'Unprocessable Entity', errors.getMessage(err))(err);
853+
// #3966 hardening: sendVerificationEmail (mailer.sendMail) now propagates a
854+
// transport failure instead of swallowing it — the raw SMTP/provider error
855+
// string must not leak to the client. Log the real error server-side with
856+
// context (this catch is resend-email-scoped: an unexpected failure here is
857+
// effectively always the mail send); respond with a stable generic message.
858+
logger.error('[auth.resendVerification] failed', {
859+
userId: req.user?.id,
860+
message: err?.message,
861+
stack: err?.stack,
862+
});
863+
responses.error(res, 422, 'Unprocessable Entity', 'Failed to send the email, please try again.')(err);
854864
}
855865
};
856866

0 commit comments

Comments
 (0)