instrumentedsql breaks go-oci8 v0.0.9 and above

[nvx]

The following code works with v0.0.8 of go-oci8, but breaks under v0.0.9 of go-oci8. The commit that triggers the issue is https://github.com/mattn/go-oci8/commit/4a4497791f93ed91967ff2feb680aec865e804da

stmt.NumInput() returning -1 is valid for a driver to return.

The issue stems that NumInput returning -1 is fine when driver.NamedValueChecker is used, but not fine when driver.ColumnConverter is used. Normally when both are implemented, only the NamedValueChecker is used, but when the driver NamedValueChecker returns driver.ErrSkip and the driver also implements the ColumnConverter interface, database/sql will use a wrapper (database/sql.ccChecker) to expose the ColumnConverter as if it were a NamedValueChecker. The problem arises that when NumInput returns -1 this causes the wrapper to return nil (without calling the drivers ColumnConverter) and no further functions are called. By comparison if the NamedValueChecker returns driver.ErrSkip and ColumnConverter is not implemented this causes database/sql.defaultCheckNamedValue to be called which performs a required conversion step.

Example application that exhibits the issue, runs fine with go-oci8 v0.0.8 (where NumInput() returns >= 0), fails on v0.0.9 or newer (where NumInput() returns -1). Swapping the comment on the wrappedDriver := line allows the code to work even on v0.0.9 of go-oci8 driver.

Additionally commenting out the wrappedStmt.ColumnConverter func in instrumentedsql also allows the code to run without issue.

package main

import (
    "context"
    "database/sql"
    "database/sql/driver"
    "flag"
    "fmt"
    "github.com/luna-duclos/instrumentedsql"
    "github.com/mattn/go-oci8"
)

type dsnConnector struct {
    driver driver.Driver
    dsn    string
}

func (t dsnConnector) Connect(_ context.Context) (driver.Conn, error) {
    return t.driver.Open(t.dsn)
}

func (t dsnConnector) Driver() driver.Driver {
    return t.driver
}

func main() {
    var (
        dbDSN = flag.String("db-dsn", "", "DB DSN")
    )
    flag.Parse()

    // switching the following two lines results in the code working
    wrappedDriver := instrumentedsql.WrapDriver(oci8.Driver)
    //wrappedDriver := oci8.Driver
    db := sql.OpenDB(dsnConnector{driver: wrappedDriver, dsn: *dbDSN})

    var err error
    var out int64

    err = db.QueryRow( `SELECT 1 FROM DUAL`).Scan(&out)
    if err != nil {
        fmt.Println("Error 0:", err) // This case doesn't error
    } else {
        fmt.Println("No error 0:", out)
    }

    err = db.QueryRow( `SELECT 1 FROM DUAL WHERE :1=0`, 0).Scan(&out)
    if err != nil {
        fmt.Println("Error 1:", err) // binary read for column 0 - error: binary.Write: invalid type int
    } else {
        fmt.Println("No error 1:", out)
    }

    err = db.QueryRow( `SELECT 1 FROM DUAL WHERE 1 >= :1`, sql.NullInt64{Int64: 1, Valid: true}).Scan(&out)
    if err != nil {
        fmt.Println("Error 2:", err) // ORA-01722: invalid number
    } else {
        fmt.Println("No error 2:", out)
    }

    err = db.QueryRow( `SELECT 1 FROM DUAL WHERE 1 >= :1`, sql.NullFloat64{Float64: 1, Valid: true}).Scan(&out)
    if err != nil {
        fmt.Println("Error 3:", err) // ORA-01722: invalid number
    } else {
        fmt.Println("No error 3:", out)
    }
}

pseudocode of logic differences when using go-oci8 vs wrapped in instrumentedsql:

oci8: implements NamedValueChecker but not ColumnConverter
    database/sql.driverArgsConnLocked logic
        calls NamedValueChecker
            NamedValueChecker returns driver.ErrSkip
        calls database/sql.defaultCheckNamedValue
            calls driver.DefaultParameterConverter.ConvertValue(nv.Value)

