qustavo / sqlhooks

Attach hooks to any database/sql driver

sqlhooks

Attach hooks to any database/sql driver.

The purpose of sqlhooks is to provide a way to instrument your sql statements, making really easy to log queries or measure execution time without modifying your actual code.

Install

go get github.com/qustavo/sqlhooks/v2

Requires Go >= 1.14.x

Breaking changes

V2 isn't backward compatible with previous versions, if you want to fetch old versions, you can use go modules or get them from gopkg.in

go get github.com/qustavo/sqlhooks
go get gopkg.in/qustavo/sqlhooks.v1

Usage

// This example shows how to instrument sql queries in order to display the time that they consume
package main

import (
	"context"
	"database/sql"
	"fmt"
	"time"

	"github.com/qustavo/sqlhooks/v2"
	"github.com/mattn/go-sqlite3"
)

// Hooks satisfies the sqlhook.Hooks interface
type Hooks struct {}

// Before hook will print the query with it's args and return the context with the timestamp
func (h *Hooks) Before(ctx context.Context, query string, args ...interface{}) (context.Context, error) {
	fmt.Printf("> %s %q", query, args)
	return context.WithValue(ctx, "begin", time.Now()), nil
}

// After hook will get the timestamp registered on the Before hook and print the elapsed time
func (h *Hooks) After(ctx context.Context, query string, args ...interface{}) (context.Context, error) {
	begin := ctx.Value("begin").(time.Time)
	fmt.Printf(". took: %s\n", time.Since(begin))
	return ctx, nil
}

func main() {
	// First, register the wrapper
	sql.Register("sqlite3WithHooks", sqlhooks.Wrap(&sqlite3.SQLiteDriver{}, &Hooks{}))

	// Connect to the registered wrapped driver
	db, _ := sql.Open("sqlite3WithHooks", ":memory:")

	// Do you're stuff
	db.Exec("CREATE TABLE t (id INTEGER, text VARCHAR(16))")
	db.Exec("INSERT into t (text) VALUES(?), (?)", "foo", "bar")
	db.Query("SELECT id, text FROM t")
}

/*
Output should look like:
> CREATE TABLE t (id INTEGER, text VARCHAR(16)) []. took: 121.238µs
> INSERT into t (text) VALUES(?), (?) ["foo" "bar"]. took: 36.364µs
> SELECT id, text FROM t []. took: 4.653µs
*/

Benchmarks

 go test -bench=. -benchmem
 goos: linux
 goarch: amd64
 pkg: github.com/qustavo/sqlhooks/v2
 cpu: Intel(R) Xeon(R) W-10885M CPU @ 2.40GHz
 BenchmarkSQLite3/Without_Hooks-16                 191196              6163 ns/op             456 B/op         14 allocs/op
 BenchmarkSQLite3/With_Hooks-16                    189997              6329 ns/op             456 B/op         14 allocs/op
 BenchmarkMySQL/Without_Hooks-16                    13278             83462 ns/op             309 B/op          7 allocs/op
 BenchmarkMySQL/With_Hooks-16                       13460             87331 ns/op             309 B/op          7 allocs/op
 BenchmarkPostgres/Without_Hooks-16                 13016             91421 ns/op             401 B/op         10 allocs/op
 BenchmarkPostgres/With_Hooks-16                    12339             94033 ns/op             401 B/op         10 allocs/op
 PASS
 ok      github.com/qustavo/sqlhooks/v2  10.294s

sqlhooks's Issues

can't use transactions with sqlhooks

I can't start transaction with non default isolation level because connection returned from sqlhooks.Conn wrapper doesn't implement driver.ConnBeginTx interface https://github.com/golang/go/blob/master/src/database/sql/ctxutil.go#L100

QueryerContext interface and prepared statements

If we don't implement QueryerContext or Queryer interface for connection, db.Query() will always do statement "prepare" and statement "exec". These extra roundtrips can add unneeded latency.

Run this test program and check in wireshark: https://play.golang.org/p/wvmsGliLPpz

A change like this fixes this: surki@98e9bd8

I could send a PR if you would like this fixed here

SQL commands inside hook methods

I would like to execute SQL commands inside the hook methods. These commands must be on the same transaction of the original command. I mean the one triggered by the programmer using the database/sql API. I have to do this transparently. Do you think it is feseable and straightforward to implement? I guess I would have to add extra parameters to the hook methods' signatures. However, I am wondering how I could append these extra comands to the ongoing transaction.

how to log sql when sql execute failed?

