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

运维 数据库运维
大家都知道,对于这类Bug本人是很感兴趣的。直觉告诉我,应该不是Mybatis的Bug,很可能是时区的问题。很好,今天又可以带大家一起来排查Bug了,看看从这次的Bug排查中你能Get什么技能。

[[436824]]

本文转载自微信公众号「程序新视界」,作者二师兄。转载本文请联系程序新视界公众号。

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

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

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

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

问题猜想

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

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

问题核查

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

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

第三步,Bug复现。

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

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

  1. @SpringBootTest 
  2. class DateTimeTests { 
  3.  
  4.  @Resource 
  5.  private UserMapper userMapper; 
  6.  
  7.  @Test 
  8.  public void testDate(){ 
  9.   User  user = new User(); 
  10.   // 省略其他字段 
  11.   user.setCreateDate(new Date()); 
  12.   userMapper.insertSelective(user); 
  13.  } 

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

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

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

时区排查

检查服务器时间

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

  1. [root@xxx ~]# date 
  2. 2021年 11月 25日 星期四 09:26:25 CST 
  3. [root@xxx ~]# date -R 
  4. Thu, 25 Nov 2021 09:33:34 +0800 

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

检查数据库时区

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

  1. show variables like '%time_zone%'
  2.  
  3. +----------------------------+ 
  4. |Variable         | Value | 
  5. +----------------------------+ 
  6. |system_time_zone |CST    | 
  7. |time_zone       |SYSTEM | 
  • system_time_zone:全局参数,系统时区,在MySQL启动时会检查当前系统的时区并根据系统时区设置全局参数system_time_zone的值。值为CST,与系统时间的时区一致。
  • time_zone:全局参数,设置每个连接会话的时区,默认为SYSTEM,使用全局参数system_time_zone的值。

检查代码中时区

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

  1. @Test 
  2.  public void testDate(){ 
  3.   System.out.println(System.getProperty("user.timezone")); 
  4.   User  user = new User(); 
  5.   // 省略其他字段 
  6.   user.setCreateDate(new Date()); 
  7.   userMapper.insertSelective(user); 
  8.  } 

打印的时区为:

  1. Asia/Shanghai 

也就是说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数据库,设置正确的时区:

  1. [root@xxxxx ~]# mysql -uroot -p 
  2.  
  3. mysql> set global time_zone = '+8:00'
  4.  
  5. mysql> set time_zone = '+8:00' 
  6.  
  7. mysql> flush privileges

再次执行show命令:

  1. show variables like '%time_zone%'
  2.  
  3. +----------------------------+ 
  4. |Variable         | Value | 
  5. +----------------------------+ 
  6. |system_time_zone |CST    | 
  7. |time_zone       |+08:00 | 

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

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

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

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

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

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

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

问题完了?

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

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

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

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

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

重头戏开始

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

  1. 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) 

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

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

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

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

timezone

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

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

  1. public void configureTimezone() { 
  2.         String configuredTimeZoneOnServer = this.serverSession.getServerVariable("time_zone"); 
  3.  
  4.         if ("SYSTEM".equalsIgnoreCase(configuredTimeZoneOnServer)) { 
  5.             configuredTimeZoneOnServer = this.serverSession.getServerVariable("system_time_zone"); 
  6.         } 
  7.  
  8.         String canonicalTimezone = getPropertySet().getStringProperty(PropertyKey.serverTimezone).getValue(); 
  9.  
  10.         if (configuredTimeZoneOnServer != null) { 
  11.             // user can override this with driver properties, so don't detect if that's the case 
  12.             if (canonicalTimezone == null || StringUtils.isEmptyOrWhitespaceOnly(canonicalTimezone)) { 
  13.                 try { 
  14.                     canonicalTimezone = TimeUtil.getCanonicalTimezone(configuredTimeZoneOnServer, getExceptionInterceptor()); 
  15.                 } catch (IllegalArgumentException iae) { 
  16.                     throw ExceptionFactory.createException(WrongArgumentException.class, iae.getMessage(), getExceptionInterceptor()); 
  17.                 } 
  18.             } 
  19.         } 
  20.  
  21.         if (canonicalTimezone != null && canonicalTimezone.length() > 0) { 
  22.          // 此处设置TimeZone 
  23.             this.serverSession.setServerTimeZone(TimeZone.getTimeZone(canonicalTimezone)); 
  24.  
  25.             if (!canonicalTimezone.equalsIgnoreCase("GMT") && this.serverSession.getServerTimeZone().getID().equals("GMT")) { 
  26.                 throw ExceptionFactory.createException(WrongArgumentException.class, Messages.getString("Connection.9", new Object[] { canonicalTimezone }), 
  27.                         getExceptionInterceptor()); 
  28.             } 
  29.         } 
  30.  
  31.     } 

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

