本文是對(duì)之前開(kāi)發(fā)中遇到的問(wèn)題的一個(gè)總結(jié)，文章其實(shí)早就寫好，但是覺(jué)得自己寫得不夠深入，就讓文章一直躺在草稿箱里。昨天突然想起來(lái)了，就將文章重新修改了一下，還是發(fā)出來(lái)吧!

[[389221]]

問(wèn)題1

當(dāng)時(shí)我在開(kāi)發(fā)一個(gè)異常日志記錄接口，其實(shí)業(yè)務(wù)流程很簡(jiǎn)單，就是前端提交錯(cuò)誤日志到后臺(tái)，后臺(tái)接受到信息處理一番，然后插入數(shù)據(jù)庫(kù)。因?yàn)檫@個(gè)接口的并發(fā)量比較高，為了不影響其他業(yè)務(wù)，并且同時(shí)提高響應(yīng)的速度。于是采用 @Async 注解+ Spring線程池的方案來(lái)實(shí)現(xiàn)。線程池的配置如下：

<task:annotation-driven executor="jobExecutor"/>   
<task:executor id="jobExecutor" pool-size="20" queue-capacity="500" />   

使用 task:annotation-driven/ 開(kāi)啟異步時(shí)，一定要記得配置executor屬性，不然異步使用的線程池其實(shí)是

org.springframework.core.task.SimpleAsyncTaskExecutor ，但這個(gè) SimpleAsyncTaskExecutor 不是真的線程池，這個(gè)類不重用線程，每次調(diào)用都會(huì)創(chuàng)建一個(gè)新的線程。

關(guān)鍵部分偽代碼如下：

@Async  
 public void test(){  
  
     ExceptionLogEntity exceptionLogEntity = new ExceptionLogEntity();  
     exceptionLogEntity.setXX("");  
     exceptionLogEntity.setXXX("");  
     exceptionLogEntity.setIp("");  
     exceptionLogEntity.setUrl("");  
     exceptionLogEntity.setBusinessScene("");  
     exceptionLogEntity.setExceptionType("");  
     exceptionLogEntity.setExceptionDetailType("");  
     exceptionLogEntity.setExceptionMessage("");  
     exceptionLogEntity.setNoticeStatus("");  
     exceptionLogEntity.setCreateTime(new Date());  
     exceptionLogEntity.setUpdateTime(new Date());  
  
  
     ExceptionLogEntity insert = exceptionLogDao.insert(exceptionLogEntity);  
     log.info("實(shí)體的主鍵id=[{}]", insert.getId());  
  
 }  

代碼寫完我簡(jiǎn)單的測(cè)試了一下，沒(méi)啥問(wèn)題后就告知前端可以對(duì)接了。可是奇怪的事情發(fā)生了，前端老鐵告訴我接口有時(shí)會(huì)返回錯(cuò)誤。我一聽(tīng)就感覺(jué)不對(duì)勁，心想這么簡(jiǎn)單的接口，我怎么可能有bug。于是我到日志平臺(tái)上查詢了一下日志，結(jié)果還真的是有問(wèn)題。發(fā)現(xiàn)了一個(gè)SQL錯(cuò)誤，具體錯(cuò)誤如下(敏感信息已經(jīng)處理)：

Caused by: java.lang.reflect.InvocationTargetException  
  
INSERT INTO `xx`(`xx`,`xx`,`ip`,`url`,`business_scene`,`exception_type`,`exception_detail_type`,`exception_message`,`notice_status`,`create_time`,`update_time`,`xx`,`member_phone`,`ip`,`url`,`business_scene`,`exception_type`,`exception_detail_type`,`exception_message`,`notice_status`,`create_time`,`update_time`) VALUES('','','','','','','','','','2020-01-08 19  
  
at sun.reflect.GeneratedMethodAccessor115.invoke(Unknown Source)  
  
--------------------------------------------  
  
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)  
  
at java.lang.reflect.Method.invoke(Method.java:498)  
  
at coderead.mybatis.log.JdbcCommonCollects$PreparedStatementHandler.invoke(JdbcCommonCollects.java:118)  
  
... 21 more  
  
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Column 'update_time' specified twice  
  
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)  
  
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)  
  
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)  
  
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)  
  
at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)   

復(fù)現(xiàn)問(wèn)題

