【曹工雜談】Mysql客戶端上,時間為啥和本地差了整整13個小時,就離譜

三國夢迴發表於2021-06-21

瞎扯一點非技術

本來今天上午就打算寫的,結果中途被別的事吸引了注意力,公司和某保險公司合作推了一個醫療保險,讓我們給父母買,然後我研究了半天條款;又想起來之前買的支付寶那個好醫保,也買了兩年多了,但是條款也不怎麼懂,查了下,感覺坑不少,都做好了理賠時撕逼的打算了。

研究了公司的保險後,還是決定把支付寶那個玩意給退了。尤其是健康告知那一句:最近兩年內有住院行為的,就算是不滿足健康告知。

我還打電話問了我爸媽,他們也不記得幾年前到底住沒住過院了,反正我個人感覺心裡沒底。下午找支付寶,客服都半天找不到。

大家也可以多注意下。

背景

我負責的一個後臺服務,負責接收客戶端請求,同時寫庫。比如,建立一個任務,在程式碼裡建立時間是直接new Date,然後寫入資料庫。然後,我用我的客戶端軟體去看那個建立時間的時候,是差了13個小時的。

當然了,客戶端軟體看著差了13個小時,但是我web介面上檢視,是沒啥問題的。

比如,我現在時間是21:02分,我在介面上建立了一個任務,然後我用的mysql客戶端sqlyog去檢視任務的建立時間:

Ftask_id  Fcreate_time         
--------  ---------------------
    4121  2021-06-19 08:02:36  

咦,怎麼是8點呢,和現在比,差了21 - 8 = 13個小時。

這個時區問題,一般還是和mysql的一些variable相關的,比如,我們這麼查了一下,

SHOW VARIABLES LIKE '%zone%'

結果如下:

Variable_name     Value   
----------------  --------
system_time_zone  CST     
time_zone         SYSTEM  

這個cst、system,雖然不懂,但感覺就是有點問題,這時候去某度某歌查一下,基本改改就解決了。

但是,這個mysql例項上,不止我們一個資料庫,上面有幾十個庫,我這也不敢直接改資料庫配置,萬一有人專門這麼配置的呢?

然後我問了下同事,他在這個例項上也有一個其他的資料庫,但是比較奇怪的是,他在程式裡new Date,寫進來的時間,是對的。

大家都是一個組的,都是同樣的mybatis框架,不至於你可以,我不可以。

我決定,找找原因。

當然了,這麼明顯的bug,之前沒發現?那倒不是,我web介面上查出來,是對的。

雖然只是有點噁心人(mysql客戶端看到的時間差了13小時,web前端沒問題),但還是不能繼續忍了。

mysql server錯 or sqlyog客戶端錯

sqlyog在本機,mysql server在遠端,我們可以wireshark抓包,看看mysql返回的,是不是對的

wireshark上,選擇正確的網路卡,捕獲表示式設為:tcp port 3306,然後開抓,然後跑去sqlyog上執行select語句。

SELECT Ftask_id,Fcreate_time FROM t_task ORDER BY Fcreate_time DESC  LIMIT 1;

然後,回到我們的wireshark,抓到了很多包:

然後隨便找一個右鍵-跟蹤流-tcp流,就會把對應的這個tcp連線上的包全部以ascii顯示出來,正常來說,一般mysql的報文,都是明文的,可以直接看到sql語句,和返回的結果啥的,但是,我本機這個sqlyog,不知道是不是版本很高的原因,少量語句可以明文顯示,其他的就不是明文。

不過吧,我們們暫時沒時間和這個客戶端耗著,我直接去應用所在的服務端上抓包吧,看看mysql server返回的,是什麼樣的。

上圖那個tcpdump語句,就是抓3306埠的包,不管3306是src埠,還是dst埠。然後相關的包,寫入到3306.pcap裡面,然後我們sz傳到windows上,用wireshark來分析。

大家注意看上圖,mysql返回的就有問題,先把鍋甩給mysql。

但是,mysql只是個儲存,既然存的資料有問題,那是不是說明,可能我們寫的有問題呢?

mysql server:誰寫了個錯誤的時間給我,來領鍋

很尷尬啊,這個時間,是我們的服務端寫進去的,這樣的話,我們只能繼續像上圖那樣抓包了:

只是這次,我們要抓現行,抓寫入的包,當然了,我這裡為了講解,已經提前抓了這個任務的。

看吧,果然寫入有問題,說明程式有問題,我們順便看看mybatis logger記錄的sql日誌。

但是,mybatis 日誌裡,記錄的時間是對的,就是晚上9點。

