ちょうど本業のほうでDBへのアクセスが遅い?んだかなんだかでREST APIがタイムアウトしている事象に出会っていたのでよっしゃとgo-sql-proxyを使おうと思ったのだけど、まずこのままだと実行時間とかが計測できない… ということに気づいて色々考えた結果PRを送る事にした。送ったら光速でマージされた。

今度から NewTraceProxyでプロキシを作れば Open/Exec/Queryに関しては所要時間が出力されるようになります。mysqlなら以下のような感じ:

driverName := "mysql"
if traceEnabled {
    driverName = "mysql-trace"
    sql.Register(driverName, proxy.NewTraceProxy(&mysql.MySQLDriver{}, logger))
}
db, err := sql.Open(driverName, dsn)
...

出力はこんな感じ:

tracer_test.go:27: Open (54.116µs)
tracer_test.go:27: Exec: CREATE TABLE t1 (id INTEGER PRIMARY KEY); args = [] (44.535µs)
tracer_test.go:41: Query: SELECT id FROM t1 WHERE id = ?; args = [1] (1.828µs)

わーい、これでボトルネック探すの捗るぞー!… と思っていたら、元々のNewTraceProxyのシグネチャが

func NewTraceProxy(d driver.Driver, o Outputter) *Proxy

で、これだと自前のloggerを受け付けてくれない!
type MyLogger struct { *log.Logger }
とかでも駄目だ!ということでインターフェースを定義してOutputメソッドを実装してればなんでもいいようにしておいたPRを送って取り込んでもらった。これで使えるようになった。YATTA!(けど、デプロイはこれからなのでまだなにか後で追加するかも…)

どちらのPRも光速でマージしてもらって大分たすかった。ありがとうございます。