這個(gè)問(wèn)題簡(jiǎn)單的來(lái)說(shuō)就是SQL中的字段發(fā)生了重復(fù)， Column 'update_time' specified twice。其實(shí)不止update_time字段發(fā)生了重復(fù)，是很多字段都發(fā)生了重復(fù)。因?yàn)檫@個(gè)接口除了并發(fā)高一點(diǎn)之外，和其他的接口沒(méi)有什么特別之處!突然我腦子里靈光一閃，難道是這個(gè)接口并發(fā)較高，導(dǎo)致框架在生成INSERT類型的SQL發(fā)生了錯(cuò)誤???要是這樣的話，我直接創(chuàng)造一個(gè)這樣的場(chǎng)景不就可以實(shí)現(xiàn)了嘛!然后我寫下了下面的代碼：

public void test(){  
  
        for (int i = 0; i < 1000; i++) {  
            ExceptionLogEntity exceptionLogEntity = new ExceptionLogEntity();  
            exceptionLogEntity.setXX("");  
            exceptionLogEntity.setXXX("");  
            exceptionLogEntity.setIp("");  
            exceptionLogEntity.setUrl("");  
            exceptionLogEntity.setBusinessScene("");  
            exceptionLogEntity.setExceptionType("");  
            exceptionLogEntity.setExceptionDetailType("");  
            exceptionLogEntity.setExceptionMessage("");  
            exceptionLogEntity.setNoticeStatus("");  
            exceptionLogEntity.setCreateTime(new Date());  
            exceptionLogEntity.setUpdateTime(new Date());  
  
            Thread thread = new Thread(() -> {  
                exceptionLogDao.insert(exceptionLogEntity);  
            });  
  
            thread.start();  
        }  
    }  

代碼寫完直接重啟項(xiàng)目，最后一觸發(fā)上面的代碼。果然，同樣的錯(cuò)誤又出現(xiàn)了。這里我先介紹下使用的ORM框架：

此ORM框架是集團(tuán)O2O研發(fā)中心研發(fā)的基礎(chǔ)組件，提供同Mybatis一樣的功能：只需定義接口，無(wú)需寫實(shí)現(xiàn)類。此外，對(duì)單表操作還封裝了一套常用的增刪改查處理，連接口也無(wú)需再定義，對(duì)開(kāi)發(fā)人員非常友好，大大降低了冗長(zhǎng)的jdbc操作代碼量，提升了開(kāi)發(fā)效率。

我問(wèn)了問(wèn)旁邊的同事，在使用公司的ORM框架自帶的INSERT方法時(shí)，有沒(méi)有遇到SQL列重復(fù)的問(wèn)題嗎?嘿你還別說(shuō)，大家異口同聲說(shuō)遇到過(guò)。那厲害了，看來(lái)這真的不是個(gè)別現(xiàn)象，真的是框架的bug。于是乎我花了一點(diǎn)時(shí)間來(lái)找找看到底是在哪個(gè)地方出現(xiàn)了問(wèn)題，皇天不負(fù)有心人我還真的找到了，具體的代碼如下：

public List<DalColumn> getDalColumnsWithoutId() {  
    if (this.columnsWithoutId != null) {  
        return this.columnsWithoutId;  
    } else {  
        this.columnsWithoutId = new ArrayList(this.dalColumns.size() - 1);  
        Iterator var1 = this.dalColumns.iterator();  
  
        while(var1.hasNext()) {  
            DalColumn column = (DalColumn)var1.next();  
            if (!column.isIdColumn()) {  
                this.columnsWithoutId.add(column);  
            }  
        }  
  
        return this.columnsWithoutId;  
    }  
}  

問(wèn)題就出在 columnsWithoutId 上，它的類型是 List ，是所在類的一個(gè)屬性默認(rèn)為null，保存的是一個(gè)表除主鍵ID之外的所有字段。上面的代碼在單線程情況下沒(méi)有問(wèn)題，但是在多線程的情況下就問(wèn)題大了。 columnsWithoutId 在多線程情況下就是一個(gè) 線程共享變量 ，假設(shè)在某個(gè)時(shí)機(jī)有多個(gè)線程恰好執(zhí)行到 if 代碼塊，發(fā)現(xiàn) columnsWithoutId 的值為null，則就會(huì)同時(shí)執(zhí)行 else代碼塊，那這時(shí)就會(huì)執(zhí)行多次循環(huán)，自然 columnsWithoutId 中的字段就會(huì)出現(xiàn)了重復(fù)。

解決問(wèn)題

這個(gè)問(wèn)題已經(jīng)找到，那接下來(lái)就差一個(gè)解決方案了。

官方修復(fù)

