数据库时间慢了14个小时,Mybatis说,这个锅我不背~

本文涉及的产品
RDS MySQL Serverless 基础系列,0.5-2RCU 50GB
云数据库 RDS MySQL,集群系列 2核4GB
推荐场景:
搭建个人博客
RDS MySQL Serverless 高可用系列,价值2615元额度,1个月
简介: 数据库时间慢了14个小时,Mybatis说,这个锅我不背~

同事反馈一个问题:Mybatis插入数据库的时间是昨天的,是不是因为生成Mybatis逆向工程生成的代码有问题?


大家都知道,对于这类Bug本人是很感兴趣的。直觉告诉我,应该不是Mybatis的Bug,很可能是时区的问题。


很好,今天又可以带大家一起来排查Bug了,看看从这次的Bug排查中你能Get什么技能。


这次研究的问题有点深奥,但结论很重要。Let’s go!


问题猜想

同事反馈问题的时候,带了自己的猜想:是不是数据库字段设置为datetime导致?是不是Mybatis逆向工程生成的代码中类型不一致导致的?


同事还要把datetime改为varchar……马上被我制止了,说:先排查问题,再说解决方案,下午我也抽时间看看。


问题核查

第一步,检查数据库字段类型,是datetime的,没问题。


第二步,检查实体类中类型,是java.util.Date类型,没问题。


第三步,Bug复现。


在Bug复现这一步,用到了单元测试。话说之前还跟朋友讨论过单元测试的魅力,现在本人是越来越喜欢单元测试了。


项目基于Spring Boot的,单元测试如下(代码已脱敏):


@SpringBootTest
class DateTimeTests {
  @Resource
  private UserMapper userMapper;
  @Test
  public void testDate(){
    User  user = new User();
    // 省略其他字段
    user.setCreateDate(new Date());
    userMapper.insertSelective(user);
  }
}

执行单元测试,查看数据库中插入的数据。Bug复现,时间的确是前一天的,与当前时间相差14个小时。


经过上面三步的排查,核实了数据库字段和代码中类型没问题。单元测试也复现了问题,同事没有欺骗我,总要眼见为实,哈哈~


于是基本确定是时区问题。


时区排查

检查服务器时间

登录测试服务器,执行date命令,检查服务器时间和时区:


[root@xxx ~]# date

2021年 11月 25日 星期四 09:26:25 CST

[root@xxx ~]# date -R

Thu, 25 Nov 2021 09:33:34 +0800

1

2

3

4

显示时间是当前时间,采用CST时间,最后的+0800,即东8区,没问题。


检查数据库时区

连接数据库,执行show命令:


show variables like '%time_zone%';
+----------------------------+
|Variable         | Value |
+----------------------------+
|system_time_zone |CST    |
|time_zone        |SYSTEM |

system_time_zone:全局参数,系统时区,在MySQL启动时会检查当前系统的时区并根据系统时区设置全局参数system_time_zone的值。值为CST,与系统时间的时区一致。


time_zone:全局参数,设置每个连接会话的时区,默认为SYSTEM,使用全局参数system_time_zone的值。


检查代码中时区

在单元测试的方法内再添加打印时区的代码:


@Test

public void testDate(){

 System.out.println(System.getProperty("user.timezone"));

 User  user = new User();

 // 省略其他字段

 user.setCreateDate(new Date());

 userMapper.insertSelective(user);

}

1

2

3

4

5

6

7

8

打印的时区为:


Asia/Shanghai

1

也就是说Java中使用的是UTC时区进行业务逻辑处理的,也是东八区的时间。


那么问题到底出在哪里呢?


问题基本呈现

经过上述排查,基本上确定是时区的问题。这里,再补充一下上述相关的时区知识点。


UTC时间

UTC时间:世界协调时间(UTC)是世界上不同国家用来调节时钟和时间的主要时间标准,也就是零时区的时间。


UTC, Coordinated Universal Time是一个标准,而不是一个时区。UTC 是一个全球通用的时间标准。全球各地都同意将各自的时间进行同步协调 (coordinated),这也是UTC名字的来源:Universal Coordinated Time。


CST时间

CST时间:中央标准时间。


CST可以代表如下4个不同的时区:


Central Standard Time (USA) UT-6:00,美国

Central Standard Time (Australia) UT+9:30,澳大利亚

China Standard Time UT+8:00,中国

Cuba Standard Time UT-4:00,古巴

再次分析

很显然,这里与UTC时间无关,它只是时间标准。目前Mysql中的system_time_zone是CST,而CST可以代表4个不同的时区,那么,Mysql把它当做哪个时区进行处理了呢?


