gorpで実行されるSQLをログに出力する

DBが絡む開発をしていると、実際に投げているSQLを確認したくなることがあります。そんな場合に、gorpでは実行されたSQLを出力する方法が用意されています。

どうやるか

gorpのLoggerインターフェイスを実装して、それを渡すことで利用者がある程度コントロールできるようになっています。

GorpLogger

type GorpLogger interface {
    Printf(format string, v ...interface{})
}

やってみる

プログラム全体はこちら
ec2用のテーブルを作って適当にデータを入れています。

GorpLoggerインターフェイスをを実装した構造体を作って渡します。今回は標準logをラップしてるだけのものです。

GorpLogger簡易実装

type MyGorpTracer struct{}

func (t *MyGorpTracer) Printf(format string, v ...interface{}) {
    log.Printf(format, v...)
}

その上で、TraceOn()にprefix文字列と一緒に渡すと、出力されるようになります。

ログの有効化

// gorpのDbMap生成
dbmap := &gorp.DbMap{Db: db, Dialect: gorp.SqliteDialect{}}

// Loggerを生成
tracer := &MyGorpTracer{}

// Logging有効化
dbmap.TraceOn("[gorp SQL trace]", tracer)

そうすると、以下のように出力されます。今回はテーブルを削除して、テーブルを作ってデータを10件入れてselect allしてます。

gorpのSQLログ

2016/01/03 12:09:01 [gorp SQL trace] drop table "ec2"; []
2016/01/03 12:09:01 [gorp SQL trace] create table if not exists "ec2" ("id" integer not null primary key autoincrement, "type" varchar(255)) ; []
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro0"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro1"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro2"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro3"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro4"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro5"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro6"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro7"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro8"]
2016/01/03 12:09:01 [gorp SQL trace] insert into "ec2" ("id","type") values (null,?); [1:"t2.micro9"]
2016/01/03 12:09:01 [gorp SQL trace] select * from ec2 []

最初に標準logの日付、渡したprefix文字列、SQL、valuesが出力されています。

出力フォーマットが指定できるともっと使いやすそうですが、とりあえず開発中に出力するには十分かなと思います。

ORMとして使っているとそもそもSQL自体が見えないので、こういった形で見えるようにできると、調査時に便利です。また、adhocにSQLを投げた場合も、実行とログ出力で変数の指定を間違えるといったことも防げます。

動的にTraceOn(), TraceOff()を呼び出せるようにしておいて、コマンドであればdebug用オプション時に、Webアプリケーションであれば、内部エンドポイント呼び出しなどで切り替えられると便利かもしれません。

参考

• gorp github
• gorp.v1 godoc
• gorpのSQLite利用はこちらを参考にしました