我當(dāng)時(shí)想既然這個(gè)框架是公司研發(fā)中心提供的基礎(chǔ)組件，那就是說(shuō)明在公司內(nèi)部會(huì)有很多項(xiàng)目組使用，問(wèn)題說(shuō)不定早就被修復(fù)了。你還別說(shuō)在公司的wiki上我還真的找到了，有位負(fù)責(zé)這個(gè)組件的大佬在wiki上分享了”單表插入偶發(fā)列重復(fù)問(wèn)題定位與解決”的文章。(文章地址我就不發(fā)了，公司內(nèi)部地址發(fā)出來(lái)你們也訪問(wèn)不了)文章里詳細(xì)的描述了問(wèn)題發(fā)生的場(chǎng)景(和我上面描述的差不多)、問(wèn)題定位過(guò)程還有解決方案。摘選文章上的解決方案：

明確了是線程安全的問(wèn)題，解決方案就好確定了，解決線程安全有三種方案：

方案一：互斥同步——synchronized,ReentrantLock

方案二：非阻塞同步——CAS

方案三：無(wú)同步方案:——ThreadLocal

結(jié)合業(yè)務(wù)場(chǎng)景，綜合分析，最終確認(rèn)使用方案一，采用synchronized關(guān)鍵字，使用雙重檢查鎖的方式解決此問(wèn)題。

大佬已經(jīng)將bug修復(fù)并發(fā)布了新版本到Maven倉(cāng)庫(kù)，項(xiàng)目中有發(fā)生上述問(wèn)題的，直接升級(jí)對(duì)應(yīng)的組件版本即可。既然官方已經(jīng)給出了解決方案，我直接升級(jí)項(xiàng)目中的組件版本號(hào)就行了。結(jié)果我一更換項(xiàng)目中的版本，我的項(xiàng)目就再也沒(méi)有啟動(dòng)起來(lái)。研究發(fā)現(xiàn)，組件版本相差太多，很多依賴發(fā)生了沖突。我項(xiàng)目中使用的是 1.1.6-RELEASE ,問(wèn)題官方在版本 2.1.0-RELEASE 中修復(fù)。這組件版本差距太大貿(mào)然升級(jí)肯定是有很大的風(fēng)險(xiǎn)了，于是我放棄了!

另辟蹊徑解決

既然你自帶的插入方法有問(wèn)題，我直接自定義一個(gè)插入方法不就得了。惹不起我還躲不起么!我最后又問(wèn)了同事們最后都是怎么解決的，大家也都說(shuō)是自定義SQL，而且都不再用框架自帶的方法了，大家都很聰明呀!(其實(shí)這個(gè)還有后續(xù)，后面有一期開(kāi)發(fā)過(guò)程中，需要用到批量插入的功能，我又偷懶用了框架自帶的batch方法，又把我給坑了。從那之后，我再也沒(méi)有用自帶的方法了……)

問(wèn)題2

我在排查上面的問(wèn)題的時(shí)候，在框架里面看到了下面的代碼：

private Number execute4PrimaryKey(String sqlId, Map<String, Object> paramMap, KeyHolder keyHolder) {  
    long startTimestamp = System.currentTimeMillis();  
    String sql = null;  
  
    Object var8;  
    try {  
        MappedStatement mappedStatement = this.configuration.getMappedStatement(sqlId, true);  
        mappedStmtThreadLocal.set(mappedStatement);  
        sql = mappedStatement.getBoundSql(paramMap);  
        int result = false;  
        int result;  
        if (keyHolder != null) {  
            this.execution.update(sql, new MapSqlParameterSource(DalUtils.mapIfNull(paramMap)), keyHolder);  
            result = keyHolder.getKey() == null ? 0 : keyHolder.getKey().intValue();  
        } else {  
            result = this.execution.update(sql, DalUtils.mapIfNull(paramMap));  
        }  
  
        Integer var9 = result;  
        return var9;  
    } catch (Exception var13) {  
        this.throwException(var13);  
        var8 = null;  
    } finally {  
        mappedStmtThreadLocal.remove();  
        logger.debug("{} method:{}, sql:{}, param:{}", new Object[]{this.logPrefix, "execute", sql, paramMap});  
        this.logProfileLongTimeRunningSql(startTimestamp, sql, paramMap);  
    }  
  
    return (Number)var8;  
}  

大家仔細(xì)看看，這上面的代碼有個(gè)不容易發(fā)現(xiàn)的問(wèn)題。問(wèn)題是這樣的，我們系統(tǒng)中表的主鍵類型定義的都是 bigint ,這個(gè)類型對(duì)應(yīng)的是Java中的 Long 類型，說(shuō)到這大家明白了么?對(duì)了，就是數(shù)據(jù)溢出的問(wèn)題。

復(fù)現(xiàn)問(wèn)題

我將表中的主鍵自增量設(shè)置為Java Int類型的最大值+1，也就是2147483648。然后數(shù)據(jù)庫(kù)再新增一條記錄，此時(shí)表中記錄的主鍵是2147483648，但Java實(shí)體中的主鍵ID已經(jīng)是個(gè)負(fù)數(shù)-2147483648了。

