建站
咨詢
售后
建站咨詢
新聞中心
問題描述
某產(chǎn)品線應用【A】接收應用【B】發(fā)送到MQ的消息，經(jīng)過業(yè)務邏輯處理后，將數(shù)據(jù)存儲到數(shù)據(jù)庫中，近期發(fā)現(xiàn)應用【A】數(shù)據(jù)庫表中有些記錄的時間比應用【B]數(shù)據(jù)庫表中對應記錄的時間少了8個小時。產(chǎn)品線反饋當前線上會斷斷續(xù)續(xù)地產(chǎn)生這種異常數(shù)據(jù)，異常數(shù)據(jù)量不清楚，估計不算多。
成都創(chuàng)新互聯(lián)專注于定南網(wǎng)站建設服務及定制，我們擁有豐富的企業(yè)做網(wǎng)站經(jīng)驗。 熱誠為您提供定南營銷型網(wǎng)站建設，定南網(wǎng)站制作、定南網(wǎng)頁設計、定南網(wǎng)站官網(wǎng)定制、小程序制作服務，打造定南網(wǎng)絡公司原創(chuàng)品牌,更為您提供定南網(wǎng)站排名全網(wǎng)營銷落地服務。
分析過程
相差整整8小時，最容易想到的就是時區(qū)問題，但是分析問題還是需要把問題如何發(fā)現(xiàn)、問題發(fā)現(xiàn)的時間、問題發(fā)生前后系統(tǒng)變更情況、異常數(shù)據(jù)量、影響范圍（應用都存在問題還是局部存在問題）、異常數(shù)據(jù)是否存在規(guī)律性、相關系統(tǒng)如何交互等基本情況了解清楚，這些是基礎也是最重要的判斷依據(jù)。
分析數(shù)據(jù)，尋找規(guī)律
【B】應用的數(shù)據(jù)是準確的，通過對比找出【A】應用異常數(shù)據(jù)不同維度的統(tǒng)計信息。比如：分機構分時間（分天、分小時）統(tǒng)計異常數(shù)據(jù)的數(shù)量，根據(jù)這個統(tǒng)計信息可以判斷出系統(tǒng)在什么時候開始出現(xiàn)問題及逐漸變化的過程（是逐漸變差的還是在某個時間突然就變差了），這個是產(chǎn)品線在問題發(fā)現(xiàn)時候就應該去做的事，很可惜并沒有去做；異常數(shù)據(jù)并不是預估的不多，而是每天百萬的量級。
通過異常數(shù)據(jù)中訂單ID可以去系統(tǒng)中撈出這個訂單從最開始處理到結束之間所有的日志（入?yún)?、處理過程中的參數(shù)等等），通過日志可以分析出發(fā)生問題的機器有哪些，確定了機器就比較有針對性了（該應用在線上有180臺ECS），通過日志也可以在線下環(huán)境通過模擬回放的方式去嘗試復現(xiàn)問題。由于缺少類似SLS的產(chǎn)品，當前日志分析比較辛苦和低效，這個做的結果不夠清晰，也是這次分析問題比較遺憾的一個地方。
系統(tǒng)交互流程圖
為了便于表達和理解，下面只對涉及時間的入?yún)⒑筒僮鬟M行邏輯抽象。
系統(tǒng)交互關系
檢查MQ消息
在日志中找到異常數(shù)據(jù)對應的MQ消息報文，時間戳字段值都是正確的。
確認時區(qū)配置
操作系統(tǒng)時鐘正常：檢查應用180臺ECS系統(tǒng)時間是否同步，Linux命令：date操作系統(tǒng)時區(qū)正常：
- 檢查/etc/localtime正常
- timedatectl，發(fā)現(xiàn)有報Warning的機器，經(jīng)過數(shù)據(jù)確認，并不是造成時間不一致的原因
正常
Warning
JVM時區(qū)配置正常（可以使用下面兩種檢查方式）：
- jinfo
| grep user.timezone
user.timezone：PRC
- arthas：sysprop user.timezone
user.timezone：PRC
DRDS、RDS時區(qū)配置正常
由數(shù)據(jù)庫負責同學進行檢查
應用代碼邏輯
數(shù)據(jù)庫兩個時間字段對應的類型均為：datetime刨除其他無關邏輯，時間字段的處理邏輯可以用下面代碼來表達：
應用代碼邏輯
數(shù)據(jù)庫表：
表結構
經(jīng)過代碼Review（沒有特殊的時間轉換邏輯），也沒有發(fā)現(xiàn)問題到底出在哪！
datetime和timestamp
這里有比較關鍵的知識點，需要引起關注：datetime、timestamp如何轉換和存儲的，示例解釋如下：
datetime該字段在MySQL Server中存進去的是什么取出來的就是什么
【datetime示例一】：
- JVM是UTC + 8，MySQL server session是UTC + 0
- JVM client原始時間是（UTC + 8）：2022-10-16 10:00:00
- MySQL JDBC Driver發(fā)送給MySQL server的時間是：2022-10-16 02:00:00（時間由UTC + 8轉換為UTC + 0）
- MySQL server最終存儲的時間為：2022-10-16 02:00:00
- JVM client從數(shù)據(jù)庫中查出的時間是：2022-10-16 02:00:00
【datetime示例二】：
- JVM是UTC + 8，MySQL最初的server session是UTC + 0，MySQL JDBC Driver配置的是UTC + 1
- JVM client原始時間是（UTC + 8）：2022-10-16 10:00:00
- MySQL JDBC Driver發(fā)送給MySQL server的時間是：2022-10-16 03:00:00（時間由UTC + 8轉換為UTC + 1）
- MySQL server最終存儲的時間為：2022-10-16 03:00:00
- JVM client從數(shù)據(jù)庫中查出的時間是：2022-10-16 03:00:00
從上面看出datetime最終存儲的時間是與MySQL JDBC Driver Session配置的時區(qū)直接相關的；
timestamp該字段在MySQL Server中存儲的是UTC時間
【timestamp示例一】：
- JVM是UTC + 8，MySQL server session是UTC + 0
- JVM client原始時間是（UTC + 8）：2022-10-16 10:00:00
- MySQL JDBC Driver發(fā)送給MySQL server的時間是：2022-10-16 02:00:00（時間由UTC + 8轉換為UTC + 0）
- MySQL Server最終存儲的時間是：2022-10-16 02:00:00（不需要轉換）
- 從MySQL Server檢索到server session的時間是：2022-10-16 02:00:00（不需要轉換）
- MySQL JDBC Driver在JVM時區(qū)內(nèi)解析的時間是：2022-10-16 10:00:00（時間由UTC + 0轉換為UTC + 8）
- 另外一臺機器JVM時區(qū)是UTC + 9，MySQL JDBC Driver在該JVM內(nèi)解析的時間是：2022-10-16 11:00:00（時間由UTC + 0轉換為UTC + 9）
【timestamp示例二】：
- JVM是UTC + 8，MySQL最初的server session是UTC + 0，MySQL JDBC Driver配置的是UTC + 1
- JVM client原始時間是（UTC + 8）：2022-10-16 10:00:00
- MySQL JDBC Driver發(fā)送給MySQL server的時間是：2022-10-16 03:00:00（時間由UTC + 8轉換為UTC + 1）
- MySQL Server最終存儲的時間是：2022-10-16 02:00:00（時間由UTC + 1轉換為UTC + 0）
- 從MySQL Server檢索到server session的時間是：2022-10-16 03:00:00（MySQL內(nèi)部轉換，由UTC + 0轉換為UTC + 1）
- MySQL JDBC Driver在JVM時區(qū)內(nèi)解析的時間是：2022-10-16 10:00:00（時間由UTC + 1轉換為UTC + 8）
- 另外一臺機器JVM時區(qū)是UTC + 9，MySQL JDBC Driver在該JVM內(nèi)解析的時間是：2022-10-16 11:00:00（時間由UTC + 1轉換為UTC + 9）
JVM運行時時區(qū)
在上面我們排查了JVM時區(qū)配置屬性user.timezone:PRC是正常的，同時我們也排查了幾臺機器的TimeZone.getDefault()也是正常的：
user.timezone
由于線上180臺機器，檢查TimeZone.getDefault()比較繁瑣，所以沒有對每臺機器進行檢查（這也是導致我們走了彎路的一步）。
柳暗花明
在應用排查的同時，我們排查了下游DRDS SQL日志，通過對比異常數(shù)據(jù)，在DRDS SQL日志中發(fā)現(xiàn)了錯誤SQL日志：
DRDS sql log
通過上面日志，找到了問題ECS的IP和端口號，登錄到ECS，使用arthas查看TimeZone信息，居然是0時區(qū)：
user.timezone-GMT
接著查看了這臺ECS上處理的數(shù)據(jù)都存在時區(qū)錯誤的情況。
之后在應用代碼里搜索【TimeZone.setDefault】，發(fā)現(xiàn)了這樣的代碼：
異常代碼
最后通過與產(chǎn)品線溝通，這塊代碼偶爾會調(diào)用掉（無論如何這兩行代碼都是有問題的）。
異常場景復盤
異常場景
從上圖的【5.業(yè)務操作】之后，我們的數(shù)據(jù)開始出現(xiàn)異常。由于【5.業(yè)務操作】是即將下線的功能，后端服務器數(shù)量比較多，所以沒有造成更大范圍的異常數(shù)據(jù)。
解決辦法
BUG修復
對于需要單獨格式化時間的場景，可以為單獨的DateFormat設置時區(qū)信息，示例：
DateFormat示例
時區(qū)配置監(jiān)控&報警
定時采集時區(qū)配置（操作系統(tǒng) OR JVM系統(tǒng)配置 OR JVM運行時時區(qū)）信息。
對于異常數(shù)據(jù)及時報警出來?。
分享文章：JVM&MySQL時區(qū)配置問題-兩行代碼讓我們一幫子人熬了一個通宵
新聞來源：http://www.5511xx.com/article/dhjhhod.html
