fix(crm): pass trx to logActivity inside transactions — audit rows silently lost on SQLite (#851)

* fix(crm): pass trx to logActivity inside transactions — audit rows were silently lost on SQLite

createContract, updateContract, createStorno and reissueInvoice called
logActivity() (contract paths also adminActor()) from inside a knex
transaction without the trx executor — the pattern db.js:648's comment
explicitly warns about. On single-connection SQLite the audit insert
waits on a second pool connection while the trx holds the only one:
a 60s acquire-timeout stall per call, then logActivity's catch swallows
the failure and the audit row is silently lost. Postgres unaffected.

Fix mirrors the one call site that already did it right
(contract_created_from_quote, conversions.js): resolve the audit actor
before the transaction opens and pass trx as logActivity's executor so
the insert rides the transaction's connection.

Verified NOT affected (logActivity outside any trx, unchanged):
cancelContract, contract_converted_to_event, contract_signed_by_customer,
contract_sent, invoice_sent/_cancelled(draft)/_released/monthly_bill.

Found by the #587 integration-test work (PR #850, which shrank the pool
acquire timeout to tolerate the stall — that workaround can be dropped
once both land).

* fix(crm): run reissueInvoice's createInvoice without a wrapping transaction (codex review of #851)

The round-1 fix passed trx to the reissue audit call — but that point
was never reached on single-connection SQLite: createInvoice internally
reads via the global connection (businessProfileService.getProfile,
getAppSetting, bank-account resolution), so the outer trx deadlocked
first and aborted the replacement AFTER the Storno had already
committed and been emailed.

createInvoice's five other callers all run it without a trx; reissue
now does the same and backlinks afterwards. Trade-off documented in
code: replacement + backlink are no longer atomic — a crash between
them leaves a visible draft without replaces_invoice_id, which beats
the guaranteed stall. New regression test drives a full cancel+reissue
on the SQLite harness and pins the invoice_reissued audit row.

* fix(crm): restore the reissue transaction by routing createInvoice's reads through trx (codex review of #851, round 2)

Round 2 was right that dropping the wrapping transaction traded the
deadlock for orphan drafts: createInvoice inserts the invoice row and
claims a sequence number BEFORE line-item validation can throw, so a
failed reissue would persist partial state after the Storno committed.