使用Long類型時(shí)，要注意JavaScript接收后端Long類型數(shù)據(jù)精度丟失問(wèn)題

解決問(wèn)題

這個(gè)問(wèn)題還真不好另辟蹊徑了，只能后面出現(xiàn)類似的問(wèn)題，升級(jí)ORM框架的版本了。

問(wèn)題3

其實(shí)這個(gè)問(wèn)題我應(yīng)該在看那篇內(nèi)部文章的時(shí)候就應(yīng)該發(fā)現(xiàn)的，但我當(dāng)時(shí)就是沒(méi)有看出來(lái)!此時(shí)的我留下了沒(méi)有技術(shù)的淚水。對(duì)于問(wèn)題1，當(dāng)時(shí)那位大佬最終采用 synchronized 進(jìn)行加鎖解決多線程情況下共享變量讀寫問(wèn)題，具體代碼如下(敏感信息打碼)：

修改前的代碼：

public List<DalColumn> getDalColumnsWithoutId() {  
        if (this.columnsWithoutId != null) {  
            return this.columnsWithoutId;  
        } else {  
            this.columnsWithoutId = new ArrayList(this.dalColumns.size() - 1);  
            Iterator var1 = this.dalColumns.iterator();  
  
            while(var1.hasNext()) {  
                DalColumn column = (DalColumn)var1.next();  
                if (!column.isIdColumn()) {  
                    this.columnsWithoutId.add(column);  
                }  
            }  
  
            return this.columnsWithoutId;  
        }  
    }  

修改后的代碼(引用文章中的代碼截圖)：

問(wèn)題復(fù)現(xiàn)

這個(gè)問(wèn)題要復(fù)現(xiàn)的話，不太好復(fù)現(xiàn)，因?yàn)榍闆r是比較極端的，但是在復(fù)雜的生產(chǎn)環(huán)境還是很可能出現(xiàn)的。

舉例說(shuō)明：

假設(shè)有A、B兩個(gè)線程，A線程執(zhí)行到for循環(huán)處，B線程恰好執(zhí)行到最開(kāi)始的if判斷處，由于此時(shí)的cloumnsWithId已經(jīng)被A線程賦值，肯定不為null，然后線程B就直接返回了，導(dǎo)致B線程調(diào)用者獲得了一個(gè)空的或者保存部分字段的cloumnsWithId。這種情況最終導(dǎo)致的結(jié)果是INSERT SQL中的字段缺失。

解決辦法

對(duì)于多線程下的共享變量，我們一定要堅(jiān)持 讀讀可并行，讀寫要排隊(duì) 的原則。當(dāng)然能不加鎖的話，也是不錯(cuò)的選擇。

我發(fā)現(xiàn)這個(gè)問(wèn)題之后，就找到了前文中說(shuō)的大佬，跟他反饋了我的想法，并提出我的解決方案。

1. 直接在 getDalColumnsWithoutId 方法上添加 synchronized 。
2. 修改第一個(gè)if判斷邏輯，然后使用 synchronized 鎖代碼塊。

public List<DalColumn> getDalColumnsWithoutId() {  
    int size = CollectionUtils.size(this.dalColumns);  
    if (CollectionUtils.size(this.columnsWithoutId) == size && size > 0 ) {  
        return this.columnsWithoutId;  
    }  
    synchronized(lock){  
        if (columnsWithoutId == null) {  
            columnsWithoutId = new ArrayList<>(size*2);  
        }  
        for (DalColumn column :  this.dalColumns){  
            if (!column.isIdColumn()) {  
                this.columnsWithoutId.add(column);  
            }  
        }  
    }  
    return this.columnsWithoutId;  
}  

當(dāng)時(shí)與大佬的溝通截圖，來(lái)自大佬的肯定：

總結(jié)

在遇到問(wèn)題的時(shí)候不要著急，一定要學(xué)會(huì)大膽假設(shè)，然后小心求證。要勇敢地質(zhì)疑權(quán)威，不要認(rèn)為既然已經(jīng)是框架了就沒(méi)有bug。例如Spring從當(dāng)初的1.0到現(xiàn)在版本號(hào)都超過(guò)5.0了，除了給Spring增加新的功能，其他的升級(jí)就是在修復(fù)Spring中的bug。做出自己的假設(shè)之后，就要進(jìn)行場(chǎng)景復(fù)現(xiàn)，一個(gè)正常的bug是可以不斷地被復(fù)現(xiàn)的。復(fù)現(xiàn)了問(wèn)題那就是找到問(wèn)題的癥結(jié)所在，剩下的就是如何去解決啦!