快捷導(dǎo)航

淺談MySQL timestamp(3)問題

更新時間：2023年01月05日 10:02:53 作者：johnny233

本文主要介紹了淺談MySQL timestamp(3)問題，文中通過示例代碼介紹的非常詳細，對大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價值，需要的朋友們下面隨著小編來一起學(xué)習(xí)學(xué)習(xí)吧

背景

最近在負責(zé)開發(fā)維護的一款數(shù)據(jù)平臺，有一個功能是把數(shù)據(jù)從某個源頭數(shù)據(jù)源（如常規(guī)的JDBC數(shù)據(jù)源，MySQL，Oracle等）推到目地數(shù)據(jù)源（還包括企微，MQ等）。一次推送數(shù)據(jù)就是一個任務(wù)，當(dāng)然需要記錄此次推送任務(wù)的執(zhí)行情況，如任務(wù)的開始時間，結(jié)束時間，任務(wù)名稱，任務(wù)執(zhí)行狀態(tài)，任務(wù)日志（失敗原因），執(zhí)行人，執(zhí)行方式（手動執(zhí)行還是定時觸發(fā)）。另外，從來源數(shù)據(jù)源取數(shù)，怎么取數(shù)是通過SQL指定的，那我們還可以記錄一下SQL查詢耗時，以及SQL查詢條數(shù)?？偤臅r就是任務(wù)執(zhí)行結(jié)束時間減去任務(wù)開始時間，總耗時肯定大于SQL查詢耗時。

統(tǒng)計SQL查詢耗時時，還需要考慮到SQL取數(shù)的數(shù)據(jù)量，假如SQL查詢量為1000w，程序不可能一次查詢?nèi)繑?shù)據(jù)，然后加工處理并發(fā)送到下游目地數(shù)據(jù)源，故而需要設(shè)置分批。假設(shè)批次為50w，則SQL查詢耗時為20次查詢的耗時之和。

扯遠一句，項目是接手維護的，一開始的設(shè)計開發(fā)者是用秒來記錄SQL查詢耗時，這樣一看就不嚴謹，因為很多SQL查詢耗時根本不需要1秒。事實上就算查詢耗時超過1s，1.6s和1.7s也是有區(qū)別的，故而需要帶毫秒來優(yōu)化記錄SQL查詢耗時。最后在前端展示時，用小數(shù)點來表示毫秒。

很常規(guī)，看起來也沒有任何問題的數(shù)據(jù)表設(shè)計：

create table execlog (
    id             bigint(11) auto_increment primary key,
    total_sql_time bigint                                  null comment 'SQL執(zhí)行耗時，單位豪秒',
    start_date     timestamp default CURRENT_TIMESTAMP not null comment '執(zhí)行開始時間',
    end_date       timestamp                               null comment '執(zhí)行結(jié)束時間',
);

注：total_sql_time注釋單位毫秒，以及程序記錄單位是后來優(yōu)化調(diào)整的。

某次任務(wù)執(zhí)行記錄截圖如下，發(fā)現(xiàn)總耗時為0秒，而查詢耗時為146毫秒。這顯然不符合邏輯。

在這里插入圖片描述

優(yōu)化

優(yōu)化思路也不難，就是任務(wù)開始時間需要記錄到毫秒級別，改進后的表結(jié)構(gòu)為：

create table execlog (
    id             bigint(11) auto_increment primary key,
    total_sql_time bigint                                    null comment 'SQL執(zhí)行耗時，單位豪秒',
    start_date     timestamp(3) default CURRENT_TIMESTAMP(3) not null comment '執(zhí)行開始時間',
    end_date       timestamp(3)                                  null comment '執(zhí)行結(jié)束時間',
);

值得注意的是，MySQL直到版本5.6（不太確定）才支持，如何知道自己使用的MySQL Server版本是否支持timestamp(3)，執(zhí)行語句即可驗證，沒有報錯并且返回毫秒數(shù)表示支持：select now(3);

優(yōu)化上面截圖中的日志記錄問題分為兩個步驟，即日志記錄和日志顯示。

日志記錄

增加一個取當(dāng)時時間精確到毫秒的靜態(tài)方法：

public static final String COMMON_DATE_WITH_MILLI_SECOND = "yyyy-MM-dd HH:mm:ss:sss";

public static String getNowWithMilliSecond() {
    SimpleDateFormat sdf = new SimpleDateFormat(Constant.COMMON_DATE_WITH_MILLI_SECOND);
    return sdf.format(new Date());
}

表結(jié)構(gòu)如上改進后，發(fā)現(xiàn)start_date記錄沒有問題，帶3位小數(shù)點。但end_date記錄不到小數(shù)點，即未記錄到毫秒，于是懷疑表結(jié)構(gòu)不對。

某次任務(wù)執(zhí)行肯定會有start_date，故而設(shè)置為not null，但會因發(fā)布，或調(diào)試中斷等各種原因?qū)е掠涗洸坏?code>end_date時間點，因此字段不能設(shè)置為not null。

落不到數(shù)據(jù)，懷疑需要給一個默認值，于是如下改表結(jié)構(gòu)

create table execlog (
    id             bigint(11) auto_increment primary key,
    start_date     timestamp(3) default CURRENT_TIMESTAMP(3) not null comment '執(zhí)行開始時間',
	end_date       timestamp(3) default CURRENT_TIMESTAMP(3) null comment '執(zhí)行結(jié)束時間'
);

但是還是記錄不到結(jié)束時間的毫秒數(shù)。

此時只能好好看代碼，end_date是在任務(wù)結(jié)束（不管是正常結(jié)束還是異常結(jié)束，異常結(jié)束在finally語句塊）時updateExecLog更新：

