[[436824]]

本文轉載自微信公眾號「程序新視界」，作者二師兄。轉載本文請聯系程序新視界公眾號。

同事反饋一個問題：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來格式化系統獲取的中國時間，時差問題便出現了;
• 最終反映在數據庫數據上就是錯誤的時間。

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一下：

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查找的文章，你學到了什么?如果有那么一點啟發，不要吝嗇，給點個贊吧!