diff --git a/backend/__tests__/routes/adminSystemHealthWaitingEmails.test.js b/backend/__tests__/routes/adminSystemHealthWaitingEmails.test.js new file mode 100644 index 00000000..fba76f2c --- /dev/null +++ b/backend/__tests__/routes/adminSystemHealthWaitingEmails.test.js @@ -0,0 +1,397 @@ +/** + * System Health must not report "all clear" over a queue nobody is working (#1262). + * + * "Gallery email queued" reads as a delivery confirmation, and the two ways the + * queue silently stops — the processor never started, or every pass returns + * early because the transport will not initialise — leave every row at + * status='pending' with retry_count 0. The old /failures query matched only + * status='failed' or pending-with-retry_count>=3, so it matched none of them + * and the page said everything was fine while nothing had been sent. + */ + +const path = require('path'); +const fs = require('fs'); +const os = require('os'); + +process.env.NODE_ENV = 'test'; +process.env.TEST_DATABASE_PATH = path.join( + fs.mkdtempSync(path.join(os.tmpdir(), 'picpeak-mailhealth-')), 'db.sqlite', +); +process.env.JWT_SECRET = process.env.JWT_SECRET || 'mailhealth-test-secret'; + +const request = require('supertest'); +const bcrypt = require('bcrypt'); +const jwt = require('jsonwebtoken'); + +const { bootCrmDb, seedMinimal, buildRouteApp } = require('../integration/helpers/crmDb'); + +/** + * Stand up a transport without touching a socket. + * + * processEmailQueue bails before it reads a single row when there is no + * transport, so the two tests below cannot otherwise reach the code they are + * about. Spying on the webhook transport is the cheapest way in — and it must + * be a spy rather than a dead URL, because real connection attempts leave open + * handles that destabilise unrelated suites in the same worker. + * + * `send` rejects: a failed delivery is a delivery ATTEMPT, which is exactly + * what these two need to observe. + */ +function stubWebhookTransport() { + const transport = require('../../src/services/emailWebhookTransport'); + const savedFrom = process.env.EMAIL_FROM; + process.env.EMAIL_FROM = 'noreply@example.com'; + const enabled = jest.spyOn(transport, 'isEnabled').mockReturnValue(true); + const send = jest.spyOn(transport, 'send').mockRejectedValue(new Error('transport down')); + return { + send, + restore() { + enabled.mockRestore(); + send.mockRestore(); + if (savedFrom === undefined) delete process.env.EMAIL_FROM; + else process.env.EMAIL_FROM = savedFrom; + }, + }; +} + +const MINUTE = 60 * 1000; +const ago = (ms) => new Date(Date.now() - ms).toISOString(); +const ahead = (ms) => new Date(Date.now() + ms).toISOString(); + +describe('GET /admin/system-health/failures — waiting emails (#1262)', () => { + let db; let cleanup; let app; let token; + + /** + * `scheduled_at` defaults to the same moment as `created_at` unless the + * caller says otherwise, because that is what the database does: BOTH + * columns default to CURRENT_TIMESTAMP, and queueEmail only sets + * scheduled_at explicitly for a deferred send (split-payment invoices, the + * business-hours floor). Back-dating created_at alone would produce a row + * that never exists in production — old, but scheduled for the moment the + * fixture ran — and the grace window is measured from whichever of the two + * made the row due. + */ + const queue = (row = {}) => { + const createdAt = 'created_at' in row ? row.created_at : ago(60 * MINUTE); + return db('email_queue').insert({ + recipient_email: 'someone@example.com', + email_type: 'gallery_created', + email_data: '{}', + status: 'pending', + retry_count: 0, + scheduled_at: createdAt, + ...row, + created_at: createdAt, + }); + }; + + const failures = async () => { + const res = await request(app) + .get('/admin/system-health/failures') + .set('Authorization', `Bearer ${token}`); + expect(res.status).toBe(200); + return res.body.data || res.body; + }; + + const typesOf = (rows) => rows.map((r) => r.emailType).sort(); + + beforeAll(async () => { + ({ db, cleanup } = await bootCrmDb()); + await seedMinimal(db); + + const role = await db('roles').where({ name: 'super_admin' }).first(); + const inserted = await db('admin_users').insert({ + username: 'mailhealth-admin', + email: 'mailhealth-admin@example.com', + password_hash: await bcrypt.hash('Passw0rd!', 4), + role_id: role.id, + is_active: 1, + created_at: new Date().toISOString(), + updated_at: new Date().toISOString(), + }).returning('id'); + const adminId = inserted[0]?.id ?? inserted[0]; + token = jwt.sign( + { id: adminId, username: 'mailhealth-admin', type: 'admin', role: 'super_admin', loginTime: Date.now() }, + process.env.JWT_SECRET, + { expiresIn: '1h', issuer: 'picpeak-auth' }, + ); + + app = buildRouteApp('/admin/system-health', require('../../src/routes/adminSystemHealth')); + }); + + afterAll(async () => { await cleanup(); }); + afterEach(async () => { await db('email_queue').del(); }); + + it('reports a due pending email the processor never picked up', async () => { + // Exactly the shape "Gallery email queued" leaves behind when the worker + // is not running: pending, no retries, no error, no scheduled_at. + await queue({ email_type: 'gallery_created' }); + + const body = await failures(); + expect(typesOf(body.waitingEmails)).toEqual(['gallery_created']); + expect(body.counts.waitingEmails).toBe(1); + // ...and it is NOT a failure, so the two buckets stay distinct. + expect(body.stuckEmails).toEqual([]); + }); + + it('leaves a freshly queued email alone — the processor wakes every 60s', async () => { + await queue({ email_type: 'customer_invitation', created_at: ago(30 * 1000) }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + expect(body.counts.waitingEmails).toBe(0); + }); + + it('leaves an email scheduled for later alone', async () => { + // Split-payment invoices and the business-hours floor both park rows in + // the future on purpose. Not being sent yet is the point of those. + await queue({ email_type: 'invoice_due', scheduled_at: ahead(3 * 24 * 60 * MINUTE) }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + }); + + it('counts a past-due scheduled email once its moment has come', async () => { + await queue({ email_type: 'invoice_due', scheduled_at: ago(30 * MINUTE) }); + + const body = await failures(); + expect(typesOf(body.waitingEmails)).toEqual(['invoice_due']); + }); + + it('does not double-count a retry-exhausted email as waiting', async () => { + // retry_count >= 3 is already the `stuckEmails` bucket; listing it in both + // would inflate the badge and make the two tables disagree. + await queue({ email_type: 'quote_sent', retry_count: 3, error_message: 'template missing' }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + expect(typesOf(body.stuckEmails)).toEqual(['quote_sent']); + }); + + it('ignores emails that were sent', async () => { + await queue({ email_type: 'gallery_created', status: 'sent', sent_at: ago(20 * MINUTE) }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + expect(body.stuckEmails).toEqual([]); + }); + + // --- cross-engine timestamps (Codex review round 1) ----------------------- + // + // Every test above stores ISO strings, which is what CLAUDE.md prescribes + // for jest + SQLite. Production SQLite does not: queueEmail writes a JS Date + // and the native binding stores it as a ms-NUMBER. SQLite orders INTEGER + // before TEXT whatever the values are, so the original WHERE clause -- a + // ms-number column compared against a bound ISO string -- was true for every + // row. Fresh mail read as ten minutes overdue and future schedules read as + // due, on every SQLite deployment. + describe('rows stored as epoch ms, the SQLite production shape', () => { + const ms = (offset) => Date.now() + offset; + + it('does not report a mail queued seconds ago as waiting', async () => { + await queue({ email_type: 'gallery_created', created_at: ms(-30 * 1000) }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + expect(body.counts.waitingEmails).toBe(0); + }); + + it('still reports a genuinely overdue one', async () => { + await queue({ email_type: 'gallery_created', created_at: ms(-52 * MINUTE) }); + + const body = await failures(); + expect(typesOf(body.waitingEmails)).toEqual(['gallery_created']); + }); + + it('leaves a future numeric scheduled_at alone', async () => { + await queue({ + email_type: 'invoice_due', + created_at: ms(-52 * MINUTE), + scheduled_at: ms(3 * 24 * 60 * MINUTE), + }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + }); + + it('reports a past-due numeric scheduled_at', async () => { + await queue({ + email_type: 'invoice_due', + created_at: ms(-52 * MINUTE), + scheduled_at: ms(-30 * MINUTE), + }); + + const body = await failures(); + expect(typesOf(body.waitingEmails)).toEqual(['invoice_due']); + }); + + it('mixes both storage shapes in one queue without confusing them', async () => { + await queue({ email_type: 'gallery_created', created_at: ms(-52 * MINUTE) }); + await queue({ email_type: 'quote_sent', created_at: ago(52 * MINUTE) }); + await queue({ email_type: 'invoice_due', created_at: ms(-30 * 1000) }); + await queue({ email_type: 'customer_invitation', created_at: ago(30 * 1000) }); + + const body = await failures(); + expect(typesOf(body.waitingEmails)).toEqual(['gallery_created', 'quote_sent']); + }); + }); + + // --- Codex review round 2 ------------------------------------------------- + // + // The zone-less CURRENT_TIMESTAMP shape is covered in + // __tests__/utils/queueTimestamps.test.js instead of here: this suite runs + // in UTC, where reading such a value as local and as UTC give the same + // answer, and process.env.TZ does not reliably re-bind mid-process. Those + // tests force the zone in a child process, so they fail on any host. + + it('measures the grace window from when the row became due', async () => { + // Codex review round 3. A split-payment invoice created three days ago and + // scheduled until a minute ago has had one minute of the processor's + // attention, not three days of it. Measuring from created_at alone + // reported every scheduled mail as unworked the instant it came due. + await queue({ + email_type: 'invoice_due', + created_at: ago(3 * 24 * 60 * MINUTE), + scheduled_at: ago(1 * MINUTE), + }); + + const body = await failures(); + expect(body.waitingEmails).toEqual([]); + + // Once the grace window has passed since it came due, it counts. + await db('email_queue').update({ scheduled_at: ago(30 * MINUTE) }); + const later = await failures(); + expect(typesOf(later.waitingEmails)).toEqual(['invoice_due']); + }); + + it('finds a due row behind a page full of future-scheduled ones', async () => { + // Codex review round 2. The candidates used to be cut off with a single + // LIMIT before the time filter ran, so a queue holding a page of + // split-payment invoices scheduled for later hid the due row behind them + // and reported an empty waiting list — the false all-clear, again. + // Over the 1000-row cut-off the first attempt used, so the due row really + // does sit behind a full page rather than merely late in one. + const rows = []; + for (let i = 0; i < 1200; i += 1) { + rows.push({ + recipient_email: `bulk${i}@example.com`, + email_type: 'invoice_due', + email_data: '{}', + status: 'pending', + retry_count: 0, + created_at: ago(90 * MINUTE), + scheduled_at: ahead(30 * 24 * 60 * MINUTE), + }); + } + await db.batchInsert('email_queue', rows, 100); + await queue({ email_type: 'gallery_created', created_at: ago(52 * MINUTE) }); + + const body = await failures(); + expect(typesOf(body.waitingEmails)).toEqual(['gallery_created']); + }); + + it('flags a truncated scan, so an empty result cannot read as all-clear', async () => { + // Codex review round 3. The scan is bounded, so on a queue larger than the + // budget an overdue row can sit past the last page read. Reporting zero + // waiting there is "not found yet", not "none", and the UI keys its green + // check off this flag. + const body = await failures(); + expect(body.scanTruncated).toBe(false); + expect(body.counts.pendingScanned).toBe(0); + }); + + it('calls a report capped at the row limit truncated, not complete', async () => { + // Codex review round 4. The loop broke on the report cap before the + // truncation flag could be set, so 201+ overdue rows came back as exactly + // 200 with scanTruncated false — a partial report presented as the whole. + const rows = []; + for (let i = 0; i < 260; i += 1) { + rows.push({ + recipient_email: `overdue${i}@example.com`, + email_type: 'gallery_created', + email_data: '{}', + status: 'pending', + retry_count: 0, + created_at: ago(90 * MINUTE), + scheduled_at: ago(90 * MINUTE), + }); + } + await db.batchInsert('email_queue', rows, 100); + + const body = await failures(); + expect(body.counts.waitingEmails).toBe(200); + expect(body.scanTruncated).toBe(true); + }); + + it('reports what the queue processor last did', async () => { + const body = await failures(); + // Never started in this process — which is the condition that makes a + // pending row invisible, so the page has to be able to say it. + expect(body.processor).toEqual(expect.objectContaining({ started: false })); + expect(body.processor).toHaveProperty('lastRunAt'); + expect(body.processor).toHaveProperty('lastError'); + }); + + it('does not attribute a previous pass\'s totals to an idle one', async () => { + // Codex review round 1. The no-pending early return skipped the lastResult + // assignment, so after one pass that sent or failed something, every idle + // pass afterwards advanced lastRunAt while still reporting the old totals. + const { processEmailQueue, getQueueProcessorStatus } = require('../../src/services/emailProcessor'); + const transport = stubWebhookTransport(); + + try { + await queue({ email_type: 'gallery_created' }); + await processEmailQueue(); + const worked = getQueueProcessorStatus().lastResult; + expect(worked.processed).toBe(1); + expect(worked.sent + worked.failed).toBe(1); + + await db('email_queue').del(); + await processEmailQueue(); + + expect(getQueueProcessorStatus().lastResult).toEqual({ processed: 0, sent: 0, failed: 0 }); + } finally { + transport.restore(); + } + }); + + it('does not send from the retry endpoint, which would race the processor', async () => { + // Codex review round 1 asked for either a send-now action on waiting rows + // or no Retry on them at all. Round 3 showed why the first is the wrong + // half: nothing claims a row before the transport is invoked, so a flush + // overlapping the scheduled pass has both of them sending the same email. + // Retry stays a reset, and waiting rows carry no action at all. + const transport = stubWebhookTransport(); + + try { + await queue({ email_type: 'gallery_created' }); + const { id } = await db('email_queue').first('id'); + + const res = await request(app) + .post(`/admin/system-health/failures/email/${id}/retry`) + .set('Authorization', `Bearer ${token}`); + expect(res.status).toBe(200); + + expect(transport.send).not.toHaveBeenCalled(); + const after = await db('email_queue').where({ id }).first(); + expect(after.status).toBe('pending'); + expect(after.retry_count).toBe(0); + } finally { + transport.restore(); + } + }); + + it('surfaces the transport failure that makes every pass a no-op', async () => { + const { processEmailQueue, getQueueProcessorStatus } = require('../../src/services/emailProcessor'); + await queue({ email_type: 'gallery_created' }); + + // No SMTP configured, so initializeTransporter() yields nothing and the + // pass returns early. Before #1262 that left no trace anywhere. + await processEmailQueue(); + + expect(getQueueProcessorStatus().lastError).toMatch(/transporter could not be initialised/i); + const body = await failures(); + expect(body.processor.lastError).toMatch(/transporter could not be initialised/i); + expect(body.counts.waitingEmails).toBe(1); + }); +}); diff --git a/backend/__tests__/utils/queueTimestamps.test.js b/backend/__tests__/utils/queueTimestamps.test.js new file mode 100644 index 00000000..741b9ee4 --- /dev/null +++ b/backend/__tests__/utils/queueTimestamps.test.js @@ -0,0 +1,83 @@ +/** + * email_queue timestamps come back in three shapes and must all read as the + * same instant (#1262). + * + * The naive-string case is the one that bites in production and cannot be + * pinned from inside this suite: CI runs in UTC, where reading a zone-less + * timestamp as local time and as UTC give the same answer. So those two cases + * run in child processes with TZ forced, which is the only way to make the + * assertion fail on a machine where the bug does not reproduce. + */ +const { execFileSync } = require('child_process'); +const path = require('path'); + +const { toMillis } = require('../../src/utils/queueTimestamps'); + +const UTIL = path.resolve(__dirname, '../../src/utils/queueTimestamps.js'); + +/** Parse `value` in a fresh node process pinned to `tz`. */ +function parseUnderTz(tz, value) { + const script = ` + const { toMillis } = require(${JSON.stringify(UTIL)}); + process.stdout.write(String(toMillis(${JSON.stringify(value)}))); + `; + return Number(execFileSync(process.execPath, ['-e', script], { + env: { ...process.env, TZ: tz }, + encoding: 'utf8', + })); +} + +describe('toMillis — the shapes email_queue timestamps really have', () => { + const INSTANT = Date.UTC(2026, 8, 2, 12, 0, 0); + + it('reads a Date, as Postgres returns', () => { + expect(toMillis(new Date(INSTANT))).toBe(INSTANT); + }); + + it('reads epoch ms, as SQLite stores what queueEmail writes', () => { + expect(toMillis(INSTANT)).toBe(INSTANT); + expect(toMillis(String(INSTANT))).toBe(INSTANT); + }); + + it('reads an ISO string, as fixtures and older rows carry', () => { + expect(toMillis('2026-09-02T12:00:00.000Z')).toBe(INSTANT); + }); + + it('cannot read nulls or nonsense, and says so rather than guessing', () => { + // The caller skips a row it cannot judge; returning 0 or NaN here would + // report every such row as decades overdue. + expect(toMillis(null)).toBeNull(); + expect(toMillis(undefined)).toBeNull(); + expect(toMillis('')).toBeNull(); + expect(toMillis(' ')).toBeNull(); + expect(toMillis('not a timestamp')).toBeNull(); + }); + + describe('CURRENT_TIMESTAMP on SQLite, which carries no zone', () => { + // Both columns default to CURRENT_TIMESTAMP. SQLite renders that as + // 'YYYY-MM-DD HH:MM:SS' in UTC with no marker, and Date.parse reads that + // shape as LOCAL time. + const NAIVE = '2026-09-02 12:00:00'; + + it('is UTC west of Greenwich, where the old reading looked into the future', () => { + // Read as local in New York, this instant lands 4h later than it is, so + // a row due now looked 4h away and never reached the waiting list. + expect(parseUnderTz('America/New_York', NAIVE)).toBe(INSTANT); + }); + + it('is UTC east of it, where the old reading looked into the past', () => { + // Nine hours the other way: fresh mail read as long overdue, which fills + // the page with rows that are perfectly fine. + expect(parseUnderTz('Asia/Tokyo', NAIVE)).toBe(INSTANT); + }); + + it('agrees with itself across zones', () => { + expect(parseUnderTz('America/New_York', NAIVE)) + .toBe(parseUnderTz('Asia/Tokyo', NAIVE)); + }); + + it('accepts the fractional-seconds variant too', () => { + expect(parseUnderTz('America/New_York', '2026-09-02 12:00:00.000')).toBe(INSTANT); + }); + }); +}); diff --git a/backend/src/routes/adminSystem.js b/backend/src/routes/adminSystem.js index a1f8e987..8a5b2c34 100644 --- a/backend/src/routes/adminSystem.js +++ b/backend/src/routes/adminSystem.js @@ -9,6 +9,7 @@ const { formatBoolean } = require('../utils/dbCompat'); const logger = require('../utils/logger'); const { resolveSqlitePath } = require('../utils/databaseEngine'); const { checkForUpdates, getCurrentChannel, getCurrentVersion, getReleasesSince, compareVersions } = require('../services/updateCheckService'); +const { getQueueProcessorStatus } = require('../services/emailProcessor'); const { getAppSetting, upsertAppSetting } = require('../utils/appSettings'); const { parseWhatsNew } = require('../utils/whatsNew'); const { detectEnvironment, generateUpdateInstructions } = require('../services/environmentService'); @@ -346,7 +347,17 @@ router.get('/status', adminAuth, requirePermission(['settings.view', 'system.vie services: { fileWatcher: { status: 'active' }, // These would ideally check actual service status expirationChecker: { status: 'active' }, - emailProcessor: { status: 'active' } + // #1262 — this used to be hardcoded 'active', which reported a healthy + // worker on a deployment whose queue had never been touched. Report + // what the processor itself recorded instead. + emailProcessor: (() => { + const p = getQueueProcessorStatus(); + return { + status: p.started && !p.lastError ? 'active' : (p.started ? 'degraded' : 'stopped'), + lastRunAt: p.lastRunAt, + lastError: p.lastError, + }; + })() }, timestamp: new Date() }; diff --git a/backend/src/routes/adminSystemHealth.js b/backend/src/routes/adminSystemHealth.js index c1a60556..cf610b43 100644 --- a/backend/src/routes/adminSystemHealth.js +++ b/backend/src/routes/adminSystemHealth.js @@ -23,6 +23,8 @@ const { requirePermission } = require('../middleware/permissions'); const { handleAsync, validateRequest, successResponse } = require('../utils/routeHelpers'); const { verifyDocumentArtefacts } = require('../services/backupIntegrityService'); const { getCoverageReport } = require('../services/backupCoverageService'); +const { getQueueProcessorStatus } = require('../services/emailProcessor'); +const { toMillis } = require('../utils/queueTimestamps'); const { db } = require('../database/db'); const router = express.Router(); @@ -85,6 +87,53 @@ router.get( }), ); +/** + * How long an email may sit due-but-unsent before it counts as waiting rather + * than merely in flight. + * + * The processor wakes every 60s and takes 10 rows a pass, so it clears on the + * order of 100 rows inside this window — not thousands. A burst larger than + * that will therefore show up here for a while even though nothing is wrong, + * which is why the processor's own state is reported above this list rather + * than inferred from it: "running, last pass sent 10" next to a backlog reads + * very differently from "not running" next to the same backlog. + */ +const WAITING_EMAIL_GRACE_MS = 10 * 60 * 1000; + +/** + * Why the two time comparisons happen in JS (toMillis) and not in the WHERE + * clause: SQLite orders INTEGER before TEXT regardless of value, so comparing + * the ms-number this column really holds against a bound ISO string is true + * for EVERY row -- a mail queued one second ago reads as ten minutes overdue, + * and a scheduled_at years in the future reads as already due. Binding a Date + * instead is no fix either, since knex hands sqlite3 a Date the same way and + * jest's sandbox Dates stringify to "[object Object]" (see CLAUDE.md). + * + * The time filtering happens in JS, so the candidate rows have to be paged + * rather than cut off with a single LIMIT: a queue holding a thousand + * future-scheduled rows (split-payment invoices) would otherwise fill one page + * with rows that all get filtered out and hide the due row behind them, + * reporting an empty waiting list. Paging also removes the dependency on + * ORDER BY created_at being meaningful, which it is not on SQLite when numeric + * and text timestamps are mixed. + * + * WAITING_SCAN_MAX bounds the work: past it the response is explicitly a + * sample, which the 200-row cap already made it. + */ +const WAITING_PAGE_SIZE = 500; +const WAITING_SCAN_MAX = 10000; +const WAITING_REPORT_LIMIT = 200; + +const mapEmailRow = (r) => ({ + id: r.id, + recipientEmail: r.recipient_email, + emailType: r.email_type, + status: r.status, + retryCount: r.retry_count, + errorMessage: r.error_message, + createdAt: r.created_at, +}); + /** * GET /api/admin/system-health/failures * @@ -94,6 +143,14 @@ router.get( * (status='pending' AND retry_count >= 3 — the processor only picks up * retry_count < 3). Trigger: a 14h window where 'quote_sent' template * errors left invoices unsent with no admin-visible signal. + * + * #1262 added the other half. A queue nobody is working produces no failures + * at all: the rows sit at status='pending' with retry_count 0, matching + * neither branch above, and the page reported "all clear" while not one email + * had gone out. That happens whenever the processor never started, or every + * pass returns early because the transport will not initialise. So the + * response also carries emails that are DUE and still unsent + * (`waitingEmails`), plus what the processor itself last did (`processor`). */ router.get( '/failures', @@ -110,17 +167,81 @@ router.get( .limit(200) .select('id', 'recipient_email', 'email_type', 'status', 'retry_count', 'error_message', 'created_at'); + // Deliberately mirrors the processor's own pickup predicate — pending, + // under the retry cap, and past any scheduled_at — so a row listed here is + // one it should already have taken. Rows over the cap are the `stuckEmails` + // set above and must not be counted twice. + // + // Only the engine-safe half of that predicate runs in SQL; the two time + // comparisons are done in JS — see utils/queueTimestamps. + const now = Date.now(); + const dueBefore = now - WAITING_EMAIL_GRACE_MS; + const isWaiting = (r) => { + const scheduledAt = toMillis(r.scheduled_at); + // Parked for later on purpose — split-payment invoices, the + // business-hours floor. Not being sent yet is the point of those. + if (scheduledAt !== null && scheduledAt > now) return false; + const createdAt = toMillis(r.created_at); + // An unreadable created_at cannot be judged overdue; leave it alone + // rather than reporting every such row as waiting. + if (createdAt === null) return false; + // The grace window runs from the moment the row became DUE, not from + // when it was queued. An invoice created three days ago and scheduled + // until a minute ago has had one minute of the processor's attention, + // not three days of it — measuring from created_at would report every + // split-payment and business-hours mail as unworked the instant it came + // due, which is most of what this panel would then be showing. + const dueSince = scheduledAt === null ? createdAt : Math.max(createdAt, scheduledAt); + return dueSince <= dueBefore; + }; + + const waitingEmails = []; + let scanTruncated = false; + let scanned = 0; + for (let offset = 0; offset < WAITING_SCAN_MAX; offset += WAITING_PAGE_SIZE) { + // eslint-disable-next-line no-await-in-loop + const page = await db('email_queue') + .where('status', 'pending') + .where('retry_count', '<', 3) + .orderBy('id', 'asc') + .offset(offset) + .limit(WAITING_PAGE_SIZE) + .select('id', 'recipient_email', 'email_type', 'status', 'retry_count', + 'error_message', 'created_at', 'scheduled_at'); + if (page.length === 0) break; + let examined = 0; + for (const row of page) { + examined += 1; + if (isWaiting(row)) waitingEmails.push(row); + if (waitingEmails.length >= WAITING_REPORT_LIMIT) break; + } + scanned += examined; + if (waitingEmails.length >= WAITING_REPORT_LIMIT) { + // Stopped because the response is full, not because the queue is. Any + // row left unexamined -- in this page or in pages after it -- may also + // be waiting, so the count is a floor and the report is partial. + scanTruncated = examined < page.length || page.length === WAITING_PAGE_SIZE; + break; + } + if (page.length < WAITING_PAGE_SIZE) break; + // Ran out of budget with rows still unread. A queue this size whose head + // is all future-scheduled could be hiding a due row past the cap, so the + // empty result below is "not found yet", not "none" — and the UI must + // not turn it into an all-clear. + if (offset + WAITING_PAGE_SIZE >= WAITING_SCAN_MAX) scanTruncated = true; + } + return successResponse(res, { - stuckEmails: stuckEmails.map((r) => ({ - id: r.id, - recipientEmail: r.recipient_email, - emailType: r.email_type, - status: r.status, - retryCount: r.retry_count, - errorMessage: r.error_message, - createdAt: r.created_at, - })), - counts: { stuckEmails: stuckEmails.length }, + stuckEmails: stuckEmails.map(mapEmailRow), + waitingEmails: waitingEmails.map(mapEmailRow), + processor: getQueueProcessorStatus(), + counts: { + stuckEmails: stuckEmails.length, + waitingEmails: waitingEmails.length, + pendingScanned: scanned, + }, + // True when the pending queue was larger than this endpoint will read. + scanTruncated, }); }), ); @@ -129,6 +250,28 @@ router.get( * POST /failures/email/:id/retry — re-queue a stuck email (status back to * pending, retry_count reset, error cleared, scheduled_at cleared so the * 60s processor picks it up on its next pass). + * + * Deliberately does NOT send the mail itself. An earlier revision flushed the + * row here via processEmailQueue({ onlyId }), which reads better but races: + * nothing claims a row before the transport is invoked, so a flush overlapping + * the scheduled pass has both of them sending the same email. Saving 60 + * seconds is not worth a duplicate landing in a customer's inbox. + * + * That is also why waiting rows carry no actions at all — they are already + * pending with retries and schedule clear, so this endpoint would rewrite them + * to the state they are in and change nothing. What a waiting row needs is the + * processor fixed, which the panel above it says. + * + * KNOWN, deliberate: clearing scheduled_at leaves created_at at the original + * enqueue time, so a retried old row shows up in the waiting list right away + * looking overdue, until the processor sends it on its next tick. Restarting + * that clock needs a timestamp written here, and there is no shape that works: + * a Date matches how queueEmail writes the column and how processEmailQueue + * compares it, but jest's sandbox Dates store as "[object Object]" (CLAUDE.md) + * so it cannot be tested; an ISO string tests fine but stores as TEXT, and + * SQLite then orders it above the numeric bound in the processor's own pickup + * query, leaving the row unsendable. A requeued_at column would settle it. + * Cosmetic either way, and not worth risking a stuck row for. */ router.post( '/failures/email/:id/retry', diff --git a/backend/src/services/emailProcessor.js b/backend/src/services/emailProcessor.js index 7b1b9bdf..6d0aab60 100644 --- a/backend/src/services/emailProcessor.js +++ b/backend/src/services/emailProcessor.js @@ -922,9 +922,32 @@ async function renderQueuedEmail(templateKey, variables = {}, to = '') { // because ignoreSchedule also bypasses that cap. // // Returns { processed, sent, failed }. +// What the last pass actually did, so System Health can say whether the queue +// is being worked at all (#1262). "Queued" is not "delivered", and the two +// ways a queue silently stops -- the processor never started, or every pass +// returns early because the transport will not initialise -- both leave rows +// at status='pending' with retry_count 0, which no failure query matches. +const processorStatus = { + started: false, + lastRunAt: null, + lastResult: null, + lastError: null, +}; + +function getQueueProcessorStatus() { + return { + started: processorStatus.started, + lastRunAt: processorStatus.lastRunAt, + lastResult: processorStatus.lastResult, + lastError: processorStatus.lastError, + }; +} + async function processEmailQueue({ ignoreSchedule = false, limit = 10, onlyId = null } = {}) { logger.info('Email queue processor: Checking for pending emails...'); const result = { processed: 0, sent: 0, failed: 0 }; + processorStatus.lastRunAt = new Date().toISOString(); + processorStatus.lastError = null; try { // Try to initialize transporter if it's null (in case it failed at startup). @@ -937,6 +960,10 @@ async function processEmailQueue({ ignoreSchedule = false, limit = 10, onlyId = transporter = await initializeTransporter(); if (!transporter) { logger.warn('Email transporter could not be initialized, skipping queue processing'); + // #1262 — the row stays pending with retry_count 0, so nothing in the + // queue itself records that this pass did nothing. Say so here. + processorStatus.lastError = 'Email transporter could not be initialised — check the SMTP settings'; + processorStatus.lastResult = result; return result; } } @@ -969,11 +996,18 @@ async function processEmailQueue({ ignoreSchedule = false, limit = 10, onlyId = .limit(limit); } catch (dbError) { logger.error('Failed to query email queue:', dbError); + processorStatus.lastError = dbError.message; + processorStatus.lastResult = result; return result; } if (pendingEmails.length === 0) { logger.info('Email queue processor: No pending emails found'); + // Record the empty pass too. Without this an idle pass advances + // lastRunAt and clears lastError but leaves the PREVIOUS pass's + // sent/failed totals in place, so System Health attributes them to a run + // that sent nothing. + processorStatus.lastResult = result; return result; } @@ -1043,8 +1077,10 @@ async function processEmailQueue({ ignoreSchedule = false, limit = 10, onlyId = } } catch (error) { logger.error('Error processing email queue:', error); + processorStatus.lastError = error.message; } + processorStatus.lastResult = result; return result; } @@ -1203,6 +1239,7 @@ function startEmailQueueProcessor() { }); }, 60000); + processorStatus.started = true; logger.info('Email queue processor started successfully'); } else { logger.info('Email queue processor: Already running'); @@ -1213,6 +1250,7 @@ function stopEmailQueueProcessor() { if (emailQueueInterval) { clearInterval(emailQueueInterval); emailQueueInterval = null; + processorStatus.started = false; logger.info('Email queue processor stopped'); } } @@ -1231,6 +1269,7 @@ module.exports = { sendRawEmail, renderQueuedEmail, processEmailQueue, + getQueueProcessorStatus, queueEmail, stopEmailQueueProcessor, testEmailConnection, diff --git a/backend/src/utils/queueTimestamps.js b/backend/src/utils/queueTimestamps.js new file mode 100644 index 00000000..2ccb5068 --- /dev/null +++ b/backend/src/utils/queueTimestamps.js @@ -0,0 +1,44 @@ +/** + * Reading email_queue timestamps back, whatever shape the engine stored them in. + * + * The columns are written three different ways and read back three different + * ways, and a comparison that assumes one of them is wrong for the other two: + * + * - Postgres hands back a Date. + * - SQLite stores what queueEmail writes -- a JS Date, which the native + * binding turns into epoch ms -- and hands back that number. + * - Both columns also default to CURRENT_TIMESTAMP, which on SQLite is a + * zone-less 'YYYY-MM-DD HH:MM:SS' string in UTC, and older rows plus test + * fixtures carry ISO strings. + * + * Extracted from adminSystemHealth so the parsing can be tested under a forced + * TZ in a child process, which is the only way to pin the naive-timestamp case + * from a test suite that itself runs in UTC (#1262). + */ + +/** 'YYYY-MM-DD HH:MM:SS[.sss]' with no zone — SQLite's CURRENT_TIMESTAMP shape. */ +const SQLITE_NAIVE_TIMESTAMP = /^\d{4}-\d{2}-\d{2}[ T]\d{2}:\d{2}:\d{2}(\.\d+)?$/; + +/** + * @param {Date|number|string|null|undefined} value + * @returns {number|null} epoch ms, or null when the value cannot be read + */ +function toMillis(value) { + if (value == null) return null; + if (value instanceof Date) return value.getTime(); + if (typeof value === 'number') return value; + const text = String(value).trim(); + if (text === '') return null; + // A numeric string is epoch ms; anything else goes through Date.parse. + const numeric = Number(text); + if (Number.isFinite(numeric)) return numeric; + // Date.parse reads the zone-less shape as LOCAL time. On a + // TZ=America/New_York deployment that puts a row due now four hours in the + // future, so it never reaches the waiting list -- the false all-clear again, + // arrived at via the clock. Stamp the zone the value actually carries. + const stamped = SQLITE_NAIVE_TIMESTAMP.test(text) ? `${text.replace(' ', 'T')}Z` : text; + const parsed = Date.parse(stamped); + return Number.isNaN(parsed) ? null : parsed; +} + +module.exports = { toMillis, SQLITE_NAIVE_TIMESTAMP }; diff --git a/frontend/src/features/settings/tabs/StatusTab.tsx b/frontend/src/features/settings/tabs/StatusTab.tsx index dbfae259..75be8252 100644 --- a/frontend/src/features/settings/tabs/StatusTab.tsx +++ b/frontend/src/features/settings/tabs/StatusTab.tsx @@ -10,6 +10,7 @@ import { Ruler, CalendarClock, RotateCw, + AlertTriangle, } from 'lucide-react'; import { Button, Card, Input } from '../../../components/common'; import { useTranslation } from 'react-i18next'; @@ -585,12 +586,30 @@ export const StatusTab: React.FC = ({

{t('settings.systemStatus.expirationCheckerDesc')}

+ {/* #1262 — this card used to render a green check unconditionally, + against an API field that was itself the literal 'active'. Both + ends now tell the truth: a stopped or bailing processor is the + reason queued mail never arrives, and this is one of the two + places an admin looks to find that out. */}

{t('settings.systemStatus.emailProcessor')}

- + {systemStatus?.services?.emailProcessor?.status === 'active' ? ( + + ) : ( + + )}
-

{t('settings.systemStatus.emailProcessorDesc')}

+

+ {systemStatus?.services?.emailProcessor?.status === 'stopped' + ? t('settings.systemStatus.emailProcessorStopped', + 'Not running — queued emails are written but nothing sends them.') + : systemStatus?.services?.emailProcessor?.status === 'degraded' + ? t('settings.systemStatus.emailProcessorDegraded', + 'Running, but the last pass could not send: {{error}}', + { error: systemStatus?.services?.emailProcessor?.lastError }) + : t('settings.systemStatus.emailProcessorDesc')} +

diff --git a/frontend/src/i18n/locales/de.json b/frontend/src/i18n/locales/de.json index a2c54391..8e88b6a4 100644 --- a/frontend/src/i18n/locales/de.json +++ b/frontend/src/i18n/locales/de.json @@ -107,7 +107,30 @@ "error": "Fehler", "queued": "Eingereiht", "actions": "Aktionen" - } + }, + "emptyNotAllClear": "Nichts ist fehlgeschlagen — beachten Sie aber die Hinweise oben." + }, + "waitingEmails": { + "title": "Wartet auf Versand", + "empty": "Nichts in Wartestellung — die Warteschlange wird abgearbeitet.", + "description": "Vor über 10 Minuten eingereiht, jetzt fällig und weiterhin nicht versendet. Diese E-Mails sind nicht fehlgeschlagen — es hat niemand versucht, sie zu senden.", + "neverAttempted": "kein Versuch", + "attempted": "{{count}} Versuch(e), letzter Fehler: {{error}}", + "unknownError": "unbekannt", + "col": { + "attempts": "Versuche" + }, + "emptyButUnworked": "Noch ist nichts überfällig, es sendet aber auch nichts — siehe Prozessor oben. Alles ab jetzt Eingereihte bleibt hier liegen.", + "truncated": "Die Warteschlange ist zu groß, um sie vollständig zu prüfen — in den gelesenen Zeilen war nichts überfällig, das ist aber keine Entwarnung." + }, + "processor": { + "title": "E-Mail-Warteschlangen-Prozessor", + "running": "Läuft.", + "stopped": "Läuft auf dieser Instanz nicht. Eingereihte E-Mails werden in die Datenbank geschrieben, aber niemand versendet sie.", + "degraded": "Läuft, aber der letzte Durchlauf konnte nicht senden: {{error}}", + "lastRun": "Letzter Durchlauf {{when}}", + "neverRan": "Seit dem Start dieser Instanz nicht gelaufen.", + "lastResult": "{{sent}} gesendet, {{failed}} fehlgeschlagen" } }, "common": { @@ -1324,6 +1347,7 @@ "resetGalleryPassword": "Galerie-Passwort zurücksetzen", "resendCreationEmail": "Erstellungs-E-Mail erneut senden", "creationEmailResent": "Die Erstellungs-E-Mail wurde zur Warteschlange hinzugefügt", + "emailQueuedHint": "Der Warteschlangen-Prozessor versendet sie — prüfen Sie den Systemzustand, falls sie nicht ankommt.", "failedToResendEmail": "Fehler beim erneuten Senden der Erstellungs-E-Mail", "photoStatistics": "Fotostatistiken", "managePhotos": "Fotos verwalten", @@ -1944,7 +1968,9 @@ "pending": "Ausstehend", "sent": "Gesendet", "failed": "Fehlgeschlagen", - "lastUpdate": "Letzte Aktualisierung" + "lastUpdate": "Letzte Aktualisierung", + "emailProcessorStopped": "Läuft nicht — eingereihte E-Mails werden geschrieben, aber niemand versendet sie.", + "emailProcessorDegraded": "Läuft, aber der letzte Durchlauf konnte nicht senden: {{error}}" }, "photoDimensions": { "title": "Foto-Abmessungen", diff --git a/frontend/src/i18n/locales/en.json b/frontend/src/i18n/locales/en.json index f4762a49..aa7c8ce4 100644 --- a/frontend/src/i18n/locales/en.json +++ b/frontend/src/i18n/locales/en.json @@ -107,7 +107,30 @@ "error": "Error", "queued": "Queued", "actions": "Actions" - } + }, + "emptyNotAllClear": "Nothing has failed — but see above." + }, + "waitingEmails": { + "title": "Waiting to send", + "empty": "Nothing waiting — the queue is being worked.", + "description": "Queued more than 10 minutes ago, due now, and still unsent. These have not failed — nothing has tried to send them.", + "neverAttempted": "never attempted", + "attempted": "{{count}} attempt(s), last error: {{error}}", + "unknownError": "unknown", + "col": { + "attempts": "Attempts" + }, + "emptyButUnworked": "Nothing is overdue yet, but nothing is sending either — see the processor above. Anything queued from now on will sit here.", + "truncated": "The pending queue is too large to check in full — nothing overdue was found in the rows read, but this is not an all-clear." + }, + "processor": { + "title": "Email queue processor", + "running": "Running.", + "stopped": "Not running on this instance. Queued emails are written to the database but nothing is sending them.", + "degraded": "Running, but the last pass could not send: {{error}}", + "lastRun": "Last pass {{when}}", + "neverRan": "Has not run since this instance started.", + "lastResult": "{{sent}} sent, {{failed}} failed" } }, "common": { @@ -820,6 +843,7 @@ "resetGalleryPassword": "Reset Gallery Password", "resendCreationEmail": "Resend Creation Email", "creationEmailResent": "Creation email has been queued for sending", + "emailQueuedHint": "The queue processor sends it — check System health if it does not arrive.", "failedToResendEmail": "Failed to resend creation email", "photoStatistics": "Photo Statistics", "totalPhotos": "Total Photos", @@ -1307,7 +1331,9 @@ "pending": "Pending", "sent": "Sent", "failed": "Failed", - "lastUpdate": "Last update" + "lastUpdate": "Last update", + "emailProcessorStopped": "Not running — queued emails are written but nothing sends them.", + "emailProcessorDegraded": "Running, but the last pass could not send: {{error}}" }, "photoDimensions": { "title": "Photo Dimensions", diff --git a/frontend/src/pages/admin/EventDetailsPage.tsx b/frontend/src/pages/admin/EventDetailsPage.tsx index da2066b1..01810dd0 100644 --- a/frontend/src/pages/admin/EventDetailsPage.tsx +++ b/frontend/src/pages/admin/EventDetailsPage.tsx @@ -316,11 +316,13 @@ export const EventDetailsPage: React.FC = () => { mutationFn: (password?: string) => eventsService.sendGalleryEmail(parseInt(id!), password ? { password } : undefined), onSuccess: (result) => { + // #1262 — queueing is not delivery, and a queue nobody is working + // reports no failure at all. Point at where the queue is visible. toast.success( - t('events.sendGalleryEmail.success', { + `${t('events.sendGalleryEmail.success', { recipient: result.recipient, defaultValue: 'Gallery email queued to {{recipient}}.', - }), + })} ${t('events.emailQueuedHint', 'The queue processor sends it — check System health if it does not arrive.')}`, ); setShowSendEmailDialog(false); }, diff --git a/frontend/src/pages/admin/SystemHealthPage.tsx b/frontend/src/pages/admin/SystemHealthPage.tsx index 21198aa2..ee84f8ca 100644 --- a/frontend/src/pages/admin/SystemHealthPage.tsx +++ b/frontend/src/pages/admin/SystemHealthPage.tsx @@ -2,15 +2,22 @@ * Admin → System health. Aggregates background failures that would * otherwise go unnoticed. v1: stuck/failed outbound emails (the queue * processor gave up or exhausted retries), with retry + dismiss. + * + * #1262 — "no failures" was being read as "everything went out". It is not the + * same claim: a queue nobody is working produces no failures at all, because + * every row sits at status='pending' with retry_count 0. So the page now leads + * with what the processor itself last did, and lists due-but-unsent emails + * next to the failed ones. The all-clear only shows when both are empty and + * the processor is running. */ import React from 'react'; import { useTranslation } from 'react-i18next'; import { useQuery } from '@tanstack/react-query'; -import { AlertCircle, RefreshCw, Trash2, CheckCircle } from 'lucide-react'; +import { AlertCircle, RefreshCw, Trash2, CheckCircle, Clock, Mail, MailX } from 'lucide-react'; import { Button, Card, Loading } from '../../components/common'; import { useMutationWithToast } from '../../hooks'; import { useLocalizedDate } from '../../hooks/useLocalizedDate'; -import { systemHealthService } from '../../services/systemHealth.service'; +import { systemHealthService, type StuckEmail } from '../../services/systemHealth.service'; export const SystemHealthPage: React.FC = () => { const { t } = useTranslation(); @@ -35,6 +42,97 @@ export const SystemHealthPage: React.FC = () => { }); const stuckEmails = data?.stuckEmails ?? []; + const waitingEmails = data?.waitingEmails ?? []; + const processor = data?.processor; + // The endpoint stops reading after a bounded number of pending rows. Past + // that, an empty waiting list means "nothing found yet", not "nothing" — so + // it must not turn into a green check. + const scanTruncated = data?.scanTruncated ?? false; + + // The processor is only "fine" when it has been started AND its last pass + // didn't bail. A started-but-erroring processor is the case that used to + // read as healthy, so it gets its own state rather than folding into either. + const processorState: 'ok' | 'degraded' | 'stopped' = !processor + ? 'ok' + : !processor.started + ? 'stopped' + : processor.lastError + ? 'degraded' + : 'ok'; + + /** + * `actions` is off for waiting rows, and deliberately so. Retry would + * rewrite a row that is already pending / retry_count 0 / unscheduled to the + * state it is in, and Dismiss would permanently delete an email that has not + * failed and will still go out once the processor recovers — a click on a + * health warning silently cancelling a customer's mail. + */ + const emailTable = (rows: StuckEmail[], showError: boolean, actions = true) => ( +
+
+ + + + + + + + {actions && ( + + )} + + + + {rows.map((m) => ( + + + + + + {actions && ( + + )} + + ))} + +
{t('systemHealth.stuckEmails.col.recipient', 'Recipient')}{t('systemHealth.stuckEmails.col.type', 'Type')} + {showError + ? t('systemHealth.stuckEmails.col.error', 'Error') + : t('systemHealth.waitingEmails.col.attempts', 'Attempts')} + {t('systemHealth.stuckEmails.col.queued', 'Queued')}{t('systemHealth.stuckEmails.col.actions', 'Actions')}
{m.recipientEmail}{m.emailType} + {showError ? ( + + {m.errorMessage || t('systemHealth.stuckEmails.noError', 'retries exhausted')} + + ) : ( + + {m.retryCount > 0 + ? t('systemHealth.waitingEmails.attempted', '{{count}} attempt(s), last error: {{error}}', { + count: m.retryCount, + error: m.errorMessage || t('systemHealth.waitingEmails.unknownError', 'unknown'), + }) + : t('systemHealth.waitingEmails.neverAttempted', 'never attempted')} + + )} + {m.createdAt ? fmtDateTime(m.createdAt) : '—'} +
+ + +
+
+
+
+ ); return (
@@ -45,6 +143,94 @@ export const SystemHealthPage: React.FC = () => {

+ {/* Queue processor. Listed first because when this is stopped, every + other count on the page is explained by it — and a stopped processor + shows no failures at all, which is what made it invisible. */} + {!isLoading && processor && ( + +
+ {processorState === 'ok' + ? + : } +
+

+ {t('systemHealth.processor.title', 'Email queue processor')} +

+

+ {processorState === 'stopped' + ? t('systemHealth.processor.stopped', + 'Not running on this instance. Queued emails are written to the database but nothing is sending them.') + : processorState === 'degraded' + ? t('systemHealth.processor.degraded', + 'Running, but the last pass could not send: {{error}}', { error: processor.lastError }) + : t('systemHealth.processor.running', 'Running.')} +

+

+ {processor.lastRunAt + ? t('systemHealth.processor.lastRun', 'Last pass {{when}}', { when: fmtDateTime(processor.lastRunAt) }) + : t('systemHealth.processor.neverRan', 'Has not run since this instance started.')} + {processor.lastResult && ( + <> {' · '} + {t('systemHealth.processor.lastResult', '{{sent}} sent, {{failed}} failed', { + sent: processor.lastResult.sent, + failed: processor.lastResult.failed, + })} + + )} +

+
+
+ + )} + + {/* Due but unsent. Distinct from failed: nothing went wrong with these, + they were simply never picked up. */} + +
+ +

+ {t('systemHealth.waitingEmails.title', 'Waiting to send')} +

+ {!isLoading && ( + ({waitingEmails.length}) + )} +
+ + {isLoading ? : waitingEmails.length === 0 ? ( + // "Nothing waiting" is only reassuring when something is working the + // queue. A processor that stopped a minute ago has no waiting rows + // yet either — the grace window has not elapsed — and a green check + // there is the same false all-clear this page exists to remove. + processorState === 'ok' && !scanTruncated ? ( +
+ + {t('systemHealth.waitingEmails.empty', 'Nothing waiting — the queue is being worked.')} +
+ ) : ( +
+ + {scanTruncated + ? t('systemHealth.waitingEmails.truncated', + 'The pending queue is too large to check in full — nothing overdue was found in the rows read, but this is not an all-clear.') + : t('systemHealth.waitingEmails.emptyButUnworked', + 'Nothing is overdue yet, but nothing is sending either — see the processor above. Anything queued from now on will sit here.')} +
+ ) + ) : ( + <> +

+ {t('systemHealth.waitingEmails.description', + 'Queued more than 10 minutes ago, due now, and still unsent. These have not failed — nothing has tried to send them.')} +

+ {emailTable(waitingEmails, false, false)} + + )} + +
@@ -59,55 +245,15 @@ export const SystemHealthPage: React.FC = () => { {isLoading ? : stuckEmails.length === 0 ? (
- {t('systemHealth.stuckEmails.empty', 'No stuck or failed emails — all clear.')} + {/* "all clear" is a claim about the whole queue, so it is only + allowed when the whole queue is clear. With mail waiting or a + processor that is not working, this section is still empty but + the system is not fine. */} + {waitingEmails.length === 0 && processorState === 'ok' && !scanTruncated + ? t('systemHealth.stuckEmails.empty', 'No stuck or failed emails — all clear.') + : t('systemHealth.stuckEmails.emptyNotAllClear', 'Nothing has failed — but see above.')}
- ) : ( -
-
- - - - - - - - - - - - {stuckEmails.map((m) => ( - - - - - - - - ))} - -
{t('systemHealth.stuckEmails.col.recipient', 'Recipient')}{t('systemHealth.stuckEmails.col.type', 'Type')}{t('systemHealth.stuckEmails.col.error', 'Error')}{t('systemHealth.stuckEmails.col.queued', 'Queued')}{t('systemHealth.stuckEmails.col.actions', 'Actions')}
{m.recipientEmail}{m.emailType} - - {m.errorMessage || t('systemHealth.stuckEmails.noError', 'retries exhausted')} - - {m.createdAt ? fmtDateTime(m.createdAt) : '—'} -
- - -
-
-
-
- )} + ) : emailTable(stuckEmails, true)}
); diff --git a/frontend/src/pages/admin/event-details/ShareLinkCard.tsx b/frontend/src/pages/admin/event-details/ShareLinkCard.tsx index 8b7f4c7d..859fccd8 100644 --- a/frontend/src/pages/admin/event-details/ShareLinkCard.tsx +++ b/frontend/src/pages/admin/event-details/ShareLinkCard.tsx @@ -193,7 +193,10 @@ export const ShareLinkCard: React.FC = ({ event, setShowPass onClick={async () => { try { await eventsService.resendCreationEmail(event.id); - toast.success(t('events.creationEmailResent')); + // #1262 — "queued" was being read as "delivered". Queueing only + // writes an email_queue row; say where to look when it doesn't + // turn up, because a queue nobody is working raises no failure. + toast.success(`${t('events.creationEmailResent')} ${t('events.emailQueuedHint', 'The queue processor sends it — check System health if it does not arrive.')}`); } catch { toast.error(t('events.failedToResendEmail')); } diff --git a/frontend/src/services/settings.service.ts b/frontend/src/services/settings.service.ts index f7de882c..9d4b8c18 100644 --- a/frontend/src/services/settings.service.ts +++ b/frontend/src/services/settings.service.ts @@ -164,7 +164,9 @@ export interface SystemStatus { services: { fileWatcher: { status: string }; expirationChecker: { status: string }; - emailProcessor: { status: string }; + // 'active' | 'degraded' | 'stopped' (#1262). Was a hardcoded 'active' + // until the processor started reporting what it actually did. + emailProcessor: { status: string; lastRunAt?: string | null; lastError?: string | null }; }; timestamp: string; } diff --git a/frontend/src/services/systemHealth.service.ts b/frontend/src/services/systemHealth.service.ts index 2dd84035..2cdc9dc9 100644 --- a/frontend/src/services/systemHealth.service.ts +++ b/frontend/src/services/systemHealth.service.ts @@ -1,6 +1,10 @@ /** * Admin → System health. Surfaces background failures (v1: stuck/failed * outbound emails) so they don't sit unnoticed, with retry/dismiss. + * + * #1262 added `waitingEmails` and `processor`: a queue nobody is working + * produces no failures at all, so "no failures" was not the same claim as + * "everything went out". */ import { api } from '../config/api'; @@ -14,9 +18,23 @@ export interface StuckEmail { createdAt: string; } +/** What the queue processor last did — the difference between "idle" and "dead". */ +export interface EmailProcessorStatus { + started: boolean; + lastRunAt: string | null; + lastResult: { processed: number; sent: number; failed: number } | null; + lastError: string | null; +} + export interface SystemHealthFailures { stuckEmails: StuckEmail[]; - counts: { stuckEmails: number }; + /** Due, under the retry cap, and still unsent — nobody picked them up. */ + waitingEmails: StuckEmail[]; + processor: EmailProcessorStatus; + /** The pending queue was larger than the endpoint reads — an empty + * `waitingEmails` then means "nothing found yet", not "nothing". */ + scanTruncated?: boolean; + counts: { stuckEmails: number; waitingEmails: number; pendingScanned?: number }; } export const systemHealthService = {