7月に株式会社カミナシに入社したくらさわです！
カミナシでは、現場DXプラットフォーム「カミナシ」の開発をしています！
よろしくお願いします！！！

きっかけ

現在、カミナシの開発では、サーバサイドの言語は Go 、ORマッパーとして「GORM」を使い、DB には Amazon Aurora MySQL を使っています。

ある日、開発中に GORM が吐いてくれるログで query を調べていると、アプリケーションの実行中は結果が取れていないのに、その query をコピーして、手動で MySQL に投げると結果が取得できるということがありました。

パッとわからなかったので、それについて調べたことを記事にしてみました！

検証バージョン

GORM には「GORM V1」と「GORM V2」があり、検証には GORM V2 の v1.23.8 を使用しています。
また、「go-sql-driver/mysql」は v1.6.0 を使用しています。

結論

先に結論を書いておくと、where 句に指定している日時のタイムゾーンの違いにより、結果に違いが出ていました。
ものすごく単純にすると以下のようなコードです。

// [ 1 ] loc の指定をせずにコネクションをオープン
db, _ := gorm.Open(mysql.Open("user:pass@/sample?parseTime=true"), &gorm.Config{
    // ログの設定
    Logger: logger.Default.LogMode(logger.Info),
})

// [ 2 ] JST の time.Time 型の変数を生成
jst, _ := time.LoadLocation("Asia/Tokyo")
jstTime := time.Date(2022, 8, 20, 0, 0, 0, 0, jst)

// [ 3 ] JST の time.Time 型の変数を Where 句に渡す
var result Type
db.Where("datetime = ?", time).First(&result)

[ 1 ] で DSN パラメータの loc を指定しなければ、 query に渡される time.Time 型の変数は UTC として扱われます。そのため、[ 2 ] で JST の time.Time 型を生成して、 [ 3 ] で渡したとしても query には UTC として渡されます。ここでは 2022-08-19 15:00:00 になります。

しかし、GORM のログでは、[ 3 ] で渡された time.Time のロケーションを使用して文字列に変換されるので、ログには JST として出力されます。ここでは 2022-08-20 00:00:00 になります。

その結果、アプリケーションの実行時と、ログに出力された query にずれが生じてしまったのです。

コード書いて確認してみた

というわけで、この件について調べてみました。
まず初めに「JST として生成した time.Time 型の変数を UTC として扱う」挙動は GORM によるものなのか、それとも go-sql-driver/mysql によるものなのかを確認するために、GORM を使わずにコードを書いてみました。
※ コードの全文は「こちら」にあります。

テーブルとレコードはこちら。

CREATE TABLE IF NOT EXISTS sample_table(
    id INT(11) AUTO_INCREMENT NOT NULL, 
    datetime DATETIME NOT NULL,
    PRIMARY KEY (id)
);

INSERT INTO sample_table (datetime) VALUES ('2022-08-20 00:00:00');

コードはこちら。

type sample struct {
    id       int
    datetime time.Time
}

func main() {
    db, err := sql.Open("mysql", "root:root@/sample?parseTime=true")
    if err != nil {
        log.Fatal("unable to use data source name", err)
    }
    defer db.Close()

    // [1] UTC の 2022-08-20 00:00:00 で検索
    utc, _ := time.LoadLocation("UTC")
    utcTime := time.Date(2022, 8, 20, 0, 0, 0, 0, utc)
    if result, err := findByDatetime(db, utcTime); err == nil {
        fmt.Printf("[1] id: %d, datetime: %v\n", result.id, result.datetime)
    } else {
        fmt.Println("[1]", err)
    }

    // [2] JST の 2022-08-20 00:00:00 で検索
    jst, _ := time.LoadLocation("Asia/Tokyo")
    jstTime := time.Date(2022, 8, 20, 0, 0, 0, 0, jst)
    if result, err := findByDatetime(db, jstTime); err == nil {
        fmt.Printf("[2] id: %d, datetime: %v\n", result.id, result.datetime)
    } else {
        fmt.Println("[2]", err)
    }

    // [3] UTC の 2022-08-20 00:00:00 を JST にして検索
    if result, err := findByDatetime(db, utcTime.In(jst)); err == nil {
        fmt.Printf("[3] id: %d, datetime: %v\n", result.id, result.datetime)
    } else {
        fmt.Println("[3]", err)
    }
}

