Merge pull request #144 from erizocosmico/feature/sql-debug

add methods to enable debug of SQL statements

Author: Miguel Molina

README.md

@@ -34,6 +34,7 @@ Support for arrays of all basic Go types and all JSON and arrays operators is pr
   * [Query with relationships](#query-with-relationships)
   * [Querying JSON](#querying-json)
 * [Transactions](#transactions)
+* [Debug SQL queries](#debug-sql-queries)
 * [Benchmarks](#benchmarks)
 * [Acknowledgements](#acknowledgements)
 * [Contributing](#contributing)
@@ -602,6 +603,26 @@ store.Transaction(func(s *UserStore) error {
 * `time.Time` and `url.URL` need to be used as is. That is, you can not use a type `Foo` being `type Foo time.Time`. `time.Time` and `url.URL` are types that are treated in a special way, if you do that, it would be the same as saying `type Foo struct { ... }` and kallax would no longer be able to identify the correct type.
 * Multidimensional arrays or slices are **not supported** except inside a JSON field.
 
+## Debug SQL queries
+
+It is possible to debug the SQL queries being executed with kallax. To do that, you just need to call the `Debug` method of a store. This returns a new store with debugging enabled.
+
+```go
+store.Debug().Find(myQuery)
+```
+
+This will log to stdout using `log.Printf` `kallax: Query: THE QUERY SQL STATEMENT, args: [arg1 arg2]`.
+
+You can use a custom logger (any function with a type `func(string, ...interface{})` using the `DebugWith` method instead.
+
+```go
+func myLogger(message string, args ...interface{}) {
+        myloglib.Debugf("%s, args: %v", message, args)
+}
+
+store.DebugWith(myLogger).Find(myQuery)
+```
+
 ## Benchmarks
 
 Here are some benchmarks against [GORM](https://github.com/jinzhu/gorm) and `database/sql`, which is one of the most popular ORMs for Go. In the future we might add benchmarks for some more complex cases and other available ORMs.

generator/templates/model.tgo

@@ -106,6 +106,18 @@ func (s *{{.StoreName}}) SetGenericStore(store *kallax.Store) {
         s.Store = store
 }
 
+// Debug returns a new store that will print all SQL statements to stdout using
+// the log.Printf function.
+func (s *{{.StoreName}}) Debug() *{{.StoreName}} {
+        return &{{.StoreName}}{s.Store.Debug()}
+}
+
+// DebugWith returns a new store that will print all SQL statements using the
+// given logger function.
+func (s *{{.StoreName}}) DebugWith(logger kallax.LoggerFunc) *{{.StoreName}} {
+        return &{{.StoreName}}{s.Store.DebugWith(logger)}
+}
+
 {{if .HasNonInverses}}
 func (s *{{.StoreName}}) relationshipRecords(record *{{.Name}}) []kallax.RecordWithSchema {
         var records []kallax.RecordWithSchema

store.go

@@ -4,6 +4,7 @@ import (
 	"database/sql"
 	"errors"
 	"fmt"
+	"log"
 
 	"github.com/Masterminds/squirrel"
 	"github.com/lann/builder"
@@ -51,6 +52,40 @@ func StoreFrom(to, from GenericStorer) {
 	to.SetGenericStore(from.GenericStore())
 }
 
+// LoggerFunc is a function that takes a log message with some arguments and
+// logs it.
+type LoggerFunc func(string, ...interface{})
+
+// debugProxy is a database proxy that logs all SQL statements executed.
+type debugProxy struct {
+	logger LoggerFunc
+	proxy  squirrel.DBProxy
+}
+
+func defaultLogger(message string, args ...interface{}) {
+	log.Printf("%s, args: %v", message, args)
+}
+
+func (p *debugProxy) Exec(query string, args ...interface{}) (sql.Result, error) {
+	p.logger(fmt.Sprintf("kallax: Exec: %s", query), args...)
+	return p.proxy.Exec(query, args...)
+}
+
+func (p *debugProxy) Query(query string, args ...interface{}) (*sql.Rows, error) {
+	p.logger(fmt.Sprintf("kallax: Query: %s", query), args...)
+	return p.proxy.Query(query, args...)
+}
+
+func (p *debugProxy) QueryRow(query string, args ...interface{}) squirrel.RowScanner {
+	p.logger(fmt.Sprintf("kallax: QueryRow: %s", query), args...)
+	return p.proxy.QueryRow(query, args...)
+}
+
+func (p *debugProxy) Prepare(query string) (*sql.Stmt, error) {
+	p.logger(fmt.Sprintf("kallax: Prepare: %s", query))
+	return p.proxy.Prepare(query)
+}
+
 // Store is a structure capable of retrieving records from a concrete table in
 // the database.
 type Store struct {
@@ -79,6 +114,22 @@ func newStoreWithTransaction(tx *sql.Tx) *Store {
 	}
 }
 
+// Debug returns a new store that will print all SQL statements to stdout using
+// the log.Printf function.
+func (s *Store) Debug() *Store {
+	return s.DebugWith(defaultLogger)
+}
+
+// DebugWith returns a new store that will print all SQL statements using the
+// given logger function.
+func (s *Store) DebugWith(logger LoggerFunc) *Store {
+	return &Store{
+		builder: s.builder,
+		db:      s.db,
+		proxy:   &debugProxy{logger, s.proxy},
+	}
+}
+
 // Insert insert the given record in the table, returns error if no-new
 // record is given. The record id is set if it's empty.
 func (s *Store) Insert(schema Schema, record Record) error {

store_test.go

@@ -236,10 +236,27 @@ func (s *StoreSuite) TestMustFind() {
 	})
 
 	s.Panics(func() {
-		s.errStore.MustFind(q)
+		s.errStore.Debug().MustFind(q)
 	})
 }
 
+func (s *StoreSuite) TestDebugWith() {
+	var queries []string
+	var logger = func(q string, args ...interface{}) {
+		queries = append(queries, q)
+	}
+	s.store.DebugWith(logger).RawQuery("SELECT 1 + 1")
+	s.store.DebugWith(logger).RawExec("UPDATE foo SET bar = 1")
+
+	s.Equal(
+		queries,
+		[]string{
+			"kallax: Query: SELECT 1 + 1",
+			"kallax: Exec: UPDATE foo SET bar = 1",
+		},
+	)
+}
+
 func (s *StoreSuite) assertFound(rs ResultSet, expected ...string) {
 	var names []string
 	for rs.Next() {