記一次AOP問題排查

背景和問題

狀況是這樣的：
因爲某業務上的需求，須要數據庫表T的數據發生變化時，通知給其它系統。
改造前，在各數據發生變化的業務節點，直接調用通知方法，將數據同步給其它系統；
改造後，使用了spring aop，基於抽象出的update方法，進行數據同步。

因而代碼改爲了這樣：

##切面類
class NotifyXSystemAOP{
    //切面定義
    @Pointcut("execution(* com.xxx.updateMethod(com.xxx.XBean)) && args(record)")
    public void updatePointcut(XBean xBean){}

    //切面邏輯
    @After(value = "updatePointcut(record)",argNames = "xBean")
    public void afterUpdate(XBean xBean){
        //要將全量數據同步給兄弟系統，因此查了庫
        xBean = xBeanMapper.selectByPrimaryKey(xBean.getId());
        
        //利用線程池，將數據同步至兄弟系統`XSystem`
        ThreadManager.executeTask(()-> {
            sendToXSystem(xBean);
        });
    }
}

##業務類關鍵方法
public void keyMethod(){
    ...
    xBean.setPropertyA(999);
    com.xxx.updateMethod(xBean);    //修改動做
    ...
}

看着一副還算合理的樣子，測試時卻發現推送的xBean對象與數據庫表T中的數據不一致（好比庫中PropertyA字段=999，推送數據PropertyA=1）

分析

發現問題後，先檢查了切面中的邏輯，發現 切面中確實沒有任何修改XBean的痕跡。
並且從日誌觀察，業務中的修改方法確實已經成功執行了，才進入了切面。
因此愈加的以爲這個問題很詭異！

推理1：事務設置

衆所周知，mysql默認的事務隔離級別是可重複讀（Repeatable read），有沒有多是這樣的？
業務方法中執行了修改，因爲事務還沒提交，因此切面中查詢時沒有獲取到最新的屬性值，而把舊版本數據推送給兄弟系統了。

有了思路，就進行求證嘍。因而在切面方法中增長了日誌：

@After(value = "updatePointcut(record)",argNames = "xBean")
public void afterUpdate(XBean xBean){
    log.info("查詢前xBean={}",xBean);    //增長日誌——查詢前
    xBean = xBeanMapper.selectByPrimaryKey(xBean.getId());
    log.info("查詢後xBean={}",xBean);   //增長日誌——查詢後

    ThreadManager.executeTask(()-> {
        sendToXSystem(xBean);
    });
}

若是確實如咱們猜想，問題是由事務引發的，那麼查詢後和查詢前的PropertyA屬性值會不同。
從新執行，觀察日誌，結論是：查詢先後，PropertyA的值同樣！也就證實——推論錯誤，兇手不是事務。

其實仔細想一想，也能想明白。
代碼裏是在切面主線程中作的數據庫查詢。而切面AOP的本質是動態代理，那麼一個代理對象，又在同一個線程中，先執行業務方法邏輯，再執行切面中切入的邏輯，若是沒有什麼特殊的事務控制，這些邏輯理應在一個事務當中。

經過新增的日誌，發現xBean確實已經修改過了——新增日誌中的xBean和數據庫表的數據徹底一致。
問題在於，只是到推送時（sendToXSystem(xBean)方法處），某些屬性，如PropertyA就發生了改變。

推理2：對象傳遞

因而有了第二種猜想，會不會切面在推送數據過程當中，業務方法中有修改邏輯？

先來複習一波java參數傳遞的問題：

# 參數傳遞demo
void methodK(){
    Person person = new Person();
    person.setName("zhang3");

    changeName(person);    //傳遞person對象
    System.out.println(person);    //重寫了person的toString方法
}

void changeName(Person person){
    person.setName("li4");    //方法內部修改了name屬性
}

程序並不複雜，輸出結果中：

name=li4

這不難解釋，因爲changeName方法中的person和methodK方法中的person指向同一個對象，因此changeName的修改會致使name屬性的變化。

基於此，我猜想問題就出在這裏，因而搜索了業務方法：

##業務類關鍵方法
public void keyMethod(){
    ...
    xBean.setPropertyA(999);
    com.xxx.updateMethod(xBean);    //修改動做
    ...
    xBean.setPropertyA(1);    //真的找到了這貨
}

正所謂「成也參數傳遞，敗也參數傳遞」。
思考一下好像有些不對，由於在切面方法中，一開始就從新修改了xBean對象的引用：

xBean = xBeanMapper.selectByPrimaryKey(xBean.getId());    //查庫，修改了xBean的引用

還用前面的demo模擬，這至關於做了以下修改：

# 對象傳遞demo
void methodK(){
    Person person = new Person();
    person.setName("zhang3");

    changeName(person);    
    System.out.println(person);
}

void changeName(Person person){
    person = new Person();    //修改引用
    person.setName("li4");    
}

執行結果會變成：

name=zhang3

也就是說，隨着changeName方法從新修改了引用指向，導致changeName方法中的person和methodK方法中的person指向不一樣對象，所以changeName不能再改變methodK-person指向的對象了。

這個理論一樣適用於咱們遇到的問題，因此這也不能解釋爲何推送數據發生變化了。

推理3：真正的兇手

不死心的我再次翻看了業務方法：

##業務類關鍵方法
public void keyMethod(){
    ...
    xBean.setPropertyA(999);
    com.xxx.updateMethod(xBean);    //修改動做，觸發切面
    ...
    xBean.setPropertyA(1);    //賦值
}

PropertyA最終被賦值爲1，而切面中最終推送的數據裏PropertyA也等於1。
這有些過於巧合了吧，因而耐着性子再仔細找找：

##業務類關鍵方法
public void keyMethod(){
    ...
    xBean.setPropertyA(999);
    com.xxx.updateMethod(xBean);    //修改動做，觸發切面
    ...
    xBean = xBeanMapper.selectByPrimaryKey(xBean.getId());    //又找到了這個
    ...
    xBean.setPropertyA(1);    
}

業務方法中，調用了和切面中一樣的查詢方法。咱們用的orm框架是mybatis，而mybatis彷佛有個一級緩存？

科普下什麼是mybatis的一級緩存：

• 在同一個sqlsession中，若是某查詢sql已經執行過了，會將結果緩存，再次執行此查詢sql時直接從緩存中獲取結果，以提高性能。（固然，update等操做會做廢一級緩存）

結合spring以後，sqlsession默認會和事務綁定。

那麼狀況應該是這樣的：
代碼中切面先從db中查詢告終果，放入一級緩存中；以後業務邏輯再次執行一樣的sql，因爲緩存中已有結果，直接從緩存中獲取（這裏獲取的對象和切面中相同）。以後業務邏輯從新賦值PropertyA，再以後切面中用另外一個線程推送被修改的對象，完成絕殺。

解決方式簡單粗暴，直接在切面中搞個副本就好：

@After(value = "updatePointcut(record)",argNames = "xBean")
public void afterUpdate(XBean xBean){
    xBean = xBeanMapper.selectByPrimaryKey(xBean.getId());
    
    xBean = BeanUtils.cloneBean(xBean);    //查詢後建立副本

    ThreadManager.executeTask(()-> {
        sendToXSystem(xBean);
    });
}

最後總結一下吧：這是一篇以aop勾引你進來，主打驚悚懸疑，中間夾瑣事務隔離級別、對象參數傳遞和mybatis一級緩存的奇葩文章……