func findByDatetime(db *sql.DB, datetime time.Time) (sample, error) {
    var result sample
    if err := db.QueryRow("select id, datetime from sample_table where datetime = ?", datetime).Scan(&result.id, &result.datetime); err != nil {
        return sample{}, err
    }
    return result, nil
}

3回、日時を使って検索をしており、
[ 1 ] では UTC の 2022-08-20 00:00:00 で検索、
[ 2 ] では JST の 2022-08-20 00:00:00 で検索、
[ 3 ] では UTC の 2022-08-20 00:00:00 を JST にして検索、つまり JST の 2022-08-20 09:00:00 で検索しています。

結果は以下のように出力されます。

[1] id: 1, datetime: 2022-08-20 00:00:00 +0000 UTC
[2] sql: no rows in result set
[3] id: 1, datetime: 2022-08-20 00:00:00 +0000 UTC

[ 2 ] では JST の 2022-08-20 00:00:00 が UTC の 2022-08-19 15:00:00 として扱われるので結果が取得できておらず、
[ 3 ] では JST の 2022-08-20 09:00:00 が UTC の 2022-08-20 00:00:00 として扱われるので結果が取得できていることがわかります。

この結果から、time.Time の変数を UTC にしているのは go-sql-driver/mysql だということがわかりました。

ドキュメント読んでみた

それでは go-sql-driver/mysql のドキュメントを読んでみましょう。
go-sql-driver/mysql の README に「time.Time support」という見出しがあります。
そこには以下のように書いてあります。

You can set the default time.Time location with the loc DSN parameter.

書いてある通りですが、DSN パラメータの loc で time.Time のデフォルトのロケーションを指定することができるようです。

「DSN パラメータの loc の説明」もみてみましょう。

Sets the location for time.Time values

と書いてあります。やはり DSN パラメータの loc で time.Time のロケーションを指定するようです。

コード読んでみた

ドキュメントを読んでなんとなくわかった気がしますが、実際のコードがどうなってるかも確認しておきましょう。

go-sql-driver/mysql のコード

まず、DSN パラメータの loc を指定した場合、「ここ」で cfg.Loc にロケーションが設定されます。

case "loc":
    if value, err = url.QueryUnescape(value); err != nil {
      return
    }
    cfg.Loc, err = time.LoadLocation(value)
    if err != nil {
      return
    }

もし loc の指定がなければ、cfg の初期化時に UTC が入っているので UTC になります。
「ここ」。

// NewConfig creates a new Config and sets default values.
func NewConfig() *Config {
    return &Config{
        Collation:            defaultCollation,
        Loc:                  time.UTC,
        MaxAllowedPacket:     defaultMaxAllowedPacket,
        AllowNativePasswords: true,
        CheckConnLiveness:    true,
    }
}

そして、そこで設定した Loc を使用するのが「ここ」です。

case time.Time:
    paramTypes[i+i] = byte(fieldTypeString)
    paramTypes[i+i+1] = 0x00

    var a [64]byte
    var b = a[:0]

    if v.IsZero() {
        b = append(b, "0000-00-00"...)
    } else {
        b, err = appendDateTime(b, v.In(mc.cfg.Loc))
        if err != nil {
            return err
        }
    }

    paramValues = appendLengthEncodedInteger(paramValues,
        uint64(len(b)),
    )
    paramValues = append(paramValues, b...)

ここでは MySQL のパケットを生成しており、その中で time.Time 型の変数を byte 配列に変換しています。その際に cfg.Loc を使用して、ロケーションを指定しています。
ここまでが、go-sql-driver/mysql でロケーションを設定して使用するまでの流れでした。

GORM のコード

あともう一つ見ておきたいコードがありまして、 GORM 側のログを吐くところです。
「ここ」です。

case time.Time:
    if v.IsZero() {
        vars[idx] = escaper + tmFmtZero + escaper
    } else {
        vars[idx] = escaper + v.Format(tmFmtWithMS) + escaper
    }

これは ExplainSQL というログ出力のための string を生成する関数の一部です。
この v という変数が time.Time 型の変数になっており、ロケーションの指定が特に行われていないので、time.Time 型の変数のローケーションがそのまま使用されます。
そのため JST の変数であれば JST のまま文字列に変換されます。
これによって、クエリの実行時と、ログ出力時のタイムゾーンのずれが発生していたというわけでした。