From 6485470531a2a9e9660fd208f68b6bbe4704b860 Mon Sep 17 00:00:00 2001 From: michael sorens Date: Thu, 20 Feb 2020 19:48:20 -0800 Subject: [PATCH 1/2] Instrument additional forced migration logging Signed-off-by: michael sorens --- .../storage/postgres/migration/migration.go | 17 +++++++++++++++-- .../storage/v1/postgres/postgres.go | 2 +- .../storage/v2/postgres/postgres.go | 2 +- 3 files changed, 17 insertions(+), 4 deletions(-) diff --git a/components/authz-service/storage/postgres/migration/migration.go b/components/authz-service/storage/postgres/migration/migration.go index d3016a07d31..b23431dabd2 100644 --- a/components/authz-service/storage/postgres/migration/migration.go +++ b/components/authz-service/storage/postgres/migration/migration.go @@ -36,7 +36,7 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { migrationsTable := "" ctx := context.Background() - l.Infof("Running db migrations from %q", migrationsPath) + l.Info("Running db migrations...") purl, err := addMigrationsTable(pgURL, migrationsTable) if err != nil { return errors.Wrap(err, "parse PG URL") @@ -63,7 +63,9 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { } if version < PreForceUpgradeMigration { + l.Infof("Migrating schema from version %v to %v...", version, PreForceUpgradeMigration) err = m.Migrate(PreForceUpgradeMigration) + l.Infof("Migrating schema from version %v to %v -- complete", version, PreForceUpgradeMigration) if err != nil && err != migrate.ErrNoChange { return errors.Wrap(err, "migration up to IAM-V2-force-upgrade failed") } @@ -90,6 +92,7 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { if isOnV1 { if isDirty { // we've attempted to migrate and not finished // get IAM db in original, clean state to avoid conflicts + l.Infof("Detected unfinished migration; resetting IAM DB to original, clean state") err = legacy.ResetIAMDb(ctx, db) if err != nil { return errors.Wrap(err, "reset IAM V2 database") @@ -106,7 +109,9 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { if err != nil { return errors.Wrapf(err, "failed to set IAM v2 migration_status to %s", constants_v2.EnumInProgress) } + l.Info("Migrating from IAM v1 to v2...") err = legacy.MigrateToV2(ctx, db, migrateV1Policies) + l.Info("Migrating from IAM v1 to v2 -- complete") if err != nil { statusErr := legacy.RecordMigrationStatus(ctx, constants_v2.EnumFailed, db) if statusErr != nil { @@ -121,18 +126,26 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { } // idempotent + l.Info("Migrating data if needed...") err = dataMigConf.Migrate() + l.Info("Migrating data if needed -- complete") if err != nil { return errors.Wrap(err, "IAM data migrations failed") } // perform remaining migrations + l.Infof("Migrating schema post-version %v...", PreForceUpgradeMigration) err = m.Up() if err != nil && err != migrate.ErrNoChange { return errors.Wrap(err, "migrations failed") } + resolution := "complete" + if err == migrate.ErrNoChange { + resolution = "no changes necessary" + } + l.Infof("Migrating schema post-version %v -- %s", PreForceUpgradeMigration, resolution) - l.Infof("Completed db migrations") + l.Info("Running db migrations -- complete") err = db.Close() if err != nil { diff --git a/components/authz-service/storage/v1/postgres/postgres.go b/components/authz-service/storage/v1/postgres/postgres.go index 6cfb990c834..538f9ece9f5 100644 --- a/components/authz-service/storage/v1/postgres/postgres.go +++ b/components/authz-service/storage/v1/postgres/postgres.go @@ -67,7 +67,7 @@ func (m *policyMap) Scan(src interface{}) error { // New instantiates the postgres IAM v1 storage backend. func New(ctx context.Context, l logger.Logger, migConf migration.Config, dataMigConf datamigration.Config) (storage.Storage, error) { - l.Infof("applying database migrations from %s", migConf.Path) + l.Infof("[v1] applying database migrations from %s", migConf.Path) db, err := postgres.New(ctx, migConf, dataMigConf) if err != nil { diff --git a/components/authz-service/storage/v2/postgres/postgres.go b/components/authz-service/storage/v2/postgres/postgres.go index 463e41a6f3c..8a808bc2608 100644 --- a/components/authz-service/storage/v2/postgres/postgres.go +++ b/components/authz-service/storage/v2/postgres/postgres.go @@ -44,7 +44,7 @@ func GetInstance() *pg { return singletonInstance } -// New instantiates the singleton postgres storage backend. +// Initialize instantiates the singleton postgres storage backend. // Will only initialize once. Will simply return nil if already initialized. func Initialize(ctx context.Context, e engine.Engine, l logger.Logger, migConf migration.Config, dataMigConf datamigration.Config, projectLimit int) error { From c4a8480dfd2ad583a399f2a4a7a8d3248e865433 Mon Sep 17 00:00:00 2001 From: michael sorens Date: Mon, 24 Feb 2020 12:27:38 -0800 Subject: [PATCH 2/2] Revisions per review feedback Signed-off-by: michael sorens --- .../storage/postgres/migration/migration.go | 37 +++++++++---------- 1 file changed, 17 insertions(+), 20 deletions(-) diff --git a/components/authz-service/storage/postgres/migration/migration.go b/components/authz-service/storage/postgres/migration/migration.go index b23431dabd2..8e6affe58ad 100644 --- a/components/authz-service/storage/postgres/migration/migration.go +++ b/components/authz-service/storage/postgres/migration/migration.go @@ -36,7 +36,7 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { migrationsTable := "" ctx := context.Background() - l.Info("Running db migrations...") + l.Info("Initializing DB migrations...") purl, err := addMigrationsTable(pgURL, migrationsTable) if err != nil { return errors.Wrap(err, "parse PG URL") @@ -63,11 +63,10 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { } if version < PreForceUpgradeMigration { - l.Infof("Migrating schema from version %v to %v...", version, PreForceUpgradeMigration) + l.Infof("Migrating schema version %v to %v...", version, PreForceUpgradeMigration) err = m.Migrate(PreForceUpgradeMigration) - l.Infof("Migrating schema from version %v to %v -- complete", version, PreForceUpgradeMigration) if err != nil && err != migrate.ErrNoChange { - return errors.Wrap(err, "migration up to IAM-V2-force-upgrade failed") + return errors.Wrapf(err, "migration up to version %v failed", PreForceUpgradeMigration) } } @@ -92,13 +91,13 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { if isOnV1 { if isDirty { // we've attempted to migrate and not finished // get IAM db in original, clean state to avoid conflicts - l.Infof("Detected unfinished migration; resetting IAM DB to original, clean state") + l.Infof("Detected unfinished migration; resetting IAM DB to clean state") err = legacy.ResetIAMDb(ctx, db) if err != nil { - return errors.Wrap(err, "reset IAM V2 database") + return errors.Wrap(err, "reset database") } if err := dataMigConf.Reset(); err != nil { - return errors.Wrap(err, "reset v2 data migrations") + return errors.Wrap(err, "reset data migrations") } if version != 0 { migrateV1Policies = true @@ -109,43 +108,41 @@ func (c *Config) Migrate(dataMigConf datamigration.Config) error { if err != nil { return errors.Wrapf(err, "failed to set IAM v2 migration_status to %s", constants_v2.EnumInProgress) } - l.Info("Migrating from IAM v1 to v2...") + l.Info("Setting up IAM data basics...") err = legacy.MigrateToV2(ctx, db, migrateV1Policies) - l.Info("Migrating from IAM v1 to v2 -- complete") if err != nil { statusErr := legacy.RecordMigrationStatus(ctx, constants_v2.EnumFailed, db) if statusErr != nil { - return errors.Wrapf(statusErr, "failed to set IAM v2 migration_status to %s:%s", constants_v2.EnumFailed, err.Error()) + return errors.Wrapf(statusErr, "failed to set IAM migration_status to %s:%s", constants_v2.EnumFailed, err.Error()) } - return errors.Wrap(err, "IAM v2 force-upgrade failed") + return errors.Wrap(err, "IAM data basics failed") } err = legacy.RecordMigrationStatus(ctx, constants_v2.EnumSuccessful, db) if err != nil { - return errors.Wrapf(err, "failed to set IAM v2 migration_status to %s", constants_v2.EnumSuccessful) + return errors.Wrapf(err, "failed to set IAM migration_status to %s", constants_v2.EnumSuccessful) } } // idempotent - l.Info("Migrating data if needed...") + l.Info("Checking for data migrations...") err = dataMigConf.Migrate() - l.Info("Migrating data if needed -- complete") if err != nil { return errors.Wrap(err, "IAM data migrations failed") } // perform remaining migrations - l.Infof("Migrating schema post-version %v...", PreForceUpgradeMigration) + l.Infof("Checking for remaining schema migrations...") err = m.Up() if err != nil && err != migrate.ErrNoChange { return errors.Wrap(err, "migrations failed") } - resolution := "complete" - if err == migrate.ErrNoChange { - resolution = "no changes necessary" + + version, _, err = m.Version() + if err != nil { + return errors.Wrap(err, "failed to get version post-migration") } - l.Infof("Migrating schema post-version %v -- %s", PreForceUpgradeMigration, resolution) - l.Info("Running db migrations -- complete") + l.Infof("DB initialization complete at version %v", version) err = db.Close() if err != nil {