adding verbose output for statement execution (#138)

* adding verbose output for statement execution

* fixing lint and redefined v flag

* changing name due to inherited verbose flag and updating README

* linting

* moving verbose flag to subcommand, removing driver verbose, adding tests

* fixing README, cleaning up spacing

go.mod

@@ -7,6 +7,7 @@ require (
 	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/go-sql-driver/mysql v1.5.0
 	github.com/joho/godotenv v1.3.0
+	github.com/kami-zh/go-capturer v0.0.0-20171211120116-e492ea43421d
 	github.com/kr/pretty v0.1.0 // indirect
 	github.com/lib/pq v1.5.2
 	github.com/mattn/go-sqlite3 v1.13.0

go.sum

@@ -9,6 +9,8 @@ github.com/go-sql-driver/mysql v1.5.0 h1:ozyZYNQW3x3HtqT1jira07DN2PArx2v7/mN66gG
 github.com/go-sql-driver/mysql v1.5.0/go.mod h1:DCzpHaOWr8IXmIStZouvnhqoel9Qv2LBy8hT2VhHyBg=
 github.com/joho/godotenv v1.3.0 h1:Zjp+RcGpHhGlrMbJzXTrZZPrWj+1vfm90La1wgB6Bhc=
 github.com/joho/godotenv v1.3.0/go.mod h1:7hK45KPybAkOC6peb+G5yklZfMxEjkZhHbwpqxOKXbg=
+github.com/kami-zh/go-capturer v0.0.0-20171211120116-e492ea43421d h1:cVtBfNW5XTHiKQe7jDaDBSh/EVM4XLPutLAGboIXuM0=
+github.com/kami-zh/go-capturer v0.0.0-20171211120116-e492ea43421d/go.mod h1:P2viExyCEfeWGU259JnaQ34Inuec4R38JCyBx2edgD0=
 github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI=
 github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
 github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=

main.go

@@ -75,7 +75,14 @@ func NewApp() *cli.App {
 		{
 			Name:  "up",
 			Usage: "Create database (if necessary) and migrate to the latest version",
+			Flags: []cli.Flag{
+				cli.BoolFlag{
+					Name:  "verbose, v",
+					Usage: "print the result of each statement execution",
+				},
+			},
 			Action: action(func(db *dbmate.DB, c *cli.Context) error {
+				db.Verbose = c.Bool("verbose")
 				return db.CreateAndMigrate()
 			}),
 		},
@@ -96,7 +103,14 @@ func NewApp() *cli.App {
 		{
 			Name:  "migrate",
 			Usage: "Migrate to the latest version",
+			Flags: []cli.Flag{
+				cli.BoolFlag{
+					Name:  "verbose, v",
+					Usage: "print the result of each statement execution",
+				},
+			},
 			Action: action(func(db *dbmate.DB, c *cli.Context) error {
+				db.Verbose = c.Bool("verbose")
 				return db.Migrate()
 			}),
 		},
@@ -104,7 +118,14 @@ func NewApp() *cli.App {
 			Name:    "rollback",
 			Aliases: []string{"down"},
 			Usage:   "Rollback the most recent migration",
+			Flags: []cli.Flag{
+				cli.BoolFlag{
+					Name:  "verbose, v",
+					Usage: "print the result of each statement execution",
+				},
+			},
 			Action: action(func(db *dbmate.DB, c *cli.Context) error {
+				db.Verbose = c.Bool("verbose")
 				return db.Rollback()
 			}),
 		},

pkg/dbmate/db.go

@@ -30,6 +30,7 @@ type DB struct {
 	DatabaseURL    *url.URL
 	MigrationsDir  string
 	SchemaFile     string
+	Verbose        bool
 	WaitBefore     bool
 	WaitInterval   time.Duration
 	WaitTimeout    time.Duration
@@ -304,8 +305,11 @@ func (db *DB) Migrate() error {
 
 		execMigration := func(tx Transaction) error {
 			// run actual migration
-			if _, err := tx.Exec(up.Contents); err != nil {
+			result, err := tx.Exec(up.Contents)
+			if err != nil {
 				return err
+			} else if db.Verbose {
+				printVerbose(result)
 			}
 
 			// record migration
@@ -425,8 +429,11 @@ func (db *DB) Rollback() error {
 
 	execMigration := func(tx Transaction) error {
 		// rollback migration
-		if _, err := tx.Exec(down.Contents); err != nil {
+		result, err := tx.Exec(down.Contents)
+		if err != nil {
 			return err
+		} else if db.Verbose {
+			printVerbose(result)
 		}
 
 		// remove migration record

pkg/dbmate/db_test.go

@@ -8,6 +8,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/kami-zh/go-capturer"
 	"github.com/stretchr/testify/require"
 )
 
@@ -161,9 +162,10 @@ func checkWaitCalled(t *testing.T, u *url.URL, command func() error) {
 	u.Host = oldHost
 }
 
-func TestWaitBefore(t *testing.T) {
+func testWaitBefore(t *testing.T, verbose bool) {
 	u := postgresTestURL(t)
 	db := newTestDB(t, u)
+	db.Verbose = verbose
 	db.WaitBefore = true
 	// so that checkWaitCalled returns quickly
 	db.WaitInterval = time.Millisecond
@@ -200,6 +202,24 @@ func TestWaitBefore(t *testing.T) {
 	checkWaitCalled(t, u, db.DumpSchema)
 }
 
+func TestWaitBefore(t *testing.T) {
+	testWaitBefore(t, false)
+}
+
+func TestWaitBeforeVerbose(t *testing.T) {
+	output := capturer.CaptureOutput(func() {
+		testWaitBefore(t, true)
+	})
+	require.Contains(t, output,
+		`Applying: 20151129054053_test_migration.sql
+Rows affected: 1
+Applying: 20200227231541_test_posts.sql
+Rows affected: 0`)
+	require.Contains(t, output,
+		`Rolling back: 20200227231541_test_posts.sql
+Rows affected: 0`)
+}
+
 func testURLs(t *testing.T) []*url.URL {
 	return []*url.URL{
 		postgresTestURL(t),

pkg/dbmate/utils.go

@@ -127,3 +127,14 @@ func queryColumn(db *sql.DB, query string) ([]string, error) {
 
 	return result, nil
 }
+
+func printVerbose(result sql.Result) {
+	lastInsertId, err := result.LastInsertId()
+	if err == nil {
+		fmt.Printf("Last insert ID: %d\n", lastInsertId)
+	}
+	rowsAffected, err := result.RowsAffected()
+	if err == nil {
+		fmt.Printf("Rows affected: %d\n", rowsAffected)
+	}
+}