CST获得

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

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

  1. public static String getCanonicalTimezone(String timezoneStr, ExceptionInterceptor exceptionInterceptor) { 
  2.         if (timezoneStr == null) { 
  3.             return null
  4.         } 
  5.  
  6.         timezoneStr = timezoneStr.trim(); 
  7.  
  8.         // handle '+/-hh:mm' form ... 
  9.         if (timezoneStr.length() > 2) { 
  10.             if ((timezoneStr.charAt(0) == '+' || timezoneStr.charAt(0) == '-') && Character.isDigit(timezoneStr.charAt(1))) { 
  11.                 return "GMT" + timezoneStr; 
  12.             } 
  13.         } 
  14.  
  15.         synchronized (TimeUtil.class) { 
  16.             if (timeZoneMappings == null) { 
  17.                 loadTimeZoneMappings(exceptionInterceptor); 
  18.             } 
  19.         } 
  20.  
  21.         String canonicalTz; 
  22.         if ((canonicalTz = timeZoneMappings.getProperty(timezoneStr)) != null) { 
  23.             return canonicalTz; 
  24.         } 
  25.  
  26.         throw ExceptionFactory.createException(InvalidConnectionAttributeException.class, 
  27.                 Messages.getString("TimeUtil.UnrecognizedTimezoneId", new Object[] { timezoneStr }), exceptionInterceptor); 
  28.     } 

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

  1. private static void loadTimeZoneMappings(ExceptionInterceptor exceptionInterceptor) { 
  2.         timeZoneMappings = new Properties(); 
  3.         try { 
  4.             timeZoneMappings.load(TimeUtil.class.getResourceAsStream(TIME_ZONE_MAPPINGS_RESOURCE)); 
  5.         } catch (IOException e) { 
  6.             throw ExceptionFactory.createException(Messages.getString("TimeUtil.LoadTimeZoneMappingError"), exceptionInterceptor); 
  7.         } 
  8.         // bridge all Time Zone ids known by Java 
  9.         for (String tz : TimeZone.getAvailableIDs()) { 
  10.             if (!timeZoneMappings.containsKey(tz)) { 
  11.                 timeZoneMappings.put(tz, tz); 
  12.             } 
  13.         } 
  14.     } 

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

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

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

  1. public class TimeZoneTest { 
  2.  
  3.  @Test 
  4.  public void testTimeZone(){ 
  5.   System.out.println(TimeZone.getTimeZone("CST")); 
  6.  } 

打印结果:

  1. 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]] 