Proper fix: the transaction is back, and every read inside createInvoice
now rides it — getProfile and resolveBankAccountForCurrency gained an
optional conn param (default db, all other callers unchanged),
getAppSetting calls pass trx (crm_invoice_round_total + the
resolveNetDays default the regression test flushed out), and the
invoice_created audit uses the trx executor. The reissue regression test
now proves a full cancel+reissue commits atomically on single-connection
SQLite.
This commit is contained in:
Paul Nothaft
2026-07-19 22:36:52 +02:00
committed by GitHub
parent 997a85cdbc
commit a6a3c9f9f8
6 changed files with 202 additions and 19 deletions
@@ -0,0 +1,155 @@
/**
* Regression tests for logActivity calls inside transactions (#850 review
* find). createContract / updateContract / createStorno / reissueInvoice
* called logActivity() (and contract paths also adminActor()) from inside
* a knex transaction WITHOUT the trx executor. On single-connection SQLite
* the audit insert then waits on a second pool connection while the trx
* holds the only one — a 60s acquire-timeout stall per call, after which
* logActivity's catch swallows the failure and the audit row is silently
* lost. Postgres was unaffected.
*
* The observable fix: the activity_logs rows now exist, and the calls
* complete without waiting on the pool. The shrunken acquire timeout
* below makes any reintroduced deadlock fail the test quickly instead
* of appearing to pass after a long stall.
*/
const path = require('path');
const {
bootCrmDb, seedMinimal, assignAdminRole,
} = require('../integration/helpers/crmDb');
jest.setTimeout(120000);
let db;
let cleanup;
let tmpDir;
let adminId;
let customerId;
let contractService;
let invoiceService;
const prevCwd = process.cwd();
beforeAll(async () => {
({ db, cleanup, tmpDir } = await bootCrmDb());
// Business-doc artifacts land under process.cwd()/storage — isolate.
process.chdir(tmpDir);
// A reintroduced in-trx pool grab should fail fast (2s), not stall 60s.
db.client.pool.acquireTimeoutMillis = 2000;
// node-sqlite3 detects Date bindings via the NATIVE realm's Date —
// under jest's vm sandbox that check fails and Dates stringify to
// "[object Object]". Normalize to ISO strings on the client prototype
// (transaction clients are Object.create()d from it). Same shim as
// crmMintPaths.test.js.
const clientProto = Object.getPrototypeOf(db.client);
const origQuery = clientProto._query;
clientProto._query = function patchedQuery(connection, obj) {
if (obj && Array.isArray(obj.bindings)) {
obj.bindings = obj.bindings.map(
(b) => (b && typeof b === 'object' && typeof b.toISOString === 'function' ? b.toISOString() : b),
);
}
return origQuery.call(this, connection, obj);
};
({ adminId, customerId } = await seedMinimal(db));
await assignAdminRole(db, adminId, 'super_admin');
contractService = require('../../src/services/contractService');
invoiceService = require('../../src/services/invoiceService');
}, 120000);
afterAll(async () => {
process.chdir(prevCwd);
if (cleanup) await cleanup();
});
test('createContract persists the contract_created audit row (was silently lost on SQLite)', async () => {
const contractId = await contractService.createContract({
customerAccountId: customerId,
title: 'Audit-Trail-Vertrag',
}, adminId);
const row = await db('activity_logs')
.where({ activity_type: 'contract_created' })
.orderBy('id', 'desc')
.first();
expect(row).toBeTruthy();
expect(JSON.parse(row.metadata).contractId).toBe(contractId);
expect(row.actor_type).toBe('admin');
});
test('updateContract persists the contract_updated audit row', async () => {
const contractId = await contractService.createContract({
customerAccountId: customerId,
title: 'Vorher',
}, adminId);
await contractService.updateContract(contractId, { title: 'Nachher' }, adminId);
const row = await db('activity_logs')
.where({ activity_type: 'contract_updated' })
.orderBy('id', 'desc')
.first();
expect(row).toBeTruthy();
expect(JSON.parse(row.metadata).contractId).toBe(contractId);
});
test('cancelInvoice (Storno mint) persists the invoice_cancelled_via_storno audit row', async () => {
const { invoiceIds } = await invoiceService.createInvoice({
customerAccountId: customerId,
currency: 'CHF',
vatRate: 0,
lineItems: [
{ position: 1, quantity: 1, description: 'Coverage', unit_price_minor: 100000, discount_percent: 0 },
],
}, adminId);
const id = invoiceIds[0];
await db('invoices').where({ id }).update({ status: 'sent', sent_at: new Date(), updated_at: new Date() });
const result = await invoiceService.cancelInvoice(id, adminId);
expect(result.cancelled).toBe(true);
const row = await db('activity_logs')
.where({ activity_type: 'invoice_cancelled_via_storno' })
.orderBy('id', 'desc')
.first();
expect(row).toBeTruthy();
const meta = JSON.parse(row.metadata);
expect(meta.invoiceId).toBe(id);
expect(meta.stornoId).toBe(result.stornoId);
});
test('reissueInvoice completes on SQLite and persists the invoice_reissued audit row', async () => {
const { invoiceIds } = await invoiceService.createInvoice({
customerAccountId: customerId,
currency: 'CHF',
vatRate: 0,
lineItems: [
{ position: 1, quantity: 1, description: 'Album', unit_price_minor: 50000, discount_percent: 0 },
],
}, adminId);
const id = invoiceIds[0];
await db('invoices').where({ id }).update({ status: 'sent', sent_at: new Date(), updated_at: new Date() });
// Pre-fix this stalled inside the wrapping transaction (createInvoice's
// global-connection reads vs. the single-connection pool) and aborted
// before the replacement existed — with the Storno already committed.
const result = await invoiceService.reissueInvoice(id, adminId);
expect(result.id).toBeGreaterThan(0);
expect(result.replaces).toBe(id);
const replacement = await db('invoices').where({ id: result.id }).first();
expect(replacement.replaces_invoice_id).toBe(id);
const row = await db('activity_logs')
.where({ activity_type: 'invoice_reissued' })
.orderBy('id', 'desc')
.first();
expect(row).toBeTruthy();
expect(JSON.parse(row.metadata).newInvoiceId).toBe(result.id);
});
void path; // referenced for parity with sibling suites
+13 -10
View File
@@ -230,18 +230,21 @@ function sanitiseBankPayload(payload) {
* Always returns a profile object even if the row is empty — the
* Settings UI binds straight to this shape.
*/
async function getProfile() {
// `conn` lets transaction callers (invoice/create.js) route the reads
// through their trx — on single-connection SQLite a global-db read
// inside an open trx deadlocks the pool (codex review of #851).
async function getProfile(conn = db) {
return await withRetry(async () => {
let profile = await db('business_profile').where({ id: 1 }).first();
let profile = await conn('business_profile').where({ id: 1 }).first();
if (!profile) {
// Belt-and-braces: migration 102 seeds id=1, but if a fresh install
// ran an earlier rollback that wiped the row, re-create it so the
// service never throws.
await db('business_profile').insert({ id: 1 });
profile = await db('business_profile').where({ id: 1 }).first();
await conn('business_profile').insert({ id: 1 });
profile = await conn('business_profile').where({ id: 1 }).first();
}
const accounts = await db('business_bank_accounts')
const accounts = await conn('business_bank_accounts')
.where({ business_profile_id: 1 })
.orderBy('display_order', 'asc')
.orderBy('id', 'asc');
@@ -344,23 +347,23 @@ async function deleteBankAccount(id, adminId) {
* given currency: explicit override → default for that currency →
* default for the profile's default_currency → first by display_order.
*/
async function resolveBankAccountForCurrency(currency, overrideId = null) {
async function resolveBankAccountForCurrency(currency, overrideId = null, conn = db) {
return await withRetry(async () => {
if (overrideId) {
const explicit = await db('business_bank_accounts').where({ id: overrideId }).first();
const explicit = await conn('business_bank_accounts').where({ id: overrideId }).first();
if (explicit) return explicit;
}
if (currency) {
const match = await db('business_bank_accounts')
const match = await conn('business_bank_accounts')
.where({ business_profile_id: 1, currency, is_default: formatBoolean(true) })
.first();
if (match) return match;
}
const anyDefault = await db('business_bank_accounts')
const anyDefault = await conn('business_bank_accounts')
.where({ business_profile_id: 1, is_default: formatBoolean(true) })
.first();
if (anyDefault) return anyDefault;
return await db('business_bank_accounts')
return await conn('business_bank_accounts')
.where({ business_profile_id: 1 })
.orderBy('display_order', 'asc').orderBy('id', 'asc').first();
});
+15 -2
View File
@@ -171,6 +171,12 @@ async function createContract(payload, adminId) {
// simply skip these fields (contract still saves successfully).
const hasEventCols = await hasColumnCached('contracts', 'event_name');
// Resolve the audit actor BEFORE the transaction — adminActor reads
// admin_users via the global db, which inside the trx would grab a
// second connection from the single-connection SQLite pool and
// deadlock (60s acquire-timeout stall, audit row silently lost).
const actor = await adminActor(adminId);
return await db.transaction(async (trx) => {
// Pass trx so the sequence claim joins our outer transaction —
// SQLite deadlocks otherwise (1-connection default).
@@ -239,7 +245,9 @@ async function createContract(payload, adminId) {
}
try {
await logActivity('contract_created', { contractId, contractNumber, customerAccountId: payload.customerAccountId }, null, await adminActor(adminId));
// Pass `trx` so the audit insert rides the transaction's connection;
// the global db here deadlocks the single-connection SQLite pool.
await logActivity('contract_created', { contractId, contractNumber, customerAccountId: payload.customerAccountId }, null, actor, trx);
} catch (_) { /* logging is best-effort */ }
logger.info('Contract created', { adminId, contractId, contractNumber });
@@ -269,6 +277,9 @@ async function updateContract(id, payload, adminId) {
const hasEventCols = await hasColumnCached('contracts', 'event_name');
// Resolve the audit actor BEFORE the transaction — see createContract.
const actor = await adminActor(adminId);
return await db.transaction(async (trx) => {
const updates = { updated_at: new Date() };
const map = {
@@ -349,7 +360,9 @@ async function updateContract(id, payload, adminId) {
}
try {
await logActivity('contract_updated', { contractId: id }, null, await adminActor(adminId));
// Pass `trx` so the audit insert rides the transaction's connection;
// the global db here deadlocks the single-connection SQLite pool.
await logActivity('contract_updated', { contractId: id }, null, actor, trx);
} catch (_) { /* logging is best-effort */ }
return id;
});
+5 -4
View File
@@ -54,7 +54,8 @@ async function createInvoice(payload, adminId, trx = db) {
return { invoiceIds: draft?.id ? [draft.id] : [] };
}
const profile = (await businessProfileService.getProfile()).profile;
// Route reads through the caller's trx (no-op when trx === db) — see #851.
const profile = (await businessProfileService.getProfile(trx)).profile;
const currency = (payload.currency || profile?.default_currency || 'CHF').toUpperCase();
const language = payload.language || customer.preferred_language || profile?.default_locale || 'de';
@@ -115,7 +116,7 @@ async function createInvoice(payload, adminId, trx = db) {
// qty × unit arithmetic; the per-line rounding drift is surfaced as a
// "Rundung" row at render time (storedNet Σ line totals). Off by
// default ⇒ net stays the sum of rounded lines, unchanged behaviour.
const roundTotal = (await getAppSetting('crm_invoice_round_total', false)) === true;
const roundTotal = (await getAppSetting('crm_invoice_round_total', false, trx)) === true;
if (roundTotal) {
netMinor = cleanNetMinor(items, { parentKey: 'parent_position', positionKey: 'position' });
}
@@ -136,7 +137,7 @@ async function createInvoice(payload, adminId, trx = db) {
);
}
const bank = await businessProfileService.resolveBankAccountForCurrency(currency, payload.businessBankAccountId);
const bank = await businessProfileService.resolveBankAccountForCurrency(currency, payload.businessBankAccountId, trx);
// Snapshot the selected payment-term template (net days / Skonto /
// installment plan) onto the invoice itself. Mirrors how the quote
@@ -305,7 +306,7 @@ async function createInvoice(payload, adminId, trx = db) {
await insertLineItemsHierarchical(trx, 'invoice_line_items', 'invoice_id', invoiceId, items);
}
try { await logActivity('invoice_created', { invoiceId, invoiceNumber }, payload.eventId || null, `admin:${adminId}`); } catch (_) {}
try { await logActivity('invoice_created', { invoiceId, invoiceNumber }, payload.eventId || null, `admin:${adminId}`, trx); } catch (_) {}
return { invoiceIds: [invoiceId] };
}
+2 -1
View File
@@ -101,7 +101,8 @@ async function resolveNetDays(payload, trx = db) {
.first();
if (probe && probe.net_days != null) return ensureInt(probe.net_days) || 30;
}
const setting = ensureInt(await getAppSetting('crm_payment_default_net_days'));
// Route through the caller's trx — global-db here deadlocks SQLite (#851).
const setting = ensureInt(await getAppSetting('crm_payment_default_net_days', null, trx));
if (setting) return setting;
return 30;
}
+12 -2
View File
@@ -307,9 +307,11 @@ async function createStorno(originalId, adminId, trx = db) {
});
try {
// Pass `trx` so the audit insert rides the transaction's connection;
// the global db here deadlocks the single-connection SQLite pool.
await logActivity('invoice_cancelled_via_storno',
{ invoiceId: originalId, stornoId, stornoNumber },
original.event_id || null, `admin:${adminId}`);
original.event_id || null, `admin:${adminId}`, trx);
} catch (_) {}
return stornoId;
@@ -439,6 +441,13 @@ async function reissueInvoice(id, adminId) {
// createInvoice so totals are recomputed authoritatively from
// line items (any rounding drift gets normalised). Self-join
// carries parent_position so migration-119 sub-items survive.
//
// The wrapping transaction is REQUIRED (codex review of #851 round 2):
// without it, createInvoice's early insert + sequence claim survive a
// later validation failure, leaving orphan drafts after the Storno
// already committed. createInvoice's internal reads (getProfile,
// getAppSetting, bank resolution, audit) all accept the trx now, so
// the round-1 SQLite deadlock is gone the right way.
return await db.transaction(async (trx) => {
const lineItems = await trx('invoice_line_items as li')
.leftJoin('invoice_line_items as parent', 'parent.id', 'li.parent_line_item_id')
@@ -502,9 +511,10 @@ async function reissueInvoice(id, adminId) {
});
try {
// Pass `trx` so the audit insert rides the transaction's connection.
await logActivity('invoice_reissued',
{ originalInvoiceId: id, newInvoiceId: newId, stornoId },
original.event_id || null, `admin:${adminId}`);
original.event_id || null, `admin:${adminId}`, trx);
} catch (_) {}
return { id: newId, replaces: id, stornoId };