简单推算一下,中国时间是UT+8:00,美国是 UT-6:00,当传入中国时间,直接转换为美国时间(未考虑时区问题),时间便慢了14个小时。


既然知道了问题,那么解决方案也就有了。


解决方案

针对上述问题可通过数据库层面和代码层面进行解决。


方案一:修改数据库时区

既然是Mysql理解错了CST指定的时区,那么就将其设置为正确的。


连接Mysql数据库,设置正确的时区:


[root@xxxxx ~]# mysql -uroot -p

mysql> set global time_zone = '+8:00';

mysql> set time_zone = '+8:00'

mysql> flush privileges;

1

2

3

4

再次执行show命令:


show variables like '%time_zone%';


+----------------------------+

|Variable         | Value |

+----------------------------+

|system_time_zone |CST    |

|time_zone       |+08:00 |

1

2

3

4

5

6

7

可以看到时区已经成为东八区的时间了。再次执行单元测试,问题得到解决。


此种方案也可以直接修改MySQL的my.cnf文件进行指定时区。


方案二:修改数据库连接参数

在代码连接数据库时,通过参数指定所使用的时区。


在配置数据库连接的URL后面添加上指定的时区serverTimezone=Asia/Shanghai:


url: jdbc:mysql://xx.xx.xx.xx:3306/db_name?useUnicode=true&characterEncoding=utf8&autoReconnect=true&serverTimezone=Asia/Shanghai

1

再次执行单元测试,问题同样可以得到解决。


问题完了?

经过上述分析与操作,时区的问题已经解决了。问题就这么完事了吗?为什么是这样呢?


为了验证时区问题,在时区错误的数据库中,创建了一个字段,该字段类型为datetime,默认值为CURRENT_TIMESTAMP。


那么,此时插入一条记录,让Mysql自动生成该字段的时间,你猜该字段的时间是什么?中国时间。


神奇不?为什么同样是CST时区,系统自动生成的时间是正确的,而代码插入的时间就有时差问题呢?


到底是Mysql将CST时区理解为美国时间了,还是Mybatis、连接池或驱动程序将其理解为美国时间了?


重头戏开始

为了追查到底是代码中哪里出了问题,先开启Mybatis的debug日志,看看insert时是什么值:


2021-11-25 11:05:28.367 [|1637809527983|] DEBUG 20178 --- [   scheduling-1] c.h.s.m.H.listByCondition                : ==> Parameters: 2021-11-25 11:05:27(String), 0(Integer), 1(Integer), 2(Integer), 3(Integer), 4(Integer)

1

上面是insert时的参数,也就是说在Mybatis层面时间是没问题的。排除一个。


那是不是连接池或驱动程序的问题?连接池本身来讲跟数据库连接的具体操作关系不大,就直接来排查驱动程序。


Mybatis是xml中定义日期字段类型为TIMESTAMP,扒了一下mysql-connector-Java-8.0.x的源码,发现SqlTimestampValueFactory是用来处理TIMESTAMP类型的。


在SqlTimestampValueFactory的构造方法上打上断点,执行单元测试:


image.png可以明确的看到,Calendar将时区设置为Locale.US,也就是美国时间,时区为CST,offset为-21600000。-21600000单位为毫秒,转化为小时,恰好是“-6:00”,这与北京时间“GMT+08:00”恰好相差14个小时。


于是一路往上最终追溯调用链路,该TimeZone来自NativeServerSession的serverTimeZone,而serverTimeZone的值是由NativeProtocol类的configureTimezone方法设置的。


public void configureTimezone() {
        String configuredTimeZoneOnServer = this.serverSession.getServerVariable("time_zone");
        if ("SYSTEM".equalsIgnoreCase(configuredTimeZoneOnServer)) {
            configuredTimeZoneOnServer = this.serverSession.getServerVariable("system_time_zone");
        }
        String canonicalTimezone = getPropertySet().getStringProperty(PropertyKey.serverTimezone).getValue();
        if (configuredTimeZoneOnServer != null) {
            // user can override this with driver properties, so don't detect if that's the case
            if (canonicalTimezone == null || StringUtils.isEmptyOrWhitespaceOnly(canonicalTimezone)) {
                try {
                    canonicalTimezone = TimeUtil.getCanonicalTimezone(configuredTimeZoneOnServer, getExceptionInterceptor());
                } catch (IllegalArgumentException iae) {
                    throw ExceptionFactory.createException(WrongArgumentException.class, iae.getMessage(), getExceptionInterceptor());
                }
            }
        }
        if (canonicalTimezone != null && canonicalTimezone.length() > 0) {
          // 此处设置TimeZone
            this.serverSession.setServerTimeZone(TimeZone.getTimeZone(canonicalTimezone));
            if (!canonicalTimezone.equalsIgnoreCase("GMT") && this.serverSession.getServerTimeZone().getID().equals("GMT")) {
                throw ExceptionFactory.createException(WrongArgumentException.class, Messages.getString("Connection.9", new Object[] { canonicalTimezone }),
                        getExceptionInterceptor());
            }
        }
    }

