Adds more loglines to the database migrations and fixes some inconsistencies (#3392)

* Adds more loglines to the database migrations and fixes some inconsistencies

* Fix linter

* Add migration engine loglines

server/services/store/sqlstore/data_migrations.go

@@ -320,7 +320,7 @@ func (s *SQLStore) migrateTeamLessBoards() error {
 		return err
 	}
 
-	s.logger.Info("Migrating teamless boards to a team", mlog.Int("count", len(boards)))
+	s.logger.Debug("Migrating teamless boards to a team", mlog.Int("count", len(boards)))
 
 	// cache for best suitable team for a DM. Since a DM can
 	// contain multiple boards, caching this avoids

server/services/store/sqlstore/migrate.go

@@ -35,7 +35,7 @@ var assets embed.FS
 
 const (
 	uniqueIDsMigrationRequiredVersion        = 14
-	teamsAndBoardsMigrationRequiredVersion   = 18
+	teamLessBoardsMigrationRequiredVersion   = 18
 	categoriesUUIDIDMigrationRequiredVersion = 20
 
 	tempSchemaMigrationTableName = "temp_schema_migration"
@@ -115,12 +115,16 @@ func (s *SQLStore) Migrate() error {
 
 	var db *sql.DB
 	if s.dbType != model.SqliteDBType {
+		s.logger.Debug("Getting migrations connection")
 		db, err = s.getMigrationConnection()
 		if err != nil {
 			return err
 		}
 
-		defer db.Close()
+		defer func() {
+			s.logger.Debug("Closing migrations connection")
+			db.Close()
+		}()
 	}
 
 	if s.dbType == model.PostgresDBType {
@@ -191,11 +195,15 @@ func (s *SQLStore) Migrate() error {
 		opts = opts[:0] // sqlite driver does not support locking, it doesn't need to anyway.
 	}
 
+	s.logger.Debug("Creating migration engine")
 	engine, err := morph.New(context.Background(), driver, src, opts...)
 	if err != nil {
 		return err
 	}
-	defer engine.Close()
+	defer func() {
+		s.logger.Debug("Closing migration engine")
+		engine.Close()
+	}()
 
 	var mutex *cluster.Mutex
 	if s.isPlugin {
@@ -205,45 +213,53 @@ func (s *SQLStore) Migrate() error {
 			return fmt.Errorf("error creating database mutex: %w", mutexErr)
 		}
 
-		s.logger.Debug("Acquiring cluster lock for Unique IDs migration")
+		s.logger.Debug("Acquiring cluster lock for Focalboard migrations")
 		mutex.Lock()
 		defer func() {
-			s.logger.Debug("Releasing cluster lock for Unique IDs migration")
+			s.logger.Debug("Releasing cluster lock for Focalboard migrations")
 			mutex.Unlock()
 		}()
 	}
 
-	if err := s.migrateSchemaVersionTable(src.Migrations()); err != nil {
+	if mErr := s.migrateSchemaVersionTable(src.Migrations()); mErr != nil {
+		return mErr
+	}
+
+	if mErr := s.ensureMigrationsAppliedUpToVersion(engine, driver, uniqueIDsMigrationRequiredVersion); mErr != nil {
+		return mErr
+	}
+
+	if mErr := s.runUniqueIDsMigration(); mErr != nil {
+		return fmt.Errorf("error running unique IDs migration: %w", mErr)
+	}
+
+	if mErr := s.ensureMigrationsAppliedUpToVersion(engine, driver, teamLessBoardsMigrationRequiredVersion); mErr != nil {
+		return mErr
+	}
+
+	if mErr := s.migrateTeamLessBoards(); mErr != nil {
+		return mErr
+	}
+
+	if mErr := s.ensureMigrationsAppliedUpToVersion(engine, driver, categoriesUUIDIDMigrationRequiredVersion); mErr != nil {
+		return mErr
+	}
+
+	if mErr := s.runCategoryUUIDIDMigration(); mErr != nil {
+		return fmt.Errorf("error running categoryID migration: %w", mErr)
+	}
+
+	if mErr := s.deleteOldSchemaMigrationTable(); mErr != nil {
+		return mErr
+	}
+
+	appliedMigrations, err := driver.AppliedMigrations()
+	if err != nil {
 		return err
 	}
 
-	if err := ensureMigrationsAppliedUpToVersion(engine, driver, uniqueIDsMigrationRequiredVersion); err != nil {
-		return err
-	}
-
-	if err := s.runUniqueIDsMigration(); err != nil {
-		return fmt.Errorf("error running unique IDs migration: %w", err)
-	}
-
-	if err := ensureMigrationsAppliedUpToVersion(engine, driver, categoriesUUIDIDMigrationRequiredVersion); err != nil {
-		return err
-	}
-
-	if err := s.runCategoryUUIDIDMigration(); err != nil {
-		return fmt.Errorf("error running categoryID migration: %w", err)
-	}
-
-	if err := s.deleteOldSchemaMigrationTable(); err != nil {
-		return err
-	}
-
-	if err := ensureMigrationsAppliedUpToVersion(engine, driver, teamsAndBoardsMigrationRequiredVersion); err != nil {
-		return err
-	}
-
-	if err := s.migrateTeamLessBoards(); err != nil {
-		return err
-	}
+	s.logger.Debug("== Applying all remaining migrations ====================",
+		mlog.Int("current_version", len(appliedMigrations)))
 
 	return engine.ApplyAll()
 }
@@ -460,20 +476,29 @@ func (s *SQLStore) deleteOldSchemaMigrationTable() error {
 	return nil
 }
 
-func ensureMigrationsAppliedUpToVersion(engine *morph.Morph, driver drivers.Driver, version int) error {
+func (s *SQLStore) ensureMigrationsAppliedUpToVersion(engine *morph.Morph, driver drivers.Driver, version int) error {
 	applied, err := driver.AppliedMigrations()
 	if err != nil {
 		return err
 	}
 	currentVersion := len(applied)
 
+	s.logger.Debug("== Ensuring migrations applied up to version ====================",
+		mlog.Int("version", version),
+		mlog.Int("current_version", currentVersion))
+
 	// if the target version is below or equal to the current one, do
 	// not migrate either because is not needed (both are equal) or
 	// because it would downgrade the database (is below)
 	if version <= currentVersion {
+		s.logger.Debug("-- There is no need of applying any migration --------------------")
 		return nil
 	}
 
+	for _, migration := range applied {
+		s.logger.Debug("-- Found applied migration --------------------", mlog.Uint32("version", migration.Version), mlog.String("name", migration.Name))
+	}
+
 	if _, err = engine.Apply(version - currentVersion); err != nil {
 		return err
 	}