driver.ErrSkip error with sqlx

[gmhafiz]

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.

[qustavo]

Thanks for reporting this, how hard would it be to reproduce this with a test?

[gmhafiz]

Hmm interesting, I ran without any modifications yet to TestMySQL() unit test and the driver.ErrSkip happens without sqlx.

1. docker run --name sqlhooks-mysql -p 3307:3306 -e MYSQL_ROOT_PASSWORD=password -d mysql:8
2. create table sqlhooks;
3. export SQLHOOKS_MYSQL_DSN=root:password@(0.0.0.0:3307)/sqlhooks?parseTime=true
4. go test -run TestMySQL

go test -run TestMySQL                                                                               
--- FAIL: TestMySQL (0.00s)
    --- FAIL: TestMySQL/Query (0.00s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
        panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x6db7ab]

goroutine 23 [running]:
testing.tRunner.func1.2({0x7c94a0, 0xa82ff0})
        /home/gmhafiz/sdk/go1.17.1/src/testing/testing.go:1209 +0x24e
testing.tRunner.func1()
        /home/gmhafiz/sdk/go1.17.1/src/testing/testing.go:1212 +0x218
panic({0x7c94a0, 0xa82ff0})
        /home/gmhafiz/sdk/go1.17.1/src/runtime/panic.go:1038 +0x215
github.com/qustavo/sqlhooks/v2.(*testHooks).OnError(0xc0000c01c8, {0x88a150, 0xc0000c8000}, {0x882b20, 0xc0000a03b0}, {0x81c7f7, 0x20}, {0xc0000a1300, 0x1, 0x1})
        /home/gmhafiz/Sync/programming/goWorkspace/sqlhooks-ori/sqlhooks_test.go:40 +0xab
github.com/qustavo/sqlhooks/v2.handlerErr({0x88a150, 0xc0000c8000}, {0x887510, 0xc0000c01c8}, {0x882b20, 0xc0000a03b0}, {0x81c7f7, 0x20}, {0xc0000a1300, 0x1, ...})
        /home/gmhafiz/Sync/programming/goWorkspace/sqlhooks-ori/sqlhooks.go:32 +0xbf
github.com/qustavo/sqlhooks/v2.(*QueryerContext).QueryContext(0xc0000aa078, {0x88a150, 0xc0000c8000}, {0x81c7f7, 0x20}, {0xc0000a56e0, 0x1, 0x1})
        /home/gmhafiz/Sync/programming/goWorkspace/sqlhooks-ori/sqlhooks.go:215 +0x214
database/sql.ctxDriverQuery({0x88a150, 0xc0000c8000}, {0x7f21345f8bc0, 0xc0000da4c0}, {0x0, 0x0}, {0x81c7f7, 0x79e6b2}, {0xc0000a56e0, 0x1, ...})
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/ctxutil.go:48 +0x17d
database/sql.(*DB).queryDC.func1()
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/sql.go:1722 +0x175
database/sql.withLock({0x887290, 0xc000142090}, 0xc00005ed48)
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/sql.go:3396 +0x8c
database/sql.(*DB).queryDC(0x1, {0x88a150, 0xc0000c8000}, {0x0, 0x0}, 0xc000142090, 0xc0000a12f0, {0x81c7f7, 0x20}, {0xc0000a12a0, ...})
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/sql.go:1717 +0x211
database/sql.(*DB).query(0x474, {0x88a150, 0xc0000c8000}, {0x81c7f7, 0x20}, {0xc0000a12a0, 0x1, 0x1}, 0x24)
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/sql.go:1700 +0xfd
database/sql.(*DB).QueryContext(0x8bed24, {0x88a150, 0xc0000c8000}, {0x81c7f7, 0x20}, {0xc0000a12a0, 0x1, 0x1})
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/sql.go:1674 +0xdf
database/sql.(*DB).Query(...)
        /home/gmhafiz/sdk/go1.17.1/src/database/sql/sql.go:1691
github.com/qustavo/sqlhooks/v2.(*suite).TestHooksExecution.func3(0x0)
        /home/gmhafiz/Sync/programming/goWorkspace/sqlhooks-ori/sqlhooks_test.go:74 +0x72
testing.tRunner(0xc00013c9c0, 0xc0000e64b0)
        /home/gmhafiz/sdk/go1.17.1/src/testing/testing.go:1259 +0x102
created by testing.(*T).Run
        /home/gmhafiz/sdk/go1.17.1/src/testing/testing.go:1306 +0x35a
exit status 2
FAIL    github.com/qustavo/sqlhooks/v2  0.006s

I did a fmt.Println(err.Error()) and the error is ErrSkip: driver: skip fast-path; continue as if unimplemented

Unfortunately appending &interpolateParams=true to the dsn makes no difference.

I am unsure why &interpolateParams=true works without ErrSkip when I use this library in my server.

[qustavo]

I think this is interesting: https://github.com/go-sql-driver/mysql/blob/master/connection.go#L201 https://github.com/go-sql-driver/mysql/blob/master/connection.go#L304
I ran the test following your instructions and it did panic when used without interpolateParams but did not when i used it

[qustavo]

It seems to be an error with the way we are testing.
The testHook struct is not defining a onError hook and when it is called, if fails because it's trying to call I'll open a PR to fix that