mybatis 缓存机制（数据库时间慢了14个小时）
mybatis 缓存机制（数据库时间慢了14个小时）第二步，检查实体类中类型，是java.util.Date类型，没问题。第一步，检查数据库字段类型，是datetime的，没问题。这次研究的问题有点深奥，但结论很重要。Let's go!同事反馈问题的时候，带了自己的猜想：是不是数据库字段设置为datetime导致？是不是Mybatis逆向工程生成的代码中类型不一致导致的？同时还要把datetime改为varchar……马上被我制止了，说：先排查问题，再说解决方案，下午我也抽时间看看。
原文链接：https://mp.weixin.qq.com/s/nMzEuBOaRbc4xiMuu-pIkg
同事反馈一个问题：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
显示时间是当前时间，采用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);
}
打印的时区为：
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数据库，设置正确的时区：
[root@xxxxx ~]# mysql -uroot -p
mysql> set global time_zone = ' 8:00';
mysql> set time_zone = ' 8:00'
mysql> flush privileges;
再次执行show命令：
show variables like '%time_zone%';
----------------------------
|Variable | Value |
----------------------------
|system_time_zone |CST |
|time_zone | 08:00 |
可以看到市区已经成为东八区的时间了。再次执行单元测试，问题得到解决。
此种方案也可以直接修改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
再次执行单元测试，问题同样可以得到解决。
问题完了？经过上述分析与操作，时区的问题已经解决了。问题就这么完事了吗？为什么是这样呢？
为了验证时区问题，在时区错误的数据库中，创建了一个字段，该字段类型为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)
上面是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方法设置的。
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跟踪一下上述代码，显示信息如下：
CST获得
至此，通过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"));
}
}
打印结果：
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来格式化系统获取的中国时间，时差问题便出现了；
- 最终反映在数据库数据上就是错误的时间。
再延伸一下，其中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一下：
system_time_zone
可以看出system_time_zone的值为CST。
time_zone
同样time_zone的值为“SYSTEM”。
根据代码中的提示，拼接与代码一样的SQL查询一下数据库：
select @@time_zone;
SYSTEM
值的确是“SYSTEM”。此时，我们又得出另外一个查询Mysql当前时区的方法。
至此，该问题的排查完美收官。大出一口气~~~
小结在上述问题排查的过程中，多次用到单元测试，这也是单元测试的魅力所在，用最简单的代码，最轻量的逻辑，最节省时间的方式来验证和追踪错误。
再回顾一下上述Bug排查中用到和学到的知识点：
- Linux日期查看，时区查看及衍生如何配置时区；
- Mysql时区查看；
- Spring Boot单元测试；
- Java时区获取；
- UTC时间和CST时间；
- 两种解决时区问题的方案；
- 阅读、debug Mysql驱动源代码；
- TimeZone.getTimeZone("CST")默认时区为美国时区；
- Mysql驱动中处理时区问题基本流程逻辑；
- Mybatis debug日志相关打印；
- 其他相关知识。
通过本篇Bug查找的文章，你学到了什么？如果有那么一点启发，不要吝啬，给点个赞吧！
