java陷阱之spring事物未提交和回滾導致不可預知問題

案發現場

//防止全局配置了 所以這里定義sprnig 不托管事物
    @Transactional(propagation = Propagation.NOT_SUPPORTED)
    public boolean  deductNumber(Long id,int i){
        
        DefaultTransactionDefinition def = new DefaultTransactionDefinition();
        def.setPropagationBehavior(TransactionDefinition.PROPAGATION_REQUIRED);//設置事物傳播行為
        TransactionStatus status = null;
        try {
            //開啟事物
            status = transactionManager.getTransaction(def);
            if(id==null){
                return  false;//庫存編號不能為空
            }
            if(i<=0){
                return false;//扣除庫存不能小於0 
            }
            //提交事務
            transactionManager.commit(status);
        } catch (Exception e) {
            transactionManager.rollback(status);
              return false;
        }
        return true;
    }

導致問題

線上出現 訂單下單 提示用戶訂單創建成功  但是訂單不在了 對應的錢沒扣 庫存也沒扣   看代碼沒有問題 日志也是正常打印 沒拋錯沒回滾

mysql 部分表出現鎖等待 單表操作無並發也出現鎖等待

自己的坑自己填

1.day 1

懷疑是數據庫的問題 事物提交了 但是數據庫沒持久  在下單操作打印了日志判斷是否回滾並打印日志

if(status.isRollbackOnly()){
            logger.info("======事物已回滾=========");
            return false;
        }

2.day 2

第二天又出現這種情況 同時發現伴隨着后台有個事物一一直 在select * from information_schema.innodb_trx; runing 持續半個小時以上

但是發現丟單的地方======事物已回滾========

這個時候很疑惑 因為下單很多邏輯懷疑是某個方法設置了回滾狀態但是拋出true  來log4j開啟事物管理器debug日志

log4j.logger.org.springframework.jdbc.datasource.DataSourceTransactionManager=DEBUG

開啟之后開啟事物 設置事物狀態合並事物都會打印對應的日志
同時為了定位到runing的事物是在哪個地方 在重寫了log4j layout 打印了事物號和線程號

log4j配置log4j.appender.stdout.layout =com.chinayanghe.dms.log4jUtil.MyPatternLayout

public class MyPatternLayout extends PatternLayout {
    /**
     * 日志打印
     */
    protected Logger logger = LoggerFactory.getLogger(getClass());
    private static ThreadLocal<String> localTreadIds = new ThreadLocal<String>();

    public static void removeTreadLocalCache() {
        localTreadIds.remove();
    }
    @Override
    public String format(LoggingEvent event) {
        String logStr = super.format(event);
        try {
            if (logStr.indexOf("SELECT trx_id FROM INFORMATION_SCHEMA.INNODB_TRX WHERE TRX_MYSQL_THREAD_ID = CONNECTION_ID()") < 0
                    &&logStr.indexOf("SELECT trx_mysql_thread_id FROM INFORMATION_SCHEMA.INNODB_TRX WHERE TRX_MYSQL_THREAD_ID = CONNECTION_ID();")<0) {
                //表示是sql打印嘗試獲得事物號
                if (logStr.indexOf("[org.apache.ibatis.logging.jdbc.BaseJdbcLogger.debug(BaseJdbcLogger.java:145)] ==>  Preparing:") >= 0) {

                    WebApplicationContext wac = ContextLoader.getCurrentWebApplicationContext();
                    String treadId = localTreadIds.get();
                    if (StringUtil.isEmpty(treadId)) {
                        JDBCTransactionInfoService jdbcTransactionInfoService = (JDBCTransactionInfoService) wac.getBean("jDBCTransactionInfoServiceImpl");
                        List<String> treadIds = jdbcTransactionInfoService.selectTrxMysqlThreadId();
                        if (CollectionUtils.isNotEmpty(treadIds)) {
                            treadId = treadIds.get(0);
                            localTreadIds.set(treadId);
                        }
                    }
                    if (treadId != null) {
                        logStr = logStr.replace("[DEBUG]", "[DEBUG][事務號" + treadId + "]");
                    }

                } else if (logStr.indexOf("Transactional code has requested rollback") >= 0) {
                    logStr = logStr.replace("Transactional code has requested rollback", "Transactional code has requested rollback,線程id:" + Thread.currentThread().getId());
                }
            } else {
                return "";
            }
            long treadId = Thread.currentThread().getId();
            logStr = logStr.replace("[DEBUG]", "[DEBUG][線程id:" + Thread.currentThread().getId() + "]").replace("[INFO]", "[INFO][線程id:" + treadId + "]");
        } catch (Exception e) {
            logger.info(e.getMessage());
        }
        return logStr;
    }
}

3.day3出現丟單根據日志發現 丟單的都是同一個線程id 事物號也相同  同時丟單的地方都沒有開啟事物日志而是事物已存在合並的日志

根據日志 一個一個看 發現規律 線程id最后一次打印 creating transaction  之后 再也沒打印  然后定位到最后一次打印事物 的方法是手動開啟事物的方法  有個地方忘記回滾 直接return了

這個時候反應過來 是這個方法沒提交一直掛起  spring事物是基於線程緩存 tomcat會回收線程到線程池  下單分配到這個線程  因為手動開啟事物還存在 所以公用同一個事物  事物一致掛起 當遇到RR模式鎖等待拋出wai lock

statu的回滾狀態會設置為true 所以才會出現我的下單日志打印都是回滾 

優化代碼

 //防止全局配置了 所以這里定義sprnig 不托管事物
    @Transactional(propagation = Propagation.NOT_SUPPORTED)
    public boolean  deductNumber(Long id,int i){

        DefaultTransactionDefinition def = new DefaultTransactionDefinition();
        def.setPropagationBehavior(TransactionDefinition.PROPAGATION_REQUIRED);//設置事物傳播行為
        TransactionStatus status = null;
        try {
            //開啟事物
            status = transactionManager.getTransaction(def);
            if(id==null){
                transactionManager.rollback(status);
                return  false;//庫存編號不能為空
            }
            if(i<=0){
                return false;//扣除庫存不能小於0
            }
            //提交事務
            transactionManager.commit(status);
        } catch (Exception e) {
            transactionManager.rollback(status);
              return false;
        }finally {
            //加上此代碼 防止忘記
            if(status!=null&&!status.isCompleted()){
                transactionManager.rollback(status);
                return false;
            }
        }

        return true;
    }

 總結原因:

            事物一直沒有被提交,事物狀態是通過線程緩存實現的,當線程回收到線程池,后面再分分派的這個線程使用的同一個連接和事物,事物其實一直掛起