diff --git a/db/database.cts b/db/database.cts index 7892210..96f4898 100644 --- a/db/database.cts +++ b/db/database.cts @@ -1,5 +1,6 @@ // @ts-nocheck — .cts via Node type-stripping; rich typing deferred (large dynamic DB/migration infra). const Database = require('better-sqlite3'); +const { log } = require('../utils/logger.cts'); const path = require('path'); const fs = require('fs'); @@ -156,7 +157,7 @@ function runSubscriptionCatalogV2Migration(database) { for (const row of rows) insert.run(...row); }); insertMany(toInsert); - console.log(`[migration] subscription_catalog v2: added ${toInsert.length} new entries`); + log.info(`[migration] subscription_catalog v2: added ${toInsert.length} new entries`); } } @@ -198,9 +199,7 @@ function runAdvisoryFiltersMigration(database) { } }); insertFilters(data.patterns || []); - console.log( - `[migration] advisory_non_bill_filters: seeded ${(data.patterns || []).length} rows`, - ); + log.info(`[migration] advisory_non_bill_filters: seeded ${(data.patterns || []).length} rows`); const overrideTerms = data.bill_like_override_terms || []; if (overrideTerms.length > 0) { @@ -211,7 +210,7 @@ function runAdvisoryFiltersMigration(database) { for (const term of terms) insertOverride.run(term); }); insertOverrides(overrideTerms); - console.log(`[migration] advisory_bill_like_overrides: seeded ${overrideTerms.length} rows`); + log.info(`[migration] advisory_bill_like_overrides: seeded ${overrideTerms.length} rows`); } } } @@ -275,7 +274,7 @@ function runMerchantStoreMatchMigration(database) { } }); insertEntries(data.merchant_store_entries || []); - console.log( + log.info( `[migration] merchant_store_matches: seeded ${(data.merchant_store_entries || []).length} rows`, ); } @@ -306,9 +305,7 @@ function runSubscriptionCatalogMigration(database) { for (const row of rows) insert.run(...row); }); insertMany(SUBSCRIPTION_CATALOG_ROWS); - console.log( - `[migration] subscription_catalog: seeded ${SUBSCRIPTION_CATALOG_ROWS.length} rows`, - ); + log.info(`[migration] subscription_catalog: seeded ${SUBSCRIPTION_CATALOG_ROWS.length} rows`); } } @@ -472,7 +469,7 @@ function getDb() { initializing = true; try { - console.log('Opening DB at:', path.basename(DB_PATH)); + log.info('Opening DB at:', path.basename(DB_PATH)); assertWritableDbPath(); db = new Database(DB_PATH, { @@ -484,7 +481,7 @@ function getDb() { try { db.pragma('journal_mode = WAL'); } catch (e) { - console.warn('WAL failed:', e.message); + log.warn('WAL failed:', e.message); } db.pragma('foreign_keys = ON'); @@ -492,11 +489,11 @@ function getDb() { initSchema(); seedDefaults(); - console.log('DB initialized successfully'); + log.info('DB initialized successfully'); return db; } catch (err) { - console.error('DB init failed:', err); + log.error('DB init failed:', err); throw err; } finally { initializing = false; @@ -540,7 +537,7 @@ function initSchema() { .run(newPasswordHash, initUser); if (result.changes > 0) { - console.log('[init] Reset password and flags for default admin user'); + log.info('[init] Reset password and flags for default admin user'); } } @@ -568,7 +565,7 @@ function handleLegacyDatabase() { // If we have core tables but no migrations tracked, this is likely a legacy DB if (tableCheck.length >= 3) { // At least some core tables exist - console.log('[migration] Detected legacy database, reconciling schema migrations...'); + log.info('[migration] Detected legacy database, reconciling schema migrations...'); // For each migration, check if its changes are already present and mark as applied if so reconcileLegacyMigrations(); @@ -610,7 +607,7 @@ function reconcileLegacyMigrations() { if (hasNotificationColumns) { try { recordMigration('legacy-notification-columns', 'users: notification columns'); - console.log('[migration] Recorded legacy notification columns migration'); + log.info('[migration] Recorded legacy notification columns migration'); } catch (e) { // Ignore if already recorded } @@ -630,7 +627,7 @@ function reconcileLegacyMigrations() { (onlyInRun.length ? ` Only in runMigrations: ${onlyInRun.join(', ')}.` : '') + (onlyInReconcile.length ? ` Only in reconcile: ${onlyInReconcile.join(', ')}.` : '') + ' Add the missing version to both arrays.'; - console.error(msg); + log.error(msg); throw new Error(msg); } } @@ -640,7 +637,7 @@ function reconcileLegacyMigrations() { if (migration.check()) { try { recordMigration(migration.version, migration.description); - console.log( + log.info( `[migration] Recorded legacy migration ${migration.version}: ${migration.description}`, ); } catch (e) { @@ -649,19 +646,19 @@ function reconcileLegacyMigrations() { } else { // Migration changes are NOT present - run the migration to apply them try { - console.log( + log.info( `[migration] Running legacy migration ${migration.version}: ${migration.description}`, ); // Wrap legacy migration in transaction db.exec('BEGIN'); - console.log(`[migration] Transaction BEGIN for legacy ${migration.version}`); + log.info(`[migration] Transaction BEGIN for legacy ${migration.version}`); migration.run(); recordMigration(migration.version, migration.description); db.exec('COMMIT'); - console.log(`[migration] Transaction COMMIT for legacy ${migration.version}`); + log.info(`[migration] Transaction COMMIT for legacy ${migration.version}`); } catch (err) { db.exec('ROLLBACK'); - console.error( + log.error( `[migration-error] Failed to apply legacy migration ${migration.version}: ${err.message}. Rolled back.`, ); throw err; @@ -669,13 +666,13 @@ function reconcileLegacyMigrations() { } } - console.log('[migration] Legacy database reconciliation complete'); + log.info('[migration] Legacy database reconciliation complete'); } function recordMigration(version, description) { const stmt = db.prepare('INSERT INTO schema_migrations (version, description) VALUES (?, ?)'); stmt.run(version, description); - console.log(`[migration] Applied ${version}: ${description}`); + log.info(`[migration] Applied ${version}: ${description}`); } function validateMigrationDependencies(migration, appliedVersions) { @@ -689,7 +686,7 @@ function validateMigrationDependencies(migration, appliedVersions) { } function runMigrations() { - console.log('[migration] Starting database migrations'); + log.info('[migration] Starting database migrations'); const startTime = Date.now(); // Log start of migrations to audit log @@ -701,7 +698,7 @@ function runMigrations() { details: { message: 'Starting database migrations' }, }); } catch (auditErr) { - console.error(`[audit-error] Failed to log migration start to audit log: ${auditErr.message}`); + log.error(`[audit-error] Failed to log migration start to audit log: ${auditErr.message}`); } // Define all migrations with explicit version tracking and dependency chains const migrations = buildVersionedMigrations({ @@ -717,12 +714,12 @@ function runMigrations() { // ── users: notification columns ─────────────────────────────────────────── // This migration needs to run first since it's not versioned in the schema - console.log('[migration] Applying unversioned user notification columns'); + log.info('[migration] Applying unversioned user notification columns'); const unversionedStartTime = Date.now(); try { db.exec('BEGIN'); - console.log('[migration] Transaction BEGIN for unversioned user notification columns'); + log.info('[migration] Transaction BEGIN for unversioned user notification columns'); const userCols = db .prepare('PRAGMA table_info(users)') .all() @@ -768,15 +765,15 @@ function runMigrations() { AND NOT EXISTS (SELECT 1 FROM users WHERE is_default_admin = 1) `); db.exec('COMMIT'); - console.log('[migration] Transaction COMMIT for unversioned user notification columns'); + log.info('[migration] Transaction COMMIT for unversioned user notification columns'); // Log successful completion with timing const elapsed = Date.now() - unversionedStartTime; - console.log(`[migration] Unversioned user notification columns completed in ${elapsed}ms`); + log.info(`[migration] Unversioned user notification columns completed in ${elapsed}ms`); } catch (err) { db.exec('ROLLBACK'); const elapsed = Date.now() - unversionedStartTime; - console.error( + log.error( `[migration-error] Failed to apply unversioned user notification columns after ${elapsed}ms: ${err.message}. Rolled back.`, ); @@ -794,9 +791,7 @@ function runMigrations() { }, }); } catch (auditErr) { - console.error( - `[audit-error] Failed to log migration failure to audit log: ${auditErr.message}`, - ); + log.error(`[audit-error] Failed to log migration failure to audit log: ${auditErr.message}`); } throw err; @@ -819,15 +814,15 @@ function runMigrations() { // Validate dependencies before applying const depCheck = validateMigrationDependencies(migration, appliedVersions); if (!depCheck.valid) { - console.error( + log.error( `[migration-error] ${migration.version} depends on [${depCheck.missing.join(', ')}] which have not been applied. Skipping.`, ); continue; } - console.log(`[migration] Applying ${migration.version}: ${migration.description}`); + log.info(`[migration] Applying ${migration.version}: ${migration.description}`); if (migration.dependsOn && migration.dependsOn.length > 0) { - console.log( + log.info( `[migration] ${migration.version} depends on [${migration.dependsOn.join(', ')}] — satisfied`, ); } @@ -857,20 +852,20 @@ function runMigrations() { } try { db.exec('BEGIN'); - console.log(`[migration] Transaction BEGIN for ${migration.version}`); + log.info(`[migration] Transaction BEGIN for ${migration.version}`); migration.run(); recordMigration(migration.version, migration.description); db.exec('COMMIT'); - console.log(`[migration] Transaction COMMIT for ${migration.version}`); + log.info(`[migration] Transaction COMMIT for ${migration.version}`); // Log successful completion with timing const elapsed = Date.now() - migrationStartTime; - console.log(`[migration] ${migration.version} completed in ${elapsed}ms`); + log.info(`[migration] ${migration.version} completed in ${elapsed}ms`); appliedVersions.add(migration.version); } catch (innerErr) { db.exec('ROLLBACK'); const elapsed = Date.now() - migrationStartTime; - console.error( + log.error( `[migration-error] ${migration.version} failed after ${elapsed}ms: ${innerErr.message}. Rolled back.`, ); @@ -888,7 +883,7 @@ function runMigrations() { }, }); } catch (auditErr) { - console.error( + log.error( `[audit-error] Failed to log migration failure to audit log: ${auditErr.message}`, ); } @@ -903,21 +898,21 @@ function runMigrations() { } else { // Standard transaction wrapping for other migrations db.exec('BEGIN'); - console.log(`[migration] Transaction BEGIN for ${migration.version}`); + log.info(`[migration] Transaction BEGIN for ${migration.version}`); migration.run(); recordMigration(migration.version, migration.description); db.exec('COMMIT'); - console.log(`[migration] Transaction COMMIT for ${migration.version}`); + log.info(`[migration] Transaction COMMIT for ${migration.version}`); // Log successful completion with timing const elapsed = Date.now() - migrationStartTime; - console.log(`[migration] ${migration.version} completed in ${elapsed}ms`); + log.info(`[migration] ${migration.version} completed in ${elapsed}ms`); appliedVersions.add(migration.version); } } catch (err) { db.exec('ROLLBACK'); const elapsed = Date.now() - migrationStartTime; - console.error( + log.error( `[migration-error] Failed to apply ${migration.version} after ${elapsed}ms: ${err.message}. Rolled back.`, ); @@ -935,7 +930,7 @@ function runMigrations() { }, }); } catch (auditErr) { - console.error( + log.error( `[audit-error] Failed to log migration failure to audit log: ${auditErr.message}`, ); } @@ -943,7 +938,7 @@ function runMigrations() { throw err; } } else { - console.log( + log.info( `[migration] Skipping already applied ${migration.version}: ${migration.description}`, ); } @@ -963,12 +958,10 @@ function runMigrations() { }, }); } catch (auditErr) { - console.error( - `[audit-error] Failed to log migration completion to audit log: ${auditErr.message}`, - ); + log.error(`[audit-error] Failed to log migration completion to audit log: ${auditErr.message}`); } const totalTime = Date.now() - startTime; - console.log(`[migration] All migrations completed in ${totalTime}ms`); + log.info(`[migration] All migrations completed in ${totalTime}ms`); // All migrations are now versioned } @@ -1051,7 +1044,7 @@ function seedDefaults() { VALUES (?, ?, 'admin', 1, 1, ?, datetime('now'), datetime('now')) `, ).run(initUser, password_hash, initUser + '@local'); - console.log(`[seed] Created initial admin user: ${initUser}`); + log.info(`[seed] Created initial admin user: ${initUser}`); } seedManualDataSources(db); @@ -1348,27 +1341,27 @@ function rollbackMigration(version) { throw err; } - console.log(`[rollback] Rolling back ${version}: ${rollback.description}`); + log.info(`[rollback] Rolling back ${version}: ${rollback.description}`); const startTime = Date.now(); try { db.exec('BEGIN'); - console.log(`[rollback] Transaction BEGIN for ${version}`); + log.info(`[rollback] Transaction BEGIN for ${version}`); for (const stmt of rollback.sql) { - console.log(`[rollback] Executing: ${stmt}`); + log.info(`[rollback] Executing: ${stmt}`); db.exec(stmt); } // Remove migration record db.prepare('DELETE FROM schema_migrations WHERE version = ?').run(version); - console.log(`[rollback] Removed ${version} from schema_migrations`); + log.info(`[rollback] Removed ${version} from schema_migrations`); db.exec('COMMIT'); - console.log(`[rollback] Transaction COMMIT for ${version}`); + log.info(`[rollback] Transaction COMMIT for ${version}`); const elapsed = Date.now() - startTime; - console.log(`[rollback] ${version} rolled back in ${elapsed}ms`); + log.info(`[rollback] ${version} rolled back in ${elapsed}ms`); // Audit log try { @@ -1379,14 +1372,14 @@ function rollbackMigration(version) { details: { version, description: rollback.description, elapsed_ms: elapsed }, }); } catch (auditErr) { - console.error(`[audit-error] Failed to log rollback to audit log: ${auditErr.message}`); + log.error(`[audit-error] Failed to log rollback to audit log: ${auditErr.message}`); } return { success: true, version, description: rollback.description, elapsed_ms: elapsed }; } catch (err) { db.exec('ROLLBACK'); const elapsed = Date.now() - startTime; - console.error(`[rollback-error] ${version} failed after ${elapsed}ms: ${err.message}`); + log.error(`[rollback-error] ${version} failed after ${elapsed}ms: ${err.message}`); // Audit log try { @@ -1402,9 +1395,7 @@ function rollbackMigration(version) { }, }); } catch (auditErr) { - console.error( - `[audit-error] Failed to log rollback failure to audit log: ${auditErr.message}`, - ); + log.error(`[audit-error] Failed to log rollback failure to audit log: ${auditErr.message}`); } throw err; @@ -1417,7 +1408,7 @@ function rollbackMigration(version) { */ function cleanupExpiredSessions() { const result = db.prepare("DELETE FROM sessions WHERE expires_at < datetime('now')").run(); - console.log(`[cleanup] Purged ${result.changes} expired sessions`); + log.info(`[cleanup] Purged ${result.changes} expired sessions`); return result; } diff --git a/db/migrations/legacyReconcileMigrations.cts b/db/migrations/legacyReconcileMigrations.cts index 27dc076..04c7a65 100644 --- a/db/migrations/legacyReconcileMigrations.cts +++ b/db/migrations/legacyReconcileMigrations.cts @@ -1,5 +1,6 @@ // @ts-nocheck — .cts via Node type-stripping; rich typing deferred (large dynamic DB/migration infra). -'use strict'; +const { log } = require('../../utils/logger.cts'); +('use strict'); // The legacy-reconcile migration list, extracted from db/database.js. Same // factory pattern as versionedMigrations: each check/run body closes over the @@ -37,7 +38,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.exec('ALTER TABLE payments ADD COLUMN deleted_at TEXT'); // Index for fast filtering of live payments db.exec('CREATE INDEX IF NOT EXISTS idx_payments_deleted ON payments(deleted_at)'); - console.log('[migration] payments.deleted_at column added'); + log.info('[migration] payments.deleted_at column added'); } }, }, @@ -89,7 +90,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.exec( 'CREATE INDEX IF NOT EXISTS idx_monthly_bill_state_lookup ON monthly_bill_state(bill_id, year, month)', ); - console.log('[migration] monthly_bill_state table ensured'); + log.info('[migration] monthly_bill_state table ensured'); }, }, { @@ -142,7 +143,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.exec( "ALTER TABLE bills ADD COLUMN history_visibility TEXT NOT NULL DEFAULT 'default'", ); - console.log('[migration] bills.history_visibility column added'); + log.info('[migration] bills.history_visibility column added'); } }, }, @@ -163,7 +164,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { .map((c) => c.name); if (!billColsInterest.includes('interest_rate')) { db.exec('ALTER TABLE bills ADD COLUMN interest_rate REAL'); - console.log('[migration] bills.interest_rate column added'); + log.info('[migration] bills.interest_rate column added'); } }, }, @@ -344,7 +345,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.exec( 'ALTER TABLE monthly_starting_amounts ADD COLUMN other_amount REAL NOT NULL DEFAULT 0 CHECK(other_amount >= 0)', ); - console.log('[migration] monthly_starting_amounts.other_amount column added'); + log.info('[migration] monthly_starting_amounts.other_amount column added'); } }, }, @@ -461,7 +462,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { .map((c) => c.name); if (!billColsSeeded.includes('is_seeded')) { db.exec('ALTER TABLE bills ADD COLUMN is_seeded INTEGER NOT NULL DEFAULT 0'); - console.log('[migration] bills.is_seeded column added'); + log.info('[migration] bills.is_seeded column added'); } // ── categories: is_seeded flag for demo data cleanup (v0.41) ────────────── @@ -471,7 +472,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { .map((c) => c.name); if (!categoryColsSeeded.includes('is_seeded')) { db.exec('ALTER TABLE categories ADD COLUMN is_seeded INTEGER NOT NULL DEFAULT 0'); - console.log('[migration] categories.is_seeded column added'); + log.info('[migration] categories.is_seeded column added'); } }, }, @@ -526,7 +527,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { throw new Error('Invalid migration: column created_at not in whitelist'); } db.exec("ALTER TABLE sessions ADD COLUMN created_at TEXT DEFAULT (datetime('now'))"); - console.log('[migration] sessions.created_at column added'); + log.info('[migration] sessions.created_at column added'); } }, }, @@ -611,7 +612,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.prepare( "UPDATE settings SET value = '2' WHERE key = 'backup_schedule_retention_count' AND value = '14'", ).run(); - console.log('[migration] backup_schedule_retention_count updated from 14 to 2'); + log.info('[migration] backup_schedule_retention_count updated from 14 to 2'); }, }, { @@ -640,7 +641,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.exec('ALTER TABLE bills ADD COLUMN snowball_order INTEGER'); if (!cols.includes('snowball_include')) db.exec('ALTER TABLE bills ADD COLUMN snowball_include INTEGER NOT NULL DEFAULT 0'); - console.log('[migration] bills: debt snowball columns added'); + log.info('[migration] bills: debt snowball columns added'); }, }, { @@ -661,7 +662,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { if (!cols.includes('snowball_extra_payment')) { db.exec('ALTER TABLE users ADD COLUMN snowball_extra_payment REAL NOT NULL DEFAULT 0'); } - console.log('[migration] users: snowball_extra_payment column added'); + log.info('[migration] users: snowball_extra_payment column added'); }, }, { @@ -682,7 +683,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { if (!cols.includes('balance_delta')) { db.exec('ALTER TABLE payments ADD COLUMN balance_delta REAL'); } - console.log('[migration] payments: balance_delta column added'); + log.info('[migration] payments: balance_delta column added'); }, }, { @@ -703,7 +704,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { if (!cols.includes('snowball_exempt')) { db.exec('ALTER TABLE bills ADD COLUMN snowball_exempt INTEGER NOT NULL DEFAULT 0'); } - console.log('[migration] bills: snowball_exempt column added'); + log.info('[migration] bills: snowball_exempt column added'); }, }, { @@ -724,7 +725,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { if (!cols.includes('last_seen_version')) { db.exec('ALTER TABLE users ADD COLUMN last_seen_version TEXT'); } - console.log('[migration] users: last_seen_version column added'); + log.info('[migration] users: last_seen_version column added'); }, }, { @@ -751,7 +752,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { device_fingerprint TEXT ) `); - console.log('[migration] user_login_history table created'); + log.info('[migration] user_login_history table created'); }, }, { @@ -789,7 +790,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { if (row) insert.run(user.id, key, row.value); } } - console.log('[migration] user_settings table ensured'); + log.info('[migration] user_settings table ensured'); }, }, { @@ -812,7 +813,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { for (const col of ['browser', 'os', 'device_type', 'device_fingerprint']) { if (!cols.includes(col)) db.exec(`ALTER TABLE user_login_history ADD COLUMN ${col} TEXT`); } - console.log('[migration] user_login_history device metadata columns ensured'); + log.info('[migration] user_login_history device metadata columns ensured'); }, }, { @@ -848,7 +849,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { 'CREATE INDEX IF NOT EXISTS idx_categories_deleted ON categories(user_id, deleted_at)', ); } - console.log('[migration] bills/categories deleted_at columns added'); + log.info('[migration] bills/categories deleted_at columns added'); }, }, { @@ -887,7 +888,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_autopay_suggestion_dismissals_user_month ON autopay_suggestion_dismissals(user_id, year, month); `); - console.log('[migration] autopay auto_mark_paid and suggestion dismissals ensured'); + log.info('[migration] autopay auto_mark_paid and suggestion dismissals ensured'); }, }, { @@ -912,7 +913,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_bill_templates_user_name ON bill_templates(user_id, name); `); - console.log('[migration] bill_templates table ensured'); + log.info('[migration] bill_templates table ensured'); }, }, { @@ -936,7 +937,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { if (!cols.includes('transaction_id')) { db.exec('ALTER TABLE payments ADD COLUMN transaction_id INTEGER'); } - console.log('[migration] payments: source metadata columns added'); + log.info('[migration] payments: source metadata columns added'); }, }, { @@ -957,7 +958,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { }, run: function () { ensureTransactionFoundationSchema(db); - console.log('[migration] transaction foundation tables ensured'); + log.info('[migration] transaction foundation tables ensured'); }, }, { @@ -976,7 +977,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { ON payments(transaction_id) WHERE transaction_id IS NOT NULL AND deleted_at IS NULL `); - console.log('[migration] payments: transaction active unique index ensured'); + log.info('[migration] payments: transaction active unique index ensured'); }, }, { @@ -1002,7 +1003,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_match_suggestion_rejections_user ON match_suggestion_rejections(user_id, transaction_id, bill_id); `); - console.log('[migration] match suggestion rejections table ensured'); + log.info('[migration] match suggestion rejections table ensured'); }, }, { @@ -1041,7 +1042,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { db.exec( 'CREATE INDEX IF NOT EXISTS idx_bills_user_subscription ON bills(user_id, is_subscription, active)', ); - console.log('[migration] bills: subscription metadata columns added'); + log.info('[migration] bills: subscription metadata columns added'); }, }, { @@ -1061,7 +1062,7 @@ module.exports = function buildLegacyReconcileMigrations(deps) { .map((c) => c.name); if (!cols.includes('monitored')) { db.exec('ALTER TABLE financial_accounts ADD COLUMN monitored INTEGER NOT NULL DEFAULT 1'); - console.log('[migration] financial_accounts: monitored column added'); + log.info('[migration] financial_accounts: monitored column added'); } }, }, diff --git a/db/migrations/versionedMigrations.cts b/db/migrations/versionedMigrations.cts index 96be923..3c95474 100644 --- a/db/migrations/versionedMigrations.cts +++ b/db/migrations/versionedMigrations.cts @@ -1,6 +1,8 @@ // @ts-nocheck — .cts via Node type-stripping; rich typing deferred (large dynamic DB/migration infra). 'use strict'; +const { log } = require('../../utils/logger.cts'); + // The versioned migration list, extracted from db/database.js to keep that // module manageable. A factory: each migration's run/check body closes over the // live `db` connection and a handful of schema helpers, which are injected here @@ -31,7 +33,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec('ALTER TABLE payments ADD COLUMN deleted_at TEXT'); // Index for fast filtering of live payments db.exec('CREATE INDEX IF NOT EXISTS idx_payments_deleted ON payments(deleted_at)'); - console.log('[migration] payments.deleted_at column added'); + log.info('[migration] payments.deleted_at column added'); } }, }, @@ -68,7 +70,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec( 'CREATE INDEX IF NOT EXISTS idx_monthly_bill_state_lookup ON monthly_bill_state(bill_id, year, month)', ); - console.log('[migration] monthly_bill_state table ensured'); + log.info('[migration] monthly_bill_state table ensured'); }, }, { @@ -108,7 +110,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec( "ALTER TABLE bills ADD COLUMN history_visibility TEXT NOT NULL DEFAULT 'default'", ); - console.log('[migration] bills.history_visibility column added'); + log.info('[migration] bills.history_visibility column added'); } }, }, @@ -123,7 +125,7 @@ module.exports = function buildVersionedMigrations(deps) { .map((c) => c.name); if (!billColsInterest.includes('interest_rate')) { db.exec('ALTER TABLE bills ADD COLUMN interest_rate REAL'); - console.log('[migration] bills.interest_rate column added'); + log.info('[migration] bills.interest_rate column added'); } }, }, @@ -272,7 +274,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec( 'ALTER TABLE monthly_starting_amounts ADD COLUMN other_amount REAL NOT NULL DEFAULT 0 CHECK(other_amount >= 0)', ); - console.log('[migration] monthly_starting_amounts.other_amount column added'); + log.info('[migration] monthly_starting_amounts.other_amount column added'); } }, }, @@ -366,7 +368,7 @@ module.exports = function buildVersionedMigrations(deps) { .map((c) => c.name); if (!billColsSeeded.includes('is_seeded')) { db.exec('ALTER TABLE bills ADD COLUMN is_seeded INTEGER NOT NULL DEFAULT 0'); - console.log('[migration] bills.is_seeded column added'); + log.info('[migration] bills.is_seeded column added'); } // ── categories: is_seeded flag for demo data cleanup (v0.41) ────────────── @@ -376,7 +378,7 @@ module.exports = function buildVersionedMigrations(deps) { .map((c) => c.name); if (!categoryColsSeeded.includes('is_seeded')) { db.exec('ALTER TABLE categories ADD COLUMN is_seeded INTEGER NOT NULL DEFAULT 0'); - console.log('[migration] categories.is_seeded column added'); + log.info('[migration] categories.is_seeded column added'); } }, }, @@ -418,7 +420,7 @@ module.exports = function buildVersionedMigrations(deps) { throw new Error('Invalid migration: column created_at not in whitelist'); } db.exec("ALTER TABLE sessions ADD COLUMN created_at TEXT DEFAULT (datetime('now'))"); - console.log('[migration] sessions.created_at column added'); + log.info('[migration] sessions.created_at column added'); } }, }, @@ -435,7 +437,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec( 'CREATE INDEX IF NOT EXISTS idx_import_history_imported_at ON import_history(imported_at)', ); - console.log('[migration] Added indexes for frequently queried columns'); + log.info('[migration] Added indexes for frequently queried columns'); }, }, { @@ -485,7 +487,7 @@ module.exports = function buildVersionedMigrations(deps) { db.prepare( "UPDATE settings SET value = '2' WHERE key = 'backup_schedule_retention_count' AND value = '14'", ).run(); - console.log('[migration] backup_schedule_retention_count updated from 14 to 2'); + log.info('[migration] backup_schedule_retention_count updated from 14 to 2'); }, }, { @@ -506,7 +508,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec('ALTER TABLE bills ADD COLUMN snowball_order INTEGER'); if (!cols.includes('snowball_include')) db.exec('ALTER TABLE bills ADD COLUMN snowball_include INTEGER NOT NULL DEFAULT 0'); - console.log('[migration] bills: debt snowball columns added'); + log.info('[migration] bills: debt snowball columns added'); }, }, { @@ -521,7 +523,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('snowball_extra_payment')) { db.exec('ALTER TABLE users ADD COLUMN snowball_extra_payment REAL NOT NULL DEFAULT 0'); } - console.log('[migration] users: snowball_extra_payment column added'); + log.info('[migration] users: snowball_extra_payment column added'); }, }, { @@ -536,7 +538,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('balance_delta')) { db.exec('ALTER TABLE payments ADD COLUMN balance_delta REAL'); } - console.log('[migration] payments: balance_delta column added'); + log.info('[migration] payments: balance_delta column added'); }, }, { @@ -551,7 +553,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('snowball_exempt')) { db.exec('ALTER TABLE bills ADD COLUMN snowball_exempt INTEGER NOT NULL DEFAULT 0'); } - console.log('[migration] bills: snowball_exempt column added'); + log.info('[migration] bills: snowball_exempt column added'); }, }, { @@ -566,7 +568,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('last_seen_version')) { db.exec('ALTER TABLE users ADD COLUMN last_seen_version TEXT'); } - console.log('[migration] users: last_seen_version column added'); + log.info('[migration] users: last_seen_version column added'); }, }, { @@ -583,7 +585,7 @@ module.exports = function buildVersionedMigrations(deps) { user_agent TEXT ) `); - console.log('[migration] user_login_history table created'); + log.info('[migration] user_login_history table created'); }, }, { @@ -620,9 +622,7 @@ module.exports = function buildVersionedMigrations(deps) { if (row) insert.run(user.id, key, row.value); } } - console.log( - '[migration] user_settings table created and seeded from current global defaults', - ); + log.info('[migration] user_settings table created and seeded from current global defaults'); }, }, { @@ -659,7 +659,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec(`ALTER TABLE user_login_history ADD COLUMN ${col} ${def}`); } } - console.log('[migration] user_login_history device metadata columns ensured'); + log.info('[migration] user_login_history device metadata columns ensured'); }, }, { @@ -685,7 +685,7 @@ module.exports = function buildVersionedMigrations(deps) { 'CREATE INDEX IF NOT EXISTS idx_categories_deleted ON categories(user_id, deleted_at)', ); } - console.log('[migration] bills/categories deleted_at columns added'); + log.info('[migration] bills/categories deleted_at columns added'); }, }, { @@ -713,7 +713,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_autopay_suggestion_dismissals_user_month ON autopay_suggestion_dismissals(user_id, year, month); `); - console.log('[migration] autopay auto_mark_paid and suggestion dismissals ensured'); + log.info('[migration] autopay auto_mark_paid and suggestion dismissals ensured'); }, }, { @@ -734,7 +734,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_bill_templates_user_name ON bill_templates(user_id, name); `); - console.log('[migration] bill_templates table ensured'); + log.info('[migration] bill_templates table ensured'); }, }, { @@ -752,7 +752,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('transaction_id')) { db.exec('ALTER TABLE payments ADD COLUMN transaction_id INTEGER'); } - console.log('[migration] payments: source metadata columns added'); + log.info('[migration] payments: source metadata columns added'); }, }, { @@ -761,7 +761,7 @@ module.exports = function buildVersionedMigrations(deps) { dependsOn: ['v0.59'], run: function () { ensureTransactionFoundationSchema(db); - console.log('[migration] transaction foundation tables ensured'); + log.info('[migration] transaction foundation tables ensured'); }, }, { @@ -774,7 +774,7 @@ module.exports = function buildVersionedMigrations(deps) { ON payments(transaction_id) WHERE transaction_id IS NOT NULL AND deleted_at IS NULL `); - console.log('[migration] payments: transaction active unique index ensured'); + log.info('[migration] payments: transaction active unique index ensured'); }, }, { @@ -794,7 +794,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_match_suggestion_rejections_user ON match_suggestion_rejections(user_id, transaction_id, bill_id); `); - console.log('[migration] match suggestion rejections table ensured'); + log.info('[migration] match suggestion rejections table ensured'); }, }, { @@ -821,7 +821,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec( 'CREATE INDEX IF NOT EXISTS idx_bills_user_subscription ON bills(user_id, is_subscription, active)', ); - console.log('[migration] bills: subscription metadata columns added'); + log.info('[migration] bills: subscription metadata columns added'); }, }, { @@ -835,7 +835,7 @@ module.exports = function buildVersionedMigrations(deps) { .map((c) => c.name); if (!cols.includes('monitored')) { db.exec('ALTER TABLE financial_accounts ADD COLUMN monitored INTEGER NOT NULL DEFAULT 1'); - console.log('[migration] financial_accounts: monitored column added'); + log.info('[migration] financial_accounts: monitored column added'); } }, }, @@ -1100,7 +1100,7 @@ module.exports = function buildVersionedMigrations(deps) { } } } catch (err) { - console.warn('[v0.77] SMTP password encryption migration failed:', err.message); + log.warn('[v0.77] SMTP password encryption migration failed:', err.message); } }, }, @@ -1125,7 +1125,7 @@ module.exports = function buildVersionedMigrations(deps) { try { updateSource.run(encryptSecret(decryptSecret(row.encrypted_secret)), row.id); } catch (err) { - console.warn(`[v0.78] Could not re-encrypt data_source id=${row.id}:`, err.message); + log.warn(`[v0.78] Could not re-encrypt data_source id=${row.id}:`, err.message); } } @@ -1139,11 +1139,11 @@ module.exports = function buildVersionedMigrations(deps) { "UPDATE settings SET value = ?, updated_at = datetime('now') WHERE key = 'notify_smtp_password'", ).run(encryptSecret(decryptSecret(smtp.value))); } catch (err) { - console.warn('[v0.78] Could not re-encrypt SMTP password:', err.message); + log.warn('[v0.78] Could not re-encrypt SMTP password:', err.message); } } } catch (err) { - console.warn('[v0.78] HKDF re-encryption migration failed:', err.message); + log.warn('[v0.78] HKDF re-encryption migration failed:', err.message); } }, }, @@ -1168,7 +1168,7 @@ module.exports = function buildVersionedMigrations(deps) { } } } catch (err) { - console.warn('[v0.79] OIDC client secret encryption migration failed:', err.message); + log.warn('[v0.79] OIDC client secret encryption migration failed:', err.message); } }, }, @@ -1189,7 +1189,7 @@ module.exports = function buildVersionedMigrations(deps) { add('push_url', 'TEXT'); add('push_token', 'TEXT'); add('push_chat_id', 'TEXT'); - console.log('[v0.80] push notification columns added'); + log.info('[v0.80] push notification columns added'); }, }, { @@ -1202,7 +1202,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_bill_merchant_rules_user_bill ON bill_merchant_rules(user_id, bill_id) `); - console.log('[v0.81] bill_merchant_rules composite index added'); + log.info('[v0.81] bill_merchant_rules composite index added'); }, }, { @@ -1215,7 +1215,7 @@ module.exports = function buildVersionedMigrations(deps) { "UPDATE payments SET payment_source = 'provider_sync' WHERE payment_source = 'auto_match'", ) .run(); - console.log(`[v0.82] Normalised ${result.changes} auto_match payment(s) to provider_sync`); + log.info(`[v0.82] Normalised ${result.changes} auto_match payment(s) to provider_sync`); }, }, { @@ -1232,7 +1232,7 @@ module.exports = function buildVersionedMigrations(deps) { db.exec( 'ALTER TABLE bill_merchant_rules ADD COLUMN auto_attribute_late INTEGER NOT NULL DEFAULT 0', ); - console.log('[v0.83] bill_merchant_rules.auto_attribute_late added'); + log.info('[v0.83] bill_merchant_rules.auto_attribute_late added'); } }, }, @@ -1270,7 +1270,7 @@ module.exports = function buildVersionedMigrations(deps) { } catch {} } } - console.log(`[v0.84] login history: location columns added, ${rows.length} rows encrypted`); + log.info(`[v0.84] login history: location columns added, ${rows.length} rows encrypted`); }, }, { @@ -1289,7 +1289,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('session_fingerprint')) { db.exec('ALTER TABLE user_login_history ADD COLUMN session_fingerprint TEXT'); } - console.log('[v0.85] user_login_history: success + session_fingerprint columns added'); + log.info('[v0.85] user_login_history: success + session_fingerprint columns added'); }, }, { @@ -1315,7 +1315,7 @@ module.exports = function buildVersionedMigrations(deps) { created_at TEXT NOT NULL DEFAULT (datetime('now')) ) `); - console.log('[v0.86] users: TOTP columns + totp_challenges table'); + log.info('[v0.86] users: TOTP columns + totp_challenges table'); }, }, { @@ -1384,7 +1384,7 @@ module.exports = function buildVersionedMigrations(deps) { } } - console.log( + log.info( '[v0.87] spending: transactions.spending_category_id, spending_category_rules, spending_budgets', ); }, @@ -1427,7 +1427,7 @@ module.exports = function buildVersionedMigrations(deps) { /* spending_category_rules may not exist on legacy paths */ } - console.log('[v0.88] categories.spending_enabled added, seeded defaults marked'); + log.info('[v0.88] categories.spending_enabled added, seeded defaults marked'); }, }, { @@ -1465,7 +1465,7 @@ module.exports = function buildVersionedMigrations(deps) { }); } } - console.log( + log.info( `[v0.89] spending defaults seeded for users missing them (${seeded} categories inserted)`, ); }, @@ -1494,7 +1494,7 @@ module.exports = function buildVersionedMigrations(deps) { } } } catch (err) { - console.warn('[v0.90] bill_merchant_rules re-normalize skipped:', err.message); + log.warn('[v0.90] bill_merchant_rules re-normalize skipped:', err.message); } // Re-normalize spending_category_rules @@ -1509,8 +1509,7 @@ module.exports = function buildVersionedMigrations(deps) { spendFixed++; } } - if (spendFixed) - console.log(`[v0.90] spending_category_rules: ${spendFixed} re-normalized`); + if (spendFixed) log.info(`[v0.90] spending_category_rules: ${spendFixed} re-normalized`); } catch { /* spending_category_rules may not exist on legacy DBs */ } @@ -1527,7 +1526,7 @@ module.exports = function buildVersionedMigrations(deps) { ); } - console.log( + log.info( `[v0.90] merchant rules re-normalized (${billFixed} bill rules updated), rejection expiry column ensured`, ); }, @@ -1544,7 +1543,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_bills_user_active ON bills(user_id, active, deleted_at); CREATE INDEX IF NOT EXISTS idx_payments_bill_deleted ON payments(bill_id, deleted_at); `); - console.log('[v0.91] composite indexes created on categories, bills, payments'); + log.info('[v0.91] composite indexes created on categories, bills, payments'); }, }, { @@ -1590,7 +1589,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_webauthn_challenges_user ON webauthn_challenges(user_id); CREATE INDEX IF NOT EXISTS idx_webauthn_challenges_expires ON webauthn_challenges(expires_at); `); - console.log('[v0.92] WebAuthn tables + users columns added'); + log.info('[v0.92] WebAuthn tables + users columns added'); }, }, { @@ -1607,7 +1606,7 @@ module.exports = function buildVersionedMigrations(deps) { .map((c) => c.name); if (!billCols.includes('interest_accrued_month')) { db.exec('ALTER TABLE bills ADD COLUMN interest_accrued_month TEXT'); - console.log('[v0.93] bills.interest_accrued_month column added'); + log.info('[v0.93] bills.interest_accrued_month column added'); } // 2. Track the interest component of each payment separately so delete/restore @@ -1618,7 +1617,7 @@ module.exports = function buildVersionedMigrations(deps) { .map((c) => c.name); if (!paymentCols.includes('interest_delta')) { db.exec('ALTER TABLE payments ADD COLUMN interest_delta REAL'); - console.log('[v0.93] payments.interest_delta column added'); + log.info('[v0.93] payments.interest_delta column added'); } // 3. Strip the data_source_id from existing provider_transaction_id keys so @@ -1638,7 +1637,7 @@ module.exports = function buildVersionedMigrations(deps) { INSTR(SUBSTR(provider_transaction_id, 11), ':') - 1) AS INTEGER) > 0 `); - console.log('[v0.93] transactions: stripped data_source_id from provider_transaction_id'); + log.info('[v0.93] transactions: stripped data_source_id from provider_transaction_id'); // 4. Dedup: after the key change, users who disconnected and reconnected now // have duplicate (user_id, provider_transaction_id) pairs. Keep the best row @@ -1658,9 +1657,7 @@ module.exports = function buildVersionedMigrations(deps) { WHERE rn > 1 ) `); - console.log( - '[v0.93] transactions: removed duplicate provider keys from disconnect/reconnect', - ); + log.info('[v0.93] transactions: removed duplicate provider keys from disconnect/reconnect'); // 5. Replace the old dedupe index (data_source_id, provider_transaction_id) // with a user-scoped one (user_id, provider_transaction_id) so reconnect @@ -1671,7 +1668,7 @@ module.exports = function buildVersionedMigrations(deps) { ON transactions (user_id, provider_transaction_id) WHERE provider_transaction_id IS NOT NULL; `); - console.log( + log.info( '[v0.93] transactions: dedupe index changed to (user_id, provider_transaction_id)', ); }, @@ -1684,13 +1681,13 @@ module.exports = function buildVersionedMigrations(deps) { db.prepare( "INSERT OR IGNORE INTO settings (key, value) VALUES ('geolocation_enabled', 'false')", ).run(); - console.log('[v0.94] geolocation_enabled setting seeded'); + log.info('[v0.94] geolocation_enabled setting seeded'); // All existing plaintext session IDs are invalidated so everyone re-authenticates. // Going forward, sessions.id stores SHA-256(token); the raw token stays in the cookie. const count = db.prepare('SELECT COUNT(*) as n FROM sessions').get().n; db.exec('DELETE FROM sessions'); - console.log( + log.info( `[v0.94] sessions: cleared ${count} existing plaintext sessions (re-login required)`, ); }, @@ -1861,7 +1858,7 @@ module.exports = function buildVersionedMigrations(deps) { } })(); - console.log( + log.info( `[v0.95] catalog: ${nUpdated} updated, ${nInserted} inserted, ${nDescs} descriptors added`, ); }, @@ -1933,7 +1930,7 @@ module.exports = function buildVersionedMigrations(deps) { } })(); - console.log( + log.info( `[v0.96] catalog_id added to bills; ${backfilled}/${subBills.length} subscriptions backfilled`, ); }, @@ -1962,7 +1959,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_srf_user_action ON subscription_recommendation_feedback(user_id, action); `); - console.log('[v0.97] subscription recommendation feedback table ensured'); + log.info('[v0.97] subscription recommendation feedback table ensured'); }, }, { @@ -1992,7 +1989,7 @@ module.exports = function buildVersionedMigrations(deps) { ON payments(overridden_by_payment_id) WHERE overridden_by_payment_id IS NOT NULL; `); - console.log('[v0.98] payment accounting override columns ensured'); + log.info('[v0.98] payment accounting override columns ensured'); }, }, { @@ -2027,7 +2024,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!paymentCols.includes('autopay_failure')) { db.exec('ALTER TABLE payments ADD COLUMN autopay_failure INTEGER NOT NULL DEFAULT 0'); } - console.log('[v0.99] autopay trust indicators + lifecycle fields added'); + log.info('[v0.99] autopay trust indicators + lifecycle fields added'); }, }, { @@ -2048,7 +2045,7 @@ module.exports = function buildVersionedMigrations(deps) { CREATE INDEX IF NOT EXISTS idx_calendar_tokens_token ON calendar_tokens(token) WHERE active = 1; CREATE INDEX IF NOT EXISTS idx_calendar_tokens_user_active ON calendar_tokens(user_id, active); `); - console.log('[v1.00] calendar feed token table ensured'); + log.info('[v1.00] calendar feed token table ensured'); }, }, { @@ -2066,7 +2063,7 @@ module.exports = function buildVersionedMigrations(deps) { // which never posted (e.g. a pending charge that re-posted under a new id). db.exec(`CREATE INDEX IF NOT EXISTS idx_transactions_pending ON transactions(account_id) WHERE pending = 1`); - console.log('[v1.01] transactions.pending flag + partial index added'); + log.info('[v1.01] transactions.pending flag + partial index added'); }, }, { @@ -2080,7 +2077,7 @@ module.exports = function buildVersionedMigrations(deps) { if (!cols.includes('geolocation_enabled')) { db.exec('ALTER TABLE users ADD COLUMN geolocation_enabled INTEGER NOT NULL DEFAULT 0'); } - console.log('[v1.02] users.geolocation_enabled added'); + log.info('[v1.02] users.geolocation_enabled added'); }, }, { @@ -2104,7 +2101,7 @@ module.exports = function buildVersionedMigrations(deps) { ); } } - console.log('[v1.03] money columns converted to integer cents'); + log.info('[v1.03] money columns converted to integer cents'); }, }, { @@ -2122,7 +2119,7 @@ module.exports = function buildVersionedMigrations(deps) { WHERE json_extract(data, '$.${field}') IS NOT NULL `); } - console.log('[v1.04] bill_templates.data money fields converted to integer cents'); + log.info('[v1.04] bill_templates.data money fields converted to integer cents'); }, }, { @@ -2160,7 +2157,7 @@ module.exports = function buildVersionedMigrations(deps) { 'ALTER TABLE categories ADD COLUMN group_id INTEGER REFERENCES category_groups(id) ON DELETE SET NULL', ); - console.log('[v1.06] category_groups table + categories.group_id added'); + log.info('[v1.06] category_groups table + categories.group_id added'); }, }, { @@ -2202,7 +2199,7 @@ module.exports = function buildVersionedMigrations(deps) { added++; } } - console.log(`[v1.07] is_seeded marker ensured on ${added} demo table(s)`); + log.info(`[v1.07] is_seeded marker ensured on ${added} demo table(s)`); }, }, ]; diff --git a/docs/CODE_STANDARDS.md b/docs/CODE_STANDARDS.md index 0d5d42b..5357fab 100644 --- a/docs/CODE_STANDARDS.md +++ b/docs/CODE_STANDARDS.md @@ -58,8 +58,10 @@ rolled out. Update this doc when a standard changes. ## Logging (target) -- One `log` helper with levels; env-driven level; redaction of secrets/PII. Replace raw - `console.*` over time. +- Use `utils/logger.cts` (`const { log } = require('.../utils/logger.cts')`) — `log.debug/info/warn/error`, + console-compatible. Level via `LOG_LEVEL` (default: debug in dev, info in prod). It **redacts** + secrets/PII (sensitive keys, bearer/JWT) so tokens/passwords never reach logs. All server + runtime `console.*` has been migrated. Do **not** use raw `console.*` in server code. ## Data integrity diff --git a/routes/aboutAdmin.cts b/routes/aboutAdmin.cts index 0d5c3ab..f503f46 100644 --- a/routes/aboutAdmin.cts +++ b/routes/aboutAdmin.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const fs = require('fs'); const path = require('path'); const { requireAuth, requireAdmin } = require('../middleware/requireAuth.cts'); @@ -524,7 +525,7 @@ router.get('/', requireAuth, requireAdmin, (req: Req, res: Res) => { }); } catch (err) { // Generic error message to prevent path disclosure - console.error('[aboutAdmin] Error reading files'); + log.error('[aboutAdmin] Error reading files'); res.status(500).json({ error: 'Failed to read project documentation files', code: 'FILE_READ_ERROR', @@ -545,7 +546,7 @@ router.get('/roadmap', requireAuth, requireAdmin, async (req: Req, res: Res) => _forgejoCacheTs = now; res.json(_forgejoCache); } catch (err) { - console.error('[aboutAdmin] Forgejo issues error:', err.message); + log.error('[aboutAdmin] Forgejo issues error:', err.message); if (_forgejoCache) return res.json({ ..._forgejoCache, stale: true }); res .status(502) @@ -561,7 +562,7 @@ router.get('/dev-log', requireAuth, requireAdmin, (req: Req, res: Res) => { const entries = parseDevLogMd(sanitized); res.json({ entries, version: pkg.version }); } catch (err) { - console.error('[aboutAdmin] Error reading DEVELOPMENT_LOG.md for dev-log'); + log.error('[aboutAdmin] Error reading DEVELOPMENT_LOG.md for dev-log'); res.status(500).json({ error: 'Failed to read dev log data', code: 'FILE_READ_ERROR', diff --git a/routes/admin.cts b/routes/admin.cts index ed52eb7..fbd379c 100644 --- a/routes/admin.cts +++ b/routes/admin.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { getDb, rollbackMigration } = require('../db/database.cts'); const { @@ -203,7 +204,7 @@ router.post('/users', async (req: Req, res: Res) => { res.status(201).json(created); } catch (err) { - console.error('[admin] create-user error:', err.message); + log.error('[admin] create-user error:', err.message); res.status(500).json({ error: 'Failed to create user' }); } }); @@ -240,7 +241,7 @@ router.put('/users/:id/password', async (req: Req, res: Res) => { res.json({ success: true }); } catch (err) { - console.error('[admin] reset-password error:', err.message); + log.error('[admin] reset-password error:', err.message); res.status(500).json({ error: 'Failed to reset password' }); } }); diff --git a/routes/auth.cts b/routes/auth.cts index 8ecbb1d..0bc32e0 100644 --- a/routes/auth.cts +++ b/routes/auth.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); let _appVersion; @@ -109,7 +110,7 @@ router.post( res.cookie(COOKIE_NAME, result.sessionId, cookieOpts(req)); res.json({ user: result.user }); } catch (err) { - console.error('Login error:', err); + log.error('Login error:', err); res.status(500).json(standardizeError('Login failed', 'SERVER_ERROR')); } }, @@ -308,7 +309,7 @@ router.post('/totp/challenge', async (req: Req, res: Res) => { res.cookie(COOKIE_NAME, session.sessionId, cookieOpts(req)); res.json({ user: session.user }); } catch (err) { - console.error('[totp/challenge]', err); + log.error('[totp/challenge]', err); res.status(500).json(standardizeError('Login failed', 'SERVER_ERROR')); } }); @@ -326,7 +327,7 @@ router.get('/totp/setup', requireAuth, async (req: Req, res: Res) => { const { uri, qr_data_url } = await generateQrCode(secret, user.username); res.json({ secret, uri, qr_data_url }); } catch (err) { - console.error('[totp/setup]', err); + log.error('[totp/setup]', err); res.status(500).json(standardizeError('Failed to generate setup data', 'SERVER_ERROR')); } }); @@ -521,7 +522,7 @@ router.post('/change-password', passwordLimiter, requireAuth, async (req: Req, r res.json({ success: true }); } catch (err) { - console.error('[auth] change-password error:', err.message); + log.error('[auth] change-password error:', err.message); res.status(500).json(standardizeError('Password change failed', 'SERVER_ERROR')); } }); @@ -591,7 +592,7 @@ router.post('/users', requireAuth, requireAdmin, async (req: Req, res: Res) => { res.status(201).json(created); } catch (err) { - console.error('[auth] create-user error:', err.message); + log.error('[auth] create-user error:', err.message); res.status(500).json(standardizeError('Failed to create user', 'SERVER_ERROR')); } }); @@ -639,7 +640,7 @@ router.get('/webauthn/setup', requireAuth, async (req: Req, res: Res) => { ); res.json({ options, challengeId }); } catch (err) { - console.error('[webauthn/setup]', err); + log.error('[webauthn/setup]', err); res.status(500).json(standardizeError('Failed to generate setup options', 'SERVER_ERROR')); } }); @@ -682,7 +683,7 @@ router.post('/webauthn/enable', requireAuth, async (req: Req, res: Res) => { }); res.json({ enabled: true, credential_id: result.credentialId }); } catch (err) { - console.error('[webauthn/enable]', err); + log.error('[webauthn/enable]', err); res.status(500).json(standardizeError('Registration failed', 'SERVER_ERROR')); } }); @@ -720,7 +721,7 @@ router.delete('/webauthn/credentials/:credentialId', requireAuth, async (req: Re }); res.json({ success: true, webauthn_enabled: n > 0 }); } catch (err) { - console.error('[webauthn/credentials/delete]', err); + log.error('[webauthn/credentials/delete]', err); res.status(500).json(standardizeError('Failed to remove credential', 'SERVER_ERROR')); } }); @@ -756,7 +757,7 @@ router.post('/webauthn/disable', requireAuth, async (req: Req, res: Res) => { }); res.json({ enabled: false }); } catch (err) { - console.error('[webauthn/disable]', err); + log.error('[webauthn/disable]', err); res.status(500).json(standardizeError('Failed to disable WebAuthn', 'SERVER_ERROR')); } }); @@ -817,7 +818,7 @@ router.post('/webauthn/challenge', async (req: Req, res: Res) => { res.cookie(COOKIE_NAME, s.sessionId, cookieOpts(req)); res.json({ user: s.user }); } catch (err) { - console.error('[webauthn/challenge]', err); + log.error('[webauthn/challenge]', err); res.status(500).json(standardizeError('Login failed', 'SERVER_ERROR')); } }); diff --git a/routes/authOidc.cts b/routes/authOidc.cts index 3350ca8..58aa924 100644 --- a/routes/authOidc.cts +++ b/routes/authOidc.cts @@ -13,6 +13,7 @@ import type { Req, Res, Next } from '../types/http'; */ const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { @@ -48,11 +49,11 @@ router.get('/login', async (req: Req, res: Res) => { res.redirect(authUrl); } catch (err) { const msg = err.message || String(err); - console.error('[oidc] Login initiation error:', msg || '(no message)'); + log.error('[oidc] Login initiation error:', msg || '(no message)'); if (err.errors) { - err.errors.forEach((e, i) => console.error(` [${i}]`, e.message || String(e))); + err.errors.forEach((e, i) => log.error(` [${i}]`, e.message || String(e))); } - if (err.cause) console.error(' cause:', err.cause.message || String(err.cause)); + if (err.cause) log.error(' cause:', err.cause.message || String(err.cause)); res.status(502).json({ error: 'Failed to reach the identity provider. Please try again.' }); } }); @@ -78,7 +79,7 @@ router.get('/callback', async (req: Req, res: Res) => { // Provider signalled an authorization error — log code only, not description (may have PII) if (error) { - console.error('[oidc] Provider error on callback:', String(error).slice(0, 40)); + log.error('[oidc] Provider error on callback:', String(error).slice(0, 40)); return res.redirect('/?oidc_error=authorization_failed'); } @@ -111,11 +112,11 @@ router.get('/callback', async (req: Req, res: Res) => { } catch (err) { // Log message only — never log tokens, codes, or ID token contents const msg = err.message || String(err); - console.error('[oidc] Callback error:', msg || '(no message)'); + log.error('[oidc] Callback error:', msg || '(no message)'); if (err.errors) { - err.errors.forEach((e, i) => console.error(` [${i}]`, e.message || String(e))); + err.errors.forEach((e, i) => log.error(` [${i}]`, e.message || String(e))); } - if (err.cause) console.error(' cause:', err.cause.message || String(err.cause)); + if (err.cause) log.error(' cause:', err.cause.message || String(err.cause)); const errCode = err.status === 403 ? 'access_denied' : 'authentication_failed'; res.redirect(`/?oidc_error=${errCode}`); } diff --git a/routes/bills.cts b/routes/bills.cts index ad15cfa..6595f49 100644 --- a/routes/bills.cts +++ b/routes/bills.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { getDb, ensureUserDefaultCategories } = require('../db/database.cts'); const { @@ -195,7 +196,7 @@ router.get('/merchant-rules', (req: Req, res: Res) => { .all(req.user.id); res.json({ rules }); } catch (err) { - console.error('[bills/merchant-rules GET]', err.message); + log.error('[bills/merchant-rules GET]', err.message); res.status(500).json({ error: 'Failed to load merchant rules' }); } }); @@ -1835,7 +1836,7 @@ router.post('/:id/merchant-rules/import-historical', (req: Req, res: Res) => { } })(); } catch (err) { - console.error('[import-historical] Transaction failed:', err.message); + log.error('[import-historical] Transaction failed:', err.message); return res.status(500).json(standardizeError('Import failed', 'DB_ERROR')); } diff --git a/routes/import.cts b/routes/import.cts index d43c990..c98ccae 100644 --- a/routes/import.cts +++ b/routes/import.cts @@ -3,6 +3,7 @@ import type { Req, Res, Next } from '../types/http'; ('use strict'); const express = require('express'); +const { log } = require('../utils/logger.cts'); const { standardizeError } = require('../middleware/errorFormatter.cts'); const router = express.Router(); const { @@ -49,7 +50,7 @@ function sendImportError(res, err, fallback, defaultCode) { // Log error ID server-side only — never expose to clients const errorId = makeErrorId(); - console.error(`[import] ${fallback} (${errorId}):`, err.stack || err.message); + log.error(`[import] ${fallback} (${errorId}):`, err.stack || err.message); return res.status(500).json({ error: fallback, message: 'Unexpected import server error. Please try again or adjust the import decisions.', @@ -421,7 +422,7 @@ router.get('/history', requireDataImportEnabled, (req: Req, res: Res) => { const history = getImportHistory(req.user.id); res.json({ history }); } catch (err) { - console.error('[import] history error:', err.message); + log.error('[import] history error:', err.message); res.status(500).json({ error: 'Failed to load import history' }); } }); diff --git a/routes/matches.cts b/routes/matches.cts index 939ecde..c7c4ce3 100644 --- a/routes/matches.cts +++ b/routes/matches.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const router = require('express').Router(); +const { log } = require('../utils/logger.cts'); const { standardizeError } = require('../middleware/errorFormatter.cts'); const { getDb } = require('../db/database.cts'); const { @@ -22,7 +23,7 @@ function sendMatchError(res, err, fallbackMessage = 'Match operation failed') { .status(err.status) .json(standardizeError(err.message, err.code || 'MATCH_ERROR', err.field)); } - console.error('[matches] service error:', err.stack || err.message); + log.error('[matches] service error:', err.stack || err.message); return res.status(500).json(standardizeError(fallbackMessage, 'MATCH_ERROR')); } diff --git a/routes/notifications.cts b/routes/notifications.cts index f306b64..6c76f77 100644 --- a/routes/notifications.cts +++ b/routes/notifications.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { getDb, getSetting, setSetting } = require('../db/database.cts'); const { requireAuth, requireUser, requireAdmin } = require('../middleware/requireAuth.cts'); @@ -64,7 +65,7 @@ router.put('/admin', requireAuth, requireAdmin, (req: Req, res: Res) => { try { require('../workers/dailyWorker.cts').rescheduleDailyWorker(); } catch (err) { - console.error('[notifications] Failed to reschedule daily worker:', err.message); + log.error('[notifications] Failed to reschedule daily worker:', err.message); } } res.json({ success: true }); diff --git a/routes/payments.cts b/routes/payments.cts index d7858cd..c209c95 100644 --- a/routes/payments.cts +++ b/routes/payments.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const { standardizeError } = require('../middleware/errorFormatter.cts'); const router = require('express').Router(); const { getDb } = require('../db/database.cts'); @@ -287,7 +288,7 @@ router.post('/:id/undo-auto', (req: Req, res: Res) => { })(); res.json({ success: true }); } catch (err) { - console.error('[payments] undo-auto error:', err.message); + log.error('[payments] undo-auto error:', err.message); res.status(500).json(standardizeError('Failed to undo auto-match', 'SERVER_ERROR')); } }); @@ -1003,7 +1004,7 @@ router.patch('/:id/attribute-to-month', (req: Req, res: Res) => { ), ); } catch (err) { - console.error('[payments] attribute-to-month error:', err.message); + log.error('[payments] attribute-to-month error:', err.message); res.status(500).json(standardizeError('Failed to reclassify payment date', 'DB_ERROR')); } }); diff --git a/routes/profile.cts b/routes/profile.cts index ff47ca7..aca4ab0 100644 --- a/routes/profile.cts +++ b/routes/profile.cts @@ -3,6 +3,7 @@ import type { Req, Res, Next } from '../types/http'; ('use strict'); const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const bcrypt = require('bcryptjs'); const { passwordLimiter } = require('../middleware/rateLimiter.cts'); @@ -407,7 +408,7 @@ router.post('/change-password', passwordLimiter, async (req: Req, res: Res) => { res.json({ success: true }); } catch (err) { - console.error('[profile] change-password error:', err.message); + log.error('[profile] change-password error:', err.message); res.status(500).json({ error: 'Password change failed' }); } }); @@ -444,7 +445,7 @@ router.get('/import-history', requireDataImportEnabled, (req: Req, res: Res) => const history = getImportHistory(req.user.id); res.json({ history }); } catch (err) { - console.error('[profile] import-history error:', err.message); + log.error('[profile] import-history error:', err.message); res.status(500).json({ error: 'Failed to load import history' }); } }); diff --git a/routes/snowball.cts b/routes/snowball.cts index 6d5fdb9..d477c6b 100644 --- a/routes/snowball.cts +++ b/routes/snowball.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { getDb } = require('../db/database.cts'); const { standardizeError } = require('../middleware/errorFormatter.cts'); @@ -465,7 +466,7 @@ router.post('/plans', (req: Req, res: Res) => { .get(result.lastInsertRowid); res.status(201).json(enrichPlanWithProgress(db, plan)); } catch (err) { - console.error('[snowball plans] POST error:', err.message); + log.error('[snowball plans] POST error:', err.message); res.status(500).json(standardizeError('Failed to start plan', 'PLAN_CREATE_ERROR')); } }); @@ -483,7 +484,7 @@ router.get('/plans', (req: Req, res: Res) => { .all(req.user.id); res.json({ plans: plans.map((p) => enrichPlanWithProgress(db, p)) }); } catch (err) { - console.error('[snowball plans] GET /plans error:', err.message); + log.error('[snowball plans] GET /plans error:', err.message); res.status(500).json(standardizeError('Failed to load plans', 'PLAN_LIST_ERROR')); } }); @@ -503,7 +504,7 @@ router.get('/plans/active', (req: Req, res: Res) => { .get(req.user.id); res.json(plan ? enrichPlanWithProgress(db, plan) : null); } catch (err) { - console.error('[snowball plans] GET /plans/active error:', err.message); + log.error('[snowball plans] GET /plans/active error:', err.message); res.status(500).json(standardizeError('Failed to load active plan', 'PLAN_ACTIVE_ERROR')); } }); @@ -533,7 +534,7 @@ router.patch('/plans/:id', (req: Req, res: Res) => { const updated = db.prepare('SELECT * FROM snowball_plans WHERE id = ?').get(id); res.json(enrichPlanWithProgress(db, updated)); } catch (err) { - console.error('[snowball plans] PATCH error:', err.message); + log.error('[snowball plans] PATCH error:', err.message); res.status(500).json(standardizeError('Failed to update plan', 'PLAN_UPDATE_ERROR')); } }); @@ -567,7 +568,7 @@ function transitionPlan(req, res, { allowedFrom, setSql, action, past }) { const updated = db.prepare('SELECT * FROM snowball_plans WHERE id = ?').get(id); res.json(enrichPlanWithProgress(db, updated)); } catch (err) { - console.error(`[snowball plans] ${action} error:`, err.message); + log.error(`[snowball plans] ${action} error:`, err.message); res.status(500).json(standardizeError(`Failed to ${action} plan`, 'PLAN_TRANSITION_ERROR')); } } diff --git a/routes/spending.cts b/routes/spending.cts index 1dfd7ce..842ae14 100644 --- a/routes/spending.cts +++ b/routes/spending.cts @@ -3,6 +3,7 @@ import type { Req, Res, Next } from '../types/http'; ('use strict'); const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { getDb } = require('../db/database.cts'); const { @@ -33,7 +34,7 @@ router.get('/summary', (req: Req, res: Res) => { try { res.json(getSpendingSummary(getDb(), req.user.id, ym.year, ym.month)); } catch (err) { - console.error('[spending/summary]', err.message); + log.error('[spending/summary]', err.message); res.status(500).json({ error: 'Failed to load spending summary' }); } }); @@ -61,7 +62,7 @@ router.get('/transactions', (req: Req, res: Res) => { }), ); } catch (err) { - console.error('[spending/transactions]', err.message); + log.error('[spending/transactions]', err.message); res.status(500).json({ error: 'Failed to load transactions' }); } }); @@ -92,7 +93,7 @@ router.get('/budgets', (req: Req, res: Res) => { try { res.json({ budgets: getSpendingBudgets(getDb(), req.user.id, ym.year, ym.month) }); } catch (err) { - console.error('[spending/budgets GET]', err.message); + log.error('[spending/budgets GET]', err.message); res.status(500).json({ error: 'Failed to load budgets' }); } }); @@ -146,7 +147,7 @@ router.post('/budgets/copy', (req: Req, res: Res) => { budgets: getSpendingBudgets(db, req.user.id, ym.year, ym.month), }); } catch (err) { - console.error('[spending/budgets/copy]', err.message); + log.error('[spending/budgets/copy]', err.message); res.status(500).json({ error: 'Failed to copy budgets' }); } }); @@ -169,7 +170,7 @@ router.put('/budgets', (req: Req, res: Res) => { ); res.json({ ok: true }); } catch (err) { - console.error('[spending/budgets PUT]', err.message); + log.error('[spending/budgets PUT]', err.message); res.status(500).json({ error: 'Failed to save budget' }); } }); @@ -179,7 +180,7 @@ router.get('/category-rules', (req: Req, res: Res) => { try { res.json({ rules: getSpendingCategoryRules(getDb(), req.user.id) }); } catch (err) { - console.error('[spending/category-rules GET]', err.message); + log.error('[spending/category-rules GET]', err.message); res.status(500).json({ error: 'Failed to load rules' }); } }); @@ -193,7 +194,7 @@ router.post('/category-rules', (req: Req, res: Res) => { addSpendingCategoryRule(getDb(), req.user.id, parseInt(category_id, 10), merchant); res.json({ ok: true }); } catch (err) { - console.error('[spending/category-rules POST]', err.message); + log.error('[spending/category-rules POST]', err.message); res.status(err.status || 500).json({ error: err.message || 'Failed to save rule' }); } }); @@ -204,7 +205,7 @@ router.delete('/category-rules/:id', (req: Req, res: Res) => { deleteSpendingCategoryRule(getDb(), req.user.id, parseInt(req.params.id, 10)); res.json({ ok: true }); } catch (err) { - console.error('[spending/category-rules DELETE]', err.message); + log.error('[spending/category-rules DELETE]', err.message); res.status(500).json({ error: 'Failed to delete rule' }); } }); @@ -222,7 +223,7 @@ router.get('/income', (req: Req, res: Res) => { }), ); } catch (err) { - console.error('[spending/income]', err.message); + log.error('[spending/income]', err.message); res.status(500).json({ error: 'Failed to load income transactions' }); } }); diff --git a/routes/summary.cts b/routes/summary.cts index 9584afb..e2e9b8b 100644 --- a/routes/summary.cts +++ b/routes/summary.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const express = require('express'); +const { log } = require('../utils/logger.cts'); const router = express.Router(); const { getDb } = require('../db/database.cts'); const { getCycleRange, resolveDueDate } = require('../services/statusService.cts'); @@ -115,7 +116,7 @@ function buildBankTrackingSummary(db, userId, year, month) { remaining: money(effectiveDollars - unpaidDollars), }; } catch (err) { - console.error('[buildBankTrackingSummary] Error:', err.message); + log.error('[buildBankTrackingSummary] Error:', err.message); return null; } } diff --git a/routes/transactions.cts b/routes/transactions.cts index 055656b..4013b3c 100644 --- a/routes/transactions.cts +++ b/routes/transactions.cts @@ -1,6 +1,7 @@ // @ts-nocheck — route controller converted to .cts; handler req/res typed, full type-check deferred (thin glue over typed services). import type { Req, Res, Next } from '../types/http'; const router = require('express').Router(); +const { log } = require('../utils/logger.cts'); const { getDb } = require('../db/database.cts'); const { standardizeError } = require('../middleware/errorFormatter.cts'); const { @@ -361,7 +362,7 @@ function sendTransactionServiceError(res, err, fallbackMessage = 'Transaction op .status(err.status) .json(standardizeError(err.message, err.code || 'TRANSACTION_ERROR', err.field)); } - console.error('[transactions] service error:', err.stack || err.message); + log.error('[transactions] service error:', err.stack || err.message); return res.status(500).json(standardizeError(fallbackMessage, 'TRANSACTION_ERROR')); } diff --git a/server.cts b/server.cts index 91c43c6..7fad6ac 100644 --- a/server.cts +++ b/server.cts @@ -1,5 +1,6 @@ // @ts-nocheck — app entry/bootstrap converted to .cts (Node type-stripping); Express wiring, typing deferred. const express = require('express'); +const { log } = require('./utils/logger.cts'); const cookieParser = require('cookie-parser'); const path = require('path'); @@ -97,7 +98,7 @@ function skipRateLimitIfNoUsers(limiter) { } } catch (err) { // DB not ready yet — allow request to proceed - console.log('[skipRateLimit] DB not initialized, allowing request'); + log.info('[skipRateLimit] DB not initialized, allowing request'); return next(); } // User exists — apply rate limiter @@ -287,7 +288,7 @@ app.use((err, req, res, next) => { // (validation, auth, not-found) and must not spam the error tracker. if (status >= 500) { recordError('Express', err); - console.error('[error]', err.stack || err.message || String(err)); + log.error('[error]', err.stack || err.message || String(err)); } if (/^\/api\/imports?\//.test(req.path || '')) { @@ -311,10 +312,7 @@ app.use((err, req, res, next) => { // (Most rejections here are non-fatal side effects; a crash would be worse than // surfacing them. Truly fatal states are handled by uncaughtException below.) process.on('unhandledRejection', (reason) => { - console.error( - '[server] Unhandled promise rejection:', - reason?.stack || reason?.message || reason, - ); + log.error('[server] Unhandled promise rejection:', reason?.stack || reason?.message || reason); try { recordError('unhandledRejection', reason instanceof Error ? reason : new Error(String(reason))); } catch {} @@ -323,7 +321,7 @@ process.on('unhandledRejection', (reason) => { // An uncaught exception leaves the process in an undefined state — record it and // exit non-zero so the supervisor (Docker `restart: unless-stopped`) restarts clean. process.on('uncaughtException', (err) => { - console.error('[server] Uncaught exception:', err?.stack || err); + log.error('[server] Uncaught exception:', err?.stack || err); try { recordError('uncaughtException', err); } catch {} @@ -338,7 +336,7 @@ let shuttingDown = false; function gracefulShutdown(signal, server) { if (shuttingDown) return; shuttingDown = true; - console.log(`[server] ${signal} received — shutting down gracefully`); + log.info(`[server] ${signal} received — shutting down gracefully`); const finish = (code) => { try { @@ -347,9 +345,9 @@ function gracefulShutdown(signal, server) { getDb().pragma('wal_checkpoint(TRUNCATE)'); } catch {} closeDb(); - console.log('[server] database closed cleanly'); + log.info('[server] database closed cleanly'); } catch (e) { - console.error('[server] error closing database:', e?.message || e); + log.error('[server] error closing database:', e?.message || e); } process.exit(code); }; @@ -357,7 +355,7 @@ function gracefulShutdown(signal, server) { server.close(() => finish(0)); // Don't let a hung connection block shutdown forever. setTimeout(() => { - console.error('[server] shutdown timed out after 10s — forcing exit'); + log.error('[server] shutdown timed out after 10s — forcing exit'); finish(1); }, 10000).unref(); } @@ -374,16 +372,16 @@ async function main() { try { reEncryptWithEnvKey(db); } catch (err) { - console.error('[encryption] Startup key migration failed:', err.message); + log.error('[encryption] Startup key migration failed:', err.message); } // Run session cleanup on startup const { cleanupExpiredSessions } = require('./db/database.cts'); try { - console.log('[cleanup] Running session cleanup on startup'); + log.info('[cleanup] Running session cleanup on startup'); cleanupExpiredSessions(); } catch (err) { - console.error('[cleanup-error] Failed to run startup session cleanup:', err.message); + log.error('[cleanup-error] Failed to run startup session cleanup:', err.message); } const userCount = db.prepare('SELECT COUNT(*) AS count FROM users').get().count; @@ -396,7 +394,7 @@ async function main() { // Validate password length if (regularPass && regularPass.length < 8) { - console.error('[seed] INIT_REGULAR_PASS must be at least 8 characters'); + log.error('[seed] INIT_REGULAR_PASS must be at least 8 characters'); process.exit(1); } @@ -414,7 +412,7 @@ async function main() { VALUES (?, ?, 'user', 0, 0, 0) `, ).run(regularUser, regularHash); - console.log(`[seed] Regular user "${regularUser}" created.`); + log.info(`[seed] Regular user "${regularUser}" created.`); return true; } else { // Update existing regular user's password and reset flags @@ -433,7 +431,7 @@ async function main() { source: 'server-seed', }, }); - console.log(`[seed] Regular user "${regularUser}" password updated and flags reset.`); + log.info(`[seed] Regular user "${regularUser}" password updated and flags reset.`); return false; } }); @@ -441,8 +439,8 @@ async function main() { } const server = app.listen(PORT, HOST, () => { - console.log(`Bill Tracker running on ${HOST}:${PORT}`); - if (userCount > 0) console.log(`Users found: ${userCount}`); + log.info(`Bill Tracker running on ${HOST}:${PORT}`); + if (userCount > 0) log.info(`Users found: ${userCount}`); // Set up periodic session cleanup const { cleanupExpiredSessions } = require('./db/database.cts'); @@ -454,7 +452,7 @@ async function main() { // max 7 days CLEANUP_INTERVAL_MS = parsed; } else { - console.warn( + log.warn( `[cleanup] Invalid SESSION_CLEANUP_INTERVAL_MS: "${rawInterval}". Using default 24h.`, ); } @@ -463,20 +461,20 @@ async function main() { // Run cleanup periodically setInterval(() => { try { - console.log('[cleanup] Running periodic session cleanup'); + log.info('[cleanup] Running periodic session cleanup'); cleanupExpiredSessions(); } catch (err) { - console.error('[cleanup-error] Failed to run periodic session cleanup:', err.message); + log.error('[cleanup-error] Failed to run periodic session cleanup:', err.message); } }, CLEANUP_INTERVAL_MS); - console.log(`[cleanup] Scheduled periodic cleanup every ${CLEANUP_INTERVAL_MS}ms`); + log.info(`[cleanup] Scheduled periodic cleanup every ${CLEANUP_INTERVAL_MS}ms`); // Start SimpleFIN auto-sync worker (no-op when bank sync is disabled) try { require('./services/bankSyncWorker.cts').start(); } catch (err) { - console.error('[bankSync] Failed to start auto-sync worker:', err.message); + log.error('[bankSync] Failed to start auto-sync worker:', err.message); } // Start scheduled database backups only when enabled in Admin settings. @@ -486,14 +484,14 @@ async function main() { backupScheduler.start(); } } catch (err) { - console.error('[backupScheduler] Failed to start scheduled backup worker:', err.message); + log.error('[backupScheduler] Failed to start scheduled backup worker:', err.message); } // Start daily worker (autopay marking, notifications, session pruning, cleanup) try { require('./workers/dailyWorker.cts').start(); } catch (err) { - console.error('[dailyWorker] Failed to start daily worker:', err.message); + log.error('[dailyWorker] Failed to start daily worker:', err.message); } }); @@ -503,6 +501,6 @@ async function main() { } main().catch((err) => { - console.error('Failed to start server:', err); + log.error('Failed to start server:', err); process.exit(1); }); diff --git a/services/auditService.cts b/services/auditService.cts index 54ff413..83886d6 100644 --- a/services/auditService.cts +++ b/services/auditService.cts @@ -1,6 +1,7 @@ import type { Db } from '../types/db'; const { getDb } = require('../db/database.cts'); +const { log } = require('../utils/logger.cts'); interface AuditParams { user_id?: number | null; @@ -40,7 +41,7 @@ function logAudit({ ); } catch (err: any) { // Audit logging should never crash the app - console.error('[audit-error] Failed to log audit event:', err.message); + log.error('[audit-error] Failed to log audit event:', err.message); } } diff --git a/services/authService.cts b/services/authService.cts index 4f5d063..e2c3a87 100644 --- a/services/authService.cts +++ b/services/authService.cts @@ -2,6 +2,7 @@ import type { Db } from '../types/db'; import type { Req } from '../types/http'; const crypto = require('crypto'); +const { log } = require('../utils/logger.cts'); const bcrypt = require('bcryptjs'); const { getDb } = require('../db/database.cts'); const { buildDeviceFingerprint } = require('./loginFingerprint.cts'); @@ -99,7 +100,7 @@ async function login(username: any, password: any) { user.id, ); } catch (err: any) { - console.error('[cleanup-error] Failed to cleanup user expired sessions:', err.message); + log.error('[cleanup-error] Failed to cleanup user expired sessions:', err.message); } const sessionId = crypto.randomUUID(); @@ -136,7 +137,7 @@ async function createSession(userId: any) { userId, ); } catch (err: any) { - console.error('[cleanup-error] Failed to cleanup user expired sessions:', err.message); + log.error('[cleanup-error] Failed to cleanup user expired sessions:', err.message); } const sessionId = crypto.randomUUID(); @@ -427,7 +428,7 @@ function recordFailedLogin(userId: any, ipAddress: any, userAgent: any): void { // Prune expired sessions — called by daily worker function pruneExpiredSessions() { const result = getDb().prepare("DELETE FROM sessions WHERE expires_at <= datetime('now')").run(); - console.log(`[cleanup] Purged ${result.changes} expired sessions`); + log.info(`[cleanup] Purged ${result.changes} expired sessions`); return result; } diff --git a/services/backupScheduler.cts b/services/backupScheduler.cts index 0da82d8..94d2a69 100644 --- a/services/backupScheduler.cts +++ b/services/backupScheduler.cts @@ -2,6 +2,7 @@ import type { Db } from '../types/db'; const cron = require('node-cron'); +const { log } = require('../utils/logger.cts'); const { getSetting, setSetting } = require('../db/database.cts'); const { applyScheduledRetention, createBackup } = require('./backupService.cts'); @@ -130,7 +131,7 @@ function reloadSchedule() { task = cron.schedule(cronExpression(settings), () => { runScheduledBackupNow().catch((err: any) => { - console.error('[backupScheduler] Scheduled backup failed:', err.message); + log.error('[backupScheduler] Scheduled backup failed:', err.message); }); }); diff --git a/services/bankSyncService.cts b/services/bankSyncService.cts index 0381c15..a6127e6 100644 --- a/services/bankSyncService.cts +++ b/services/bankSyncService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const { assertEncryptionReady, encryptSecret, decryptSecret } = require('./encryptionService.cts'); +const { log } = require('../utils/logger.cts'); const { claimSetupToken, fetchAccountsAndTransactions, @@ -178,7 +179,7 @@ async function runSync( const since = sinceEpochDays(syncDays); if (debug) - console.log( + log.info( `[bankSync:debug] Source #${dataSource.id} user ${userId}: fetching ${syncDays} days from SimpleFIN (since epoch ${since})`, ); @@ -186,12 +187,12 @@ async function runSync( const accounts = Array.isArray(raw.accounts) ? raw.accounts : []; if (debug) - console.log( + log.info( `[bankSync:debug] Source #${dataSource.id}: SimpleFIN returned ${accounts.length} account(s)`, ); if (raw._errlistSummary) { - console.warn(`[bankSync] errlist for source ${dataSource.id}: ${raw._errlistSummary}`); + log.warn(`[bankSync] errlist for source ${dataSource.id}: ${raw._errlistSummary}`); } let accountsUpserted = 0; @@ -224,7 +225,7 @@ async function runSync( const txList = rawAccount.transactions || []; if (debug) - console.log( + log.info( `[bankSync:debug] Account "${rawAccount.name}" (monitored=${localAccount.monitored}): ${txList.length} transaction(s)`, ); @@ -245,24 +246,22 @@ async function runSync( if (outcome === 'inserted') { transactionsNew += 1; if (debug) - console.log( + log.info( `[bankSync:debug] tx ${txRow.provider_transaction_id}: inserted${txRow.pending ? ' (pending)' : ''} (${rawTx.description || rawTx.payee || '—'}, ${txRow.amount}¢)`, ); } else if (outcome === 'posted') { transactionsPosted += 1; if (debug) - console.log( - `[bankSync:debug] tx ${txRow.provider_transaction_id}: pending → posted`, - ); + log.info(`[bankSync:debug] tx ${txRow.provider_transaction_id}: pending → posted`); } else if (outcome === 'updated') { if (debug) - console.log( + log.info( `[bankSync:debug] tx ${txRow.provider_transaction_id}: pending amount refreshed`, ); } else { transactionsSkip += 1; if (debug) - console.log( + log.info( `[bankSync:debug] tx ${txRow.provider_transaction_id}: duplicate — skipped`, ); } @@ -272,7 +271,7 @@ async function runSync( if (orphans.changes > 0) { pendingCleared += orphans.changes; if (debug) - console.log( + log.info( `[bankSync:debug] Account "${rawAccount.name}": pruned ${orphans.changes} stale pending row(s)`, ); } @@ -283,7 +282,7 @@ async function runSync( ingest(); if (debug) - console.log(`[bankSync:debug] Source #${dataSource.id}: applying merchant rules + auto-match`); + log.info(`[bankSync:debug] Source #${dataSource.id}: applying merchant rules + auto-match`); // Apply stored merchant→bill rules, then spending category rules, then score-based auto-match const { @@ -310,7 +309,7 @@ async function runSync( } if (debug) - console.log( + log.info( `[bankSync:debug] Source #${dataSource.id}: auto-matched ${autoMatched} transaction(s)`, ); diff --git a/services/bankSyncWorker.cts b/services/bankSyncWorker.cts index 404e3b3..03357d3 100644 --- a/services/bankSyncWorker.cts +++ b/services/bankSyncWorker.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const { getDb } = require('../db/database.cts'); +const { log } = require('../utils/logger.cts'); const { getBankSyncConfig } = require('./bankSyncConfigService.cts'); const { syncDataSource } = require('./bankSyncService.cts'); @@ -36,7 +37,7 @@ async function runCycle(): Promise { const config = getBankSyncConfig(); if (!config.enabled) { - console.log('[bankSync] Disabled — skipping cycle'); + log.info('[bankSync] Disabled — skipping cycle'); return; } @@ -55,16 +56,16 @@ async function runCycle(): Promise { ) .all(); } catch (err: any) { - console.error('[bankSync] Worker failed to load sources:', err.message); + log.error('[bankSync] Worker failed to load sources:', err.message); return; } if (sources.length === 0) { - if (debug) console.log('[bankSync] No SimpleFIN sources configured — skipping cycle'); + if (debug) log.info('[bankSync] No SimpleFIN sources configured — skipping cycle'); return; } - console.log(`[bankSync] Cycle starting — ${sources.length} source(s)`); + log.info(`[bankSync] Cycle starting — ${sources.length} source(s)`); running = true; lastRunAt = new Date().toISOString(); @@ -77,15 +78,14 @@ async function runCycle(): Promise { if (!needsSync(source)) { if (debug) - console.log( + log.info( `[bankSync] Source #${source.id} (user ${source.user_id}): recently synced — skipping`, ); skipped++; continue; } - if (debug) - console.log(`[bankSync] Source #${source.id} (user ${source.user_id}): starting sync`); + if (debug) log.info(`[bankSync] Source #${source.id} (user ${source.user_id}): starting sync`); try { const result = await syncDataSource(db, source.user_id, source.id, { debug }); synced++; @@ -95,19 +95,19 @@ async function runCycle(): Promise { ] .filter(Boolean) .join(', '); - console.log( + log.info( `[bankSync] Source #${source.id}: OK — ${result.accountsUpserted} account(s), ${result.transactionsNew} new, ${result.transactionsSkip} skipped${extra ? `, ${extra}` : ''}${result.errlist ? ` [partial: ${result.errlist}]` : ''}`, ); } catch (err: any) { failed++; - console.error(`[bankSync] Source #${source.id}: FAILED — ${err.message}`); + log.error(`[bankSync] Source #${source.id}: FAILED — ${err.message}`); } // Stagger requests — don't fire them all simultaneously if (i < sources.length - 1) await sleep(STAGGER_DELAY_MS); } - console.log(`[bankSync] Cycle complete — ${synced} synced, ${failed} failed, ${skipped} skipped`); + log.info(`[bankSync] Cycle complete — ${synced} synced, ${failed} failed, ${skipped} skipped`); running = false; } @@ -118,7 +118,7 @@ function scheduleNext(): void { timer = setTimeout(() => { runCycle() .catch((err) => { - console.error('[bankSync] Worker cycle error:', err.message); + log.error('[bankSync] Worker cycle error:', err.message); running = false; }) .finally(scheduleNext); @@ -131,7 +131,7 @@ function scheduleNext(): void { function start(): void { if (timer) return; scheduleNext(); - console.log( + log.info( `[bankSync] Auto-sync worker started (interval: ${getBankSyncConfig().sync_interval_hours}h)`, ); } diff --git a/services/billMerchantRuleService.cts b/services/billMerchantRuleService.cts index 8559dcc..19592e7 100644 --- a/services/billMerchantRuleService.cts +++ b/services/billMerchantRuleService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const { normalizeMerchant } = require('./subscriptionService.cts'); +const { log } = require('../utils/logger.cts'); const { getUserSettings } = require('./userSettings.cts'); const { applyBankPaymentAsSourceOfTruth } = require('./paymentAccountingService.cts'); const { localDateString } = require('../utils/dates.mts') as typeof import('../utils/dates.mts'); @@ -159,7 +160,7 @@ function applyMerchantRules( ) .all(userId); } catch (err: any) { - console.error('[applyMerchantRules] Failed to fetch transactions:', err.message); + log.error('[applyMerchantRules] Failed to fetch transactions:', err.message); return { matched: 0, matched_bills: [] }; } @@ -267,7 +268,7 @@ function applyMerchantRules( } })(); } catch (err: any) { - console.error('[applyMerchantRules] Transaction failed, no payments recorded:', err.message); + log.error('[applyMerchantRules] Transaction failed, no payments recorded:', err.message); return { matched: 0, matched_bills: [], late_attributions: [] }; } @@ -319,7 +320,7 @@ function syncBillPaymentsFromSimplefin( } } } catch (err: any) { - console.error('[syncBillPaymentsFromSimplefin] Failed to read bill notes:', err.message); + log.error('[syncBillPaymentsFromSimplefin] Failed to read bill notes:', err.message); } if (rules.length === 0) return { added: 0 }; } @@ -342,7 +343,7 @@ function syncBillPaymentsFromSimplefin( ) .all(userId); } catch (err: any) { - console.error('[syncBillPaymentsFromSimplefin] Failed to fetch transactions:', err.message); + log.error('[syncBillPaymentsFromSimplefin] Failed to fetch transactions:', err.message); return { added: 0 }; } @@ -431,7 +432,7 @@ function syncBillPaymentsFromSimplefin( } })(); } catch (err: any) { - console.error( + log.error( '[syncBillPaymentsFromSimplefin] Transaction failed, no payments recorded:', err.message, ); diff --git a/services/cleanupService.cts b/services/cleanupService.cts index 9c51c83..47d974c 100644 --- a/services/cleanupService.cts +++ b/services/cleanupService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const os = require('os'); +const { log } = require('../utils/logger.cts'); const fs = require('fs'); const path = require('path'); @@ -50,7 +51,7 @@ function pruneStaleExportFiles(maxAgeHours: number): { removed: number; errors: try { entries = fs.readdirSync(tmpDir); } catch (err: any) { - console.warn('[cleanup] Cannot read tmpdir:', err.message); + log.warn('[cleanup] Cannot read tmpdir:', err.message); return { removed, errors: 1 }; } @@ -91,7 +92,7 @@ function pruneOrphanedBackupPartials(backupDir: string): { removed: number; erro try { entries = fs.readdirSync(backupDir); } catch (err: any) { - console.warn('[cleanup] Cannot read backup dir:', err.message); + log.warn('[cleanup] Cannot read backup dir:', err.message); return { removed, errors: 1 }; } @@ -257,7 +258,7 @@ async function runAllCleanup() { setSetting('cleanup_last_run_at', ran_at); setSetting('cleanup_last_result', JSON.stringify(tasks)); - console.log(`[cleanup] Ran at ${ran_at}:`, JSON.stringify(tasks)); + log.info(`[cleanup] Ran at ${ran_at}:`, JSON.stringify(tasks)); return { ran_at, tasks }; } diff --git a/services/driftService.cts b/services/driftService.cts index 32ecd7c..0e578ae 100644 --- a/services/driftService.cts +++ b/services/driftService.cts @@ -3,6 +3,7 @@ import type { Dollars } from '../utils/money.mts'; const { getDb } = require('../db/database.cts'); +const { log } = require('../utils/logger.cts'); const { getCycleRange } = require('./statusService.cts'); const { accountingActiveSql } = require('./paymentAccountingService.cts'); const { getUserSettings } = require('./userSettings.cts'); @@ -126,7 +127,7 @@ function getDriftReport(userId: number, now: Date = new Date()): DriftReport { return { bills: drifted, threshold_pct: thresholdPct }; } catch (err: any) { - console.error('[driftService] getDriftReport error:', err.message); + log.error('[driftService] getDriftReport error:', err.message); return { bills: [], threshold_pct: 5, error: err.message }; } } diff --git a/services/encryptionService.cts b/services/encryptionService.cts index e9f00a3..c45cf61 100644 --- a/services/encryptionService.cts +++ b/services/encryptionService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const crypto = require('crypto'); +const { log } = require('../utils/logger.cts'); const ALGORITHM = 'aes-256-gcm'; const IV_BYTES = 12; @@ -184,7 +185,7 @@ function reEncryptWithEnvKey(db: Db): void { })(); if (count > 0) { - console.log( + log.info( `[encryption] Migrated ${count} secret(s) from db-key to env-key (TOKEN_ENCRYPTION_KEY)`, ); } diff --git a/services/notificationService.cts b/services/notificationService.cts index 11a3349..754682a 100644 --- a/services/notificationService.cts +++ b/services/notificationService.cts @@ -1,6 +1,7 @@ import type { Db } from '../types/db'; const nodemailer = require('nodemailer'); +const { log } = require('../utils/logger.cts'); const { getDb, getSetting } = require('../db/database.cts'); const { decryptSecret, encryptSecret } = require('./encryptionService.cts'); const { accountingActiveSql } = require('./paymentAccountingService.cts'); @@ -440,9 +441,7 @@ async function runNotifications() { if (!type) continue; if (!bill.user_id) { - console.warn( - `[notifications] Bill id=${bill.id} name="${bill.name}" has no user_id — skipping`, - ); + log.warn(`[notifications] Bill id=${bill.id} name="${bill.name}" has no user_id — skipping`); continue; } @@ -493,10 +492,10 @@ async function runNotifications() { if (errors.length) { markNotificationError(new Error(errors.join('; '))); - console.error('[notifications] Send errors:', errors); + log.error('[notifications] Send errors:', errors); } else { markNotificationSuccess(); - console.log(`[notifications] Run complete for ${today}`); + log.info(`[notifications] Run complete for ${today}`); } } @@ -618,7 +617,7 @@ async function runDriftNotifications() { recordNotification(db, b.id, recipient.id, year, month, 'amount_change', today); } } catch (err: any) { - console.error( + log.error( '[drift notifications] Error for recipient', recipient.notification_email, ':', diff --git a/services/oidcService.cts b/services/oidcService.cts index c4ae130..44dee03 100644 --- a/services/oidcService.cts +++ b/services/oidcService.cts @@ -50,6 +50,7 @@ */ const crypto = require('crypto'); +const { log } = require('../utils/logger.cts'); const { Issuer } = require('openid-client'); const { getDb, getSetting, setSetting } = require('../db/database.cts'); @@ -728,7 +729,7 @@ async function findOrProvisionUser(claims, config) { `, ).run(provider, sub, claims.email, existing.id); user = db.prepare('SELECT * FROM users WHERE id = ?').get(existing.id); - console.log(`[oidc] Linked existing local account #${user.id} to OIDC identity`); + log.info(`[oidc] Linked existing local account #${user.id} to OIDC identity`); } } @@ -766,7 +767,7 @@ async function findOrProvisionUser(claims, config) { .run(finalUsername, role, provider, sub, email, displayName); user = db.prepare('SELECT * FROM users WHERE id = ?').get(result.lastInsertRowid); - console.log(`[oidc] Provisioned new ${role} user from OIDC login`); + log.info(`[oidc] Provisioned new ${role} user from OIDC login`); } if (user.active === 0) { diff --git a/services/spendingService.cts b/services/spendingService.cts index 9ab9afa..52f510c 100644 --- a/services/spendingService.cts +++ b/services/spendingService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const { normalizeMerchant } = require('./subscriptionService.cts'); +const { log } = require('../utils/logger.cts'); const { localDateString } = require('../utils/dates.mts') as typeof import('../utils/dates.mts'); const { toCents, fromCents } = require('../utils/money.mts') as typeof import('../utils/money.mts'); @@ -542,7 +543,7 @@ function getIncomeTransactions( pages: Math.ceil(total / limit), }; } catch (err: any) { - console.error('[getIncomeTransactions]', err.message); + log.error('[getIncomeTransactions]', err.message); return { transactions: [], total: 0, page: 1, pages: 1 }; } } diff --git a/services/spreadsheetImportService.cts b/services/spreadsheetImportService.cts index a959216..1f8f1d2 100644 --- a/services/spreadsheetImportService.cts +++ b/services/spreadsheetImportService.cts @@ -13,6 +13,7 @@ // 8. Content-type validation via express.raw type whitelist const xlsx = require('xlsx'); +const { log } = require('../utils/logger.cts'); const crypto = require('crypto'); const { getDb, ensureUserDefaultCategories } = require('../db/database.cts'); const { computeBalanceDelta, applyBalanceDelta } = require('./billsService.cts'); @@ -273,7 +274,7 @@ function getSheetRows(workbook, sheetName) { // raw:false → formatted string values; no formula results can leak through return xlsx.utils.sheet_to_json(sheet, { header: 1, defval: null, raw: false }); } catch (err) { - console.error(`[import] sheet="${sheetName}" failed to parse rows — skipping:`, err.message); + log.error(`[import] sheet="${sheetName}" failed to parse rows — skipping:`, err.message); return []; } } @@ -947,18 +948,18 @@ function analyzeRow( if (detectedLabels.includes('autopay') && billName) { if (_rawDue && /auto/i.test(_rawDue) && /\d/.test(_rawDue)) { - console.log( + log.info( `[import] ${_loc} autopay+date in due col: "${_rawDue}" (date portion not extracted)`, ); } else { - console.log(`[import] ${_loc} autopay detected`); + log.info(`[import] ${_loc} autopay detected`); } } if (detectedLabels.includes('past_due')) { - console.log(`[import] ${_loc} PAST DUE detected`); + log.info(`[import] ${_loc} PAST DUE detected`); } if (_rawPaid && !parsedPaidDate) { - console.log(`[import] ${_loc} unparseable paid date: "${_rawPaid}"`); + log.info(`[import] ${_loc} unparseable paid date: "${_rawPaid}"`); } // ─────────────────────────────────────────────────────────────────────────── @@ -1080,13 +1081,13 @@ function parseSheetRows( // Log detected layout for this sheet const _colLetter = (i) => String.fromCharCode(65 + i); if (!hasHeaders) { - console.log(`[import] sheet="${name}" no valid headers detected — sheet will be skipped`); + log.info(`[import] sheet="${name}" no valid headers detected — sheet will be skipped`); } else { for (const [si, set] of allHeaderSets.entries()) { const mapped = Object.entries(set.map) .map(([f, i]) => `${f}:${_colLetter(i)}`) .join(', '); - console.log( + log.info( `[import] sheet="${name}" group=${si} defaultDueDay=${set.defaultDueDay} columns={${mapped}}`, ); } @@ -1177,7 +1178,7 @@ function parseSheetRows( ), ); } catch (err) { - console.error( + log.error( `[import] sheet="${name}" row=${i + 1} failed to analyze — skipping:`, err.message, ); @@ -1246,7 +1247,7 @@ async function previewSpreadsheet(userId, buffer, options = {}) { try { pruneExpiredSessions(db); } catch (err) { - console.error('[import] failed to prune expired sessions (non-fatal):', err.message); + log.error('[import] failed to prune expired sessions (non-fatal):', err.message); } ensureUserDefaultCategories(userId); @@ -1883,7 +1884,7 @@ function applyOneDecision( db.prepare( `UPDATE bills SET autopay_enabled = 1, updated_at = datetime('now') WHERE id = ?`, ).run(billId); - console.log(`[import] bill id=${billId} "${bill.name}" autopay_enabled upgraded to 1`); + log.info(`[import] bill id=${billId} "${bill.name}" autopay_enabled upgraded to 1`); } if (!year || !month) { @@ -2112,7 +2113,7 @@ async function applyImportDecisions(userId, importSessionId, decisions, opts = { JSON.stringify(summary.details), ); } catch (histErr) { - console.error('[import] history write failed:', histErr.message); + log.error('[import] history write failed:', histErr.message); } // Session is intentionally kept alive until its 24-hour TTL expires. diff --git a/services/trackerService.cts b/services/trackerService.cts index 58a27fa..ab7bc86 100644 --- a/services/trackerService.cts +++ b/services/trackerService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const { getDb } = require('../db/database.cts'); +const { log } = require('../utils/logger.cts'); const { buildTrackerRow, getCycleRange, @@ -173,7 +174,7 @@ function buildBankTracking( last_updated: account.updated_at, }; } catch (err: any) { - console.error('[buildBankTracking] Error computing bank tracking data:', err.message); + log.error('[buildBankTracking] Error computing bank tracking data:', err.message); return { enabled: false }; } } diff --git a/services/webauthnService.cts b/services/webauthnService.cts index 02265f2..1d0d48e 100644 --- a/services/webauthnService.cts +++ b/services/webauthnService.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const crypto = require('crypto'); +const { log } = require('../utils/logger.cts'); const { generateRegistrationOptions, verifyRegistrationResponse, @@ -123,7 +124,7 @@ async function verifyRegistration( return { verified: true, credentialId: credential.id }; } catch (err: any) { - console.error('[webauthn] registration error:', err.message); + log.error('[webauthn] registration error:', err.message); return { verified: false, error: err.message }; } } @@ -200,7 +201,7 @@ async function verifyAuthentication(db: Db, userId: number, challengeId: string, return { verified: true }; } catch (err: any) { - console.error('[webauthn] authentication error:', err.message); + log.error('[webauthn] authentication error:', err.message); return { verified: false, error: err.message }; } } diff --git a/setup/firstRun.cts b/setup/firstRun.cts index dec0ccf..7a40457 100644 --- a/setup/firstRun.cts +++ b/setup/firstRun.cts @@ -1,4 +1,5 @@ const readline = require('readline'); +const { log } = require('../utils/logger.cts'); const bcrypt = require('bcryptjs'); const { logAudit } = require('../services/auditService.cts'); @@ -85,13 +86,11 @@ async function runFromEnv(db) { errors.push('INIT_REGULAR_PASS must be at least 8 characters'); if (errors.length) { - console.error('\n[first-run] Environment variable setup failed:'); - errors.forEach((e) => console.error(' ✗ ' + e)); - console.error('\nSet both vars: INIT_ADMIN_USER and INIT_ADMIN_PASS'); - console.error( - 'Optionally set: INIT_REGULAR_USER and INIT_REGULAR_PASS for a non-admin test user', - ); - console.error('Then open the web UI to create your first user account.\n'); + log.error('\n[first-run] Environment variable setup failed:'); + errors.forEach((e) => log.error(' ✗ ' + e)); + log.error('\nSet both vars: INIT_ADMIN_USER and INIT_ADMIN_PASS'); + log.error('Optionally set: INIT_REGULAR_USER and INIT_REGULAR_PASS for a non-admin test user'); + log.error('Then open the web UI to create your first user account.\n'); process.exit(1); } @@ -115,7 +114,7 @@ async function runFromEnv(db) { source: 'first-run-env', }, }); - console.log(`[first-run] Admin password updated for "${adminUser}".`); + log.info(`[first-run] Admin password updated for "${adminUser}".`); } else { // Create new admin user db.prepare( @@ -124,7 +123,7 @@ async function runFromEnv(db) { VALUES (?, ?, ?, 0, 0, 1) `, ).run(adminUser, adminHash, 'admin'); - console.log(`[first-run] Admin "${adminUser}" created.`); + log.info(`[first-run] Admin "${adminUser}" created.`); } // Handle regular user creation if specified @@ -149,7 +148,7 @@ async function runFromEnv(db) { source: 'first-run-env', }, }); - console.log(`[first-run] Regular user password updated for "${regularUser}".`); + log.info(`[first-run] Regular user password updated for "${regularUser}".`); } else { // Create new regular user db.prepare( @@ -158,11 +157,11 @@ async function runFromEnv(db) { VALUES (?, ?, ?, 0, 0, 0) `, ).run(regularUser, regularHash, 'user'); - console.log(`[first-run] Regular user "${regularUser}" created.`); + log.info(`[first-run] Regular user "${regularUser}" created.`); } } - console.log('[first-run] You can now log in with these credentials.'); + log.info('[first-run] You can now log in with these credentials.'); } async function run(db) { @@ -173,7 +172,7 @@ async function run(db) { // No TTY and no env vars if (!process.stdin.isTTY) { - console.error( + log.error( [ '', '[first-run] No admin account found and no TTY available for interactive setup.', @@ -189,10 +188,10 @@ async function run(db) { } // Interactive terminal wizard (admin only) - console.log('\n' + line('═')); - console.log(' Bill Tracker — First Run Setup'); - console.log(line('═')); - console.log(` + log.info('\n' + line('═')); + log.info(' Bill Tracker — First Run Setup'); + log.info(line('═')); + log.info(` No accounts found. Create an admin account to get started. About the admin account: @@ -202,28 +201,28 @@ About the admin account: or financial data — ever `); - console.log(line()); - console.log(' Create Admin Account'); - console.log(line()); - console.log(''); + log.info(line()); + log.info(' Create Admin Account'); + log.info(line()); + log.info(''); let username, password, confirm; while (true) { username = await prompt(' Username: '); if (username.length >= 3) break; - console.log(' Username must be at least 3 characters.\n'); + log.info(' Username must be at least 3 characters.\n'); } while (true) { password = await promptPassword(' Password: '); if (password.length < 8) { - console.log(' Password must be at least 8 characters.\n'); + log.info(' Password must be at least 8 characters.\n'); continue; } confirm = await promptPassword(' Confirm: '); if (password !== confirm) { - console.log(' Passwords do not match.\n'); + log.info(' Passwords do not match.\n'); continue; } break; @@ -231,14 +230,14 @@ About the admin account: await createUser(db, username, password, 'admin'); - console.log(`\n ✓ Admin account "${username}" created.\n`); - console.log(line('═')); - console.log(' Setup complete!'); - console.log(''); - console.log(' Open the app in your browser and log in as admin'); - console.log(' to create your first user account.'); - console.log(line('═')); - console.log(''); + log.info(`\n ✓ Admin account "${username}" created.\n`); + log.info(line('═')); + log.info(' Setup complete!'); + log.info(''); + log.info(' Open the app in your browser and log in as admin'); + log.info(' to create your first user account.'); + log.info(line('═')); + log.info(''); } module.exports = { run }; diff --git a/tests/logger.test.js b/tests/logger.test.js new file mode 100644 index 0000000..7e3c3ff --- /dev/null +++ b/tests/logger.test.js @@ -0,0 +1,45 @@ +'use strict'; + +// The logger must never let secrets/PII reach the output. These tests pin the +// redaction contract for a financial app. +const test = require('node:test'); +const assert = require('node:assert/strict'); + +const { redact } = require('../utils/logger.cts'); + +test('masks sensitive object keys at any depth', () => { + const out = redact({ + username: 'alice', + password: 'hunter2', + totp_secret: 'JBSWY3DPEHPK3PXP', + nested: { access_token: 'abc123', client_secret: 'shh', keep: 'visible' }, + encrypted_secret: 'e2:deadbeef', + }); + assert.equal(out.username, 'alice'); + assert.equal(out.password, '«redacted»'); + assert.equal(out.totp_secret, '«redacted»'); + assert.equal(out.nested.access_token, '«redacted»'); + assert.equal(out.nested.client_secret, '«redacted»'); + assert.equal(out.nested.keep, 'visible'); + assert.equal(out.encrypted_secret, '«redacted»'); +}); + +test('masks bearer tokens and JWTs inside strings', () => { + assert.match(redact('Authorization: Bearer abcdef.ghijk.lmnop'), /«redacted»/); + assert.match( + redact('token eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.payloadpayloadpayload.sig'), + /«redacted»/, + ); +}); + +test('leaves normal values (ids, amounts, names) untouched', () => { + const out = redact({ id: 42, amount_cents: 12345, name: 'Electric Company', active: true }); + assert.deepEqual(out, { id: 42, amount_cents: 12345, name: 'Electric Company', active: true }); +}); + +test('Error becomes its stack/message string', () => { + const e = new Error('boom'); + const out = redact(e); + assert.equal(typeof out, 'string'); + assert.match(out, /boom/); +}); diff --git a/utils/logger.cts b/utils/logger.cts new file mode 100644 index 0000000..9d0b037 --- /dev/null +++ b/utils/logger.cts @@ -0,0 +1,65 @@ +'use strict'; + +// Leading import so Node's type-stripping activates for `node --check`. +import type { Db } from '../types/db'; + +// Structured, redacted application logging. Console-compatible call signature so +// migrating from `console.*` is mechanical, with two things console can't do: +// 1. Level gating (LOG_LEVEL, or debug in dev / info in prod by default). +// 2. Redaction — secrets/PII (tokens, passwords, encrypted values, bearer/JWT) +// never reach the logs. Critical for a financial app. +// The backend is abstracted (currently console) so it can be swapped for pino +// later without touching call sites. + +const LEVELS: Record = { debug: 10, info: 20, warn: 30, error: 40, silent: 100 }; + +function resolveThreshold(): number { + const env = (process.env.LOG_LEVEL || '').toLowerCase(); + if (env && Object.prototype.hasOwnProperty.call(LEVELS, env)) return LEVELS[env]; + return process.env.NODE_ENV === 'production' ? LEVELS.info : LEVELS.debug; +} +let threshold = resolveThreshold(); + +// Object keys whose values are sensitive and must be masked wherever they appear. +const SENSITIVE_KEY = + /^(.*_)?(pass(word)?|secret|token|authorization|cookie|api[_-]?key|totp|totp_secret|totp_recovery_codes|encrypted|encrypted_secret|private[_-]?key|session|push_url|push_token|access_token|refresh_token|id_token|client_secret)(_.*)?$/i; +// Unambiguous secret-shaped strings (bearer tokens + JWTs). Kept conservative to +// avoid redacting legitimate ids/hashes. +const SECRETY_STRING = /(bearer\s+[\w.\-]+|eyJ[A-Za-z0-9._\-]{20,})/gi; + +const MASK = '«redacted»'; + +function redact(value: unknown, depth = 0): unknown { + if (value == null || depth > 5) return value; + if (typeof value === 'string') return value.replace(SECRETY_STRING, MASK); + if (typeof value === 'bigint' || typeof value === 'number' || typeof value === 'boolean') + return value; + if (value instanceof Error) return value.stack || value.message; + if (Array.isArray(value)) return value.map((v) => redact(v, depth + 1)); + if (typeof value === 'object') { + const out: Record = {}; + for (const [k, v] of Object.entries(value as Record)) { + out[k] = SENSITIVE_KEY.test(k) ? MASK : redact(v, depth + 1); + } + return out; + } + return value; +} + +function emit(level: string, sink: (...a: any[]) => void, args: unknown[]): void { + if (LEVELS[level] < threshold) return; + sink(...args.map((a) => redact(a))); +} + +const log = { + debug: (...a: unknown[]) => emit('debug', console.log, a), + info: (...a: unknown[]) => emit('info', console.log, a), + warn: (...a: unknown[]) => emit('warn', console.warn, a), + error: (...a: unknown[]) => emit('error', console.error, a), + /** Override the active level at runtime (e.g. tests). */ + setLevel(name: string): void { + if (Object.prototype.hasOwnProperty.call(LEVELS, name)) threshold = LEVELS[name]; + }, +}; + +module.exports = { log, redact }; diff --git a/workers/dailyWorker.cts b/workers/dailyWorker.cts index 09530ee..a603008 100644 --- a/workers/dailyWorker.cts +++ b/workers/dailyWorker.cts @@ -3,6 +3,7 @@ import type { Db } from '../types/db'; const cron = require('node-cron'); +const { log } = require('../utils/logger.cts'); const { getDb, getSetting } = require('../db/database.cts'); const { buildTrackerRow, getCycleRange } = require('../services/statusService.cts'); const { pruneExpiredSessions } = require('../services/authService.cts'); @@ -59,7 +60,7 @@ async function runDailyTasks(): Promise { ) .all(...billIds, windowStart); } catch (err: any) { - console.error('[worker] Failed to batch-fetch payments:', err.message); + log.error('[worker] Failed to batch-fetch payments:', err.message); } // Group payments by bill_id in memory @@ -89,7 +90,7 @@ async function runDailyTasks(): Promise { try { markAutopay.run(bill.id); } catch (err: any) { - console.error(`[worker] Failed to mark autopay for bill ${bill.id}:`, err.message); + log.error(`[worker] Failed to mark autopay for bill ${bill.id}:`, err.message); } } } @@ -99,19 +100,19 @@ async function runDailyTasks(): Promise { pruneWebAuthnChallenges(db); await runNotifications().catch((err: any) => { - console.error('[worker] Notification error (non-fatal):', err.message); + log.error('[worker] Notification error (non-fatal):', err.message); }); await runDriftNotifications().catch((err: any) => { - console.error('[worker] Drift notification error (non-fatal):', err.message); + log.error('[worker] Drift notification error (non-fatal):', err.message); }); await runAllCleanup().catch((err: any) => { - console.error('[worker] Cleanup error (non-fatal):', err.message); + log.error('[worker] Cleanup error (non-fatal):', err.message); }); markWorkerSuccess(nextDailyRunIso()); - console.log(`[worker] Daily tasks ran at ${todayStr}`); + log.info(`[worker] Daily tasks ran at ${todayStr}`); } let scheduledTask: any = null; @@ -126,7 +127,7 @@ function scheduleDaily(): void { scheduledTask = cron.schedule(`0 ${hour} * * *`, () => { runDailyTasks().catch((err: any) => { markWorkerError(err, nextDailyRunIso()); - console.error('[worker] Daily task error:', err); + log.error('[worker] Daily task error:', err); }); }); } @@ -136,9 +137,9 @@ function rescheduleDailyWorker(): void { try { scheduleDaily(); markWorkerStarted(nextDailyRunIso()); - console.log(`[worker] Rescheduled daily tasks to ${resolveReminderHour()}:00`); + log.info(`[worker] Rescheduled daily tasks to ${resolveReminderHour()}:00`); } catch (err: any) { - console.error('[worker] Failed to reschedule daily worker:', err.message); + log.error('[worker] Failed to reschedule daily worker:', err.message); } } @@ -148,7 +149,7 @@ function start(): void { // Run once at startup runDailyTasks().catch((err: any) => { markWorkerError(err, nextDailyRunIso()); - console.error('[worker] Startup task error:', err); + log.error('[worker] Startup task error:', err); }); // Run every day at the configured hour (default 6 AM)