ok,我們理一下,我們程式裡new date,mybatis寫入,記錄的日誌是晚上9點,沒問題;但是,最終發給mysql server的包,是晚13小時的。

說明啥,可能mysql 建立的連線有點問題,我這時候去看了下原生程式碼的配置檔案。

commondb:
  database:
    url: jdbc:mysql://xxxxxx:3306/xxxx?characterEncoding=utf8&zeroDateTimeBehavior=convertToNull&useTimezone=true&serverTimezone=GMT%2B8

大家看這個配置,useTimezone=true&serverTimezone=GMT%2B8,一看就有點不對,什麼時區,什麼GMT。

我本來以為就這個問題了,但是,我們這邊,程式和配置是分開打包、分開部署的,大家可以理解為:配置中心。

我去看了下線上配置,結果好像沒問題,即:

commondb:
  database:
    url: jdbc:mysql://xxxxxx:3306/xxxx?characterEncoding=utf8&zeroDateTimeBehavior=convertToNull

本來就沒有帶後面那個時區的東西。

我很懷疑,現線上上那個執行的java程式,到底commondb.database.url有沒有問題,我想了好幾個辦法:

1、 因為是spring boot的,所以一開始用http://xx.xx.xx.xx:8080/actuator/env之類的埠,去檢視了一下,發現訪問不通。後來發現,我們們的程式,沒引入spring boot的actuator的jar包,作罷。

2、本地使用jconsole、jvisualvm去連線這個執行著的java程式。

​ 這個怎麼玩呢,首先,這個執行著的程式,需要是開了這幾個jvm引數:

-Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9999 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false

然後,就可以去連線它了,用jconsole/jvisualvm都行。

具體可以參考我以前的一個博文:https://www.cnblogs.com/grey-wolf/p/9235073.html

當然,這個比較隨機,有時可以連上,有時不行,我這次就不行,我還在本機wireshark抓了jconsole去連線這個遠端java程式的包。

抓包的過濾語句:tcp port 9999。

抓到的包,是以tcp協議展示的,其實我們知道應用層的通訊協議的話,可以手動右鍵--decode as--然後選擇rmi,

沒錯,java自帶的那個rmi,就可以看到多一些資訊。

當然了,雖然多了些資訊,我還是沒明白為啥jconsole沒連上。放棄。

jconsole不行,最終我還是隻能試試arthas了,阿里的那個,連上去那個java程式後,只能看看環境變數、System Property之類的,好像對我們要看的東西,於事無補。

還記得嗎,我們想看的是,commondb.database.url的值,思考了一會,最終只能暴力解決了,這個屬性,好像被注入到一個bean裡去了,他就是Datasource,但是想看到這個bean的值,沒那麼簡單:

    @Bean(name = DATA_SOURCE)
    @ConfigurationProperties(prefix = DB_CONFIG_PREFIX)
    @Primary
    public DataSource omsDbDatabase() {
        DataSource build = DataSourceBuilder.create().build();
        return build;
    }

所以,最終只能jmap,把堆記憶體dump下來了,然後使用eclipse memoryAnalyzer來分析。

oql,大家不瞭解的,可以瞭解下,反正就是根據class來搜尋記憶體中的物件。

配置沒問題,那,問題在哪裡

我這時候才想起來,既然伺服器上這個java程式,配置沒問題,也會出這個時區問題。那我本地,是不是也會有這個問題(按理說,我早該這麼想,但是就是後知後覺),然後本地試了下,和伺服器上表現一樣,這時候,其實就可以慢慢debug了。

但是,暫時也沒深入去debug,我只是,排除了眾多因素之後,我還是很奇怪,同事那個程式,為啥傳送給mysql server的時間沒問題,我這個就有問題,我於是,對比了一下雙方的mysql-connector-java這個依賴,發現,咦,版本不一樣啊。

        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <version>8.0.16</version>
        </dependency>

同事用的是5.1.41,我這邊怎麼這麼高,8.0。於是,我試著改成了5.1.41,這把,果然發給mysql server的時間,就是對的了。

網上的解釋

找到了大概的答案,我開始悠閒地去網上搜尋答案,肯定有很多人升了版本後出這個問題啊,哈哈。我去看答案就行。

比如這裡就一個,mysql-connector-java升級到8.0後儲存時間到資料庫出現了時差

https://blog.csdn.net/valsong/article/details/102582582

具體的根本原因,我還沒仔細看,為啥兩個客戶端版本有這個差異,不過,大概的排查過程,就是這樣了。

相關文章