From 53503de1962773a3cbbfc07b3d78b90b257fecce Mon Sep 17 00:00:00 2001 From: Jonathan Hall Date: Sat, 6 Jul 2024 16:48:53 +0200 Subject: [PATCH 1/2] Allow registering SQL hooks on startup --- x/sqlite/go.mod | 1 + x/sqlite/go.sum | 2 ++ x/sqlite/logging.go | 44 ++++++++++++++++++++++++++++++++++++++++++++ x/sqlite/sqlite.go | 10 +++++----- 4 files changed, 52 insertions(+), 5 deletions(-) diff --git a/x/sqlite/go.mod b/x/sqlite/go.mod index 307e1e96b..85ca8fd78 100644 --- a/x/sqlite/go.mod +++ b/x/sqlite/go.mod @@ -9,6 +9,7 @@ require ( github.com/google/go-cmp v0.6.0 github.com/google/uuid v1.6.0 github.com/mitchellh/mapstructure v1.5.0 + gitlab.com/flimzy/errsql v0.1.0 gitlab.com/flimzy/testy v0.14.0 golang.org/x/text v0.15.0 modernc.org/sqlite v1.29.8 diff --git a/x/sqlite/go.sum b/x/sqlite/go.sum index 2f41f2e74..848b2d993 100644 --- a/x/sqlite/go.sum +++ b/x/sqlite/go.sum @@ -66,6 +66,8 @@ github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyC github.com/valyala/fasttemplate v1.2.1 h1:TVEnxayobAdVkhQfrfes2IzOB6o+z4roRkPF52WA1u4= github.com/valyala/fasttemplate v1.2.1/go.mod h1:KHLXt3tVN2HBp8eijSv/kGJopbvo7S+qRAEEKiv+SiQ= github.com/yuin/goldmark v1.4.13/go.mod h1:6yULJ656Px+3vBD8DxQVa3kxgyrAnzto9xy5taEt/CY= +gitlab.com/flimzy/errsql v0.1.0 h1:tq7EW8PTHWFMtJKYeo2kraxp0hsDmf1LrOrpMHowl5U= +gitlab.com/flimzy/errsql v0.1.0/go.mod h1:8tGMnnsTD13xJV3bSstTmu93kE25qRNEFiHVyFWdY4s= gitlab.com/flimzy/testy v0.14.0 h1:2nZV4Wa1OSJb3rOKHh0GJqvvhtE03zT+sKnPCI0owfQ= gitlab.com/flimzy/testy v0.14.0/go.mod h1:m3aGuwdXc+N3QgnH+2Ar2zf1yg0UxNdIaXKvC5SlfMk= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= diff --git a/x/sqlite/logging.go b/x/sqlite/logging.go index 3dd5f0491..1066db015 100644 --- a/x/sqlite/logging.go +++ b/x/sqlite/logging.go @@ -13,8 +13,11 @@ package sqlite import ( + "database/sql" "log" + "gitlab.com/flimzy/errsql" + "github.com/go-kivik/kivik/v4" ) @@ -36,3 +39,44 @@ func (o optionLogger) Apply(target interface{}) { func OptionLogger(logger *log.Logger) kivik.Option { return optionLogger{Logger: logger} } + +// connector is used temporarily on startup, to connect to a database, and +// to possibly switch to the errsql driver if query logging is enabled. +type connector struct { + dsn string + queryLogging bool +} + +func (c *connector) Connect() (*sql.DB, error) { + db, err := sql.Open("sqlite", c.dsn) + if err != nil { + return nil, err + } + if c.queryLogging { + drv := errsql.NewWithHooks(db.Driver(), &errsql.Hooks{}) + cn, err := drv.OpenConnector(c.dsn) + if err != nil { + return nil, err + } + db = sql.OpenDB(cn) + } + _, err = db.Exec("PRAGMA foreign_keys = ON") + if err != nil { + return nil, err + } + return db, nil +} + +type optionQueryLog struct{} + +func (o optionQueryLog) Apply(target interface{}) { + if cn, ok := target.(*connector); ok { + cn.queryLogging = true + } +} + +// OptionQueryLog enables query logging for the SQLite driver. Query logs are +// sent to the logger (see [OptionLogger]) at DEBUG level. +func OptionQueryLog() kivik.Option { + return optionQueryLog{} +} diff --git a/x/sqlite/sqlite.go b/x/sqlite/sqlite.go index b951eae65..239a84815 100644 --- a/x/sqlite/sqlite.go +++ b/x/sqlite/sqlite.go @@ -42,16 +42,15 @@ var _ driver.Driver = (*drv)(nil) // NewClient returns a new SQLite client. dsn should be the full path to your // SQLite database file. func (drv) NewClient(dsn string, options driver.Options) (driver.Client, error) { - db, err := sql.Open("sqlite", dsn) - if err != nil { - return nil, err - } - _, err = db.Exec("PRAGMA foreign_keys = ON") + cn := &connector{dsn: dsn} + options.Apply(cn) + db, err := cn.Connect() if err != nil { return nil, err } c := &client{ + dsn: dsn, db: db, logger: log.Default(), } @@ -61,6 +60,7 @@ func (drv) NewClient(dsn string, options driver.Options) (driver.Client, error) } type client struct { + dsn string db *sql.DB logger *log.Logger } From cd940157075b3dbb5ff7934a6c198930dba73891 Mon Sep 17 00:00:00 2001 From: Jonathan Hall Date: Wed, 10 Jul 2024 22:39:37 +0200 Subject: [PATCH 2/2] Dump queries and args in tests when QUERY_LOG=1 is set --- x/sqlite/common_test.go | 19 +++++++++++++- x/sqlite/go.mod | 2 +- x/sqlite/go.sum | 4 +-- x/sqlite/logging.go | 58 ++++++++++++++++++++++++++++++++++------- 4 files changed, 70 insertions(+), 13 deletions(-) diff --git a/x/sqlite/common_test.go b/x/sqlite/common_test.go index 26f5d7868..e82ac0a92 100644 --- a/x/sqlite/common_test.go +++ b/x/sqlite/common_test.go @@ -29,6 +29,7 @@ import ( "github.com/google/go-cmp/cmp" + "github.com/go-kivik/kivik/v4" "github.com/go-kivik/kivik/v4/driver" "github.com/go-kivik/kivik/v4/int/mock" ) @@ -81,6 +82,18 @@ func (tdb *testDB) tDelete(docID string, options ...driver.Options) string { //n return rev } +type multiOptions []kivik.Option + +var _ kivik.Option = (multiOptions)(nil) + +func (o multiOptions) Apply(t interface{}) { + for _, opt := range o { + if opt != nil { + opt.Apply(t) + } + } +} + // newDB creates a new driver.DB instance backed by an in-memory SQLite database, // and registers a cleanup function to close the database when the test is done. func newDB(t *testing.T) *testDB { @@ -104,7 +117,11 @@ func newDB(t *testing.T) *testDB { d := drv{} buf := &bytes.Buffer{} logger := log.New(buf, "", 0) - client, err := d.NewClient(dsn, OptionLogger(logger)) + options := OptionLogger(logger) + if os.Getenv("QUERY_LOG") != "" { + options = multiOptions{options, OptionQueryLogger(log.New(os.Stderr, "", 0))} + } + client, err := d.NewClient(dsn, options) if err != nil { t.Fatal(err) } diff --git a/x/sqlite/go.mod b/x/sqlite/go.mod index 85ca8fd78..c5d7f5f10 100644 --- a/x/sqlite/go.mod +++ b/x/sqlite/go.mod @@ -9,7 +9,7 @@ require ( github.com/google/go-cmp v0.6.0 github.com/google/uuid v1.6.0 github.com/mitchellh/mapstructure v1.5.0 - gitlab.com/flimzy/errsql v0.1.0 + gitlab.com/flimzy/errsql v0.1.3 gitlab.com/flimzy/testy v0.14.0 golang.org/x/text v0.15.0 modernc.org/sqlite v1.29.8 diff --git a/x/sqlite/go.sum b/x/sqlite/go.sum index 848b2d993..49739ce44 100644 --- a/x/sqlite/go.sum +++ b/x/sqlite/go.sum @@ -66,8 +66,8 @@ github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyC github.com/valyala/fasttemplate v1.2.1 h1:TVEnxayobAdVkhQfrfes2IzOB6o+z4roRkPF52WA1u4= github.com/valyala/fasttemplate v1.2.1/go.mod h1:KHLXt3tVN2HBp8eijSv/kGJopbvo7S+qRAEEKiv+SiQ= github.com/yuin/goldmark v1.4.13/go.mod h1:6yULJ656Px+3vBD8DxQVa3kxgyrAnzto9xy5taEt/CY= -gitlab.com/flimzy/errsql v0.1.0 h1:tq7EW8PTHWFMtJKYeo2kraxp0hsDmf1LrOrpMHowl5U= -gitlab.com/flimzy/errsql v0.1.0/go.mod h1:8tGMnnsTD13xJV3bSstTmu93kE25qRNEFiHVyFWdY4s= +gitlab.com/flimzy/errsql v0.1.3 h1:XRjZhW6SVHwjuGo8Rm3EVedw95bmysEVuPnG9M68V8I= +gitlab.com/flimzy/errsql v0.1.3/go.mod h1:8tGMnnsTD13xJV3bSstTmu93kE25qRNEFiHVyFWdY4s= gitlab.com/flimzy/testy v0.14.0 h1:2nZV4Wa1OSJb3rOKHh0GJqvvhtE03zT+sKnPCI0owfQ= gitlab.com/flimzy/testy v0.14.0/go.mod h1:m3aGuwdXc+N3QgnH+2Ar2zf1yg0UxNdIaXKvC5SlfMk= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= diff --git a/x/sqlite/logging.go b/x/sqlite/logging.go index 1066db015..1d9ca33a3 100644 --- a/x/sqlite/logging.go +++ b/x/sqlite/logging.go @@ -14,7 +14,10 @@ package sqlite import ( "database/sql" + "database/sql/driver" + "fmt" "log" + "strings" "gitlab.com/flimzy/errsql" @@ -43,8 +46,27 @@ func OptionLogger(logger *log.Logger) kivik.Option { // connector is used temporarily on startup, to connect to a database, and // to possibly switch to the errsql driver if query logging is enabled. type connector struct { - dsn string - queryLogging bool + dsn string + queryLogger *log.Logger +} + +func tx(e *errsql.Event) string { + if e.InTransaction { + return " (tx)" + } + return "" +} + +func args(a []driver.NamedValue) string { + result := make([]string, 0, len(a)) + for _, arg := range a { + name := arg.Name + if name == "" { + name = fmt.Sprintf("$%d", arg.Ordinal) + } + result = append(result, fmt.Sprintf("%s=%v", name, arg.Value)) + } + return strings.Join(result, ", ") } func (c *connector) Connect() (*sql.DB, error) { @@ -52,8 +74,24 @@ func (c *connector) Connect() (*sql.DB, error) { if err != nil { return nil, err } - if c.queryLogging { - drv := errsql.NewWithHooks(db.Driver(), &errsql.Hooks{}) + if c.queryLogger != nil { + drv := errsql.NewWithHooks(db.Driver(), &errsql.Hooks{ + ErrorHook: func(e *errsql.Event, err error) error { + return fmt.Errorf("[%s.%s] %s", e.Entity, e.Method, err) + }, + BeforePrepare: func(e *errsql.Event, query string) (string, error) { + c.queryLogger.Printf("[%s.%s]%s Preparing query:\n%s\n", e.Entity, e.Method, tx(e), query) + return query, nil + }, + BeforePreparedQueryContext: func(e *errsql.Event, a []driver.NamedValue) ([]driver.NamedValue, error) { + c.queryLogger.Printf("[%s.%s]%s arguments:\n%s\n", e.Entity, e.Method, tx(e), args(a)) + return a, nil + }, + BeforeQueryContext: func(e *errsql.Event, query string, a []driver.NamedValue) (string, []driver.NamedValue, error) { + c.queryLogger.Printf("[%s.%s]%s Query:\n%s\narguments:\n%s\n", e.Entity, e.Method, tx(e), query, args(a)) + return query, a, nil + }, + }) cn, err := drv.OpenConnector(c.dsn) if err != nil { return nil, err @@ -67,16 +105,18 @@ func (c *connector) Connect() (*sql.DB, error) { return db, nil } -type optionQueryLog struct{} +type optionQueryLog struct { + *log.Logger +} func (o optionQueryLog) Apply(target interface{}) { if cn, ok := target.(*connector); ok { - cn.queryLogging = true + cn.queryLogger = o.Logger } } -// OptionQueryLog enables query logging for the SQLite driver. Query logs are +// OptionQueryLogger enables query logging for the SQLite driver. Query logs are // sent to the logger (see [OptionLogger]) at DEBUG level. -func OptionQueryLog() kivik.Option { - return optionQueryLog{} +func OptionQueryLogger(logger *log.Logger) kivik.Option { + return optionQueryLog{Logger: logger} }