diff --git a/electron/src/rt/sqlite-migrations.ts b/electron/src/rt/sqlite-migrations.ts index 2aaa581e..fcfdd9b9 100644 --- a/electron/src/rt/sqlite-migrations.ts +++ b/electron/src/rt/sqlite-migrations.ts @@ -442,8 +442,10 @@ const MIGRATIONS: Migration[] = [ secretBase64 TEXT NOT NULL ); - -- Insert initial secret - INSERT INTO secret (id, secretBase64) VALUES (1, '${INITIAL_SECRET}'); + -- Insert initial secret only if no secret exists + INSERT INTO secret (id, secretBase64) + SELECT 1, '${INITIAL_SECRET}' + WHERE NOT EXISTS (SELECT 1 FROM secret WHERE id = 1); -- Settings table for user preferences and app state CREATE TABLE IF NOT EXISTS settings ( @@ -478,8 +480,10 @@ const MIGRATIONS: Migration[] = [ webPushServer TEXT ); - -- Insert default API server setting - INSERT INTO settings (id, apiServer) VALUES (1, '${DEFAULT_ENDORSER_API_SERVER}'); + -- Insert default API server setting only if no settings exist + INSERT INTO settings (id, apiServer) + SELECT 1, '${DEFAULT_ENDORSER_API_SERVER}' + WHERE NOT EXISTS (SELECT 1 FROM settings WHERE id = 1); CREATE INDEX IF NOT EXISTS idx_settings_accountDid ON settings(accountDid); @@ -811,52 +815,93 @@ const debugTableState = async ( } }; -/** - * Executes a single migration with full transaction safety - * - * Process: - * 1. Verifies plugin and transaction state - * 2. Parses and validates SQL - * 3. Executes in transaction - * 4. Updates schema version - * 5. Verifies success - * - * Error Handling: - * - Automatic rollback on failure - * - Detailed error logging - * - State verification - * - Recovery attempts - * - * @param plugin SQLite plugin instance - * @param database Database name - * @param migration Migration to execute - * @returns {Promise} Result of migration execution - * @throws {Error} If migration fails and cannot be recovered - */ +// Add new logging helper +const logMigrationProgress = ( + migration: Migration, + stage: string, + details: Record = {} +): void => { + logger.info(`[Migration ${migration.version}] ${stage}`, { + migration: { + version: migration.version, + name: migration.name, + stage, + timestamp: new Date().toISOString(), + ...details + } + }); +}; + +// Add new error tracking +interface MigrationError extends Error { + migrationVersion?: number; + migrationName?: string; + stage?: string; + context?: Record; + isRecoverable?: boolean; +} + +const createMigrationError = ( + message: string, + migration: Migration, + stage: string, + originalError?: Error, + context: Record = {} +): MigrationError => { + const error = new Error(message) as MigrationError; + error.migrationVersion = migration.version; + error.migrationName = migration.name; + error.stage = stage; + error.context = context; + error.isRecoverable = false; + + if (originalError) { + error.stack = `${error.stack}\nCaused by: ${originalError.stack}`; + } + + return error; +}; + +// Enhance executeMigration with better logging and error handling const executeMigration = async ( plugin: any, database: string, migration: Migration ): Promise => { const startTime = Date.now(); + const migrationId = `${migration.version}_${migration.name}`; + logMigrationProgress(migration, 'Starting', { + database, + startTime: new Date(startTime).toISOString() + }); + // Parse SQL and extract any parameterized values - const { statements, parameters } = parseMigrationStatements(migration.sql); - let transactionStarted = false; + const { statements, parameters, errors: parseErrors, warnings: parseWarnings } = parseMigrationStatements(migration.sql); - logger.info(`Starting migration ${migration.version}: ${migration.name}`, { - migration: { - version: migration.version, - name: migration.name, - description: migration.description, - statementCount: statements.length, - hasParameters: parameters.length > 0 - } - }); + if (parseErrors.length > 0) { + const error = createMigrationError( + 'SQL parsing failed', + migration, + 'parse', + new Error(parseErrors.join('\n')), + { errors: parseErrors } + ); + error.isRecoverable = false; + throw error; + } + + if (parseWarnings.length > 0) { + logMigrationProgress(migration, 'Parse warnings', { warnings: parseWarnings }); + } + let transactionStarted = false; + let rollbackAttempted = false; + try { // Debug table state before migration await debugTableState(plugin, database, 'before_migration'); + logMigrationProgress(migration, 'Table state verified'); // Ensure migrations table exists with retry await executeWithRetry( @@ -865,112 +910,134 @@ const executeMigration = async ( () => ensureMigrationsTable(plugin, database), 'ensureMigrationsTable' ); + logMigrationProgress(migration, 'Migrations table verified'); - // Verify plugin state + // Verify plugin state with enhanced logging const pluginState = await verifyPluginState(plugin); if (!pluginState) { - throw new Error('Plugin not available'); + throw createMigrationError( + 'Plugin not available', + migration, + 'plugin_verification', + null, + { database } + ); } + logMigrationProgress(migration, 'Plugin state verified'); - // Start transaction with retry + // Start transaction with retry and enhanced logging await executeWithRetry( plugin, database, async () => { + logMigrationProgress(migration, 'Starting transaction'); await plugin.beginTransaction({ database }); transactionStarted = true; + logMigrationProgress(migration, 'Transaction started'); }, 'beginTransaction' ); try { - // Execute each statement with retry and parameters if any + // Execute each statement with retry and parameters for (let i = 0; i < statements.length; i++) { const statement = statements[i]; const statementParams = parameters[i] || []; + logMigrationProgress(migration, 'Executing statement', { + statementNumber: i + 1, + totalStatements: statements.length, + statementPreview: statement.substring(0, 100) + (statement.length > 100 ? '...' : '') + }); + await executeWithRetry( plugin, database, () => executeSingleStatement(plugin, database, statement, statementParams), `executeStatement_${i + 1}` ); + + logMigrationProgress(migration, 'Statement executed', { + statementNumber: i + 1, + success: true + }); } - // Commit transaction before updating schema version + // Commit transaction with enhanced logging + logMigrationProgress(migration, 'Committing transaction'); await executeWithRetry( plugin, database, async () => { await plugin.commitTransaction({ database }); transactionStarted = false; + logMigrationProgress(migration, 'Transaction committed'); }, 'commitTransaction' ); - // Update schema version outside of transaction with enhanced debugging + // Update schema version with enhanced logging + logMigrationProgress(migration, 'Updating schema version'); await executeWithRetry( plugin, database, async () => { - logger.debug('Preparing schema version update:', { - version: migration.version, - name: migration.name.trim(), - description: migration.description, - nameType: typeof migration.name, - nameLength: migration.name.length, - nameTrimmedLength: migration.name.trim().length, - nameIsEmpty: migration.name.trim().length === 0 - }); - - // Use direct SQL with properly escaped values const escapedName = migration.name.trim().replace(/'/g, "''"); const escapedDesc = (migration.description || '').replace(/'/g, "''"); const insertSql = `INSERT INTO schema_version (version, name, description) VALUES (${migration.version}, '${escapedName}', '${escapedDesc}')`; - logger.debug('Executing schema version update:', { + logMigrationProgress(migration, 'Executing schema version update', { sql: insertSql, - originalValues: { + values: { version: migration.version, - name: migration.name.trim(), - description: migration.description + name: escapedName, + description: escapedDesc } }); - // Debug table state before insert await debugTableState(plugin, database, 'before_insert'); - const result = await plugin.execute({ database, statements: insertSql, transaction: false }); + await debugTableState(plugin, database, 'after_insert'); - logger.debug('Schema version update result:', { + logMigrationProgress(migration, 'Schema version updated', { result, - sql: insertSql + changes: result.changes }); - // Debug table state after insert - await debugTableState(plugin, database, 'after_insert'); - - // Verify the insert + // Verify the insert with detailed logging const verifyQuery = await plugin.query({ database, statement: `SELECT * FROM schema_version WHERE version = ${migration.version} AND name = '${escapedName}'` }); - logger.debug('Schema version verification:', { - found: verifyQuery?.values?.length > 0, - rowCount: verifyQuery?.values?.length || 0, - data: verifyQuery?.values + if (!verifyQuery?.values?.length) { + throw createMigrationError( + 'Schema version update verification failed', + migration, + 'verify_schema_update', + null, + { verifyQuery } + ); + } + + logMigrationProgress(migration, 'Schema version verified', { + rowCount: verifyQuery.values.length, + data: verifyQuery.values }); }, 'updateSchemaVersion' ); const duration = Date.now() - startTime; - logger.info(`Migration ${migration.version} completed in ${duration}ms`); + logMigrationProgress(migration, 'Completed', { + duration, + success: true, + endTime: new Date().toISOString() + }); return { success: true, @@ -982,146 +1049,236 @@ const executeMigration = async ( } }; } catch (error) { - // Rollback with retry - if (transactionStarted) { + // Enhanced rollback handling with logging + if (transactionStarted && !rollbackAttempted) { + rollbackAttempted = true; + logMigrationProgress(migration, 'Rollback initiated', { + error: error instanceof Error ? error.message : String(error) + }); + try { await executeWithRetry( plugin, database, async () => { // Record error in schema_version before rollback + const errorMessage = error instanceof Error ? error.message : String(error); + const errorStack = error instanceof Error ? error.stack : null; + + logMigrationProgress(migration, 'Recording error state', { + errorMessage, + hasStack: !!errorStack + }); + await executeSingleStatement( plugin, database, `INSERT INTO schema_version ( version, name, description, applied_at, - error_message, error_stack, error_context - ) VALUES (?, ?, ?, CURRENT_TIMESTAMP, ?, ?, ?);`, + error_message, error_stack, error_context, + is_dirty + ) VALUES (?, ?, ?, CURRENT_TIMESTAMP, ?, ?, ?, TRUE);`, [ migration.version, migration.name, migration.description, - error instanceof Error ? error.message : String(error), - error instanceof Error ? error.stack : null, + errorMessage, + errorStack, 'migration_execution' ] ); + logMigrationProgress(migration, 'Rolling back transaction'); await plugin.rollbackTransaction({ database }); + logMigrationProgress(migration, 'Transaction rolled back'); }, 'rollbackTransaction' ); } catch (rollbackError) { - logger.error('Error during rollback:', { - originalError: error, - rollbackError - }); + const rollbackFailure = createMigrationError( + 'Rollback failed', + migration, + 'rollback', + rollbackError, + { originalError: error } + ); + rollbackFailure.isRecoverable = false; + throw rollbackFailure; } } throw error; } } catch (error) { - // Debug table state on error + // Enhanced error handling with detailed logging await debugTableState(plugin, database, 'on_error'); - logger.error('Migration execution failed:', { - error: error instanceof Error ? { - message: error.message, - stack: error.stack, - name: error.name - } : error, - migration: { - version: migration.version, - name: migration.name, - nameType: typeof migration.name, - nameLength: migration.name.length, - nameTrimmedLength: migration.name.trim().length + const migrationError = createMigrationError( + 'Migration execution failed', + migration, + 'execution', + error instanceof Error ? error : new Error(String(error)), + { + transactionStarted, + rollbackAttempted, + duration: Date.now() - startTime } + ); + + logMigrationProgress(migration, 'Failed', { + error: migrationError, + stage: migrationError.stage, + isRecoverable: migrationError.isRecoverable, + duration: Date.now() - startTime }); return { success: false, version: migration.version, name: migration.name, - error: error instanceof Error ? error : new Error(String(error)), + error: migrationError, state: { plugin: { isAvailable: true, lastChecked: new Date() }, - transaction: { isActive: false, lastVerified: new Date() } + transaction: { isActive: transactionStarted, lastVerified: new Date() } } }; } }; -/** - * Main migration runner - * - * Orchestrates the complete migration process: - * 1. Verifies plugin state - * 2. Ensures migrations table - * 3. Determines pending migrations - * 4. Executes migrations in order - * 5. Verifies results - * - * Features: - * - Version-based ordering - * - Transaction safety - * - Error recovery - * - State verification - * - Detailed logging - * - * @param plugin SQLite plugin instance - * @param database Database name - * @returns {Promise} Results of all migrations - * @throws {Error} If migration process fails - */ +// Enhance runMigrations with better logging and error handling export async function runMigrations( plugin: any, database: string ): Promise { - logger.info('Starting migration process'); + const startTime = Date.now(); + logger.info('Starting migration process', { + database, + startTime: new Date(startTime).toISOString(), + totalMigrations: MIGRATIONS.length + }); - // Validate migrations before running - validateMigrationVersions(MIGRATIONS); + // Validate migrations with enhanced error handling + try { + validateMigrationVersions(MIGRATIONS); + logger.info('Migration versions validated', { + totalMigrations: MIGRATIONS.length, + versions: MIGRATIONS.map(m => m.version) + }); + } catch (error) { + const validationError = new Error('Migration validation failed') as MigrationError; + validationError.isRecoverable = false; + validationError.context = { error }; + throw validationError; + } - // Verify plugin is available - if (!await verifyPluginState(plugin)) { - throw new Error('SQLite plugin not available'); + // Verify plugin with enhanced logging + const pluginState = await verifyPluginState(plugin); + if (!pluginState) { + const error = new Error('SQLite plugin not available') as MigrationError; + error.isRecoverable = false; + error.context = { database }; + throw error; } + logger.info('Plugin state verified'); - // Ensure migrations table exists before any migrations + // Ensure migrations table with enhanced error handling try { await ensureMigrationsTable(plugin, database); + logger.info('Migrations table ensured'); } catch (error) { - logger.error('Failed to ensure migrations table:', error); - throw new Error('Failed to initialize migrations system'); + const initError = new Error('Failed to initialize migrations system') as MigrationError; + initError.isRecoverable = false; + initError.context = { error, database }; + throw initError; } - // Get current version + // Get current version with enhanced logging const currentVersion = await getCurrentVersion(plugin, database); - logger.info(`Current database version: ${currentVersion}`); + logger.info('Current database version determined', { + currentVersion, + totalMigrations: MIGRATIONS.length + }); - // Find pending migrations + // Find pending migrations with logging const pendingMigrations = MIGRATIONS.filter(m => m.version > currentVersion); + logger.info('Pending migrations identified', { + pendingCount: pendingMigrations.length, + currentVersion, + pendingVersions: pendingMigrations.map(m => m.version) + }); + if (pendingMigrations.length === 0) { logger.info('No pending migrations'); return []; } - - logger.info(`Found ${pendingMigrations.length} pending migrations`); - // Execute each migration + // Execute migrations with enhanced error tracking const results: MigrationResult[] = []; + const failures: MigrationResult[] = []; + for (const migration of pendingMigrations) { + logger.info(`Processing migration ${migration.version} of ${pendingMigrations.length}`, { + migration: { + version: migration.version, + name: migration.name, + progress: `${results.length + 1}/${pendingMigrations.length}` + } + }); + const result = await executeMigration(plugin, database, migration); results.push(result); if (!result.success) { - logger.error(`Migration failed at version ${migration.version}`); - break; + failures.push(result); + logger.error('Migration failed', { + migration: { + version: migration.version, + name: migration.name + }, + error: result.error, + totalFailures: failures.length, + remainingMigrations: pendingMigrations.length - results.length + }); + + // Check if we should continue + const migrationError = result.error as MigrationError; + if (migrationError?.isRecoverable === false) { + logger.error('Unrecoverable migration failure, stopping process', { + migration: { + version: migration.version, + name: migration.name + }, + totalFailures: failures.length, + completedMigrations: results.length - failures.length + }); + break; + } } } + // Log final results + const duration = Date.now() - startTime; + logger.info('Migration process completed', { + duration, + totalMigrations: pendingMigrations.length, + successfulMigrations: results.length - failures.length, + failedMigrations: failures.length, + endTime: new Date().toISOString() + }); + + if (failures.length > 0) { + logger.error('Migration failures:', { + totalMigrations: pendingMigrations.length, + failedCount: failures.length, + failures: failures.map(f => ({ + version: f.version, + name: f.name, + error: f.error, + state: f.state + })) + }); + } + return results; }