使用gorm写入time.Time的类型时的问题

2022.10.23更新，已经提交pull request优化这个
https://github.com/go-gorm/my...

概述

很大一部分gopher都是用过gorm，而time.Time类型也是大家常用的类型，今天我就主要介绍一个在使用过程中遇到的一个比较奇怪的问题。

问题现象描述

gorm有一个debug模式，大家并不陌生，开启之后执行的每个sql都可以输出到终端。但是我却遇到了一个奇怪的问题，终端打印的sql显示扫描到0行数据，但是实际上把这个sql拿到数据库中执行是有结果的。

原因假设

遇到这种问题，其实一开始会很莫名其妙，然后可能就会想到，是不是数据库执行的sql根本不是控制台打印出来的sql呢。因为where条件上是有时间过滤条件的，当时其实已经有一点怀疑是时间的问题了，基于这个猜测，去验证并不困难。

验证环节

因为后面其实我已经确定了是时间的问题，咱们这里的验证改为一个简单的场景，不拿我当时的业务数据在这里说明。我会重新构建一个最简单的场景（这样也方便大家亲自实践），然后捋清楚这个过程。

准备工作

golang环境 我本地是1.18.2 理论上这个没什么影响，不要太低就好
mysql环境（我当时实际业务是用的tidb，为了方便验证，直接使用docker运行一个mysql服务）

代码

package main

import (
    "fmt"
    "gorm.io/driver/mysql"
    "gorm.io/gorm"
    "time"
)

func main() {
    // 参考 https://github.com/go-sql-driver/mysql#dsn-data-source-name 获取详情
    dsn := "root:root123@tcp(127.0.0.1:3306)/lv_test?charset=utf8mb4&parseTime=True&loc=Local"
    db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{})
    if err != nil {
        panic(err)
    }

    db = db.Debug()

    var result []*map[string]interface{}
    t := time.Now()
    fmt.Println(t)
    t = t.UTC()
    err = db.Table("test").Where("created_at>?", t).Find(&result).Error
    if err != nil {
        panic(err)
    }
}

上面的代码是一个最小的验证单元

可以通过下面的命令开启通用日志以及查看日志位置

set global general_log=on;
show variables like 'general_log_file';

执行

执行golang代码

看到输出结果如下，因为时间被转换成utc时间，所以输出的sql看起来好像是正常的

2022-09-30 22:00:57.7214462 +0800 CST m=+1.290270101

2022/09/30 22:00:57 C:/work/go/code/first/mysql.go:24
[2.653ms] [rows:0] SELECT * FROM `test` WHERE created_at>'2022-09-30 14:00:57.721'

但是通过查看 mysql的general log并不是这样

2022-09-30T14:00:57.718992Z        12 Connect   root@172.17.0.1 on lv_test using TCP/IP
2022-09-30T14:00:57.719717Z        12 Query     SET NAMES utf8mb4
2022-09-30T14:00:57.720416Z        12 Query     SELECT VERSION()
2022-09-30T14:00:57.735894Z        12 Prepare   SELECT * FROM `test` WHERE created_at>?
2022-09-30T14:00:57.736664Z        12 Execute   SELECT * FROM `test` WHERE created_at>'2022-09-30 22:00:57.7214462'
2022-09-30T14:00:57.737528Z        12 Close stmt

可以看到数据库里面真实执行的时候的时间参数跟gorm打印的并不一样，这样的情况就会给排查问题造成比较大的困扰。

源码分析

通过阅读go-sql-driver源码里面的Exec方法，发现调用了interpolateParams方法处理参数（在github.com/go-sql-dirver/mysql目录的connection.go）

case time.Time:
            if v.IsZero() {
                buf = append(buf, "'0000-00-00'"...)
            } else {
                buf = append(buf, '\'')
                buf, err = appendDateTime(buf, v.In(mc.cfg.Loc))
                if err != nil {
                    return "", err
                }
                buf = append(buf, '\'')
            }

我简单截取了对传入的time.Time对象的处理方法，发现是把time.Time对象处理成cfg.Loc中的时区，那么这个cfg是哪里来的呢

阅读connector.go，发现是在Connect方法中对mc进行赋值操作

func (c *connector) Connect(ctx context.Context) (driver.Conn, error) {
    var err error

    // New mysqlConn
    mc := &mysqlConn{
        maxAllowedPacket: maxPacketSize,
        maxWriteSize:     maxPacketSize - 1,
        closech:          make(chan struct{}),
        cfg:              c.cfg,
    }
    mc.parseTime = mc.cfg.ParseTime
    //.........之后的代码省略
}

connector里面的cfg又是哪里来的呢

在driver.go中的Open函数赋值的

func (d MySQLDriver) Open(dsn string) (driver.Conn, error) {
    cfg, err := ParseDSN(dsn)
    if err != nil {
        return nil, err
    }
    c := &connector{
        cfg: cfg,
    }
    return c.Connect(context.Background())
}

这时候我们就要看ParseDSN中的处理了
通过检查不难找出

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

通过上面，可以看到，如果传入了loc=Local的参数，入库的时间会被fomat为东八区的时间字符串

我们再看看gorm打印sql时候的处理
gorm源码中的logger目录，sql.go文件

func ExplainSQL(sql string, numericPlaceholder *regexp.Regexp, escaper string, avars ...interface{}) string {
    var (
        convertParams func(interface{}, int)
        vars          = make([]string, len(avars))
    )

    convertParams = func(v interface{}, idx int) {
        switch v := v.(type) {
        case bool:
            vars[idx] = strconv.FormatBool(v)
        case time.Time:
            if v.IsZero() {
                vars[idx] = escaper + tmFmtZero + escaper
            } else {
                vars[idx] = escaper + v.Format(tmFmtWithMS) + escaper
            }
        //......略去后面的代码
}

可以看到 在打印日志的时候，时间是被按照tmFmtWithMS这个格式格式化的
不难找出这个的定义

const (
    tmFmtWithMS = "2006-01-02 15:04:05.999"
    tmFmtZero   = "0000-00-00 00:00:00"
    nullStr     = "NULL"
)

可以看到，是直接Format的，没有考虑时区的情况

总结与结论

golang中的time.Time类型本质上也是由时间戳和时区构成的，不管是什么时区，时间戳是一样的，然后根据不同的时区表现出不同的字符串形式的值。

我们一开始连接数据库传入的loc=Local参数，驱动就在数据交互操作中把所有的time.Time类型变成本地时间（东八区），这种情况下utc时间的2022-09-30 14:00:57.721就变成了东八区的2022-09-30 22:00:57.721。但是gorm在进行日志打印的时候，并没有去考虑时区的情况，而是直接打印出了2022-09-30 14:00:57.721这个字符串。这就导致看到的gorm日志和实际执行的sql不一致。其实实际上对数据库来说，即便是datatime类型，其实也是没有时区的概念的，可以认为是一个字符串。