きょこみのーと

元六本木でGo書いてました。今はVRでGo書いてます。

gormのCallbackをつかってexplain結果をログ出力する

はじめに

explainは基本的に実装時に自分で叩いてると思いますが、dev環境とかそこそこデータとか利用頻度が高い環境で雑に垂れ流したいなーと思ってgormのDebug実装を眺めていたらCallbackという仕組みがあったので、それを使ってみました。

作ったもの

github.com

使い方

gormのexampleをにちょこっと追加してみました。

package main

import (
    "fmt"

    _ "github.com/go-sql-driver/mysql" // mysqlを使う
    "github.com/jinzhu/gorm"
    explain "github.com/kyokomi/gorm-explain"
)

type options struct {
    user     string
    password string
    host     string
    port     int
    dbName   string
    location string
}

func buildDataSourceName(opts options) string {
    const format = "%s:%s@tcp(%s:%d)/%s?parseTime=True&loc=%s"
    return fmt.Sprintf(format, opts.user, opts.password, opts.host, opts.port, opts.dbName, opts.location)
}

// Product product table struct
type Product struct {
    gorm.Model
    Code  string
    Price uint
}

func main() {
    opts := options{
        user:     "test-user",
        password: "test-user",
        host:     "127.0.0.1",
        port:     3306,
        dbName:   "test_db",
        location: "UTC",
    }
    db, err := gorm.Open("mysql", buildDataSourceName(opts))
    if err != nil {
        panic("failed to connect database")
    }
    defer db.Close()
    db = db.Debug() // query trace
    db.Callback().Query().Register("explain", explain.Callback) // add explain callback

    // Migrate the schema
    db.AutoMigrate(&Product{})

    // Create
    db.Create(&Product{Code: "L1212", Price: 1000})

    // Read
    var product Product
    db.First(&product, 1)                   // find product with id 1
    db.First(&product, "code = ?", "L1212") // find product with code l1212

    // Update - update product's price to 2000
    db.Model(&product).Update("Price", 2000)

    // Delete - delete product
    db.Delete(&product)
}

実行した結果

(あと、gormのDebug機能をつかうとqueryがログに吐かれるようになるのでこれを合わせて使うと便利です)

(/Users/kyokomi/workspace/go/src/github.com/kyokomi/gorm-explain/example/main.go:53)
[2017-05-05 18:16:38]  [1.08ms]  INSERT INTO `products` (`created_at`,`updated_at`,`deleted_at`,`code`,`price`) VALUES ('2017-05-05 18:16:38','2017-05-05 18:16:38',NULL,'L1212','1000')

(/Users/kyokomi/workspace/go/src/github.com/kyokomi/gorm-explain/example/main.go:57)
[2017-05-05 18:16:38]  [0.95ms]  SELECT * FROM `products`  WHERE `products`.`deleted_at` IS NULL AND ((`products`.`id` = '1')) ORDER BY `products`.`id` ASC LIMIT 1
+-------+----------------+----------+---------------+---------+------------------+--------+------------+--------+---------+-------------+--------------------------------------------------------+
|    id |    select_type |    table |    partitions |    type |    possible_keys |    key |    key_len |    ref |    rows |    filtered |                                                  Extra |
+=======+================+==========+===============+=========+==================+========+============+========+=========+=============+========================================================+
|     1 |         SIMPLE |          |               |         |                  |        |            |        |         |             |    Impossible WHERE noticed after reading const tables |
+-------+----------------+----------+---------------+---------+------------------+--------+------------+--------+---------+-------------+--------------------------------------------------------+



  1 Fix example to add query trace

(/Users/kyokomi/workspace/go/src/github.com/kyokomi/gorm-explain/example/main.go:58)
[2017-05-05 18:16:38]  [1.11ms]  SELECT * FROM `products`  WHERE `products`.`deleted_at` IS NULL AND ((code = 'L1212')) ORDER BY `products`.`id` ASC LIMIT 1
+-------+----------------+-------------+---------------+---------+----------------------------+----------------------------+------------+----------+---------+-------------+---------------------------------------+
|    id |    select_type |       table |    partitions |    type |              possible_keys |                        key |    key_len |      ref |    rows |    filtered |                                 Extra |
+=======+================+=============+===============+=========+============================+============================+============+==========+=========+=============+=======================================+
|     1 |         SIMPLE |    products |               |     ref |    idx_products_deleted_at |    idx_products_deleted_at |          5 |    const |       2 |         100 |    Using index condition; Using where |
+-------+----------------+-------------+---------------+---------+----------------------------+----------------------------+------------+----------+---------+-------------+---------------------------------------+


(/Users/kyokomi/workspace/go/src/github.com/kyokomi/gorm-explain/example/main.go:61)
[2017-05-05 18:16:38]  [0.86ms]  UPDATE `products` SET `price` = '2000', `updated_at` = '2017-05-05 18:16:38'  WHERE `products`.`deleted_at` IS NULL AND `products`.`id` = '7'

(/Users/kyokomi/workspace/go/src/github.com/kyokomi/gorm-explain/example/main.go:64)
[2017-05-05 18:16:38]  [0.88ms]  UPDATE `products` SET `deleted_at`='2017-05-05 18:16:38'  WHERE `products`.`deleted_at` IS NULL AND `products`.`id` = '7'

注意点

さっと書いたので、fmtで出力してます。ちゃんと自前のロガーとかで出力したい場合は、このコード参考に自分で書いてください 🙏🏻 (もしくはPullRequestまってます 😇 )

おわり

explainの結果に filesortが含まれていたら〜みたいなHandlerを設定できるような感じに改修とかすると便利そうだな〜とか思ってます。