diff --git a/README.md b/README.md index ca1e25bf..dd5e7ebc 100644 --- a/README.md +++ b/README.md @@ -191,6 +191,7 @@ Dropping: myapp_test $ dbmate -e TEST_DATABASE_URL --no-dump-schema up Creating: myapp_test Applying: 20151127184807_create_users_table.sql +Applied: 20151127184807_create_users_table.sql in 123us ``` Alternatively, you can specify the url directly on the command line: @@ -343,6 +344,7 @@ Run `dbmate up` to run any pending migrations. $ dbmate up Creating: myapp_development Applying: 20151127184807_create_users_table.sql +Applied: 20151127184807_create_users_table.sql in 123us Writing: ./db/schema.sql ``` @@ -371,6 +373,7 @@ Run `dbmate rollback` to roll back the most recent migration: ```sh $ dbmate rollback Rolling back: 20151127184807_create_users_table.sql +Rolled back: 20151127184807_create_users_table.sql in 123us Writing: ./db/schema.sql ``` diff --git a/pkg/dbmate/db.go b/pkg/dbmate/db.go index b2337973..4f5c39e2 100644 --- a/pkg/dbmate/db.go +++ b/pkg/dbmate/db.go @@ -377,6 +377,8 @@ func (db *DB) Migrate() error { for _, migration := range pendingMigrations { fmt.Fprintf(db.Log, "Applying: %s\n", migration.FileName) + start := time.Now() + parsed, err := migration.Parse() if err != nil { return err @@ -403,6 +405,9 @@ func (db *DB) Migrate() error { err = execMigration(sqlDB) } + elapsed := time.Since(start) + fmt.Fprintf(db.Log, "Applied: %s in %s\n", migration.FileName, elapsed) + if err != nil { return err } @@ -541,6 +546,8 @@ func (db *DB) Rollback() error { fmt.Fprintf(db.Log, "Rolling back: %s\n", latest.FileName) + start := time.Now() + parsed, err := latest.Parse() if err != nil { return err @@ -567,6 +574,9 @@ func (db *DB) Rollback() error { err = execMigration(sqlDB) } + elapsed := time.Since(start) + fmt.Fprintf(db.Log, "Rolled back: %s in %s\n", latest.FileName, elapsed) + if err != nil { return err } diff --git a/pkg/dbmate/db_test.go b/pkg/dbmate/db_test.go index 7be16a6f..79fa6e2d 100644 --- a/pkg/dbmate/db_test.go +++ b/pkg/dbmate/db_test.go @@ -4,6 +4,7 @@ import ( "net/url" "os" "path/filepath" + "regexp" "strings" "testing" "testing/fstest" @@ -315,17 +316,13 @@ func TestWaitBeforeVerbose(t *testing.T) { output := capturer.CaptureOutput(func() { testWaitBefore(t, true) }) - require.Contains(t, output, - `Applying: 20151129054053_test_migration.sql -Last insert ID: 1 -Rows affected: 1 -Applying: 20200227231541_test_posts.sql -Last insert ID: 1 -Rows affected: 1`) - require.Contains(t, output, - `Rolling back: 20200227231541_test_posts.sql -Last insert ID: 0 -Rows affected: 0`) + matched, err := regexp.MatchString(`Applying: 20151129054053_test_migration\.sql\nLast insert ID: 1\nRows affected: 1\nApplied: 20151129054053_test_migration\.sql in ([\w.,µ]+)\nApplying: 20200227231541_test_posts\.sql\nLast insert ID: 1\nRows affected: 1\nApplied: 20200227231541_test_posts\.sql in ([\w.,µ]+)`, output) + require.NoError(t, err) + require.True(t, matched) + + matched, err = regexp.MatchString(`Rolling back: 20200227231541_test_posts\.sql\nLast insert ID: 0\nRows affected: 0\nRolled back: 20200227231541_test_posts\.sql in ([\w.,µ]+)`, output) + require.NoError(t, err) + require.True(t, matched) } func testEachURL(t *testing.T, fn func(*testing.T, *url.URL)) {