Actual resulting query?

I was hoping the after hook would include the resulting query, as it is actually passed to the database.

So instead of showing the original query like

'select id, first, last from users where id=?', '12'

It would include

'select id, first, last from users where id=12'

Useful for debugging edge cases, logging of all actual statements (to rebuild a database or specific situation) and other things.

add sqlhooks on awesome-go

https://github.com/avelino/awesome-go

Add opentracing hooks

Tracing hooks seems to be the perfect use case for sqlhooks

Run a linter in the CI

ATM no linters are set, anything will do for now. Code could be improved later

Compose hook

In order to combine multiple hooks (log+tracing) a new (compose) hook can be implemented. It should accept a list of Hooks and chain them together.

Tag latest commit

There have been a few changes to sqlhooks. We should probably tag the latest commit. I noticed this while trying out the dep tool.

Before+after hooks for prepare

When connecting over a high-latency network, it becomes visible in my tracing that Prepare takes a while to execute when using github.com/go-sql-driver/mysql.

Does it sound like it makes sense to add hooks around Prepare, too?

Expose a WrapDriver function

It'd be easier to integrate with other wrappers if a WrapDriver function was available, similar to ExpansiveWorlds/instrumentedsql

Improve performance

Benchmarks show a 2x and 3x overhead (mysql and psql). This should decrease.

Add Error handler

There's no way to react when Query|Exec fails. Hooks interface should define an Error handler.

Change Notifications

Great work! I think this could be great for data change notification events to various parts of an application. Is it possible to make the hooks pre or post execution with the ability to cancel a pre-hook query? For example, a use case might be to stop any query that contains "CREATE TABLE" for users that don't have that permission.

driver.ErrSkip error with sqlx

The hooks get entered twice for each sql query because from my understanding, the first hit to the hook get cancelled because of driver.ErrSkip "driver: skip fast-path; continue as if unimplemented" It seems to happen with sqlx.

More details is in the discussion over at data-dog DataDog/dd-trace-go#270

Right now a quick fix would be checking for driver.ErrSkip and ignore it in every execs and query

results, err := conn.execContext(ctx, query, args)
- if err != nil {
+ if err != nil && err != driver.ErrSkip {
    return results, handlerErr(ctx, conn.hooks, err, query, list...)
}

The other fix (from the thread) is to set interpolateParams=true is the database dsn.

Issues with gorm

I've recently tried out sqlhooks and encountered a problem:

(/Users/dobegor/go/src/smartback/v2/service/label_service.go:65)
[2018-05-23 14:51:15]  Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '"labels"  WHERE (user_id = 0 AND is_system = 1 AND label IN (?,?,?,?))' at line 1

(/Users/dobegor/go/src/smartback/v2/service/label_service.go:65)
[2018-05-23 14:51:15]  [2.00ms]  SELECT * FROM "labels"  WHERE (user_id = 0 AND is_system = 1 AND label IN ('Inbox','Archive','Trash','Snoozed'))

As you can see, for some reason requests went into mysql without substitution.
This only occurs if I wrap the driver with sqlhooks:

	sql.Register("mysqlWithHooks", sqlhooks.Wrap(&mysql.MySQLDriver{}, &Hooks{}))

	db, err := gorm.Open("mysqlWithHooks", config.DB.DSN())
	if err != nil {
		return stacktrace.Propagate(err, "Failed to connect to DB")
	}

I wonder if I'm doing something wrong here.

when using wraper driver, table name has Double quotes

when using wraper dierver, code like this:

sql exec err for table name has double quotes,

when not using wraper, code like this

sql exec success, table name change ok

so, what is the problem?

Add Benchmarks

V0 has some benchmarks, it would be good to have them back on v1

Implement new 1.8 interfaces

Go 1.8 has added a bunch of new interfaces that need to be wrapped, all the context related functions pretty much.

[Discussion] onError hook error ignore

i add onError hook, add collect driver.ErrSkip error, how about add error check before call onError

How get the query's Result on After Hook?

I'm using the hooks to create audit_logs for my project, I'm using the idea of this lib https://github.com/gmhafiz/audit but in this lib, the author uses a personalized version of sqlhooks (u can check this in the go.mod) that receive a driver.Result that has the LastInsertId() that he uses to populate the RowId in his audit struct.

My goal is to be able to use these Hooks to get the ID of the last record inserted on my Postgres database in a similar way.

Include Go version requirement in README

The latest version has implemented some new interfaces defined in Go 1.8. It would be useful if the Go version required is mentioned in the README.