debug跟踪一下上述代码,显示信息如下:

image.png至此,通过canonicalTimezone值的获取,可以看出URL后面配置serverTimezone=Asia/Shanghai的作用了。其中,上面第一个代码块获取time_zone的值,第二个代码块中获取system_time_zone的值。这与查询数据库获得的值一致。


因为出问题时并未在url中添加参数serverTimezone=Asia/Shanghai,所以走canonicalTimezone为null的情况。随后逻辑中调用了TimeUtil.getCanonicalTimezone方法:


public static String getCanonicalTimezone(String timezoneStr, ExceptionInterceptor exceptionInterceptor) {
        if (timezoneStr == null) {
            return null;
        }
        timezoneStr = timezoneStr.trim();
        // handle '+/-hh:mm' form ...
        if (timezoneStr.length() > 2) {
            if ((timezoneStr.charAt(0) == '+' || timezoneStr.charAt(0) == '-') && Character.isDigit(timezoneStr.charAt(1))) {
                return "GMT" + timezoneStr;
            }
        }
        synchronized (TimeUtil.class) {
            if (timeZoneMappings == null) {
                loadTimeZoneMappings(exceptionInterceptor);
            }
        }
        String canonicalTz;
        if ((canonicalTz = timeZoneMappings.getProperty(timezoneStr)) != null) {
            return canonicalTz;
        }
        throw ExceptionFactory.createException(InvalidConnectionAttributeException.class,
                Messages.getString("TimeUtil.UnrecognizedTimezoneId", new Object[] { timezoneStr }), exceptionInterceptor);
    }

上述代码中最终走到了loadTimeZoneMappings(exceptionInterceptor);方法:

private static void loadTimeZoneMappings(ExceptionInterceptor exceptionInterceptor) {
        timeZoneMappings = new Properties();
        try {
            timeZoneMappings.load(TimeUtil.class.getResourceAsStream(TIME_ZONE_MAPPINGS_RESOURCE));
        } catch (IOException e) {
            throw ExceptionFactory.createException(Messages.getString("TimeUtil.LoadTimeZoneMappingError"), exceptionInterceptor);
        }
        // bridge all Time Zone ids known by Java
        for (String tz : TimeZone.getAvailableIDs()) {
            if (!timeZoneMappings.containsKey(tz)) {
                timeZoneMappings.put(tz, tz);
            }
        }
    }

该方法加载了配置文件"/com/mysql/cj/util/TimeZoneMapping.properties"里面的值,经过转换,timeZoneMappings中,对应CST的为"CST"。


最终得到canonicalTimezone为“CST”,而TimeZone获得是通过TimeZone.getTimeZone(canonicalTimezone)方法获得的。


也就是说TimeZone.getTimeZone(“CST”)的值为美国时间。写个单元测试验证一下:


public class TimeZoneTest {


@Test

public void testTimeZone(){

 System.out.println(TimeZone.getTimeZone("CST"));

}

}

1

2

3

4

5

6

7

打印结果:


sun.util.calendar.ZoneInfo[id="CST",offset=-21600000,dstSavings=3600000,useDaylight=true,transitions=235,lastRule=java.util.SimpleTimeZone[id=CST,offset=-21600000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=2,startDay=8,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=3,endMonth=10,endDay=1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]]

1

很显然,该方法传入CST之后,默认是美国时间。


至此,问题原因基本明朗:


Mysql中设置的server_time_zone为CST,time_zone为SYSTEM。

Mysql驱动查询到time_zone为SYSTEM,于是使用server_time_zone的值,为”CST“。

JDK中TimeZone.getTimeZone(“CST”)获得的值为美国时区;

以美国时区构造的Calendar类;

SqlTimestampValueFactory使用上述Calendar来格式化系统获取的中国时间,时差问题便出现了;

最终反映在数据库数据上就是错误的时间。

serverVariables变量

再延伸一下,其中server_time_zone和time_zone都来自于NativeServerSession的serverVariables变量,该变量在NativeSession的loadServerVariables方法中进行初始化,关键代码:


if (versionMeetsMinimum(5, 1, 0)) {
                StringBuilder queryBuf = new StringBuilder(versionComment).append("SELECT");
                queryBuf.append("  @@session.auto_increment_increment AS auto_increment_increment");
                queryBuf.append(", @@character_set_client AS character_set_client");
                queryBuf.append(", @@character_set_connection AS character_set_connection");
                queryBuf.append(", @@character_set_results AS character_set_results");
                queryBuf.append(", @@character_set_server AS character_set_server");
                queryBuf.append(", @@collation_server AS collation_server");
                queryBuf.append(", @@collation_connection AS collation_connection");
                queryBuf.append(", @@init_connect AS init_connect");
                queryBuf.append(", @@interactive_timeout AS interactive_timeout");
                if (!versionMeetsMinimum(5, 5, 0)) {
                    queryBuf.append(", @@language AS language");
                }
                queryBuf.append(", @@license AS license");
                queryBuf.append(", @@lower_case_table_names AS lower_case_table_names");
                queryBuf.append(", @@max_allowed_packet AS max_allowed_packet");
                queryBuf.append(", @@net_write_timeout AS net_write_timeout");
                queryBuf.append(", @@performance_schema AS performance_schema");
                if (!versionMeetsMinimum(8, 0, 3)) {
                    queryBuf.append(", @@query_cache_size AS query_cache_size");
                    queryBuf.append(", @@query_cache_type AS query_cache_type");
                }
                queryBuf.append(", @@sql_mode AS sql_mode");
                queryBuf.append(", @@system_time_zone AS system_time_zone");
                queryBuf.append(", @@time_zone AS time_zone");
                if (versionMeetsMinimum(8, 0, 3) || (versionMeetsMinimum(5, 7, 20) && !versionMeetsMinimum(8, 0, 0))) {
                    queryBuf.append(", @@transaction_isolation AS transaction_isolation");
                } else {
                    queryBuf.append(", @@tx_isolation AS transaction_isolation");
                }
                queryBuf.append(", @@wait_timeout AS wait_timeout");
                NativePacketPayload resultPacket = sendCommand(this.commandBuilder.buildComQuery(null, queryBuf.toString()), false, 0);
                Resultset rs = ((NativeProtocol) this.protocol).readAllResults(-1, false, resultPacket, false, null,
                        new ResultsetFactory(Type.FORWARD_ONLY, null));
                Field[] f = rs.getColumnDefinition().getFields();
                if (f.length > 0) {
                    ValueFactory<String> vf = new StringValueFactory(this.propertySet);
                    Row r;
                    if ((r = rs.getRows().next()) != null) {
                        for (int i = 0; i < f.length; i++) {
                            this.protocol.getServerSession().getServerVariables().put(f[i].getColumnLabel(), r.getValue(i, vf));
                        }
                    }
                }

在上述StringBuilder的append操作中,有"@@time_zone AS time_zone"和"@@system_time_zone AS system_time_zone"两个值,然后查询数据库,从数据库获得值之后,put到serverVariables中。


再来debug一下:


image.png可以看出system_time_zone的值为CST。

image.png同样time_zone的值为“SYSTEM”。


根据代码中的提示,拼接与代码一样的SQL查询一下数据库:


select @@time_zone;

SYSTEM

1

2

值的确是“SYSTEM”。此时,我们又得出另外一个查询Mysql当前时区的方法。


至此,该问题的排查完美收官。大出一口气~~~


小结

在上述问题排查的过程中,多次用到单元测试,这也是单元测试的魅力所在,用最简单的代码,最轻量的逻辑,最节省时间的方式来验证和追踪错误。


再回顾一下上述Bug排查中用到和学到的知识点:


Linux日期查看,时区查看及衍生如何配置时区;

Mysql时区查看;

Spring Boot单元测试;

Java时区获取;

UTC时间和CST时间;

两种解决时区问题的方案;

阅读、debug Mysql驱动源代码;

TimeZone.getTimeZone(“CST”)默认时区为美国时区;

Mysql驱动中处理时区问题基本流程逻辑;

Mybatis debug日志相关打印;

其他相关知识。

通过本篇Bug查找的文章,你学到了什么?如果有那么一点启发,不要吝啬,给点个赞吧!



相关实践学习
如何在云端创建MySQL数据库
开始实验后,系统会自动创建一台自建MySQL的 源数据库 ECS 实例和一台 目标数据库 RDS。
全面了解阿里云能为你做什么
阿里云在全球各地部署高效节能的绿色数据中心,利用清洁计算为万物互联的新世界提供源源不断的能源动力,目前开服的区域包括中国(华北、华东、华南、香港)、新加坡、美国(美东、美西)、欧洲、中东、澳大利亚、日本。目前阿里云的产品涵盖弹性计算、数据库、存储与CDN、分析与搜索、云通信、网络、管理与监控、应用服务、互联网中间件、移动服务、视频服务等。通过本课程,来了解阿里云能够为你的业务带来哪些帮助 &nbsp; &nbsp; 相关的阿里云产品:云服务器ECS 云服务器 ECS(Elastic Compute Service)是一种弹性可伸缩的计算服务,助您降低 IT 成本,提升运维效率,使您更专注于核心业务创新。产品详情: https://www.aliyun.com/product/ecs
目录
相关文章
|
3月前
|
SQL 关系型数据库 MySQL
【MySQL 慢查询秘籍】慢SQL无处遁形!实战指南:一步步教你揪出数据库性能杀手!
【8月更文挑战第24天】本文以教程形式深入探讨了MySQL慢SQL查询的分析与优化方法。首先介绍了如何配置MySQL以记录执行时间过长的SQL语句。接着,利用内置工具`mysqlslowlog`及第三方工具`pt-query-digest`对慢查询日志进行了详细分析。通过一个具体示例展示了可能导致性能瓶颈的查询,并提出了相应的优化策略,包括添加索引、缩小查询范围、使用`EXPLAIN`分析执行计划等。掌握这些技巧对于提升MySQL数据库性能具有重要意义。
267 1
|
3月前
|
数据库 关系型数据库 MySQL
惊!Hibernate与MySQL的绝密优化技巧大揭秘,让你的数据库飞起来!
【8月更文挑战第31天】在企业应用开发中,结合使用持久层框架Hibernate与数据库管理系统MySQL可显著提升数据库交互效率。本文探讨了多项优化策略,包括配置二级缓存、采用单向关联减少JOIN操作、优化HQL查询语句以及合理使用MySQL索引。通过具体示例,文章详细讲解了如何实施这些优化措施,以期为企业应用提供更高效稳定的数据支持。
58 0
|
3月前
|
SQL 监控 关系型数据库
"SQL性能瓶颈大揭秘:一步步教你揪出慢查询元凶,从根源解决数据库拖沓问题,让应用速度飞起来!"
【8月更文挑战第31天】作为一名数据库管理员或开发者,面对复杂系统时,运行缓慢的SQL查询常常令人头疼。本文将指导你如何诊断并解决这些问题。首先,通过性能监控工具识别出问题查询;其次,利用`EXPLAIN`分析其执行计划,了解索引使用情况;接着,优化查询语句,如使用合适索引、减少JOIN操作等;再者,优化数据库设计,采用分区表或调整硬件资源;最后,持续监控性能并调优。通过这些步骤,可有效提升数据库的整体性能。
65 0
|
6月前
|
存储 SQL 关系型数据库
【周末闲谈】关于“数据库”你又知道多少?
【周末闲谈】关于“数据库”你又知道多少?
116 0
|
关系型数据库 MySQL Java
为了把MySQL分库分表:MyCAT学明白,我花了近一个月的时间!
MySQL分库分表:MyCAT-问题描述 随着数据库存储的内容越来越多,MySQL主从复制也开始无法存储更多的数据,此时就需要切割表,把一张过大的表切割后分别存储在不同的MySQL中,以便存储更多的内容,承载更多的用户。此阶段出现的典型问题如下: (1)随着互联网的发展,数据的量级也呈指数级增长,从GB到TB再到PB。对数据的各种操作也愈加困难,传统的关系数据库已经无法满足快速查询与插入数据的需求。如何使单表数据量存储更大?甚至期望单表数据量可以“无限扩大”。 (2)MySQL本身是不支持读写分离的,MySQL只支持主从数据复制,读写功能需要重新开发,。有没有一种办法可以不用一次次重写这部
|
SQL 移动开发 关系型数据库
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(五)
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!
198 0
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(五)
|
关系型数据库 MySQL
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(七)
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!
128 0
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(七)
|
关系型数据库 MySQL Unix
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(四)
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(四)
129 0
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(四)
|
SQL 存储 关系型数据库
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(二)
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!
152 0
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(二)
|
关系型数据库 MySQL
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(六)
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!
116 0
半个月时间把MySQL重新巩固了一遍,梳理了一篇几万字 “超硬核” 文章!(六)