instrumentedsql wrapping oci8: implements NamedValueChecker and ColumnConverter
    database/sql.driverArgsConnLocked logic
        calls NamedValueChecker
            calls oci8.NamedValueChecker
                oci8.NamedValueChecker returns driver.ErrSkip
        calls database/sql.ccChecker ColumnConverter wrapper wrapping instrumentedsql.ColumnConverter
            // c.want is -1 in oci8 v0.0.9 and newer
            if c.want <= index {
                // ColumnConverter only accepts an index, so the wrapper bails out here returning nil
                return nil
            }
            // note that instrumentedsql.ColumnConverter is never called, just the existence of this func is enough to cause the issue
        since nil was returned not driver.ErrSkip, database/sql.defaultCheckNamedValue is not called -> this causes an error

A fix would be to only implement NamedValueChecker and not ColumnConverter on go1.9+ to avoid the side effect of ColumnConverter existing.

If a driver only implements ColumnConverter and not NamedValueChecker on go1.19+, or if a driver implements both and NamedValueChecker returns driver.ErrSkip, instrumentedsql can perform wrapping of ColumnConverter as a NamedValueChecker (a copy paste of database/sql.ccChecker would work, unfortunately it's not public to be able to use it as-is). The important distinction vs what happens now is that the wrapper must only be used if the underlying driver implements ColumnConverter. I suspect that NumInput returning -1 when ColumnConverter is implemented is not a valid condition.

[nvx]

I've implemented the fix mentioned here in PR #42. The fix will make instrumentedsql behave more transparently (in this instance it will replicate the behaviour as if it is not being used) - which for a tracing library makes sense that it shouldn't affect behaviour.

There is another question which is if https://github.com/golang/go/blob/0efbd1015774a2d894138519f1efcf7704bb2d95/src/database/sql/convert.go#L56-L58 returning nil at that point is actually the right option, or if calling defaultCheckNamedValue at that point would make more sense. Of course that's out of scope of this repo and there may be some compatibility issues with the older interface to consider that requires it be handled that way, but something to think about. That said even if the behaviour of database/sql is changed, I still think it makes sense to use the fix I implemented (although the ccChecker should be updated to reflect any such changes) as it makes the way database/sql interacts with the wrapped driver more closely aligned to how database/sql would interact with the unwrapped driver.

[nvx]

I just noticed this is still open. I've been running the merged version from PR #42 for a while now without issues. Is it worth cutting a point release and marking this closed

[luna-duclos]

Yes! I will do so next week when I get to the office

[fho]

Is this issue fixed? The PR was merged a while ago.

[fho]

I ran into a similar issue with the pq driver.

According to https://github.com/golang/go/blob/f865b5fefeafaf76ce6ff99e44d41c52cb6b884b/src/database/sql/driver/driver.go#L275:

// The sql package checks for value checkers in the following order, // stopping at the first found match: Stmt.NamedValueChecker, Conn.NamedValueChecker, // Stmt.ColumnConverter, DefaultParameterConverter.

instrumentedsql in master currently does not call the methods in the descripted order. Conn.NamedValueChecker and DefaultParameterConverter are not explicitly called. Are they called implicitly in somewhere or is that missing in instrumentedsql?

I also discovered https://github.com/ngrok/sqlmw/pull/3. It fixes a similar issue. There Conn.NamedValueChecker and DefaultParameterConverter are called but Stmt.ColumnConverter isn't

[nvx]

Is this issue fixed? The PR was merged a while ago.

It is, but the latest tagged version (v1.1.3) does not include the fix. If you point to the current commit at the tip of the master branch it works fine though.

[fho]

@nvx thanks, do you maybe know if https://github.com/luna-duclos/instrumentedsql/issues/41#issuecomment-883247352 is an issue?

[nvx]

@nvx thanks, do you maybe know if #41 (comment) is an issue?

I wouldn't be surprised if v1.1.3 isn't working, have you tried updating to the current master commit and retesting? I suspect that'll fix it.

[fho]

@nvx Yes, the particular issue that I had related to lib/pq + value conversion is fixed in master.

It looks to me that the current implementation from your PR (https://github.com/luna-duclos/instrumentedsql/issues/41) does not implement the value checker order as described in the stdlib driver package (https://github.com/golang/go/blob/f865b5fefeafaf76ce6ff99e44d41c52cb6b884b/src/database/sql/driver/driver.go#L275) though. I'm wondering if that is really the case or If I'm misunderstand something.

If it does not follow the same value checker order in the stdlib, it might cause issues with driver that I'm currently missing in my test scenario.

[nvx]

It was a copy paste of the stdlib implementation at the time. That said stdlib might have changed since then and there's probably value in keeping it consistent.