<update id="updateExecLog" parameterType="com.xy.cloudiview.common.po.ExecLog">
    UPDATE execlog t
    <set>
        <if test="errorLog != null">
            t.error_log = #{errorLog},
        </if>
        t.end_date = now(),
    </set>
    WHERE t.id = #{id}
</update>

此處已經(jīng)指定end_date取數(shù)為now()，肯定不會記錄到毫秒數(shù)的。需改成t.end_date = now(3),。

再看另外一個updateExecLog更新語句：

<update id="updateByPrimaryKeySelective" parameterType="com.xy.cloudiview.common.po.ExecLogWithBlobs">
    update execlog
    <set>
        <if test="endDate != null">
            end_date = #{endDate,jdbcType=TIMESTAMP},
        </if>
    </set>
    where id = #{id,jdbcType=BIGINT}
</update>

貌似找到一點問題解決思路，開啟MySQL日志打印功能：

mybatis:
  configuration:
    log-impl: org.apache.ibatis.logging.stdout.StdOutImpl

一個很無厘頭的嘗試：

<if test="endDate != null"> end_date = #{endDate,jdbcType=TIMESTAMP(3)},</if>

報錯：

MyBatisSystemException: nested exception is org.apache.ibatis.builder.BuilderException: Error resolving JdbcType. Cause: java.lang.IllegalArgumentException: No enum constant org.apache.ibatis.type.JdbcType.TIMESTAMP(3)
at java.lang.Enum.valueOf(Enum.java:238)

那就把jdbcType去掉：

<if test="endDate != null">
    end_date = #{endDate},
</if>

打印日志如下：

JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@7ef24deb] will not be managed by Spring
==> Preparing: update execlog SET end_date = ? where id = ?
==> Parameters: 2022-10-12 17:08:13:013(String), 31542157(Long)
nested exception is com.mysql.cj.jdbc.exceptions.MysqlDataTruncation: Data truncation: Incorrect datetime value: '2022-10-12 16:05:47:047' for column 'end_date' at row 1

也就是說，當(dāng)MyBatis遇到MySQL timestamp(3)時，MyBatis上面這種寫法支持不了。

于是只能換一種寫法：

<update id="updateByPrimaryKeySelective" parameterType="com.xy.cloudiview.common.po.ExecLogWithBlobs">
    update execlog
    <set>
    	<if test="modelId != null">
            model_id = #{modelId,jdbcType=BIGINT},
        </if>
		end_date = now(3),
    </set>
    where id = #{id,jdbcType=BIGINT}
</update>

解決問題。也不需要在Java代碼層設(shè)置帶毫秒數(shù)的當(dāng)前時間。

此時，回頭看看第一個截圖，里面有一個日志類型的字段，文章開頭沒有描述。這里解釋一下，因為平臺有多種類型的任務(wù)，涉及多個maven Module模塊和多個表，于是有多個execlog的insert和update語句。

再來看一個insertExecLog語句，省略無關(guān)字段，這種方法是MyBatis插件generator自動生成的，也沒有任何問題，就是看起來非常冗余，兩個<trim>語句塊，再加上每個<trim>語句塊里面每個字段都有<if>語句塊條件判斷語句：

<insert id="insertSelective" parameterType="com.xy.cloudiview.common.po.ExecLogWithBlobs">
  <selectKey resultType="java.lang.Long" keyProperty="id" order="AFTER">
        SELECT LAST_INSERT_ID()
    </selectKey>
    insert into execlog
    <trim prefix="(" suffix=")" suffixOverrides=",">
        <if test="startDate != null">
            start_date,
        </if>
    </trim>
    <trim prefix="values (" suffix=")" suffixOverrides=",">
        <if test="startDate != null">
            #{startDate,jdbcType=TIMESTAMP},
        </if>
    </trim>
</insert>

維護項目的一個默認的潛規(guī)則，就是除非沒有大的問題，盡可能不要大面積改動代碼，大面積改動還不如重構(gòu)，重構(gòu)的前提是對項目非常了解。

當(dāng)然這個地方只是一個MyBatis方法而已，還達不到重構(gòu)那個深度。但是我也是想著盡可能不要改動太多，于是改動如下：

<insert id="insertSelective" parameterType="com.xy.cloudiview.common.po.ExecLogWithBlobs">
  <selectKey resultType="java.lang.Long" keyProperty="id" order="AFTER">
        SELECT LAST_INSERT_ID()
    </selectKey>
    insert into execlog
    <trim prefix="(" suffix=")" suffixOverrides=",">
        start_date,
    </trim>
    <trim prefix="values (" suffix=")" suffixOverrides=",">
        now(),
    </trim>
</insert>

報錯信息就不貼出來了，原因還是當(dāng)MyBatis遇到MySQL timestamp(3)時，MyBatis上面這種寫法不支持。

改動方法：

刪除start_date對應(yīng)的if判斷語句塊，讓MySQL的default CURRENT_TIMESTAMP(3)來使其生效

使用如下方法：

<insert id="saveExecLog" parameterType="com.xy.cloudiview.common.po.ExecLogWithBlobs">
    INSERT INTO execlog(start_date) VALUES (now(3))
</insert>

日志查詢

改進前的執(zhí)行日志列表頁查詢語句為：

select 
DATE_FORMAT(t.start_date,'%Y-%m-%d %H:%i:%s') as startDate,
TO_SECONDS(t.end_date)-TO_SECONDS(t.start_date) as totalTime
from execlog

改進后的：

select
SUBSTRING(DATE_FORMAT(t.end_date, '%Y-%m-%d %H:%i:%s.%f'), 1, 23) AS endDate,
TIMESTAMPDIFF(MICROSECOND, t.start_date, t.end_date) / (1000 * 1000) AS totalTime
from execlog

最后實現(xiàn)的效果是：

在這里插入圖片描述