很显然,该方法传入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方法中进行初始化,关键代码:

  1. if (versionMeetsMinimum(5, 1, 0)) { 
  2.                 StringBuilder queryBuf = new StringBuilder(versionComment).append("SELECT"); 
  3.                 queryBuf.append("  @@session.auto_increment_increment AS auto_increment_increment"); 
  4.                 queryBuf.append(", @@character_set_client AS character_set_client"); 
  5.                 queryBuf.append(", @@character_set_connection AS character_set_connection"); 
  6.                 queryBuf.append(", @@character_set_results AS character_set_results"); 
  7.                 queryBuf.append(", @@character_set_server AS character_set_server"); 
  8.                 queryBuf.append(", @@collation_server AS collation_server"); 
  9.                 queryBuf.append(", @@collation_connection AS collation_connection"); 
  10.                 queryBuf.append(", @@init_connect AS init_connect"); 
  11.                 queryBuf.append(", @@interactive_timeout AS interactive_timeout"); 
  12.                 if (!versionMeetsMinimum(5, 5, 0)) { 
  13.                     queryBuf.append(", @@language AS language"); 
  14.                 } 
  15.                 queryBuf.append(", @@license AS license"); 
  16.                 queryBuf.append(", @@lower_case_table_names AS lower_case_table_names"); 
  17.                 queryBuf.append(", @@max_allowed_packet AS max_allowed_packet"); 
  18.                 queryBuf.append(", @@net_write_timeout AS net_write_timeout"); 
  19.                 queryBuf.append(", @@performance_schema AS performance_schema"); 
  20.                 if (!versionMeetsMinimum(8, 0, 3)) { 
  21.                     queryBuf.append(", @@query_cache_size AS query_cache_size"); 
  22.                     queryBuf.append(", @@query_cache_type AS query_cache_type"); 
  23.                 } 
  24.                 queryBuf.append(", @@sql_mode AS sql_mode"); 
  25.                 queryBuf.append(", @@system_time_zone AS system_time_zone"); 
  26.                 queryBuf.append(", @@time_zone AS time_zone"); 
  27.                 if (versionMeetsMinimum(8, 0, 3) || (versionMeetsMinimum(5, 7, 20) && !versionMeetsMinimum(8, 0, 0))) { 
  28.                     queryBuf.append(", @@transaction_isolation AS transaction_isolation"); 
  29.                 } else { 
  30.                     queryBuf.append(", @@tx_isolation AS transaction_isolation"); 
  31.                 } 
  32.                 queryBuf.append(", @@wait_timeout AS wait_timeout"); 
  33.  
  34.                 NativePacketPayload resultPacket = sendCommand(this.commandBuilder.buildComQuery(null, queryBuf.toString()), false, 0); 
  35.                 Resultset rs = ((NativeProtocol) this.protocol).readAllResults(-1, false, resultPacket, falsenull
  36.                         new ResultsetFactory(Type.FORWARD_ONLY, null)); 
  37.                 Field[] f = rs.getColumnDefinition().getFields(); 
  38.                 if (f.length > 0) { 
  39.                     ValueFactory<String> vf = new StringValueFactory(this.propertySet); 
  40.                     Row r; 
  41.                     if ((r = rs.getRows().next()) != null) { 
  42.                         for (int i = 0; i < f.length; i++) { 
  43.                             this.protocol.getServerSession().getServerVariables().put(f[i].getColumnLabel(), r.getValue(i, vf)); 
  44.                         } 
  45.                     } 
  46.                 } 

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

再来debug一下:

system_time_zone

可以看出system_time_zone的值为CST。

time_zone

同样time_zone的值为“SYSTEM”。

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

  1. select @@time_zone; 
  2.  
  3. SYSTEM 

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

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

小结

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

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

  • Linux日期查看,时区查看及衍生如何配置时区;
  • Mysql时区查看;
  • Spring Boot单元测试;
  • Java时区获取;
  • UTC时间和CST时间;
  • 两种解决时区问题的方案;
  • 阅读、debug Mysql驱动源代码;
  • TimeZone.getTimeZone("CST")默认时区为美国时区;
  • Mysql驱动中处理时区问题基本流程逻辑;
  • Mybatis debug日志相关打印;
  • 其他相关知识。 

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

 

责任编辑:武晓燕 来源: 程序新视界
相关推荐

2017-09-12 16:18:22

ICO区块链互联网+

2019-06-03 14:38:11

AWS挖掘机光缆

2020-02-20 16:21:46

远程办公

2015-12-09 13:51:21

Intelskylake散热器

2021-04-13 17:38:38

区块链比特币安全

2018-10-19 16:35:20

运维

2018-05-08 09:49:15

数据库运维优化

2018-05-02 14:30:33

数据库运维优化故障

2019-12-03 13:57:38

CIO背锅IT

2019-01-16 18:11:28

程序员技能开发者

2017-08-23 17:11:40

WI-FI流量路由器

2021-04-16 09:20:34

黑客DDoS网络攻击

2019-12-17 10:01:40

开发技能代码

2023-04-26 07:16:25

游戏掉帧CPU

2017-06-09 13:36:33

人工智能深度学习

2017-09-25 10:52:27

2021-11-03 16:25:26

Linux磁盘空间命令

2020-12-09 11:00:44

Nginx 运维Tomcat

2009-07-06 08:36:28

NoSQL关系数据库

2017-02-06 11:28:01

路由器WIFI无线网络
点赞
收藏

51CTO技术栈公众号