如何優(yōu)雅地記錄操作日志?

操作日志廣泛存在于各個B端和一些C端系統(tǒng)中及志,比如:客服可以根據(jù)工單的操作日志快速知道哪些人對這個工單做了哪些操作,進而快速地定位問題寨腔。操作日志和系統(tǒng)日志不一樣速侈,操作日志必須要做到簡單易懂。所以如何讓操作日志不和業(yè)務(wù)邏輯耦合迫卢,如何讓操作日志的內(nèi)容易于理解倚搬,讓操作日志的接入更加簡單?上面這些都是本文要回答的問題乾蛤,主要圍繞著如何“優(yōu)雅”地記錄操作日志展開描述每界。

1. 操作日志的使用場景

系統(tǒng)日志和操作日志的區(qū)別

系統(tǒng)日志:系統(tǒng)日志主要是為開發(fā)排查問題提供依據(jù),一般打印在日志文件中家卖;系統(tǒng)日志的可讀性要求沒那么高眨层,日志中會包含代碼的信息,比如在某個類的某一行打印了一個日志上荡。

操作日志:主要是對某個對象進行新增操作或者修改操作后記錄下這個新增或者修改趴樱,操作日志要求可讀性比較強,因為它主要是給用戶看的酪捡,比如訂單的物流信息叁征,用戶需要知道在什么時間發(fā)生了什么事情。再比如逛薇,客服對工單的處理記錄信息航揉。

操作日志的記錄格式大概分為下面幾種:

  • 單純的文字記錄,比如:2021-09-16 10:00 訂單創(chuàng)建金刁。

  • 簡單的動態(tài)的文本記錄帅涂,比如:2021-09-16 10:00 訂單創(chuàng)建议薪,訂單號:NO.11089999,其中涉及變量訂單號“NO.11089999”媳友。

  • 修改類型的文本斯议,包含修改前和修改后的值,比如:2021-09-16 10:00 用戶小明修改了訂單的配送地址:從“金燦燦小區(qū)”修改到“銀盞盞小區(qū)” 醇锚,其中涉及變量配送的原地址“金燦燦小區(qū)”和新地址“銀盞盞小區(qū)”哼御。

  • 修改表單,一次會修改多個字段焊唬。

2. 實現(xiàn)方式

2.1 使用 Canal 監(jiān)聽數(shù)據(jù)庫記錄操作日志

Canal 是一款基于 MySQL 數(shù)據(jù)庫增量日志解析恋昼,提供增量數(shù)據(jù)訂閱和消費的開源組件,通過采用監(jiān)聽數(shù)據(jù)庫 Binlog 的方式赶促,這樣可以從底層知道是哪些數(shù)據(jù)做了修改液肌,然后根據(jù)更改的數(shù)據(jù)記錄操作日志。

這種方式的優(yōu)點是和業(yè)務(wù)邏輯完全分離鸥滨。缺點也很明顯嗦哆,局限性太高,只能針對數(shù)據(jù)庫的更改做操作日志記錄婿滓,如果修改涉及到其他團隊的 RPC 的調(diào)用老速,就沒辦法監(jiān)聽數(shù)據(jù)庫了,舉個例子:給用戶發(fā)送通知凸主,通知服務(wù)一般都是公司內(nèi)部的公共組件橘券,這時候只能在調(diào)用 RPC 的時候手工記錄發(fā)送通知的操作日志了。

2.2 通過日志文件的方式記錄

log.info("訂單創(chuàng)建")
log.info("訂單已經(jīng)創(chuàng)建卿吐,訂單編號:{}", orderNo)
log.info("修改了訂單的配送地址:從“{}”修改到“{}”约郁, "金燦燦小區(qū)", "銀盞盞小區(qū)")

這種方式的操作記錄需要解決三個問題。

問題一:操作人如何記錄

借助 SLF4J 中的 MDC 工具類但两,把操作人放在日志中鬓梅,然后在日志中統(tǒng)一打印出來。首先在用戶的攔截器中把用戶的標(biāo)識 Put 到 MDC 中谨湘。

@Component
public class UserInterceptor extends HandlerInterceptorAdapter {
  @Override
  public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
    //獲取到用戶標(biāo)識
    String userNo = getUserNo(request);
    //把用戶 ID 放到 MDC 上下文中
    MDC.put("userId", userNo);
    return super.preHandle(request, response, handler);
  }

  private String getUserNo(HttpServletRequest request) {
    // 通過 SSO 或者Cookie 或者 Auth信息獲取到 當(dāng)前登陸的用戶信息
    return null;
  }
}

其次绽快,把 userId 格式化到日志中,使用 %X{userId} 可以取到 MDC 中用戶標(biāo)識紧阔。

<pattern>"%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %X{userId} %logger{30}.%method:%L - %msg%n"</pattern>

問題二:操作日志如何和系統(tǒng)日志區(qū)分開

通過配置 Log 的配置文件坊罢,把有關(guān)操作日志的 Log 單獨放到一日志文件中。

//不同業(yè)務(wù)日志記錄到不同的文件
<appender name="businessLogAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <File>logs/business.log</File>
    <append>true</append>
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
        <level>INFO</level>
        <onMatch>ACCEPT</onMatch>
        <onMismatch>DENY</onMismatch>
    </filter>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>logs/業(yè)務(wù)A.%d.%i.log</fileNamePattern>
        <maxHistory>90</maxHistory>
        <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
            <maxFileSize>10MB</maxFileSize>
        </timeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
        <pattern>"%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %X{userId} %logger{30}.%method:%L - %msg%n"</pattern>
        <charset>UTF-8</charset>
    </encoder>
</appender>
        
<logger name="businessLog" additivity="false" level="INFO">
    <appender-ref ref="businessLogAppender"/>
</logger>

然后在 Java 代碼中單獨的記錄業(yè)務(wù)日志擅耽。

//記錄特定日志的聲明
private final Logger businessLog = LoggerFactory.getLogger("businessLog");
 
//日志存儲
businessLog.info("修改了配送地址");

問題三:如何生成可讀懂的日志文案

可以采用 LogUtil 的方式活孩,也可以采用切面的方式生成日志模板,后續(xù)內(nèi)容將會進行介紹乖仇。這樣就可以把日志單獨保存在一個文件中憾儒,然后通過日志收集可以把日志保存在 Elasticsearch 或者數(shù)據(jù)庫中询兴,接下來看下如何生成可讀的操作日志。

2.3 通過 LogUtil 的方式記錄日志

  LogUtil.log(orderNo, "訂單創(chuàng)建", "小明")模板
  LogUtil.log(orderNo, "訂單創(chuàng)建起趾,訂單號"+"NO.11089999",  "小明")
  String template = "用戶%s修改了訂單的配送地址:從“%s”修改到“%s”"
  LogUtil.log(orderNo, String.format(tempalte, "小明", "金燦燦小區(qū)", "銀盞盞小區(qū)"),  "小明")

這里解釋下為什么記錄操作日志的時候都綁定了一個 OrderNo诗舰,因為操作日志記錄的是:某一個“時間”“誰”對“什么”做了什么“事情”。當(dāng)查詢業(yè)務(wù)的操作日志的時候训裆,會查詢針對這個訂單的的所有操作眶根,所以代碼中加上了 OrderNo,記錄操作日志的時候需要記錄下操作人边琉,所以傳了操作人“小明”進來属百。

上面看起來問題并不大,在修改地址的業(yè)務(wù)邏輯方法中使用一行代碼記錄了操作日志变姨,接下來再看一個更復(fù)雜的例子:

private OnesIssueDO updateAddress(updateDeliveryRequest request) {
    DeliveryOrder deliveryOrder = deliveryQueryService.queryOldAddress(request.getDeliveryOrderNo());
    // 更新派送信息族扰,電話,收件人钳恕,地址
    doUpdate(request);
    String logContent = getLogContent(request, deliveryOrder);
    LogUtils.logRecord(request.getOrderNo(), logContent, request.getOperator);
    return onesIssueDO;
}

private String getLogContent(updateDeliveryRequest request, DeliveryOrder deliveryOrder) {
    String template = "用戶%s修改了訂單的配送地址:從“%s”修改到“%s”";
    return String.format(tempalte, request.getUserName(), deliveryOrder.getAddress(), request.getAddress);
}

可以看到上面的例子使用了兩個方法代碼,外加一個 getLogContent 的函數(shù)實現(xiàn)了操作日志的記錄蹄衷。當(dāng)業(yè)務(wù)變得復(fù)雜后忧额,記錄操作日志放在業(yè)務(wù)代碼中會導(dǎo)致業(yè)務(wù)的邏輯比較繁雜,最后導(dǎo)致 LogUtils.logRecord() 方法的調(diào)用存在于很多業(yè)務(wù)的代碼中愧口,而且類似 getLogContent() 這樣的方法也散落在各個業(yè)務(wù)類中睦番,對于代碼的可讀性和可維護性來說是一個災(zāi)難。下面介紹下如何避免這個災(zāi)難耍属。

2.4 方法注解實現(xiàn)操作日志

為了解決上面問題托嚣,一般采用 AOP 的方式記錄日志,讓操作日志和業(yè)務(wù)邏輯解耦厚骗,接下來看一個簡單的 AOP 日志的例子示启。

@LogRecord(content="修改了配送地址")
public void modifyAddress(updateDeliveryRequest request){
    // 更新派送信息 電話,收件人领舰、地址
    doUpdate(request);
}

我們可以在注解的操作日志上記錄固定文案夫嗓,這樣業(yè)務(wù)邏輯和業(yè)務(wù)代碼可以做到解耦,讓我們的業(yè)務(wù)代碼變得純凈起來冲秽∩峥В可能有同學(xué)注意到,上面的方式雖然解耦了操作日志的代碼锉桑,但是記錄的文案并不符合我們的預(yù)期排霉,文案是靜態(tài)的,沒有包含動態(tài)的文案民轴,因為我們需要記錄的操作日志是: 用戶%s修改了訂單的配送地址攻柠,從“%s”修改到“%s”球订。接下來,我們介紹一下如何優(yōu)雅地使用 AOP 生成動態(tài)的操作日志辙诞。

3. 優(yōu)雅地支持 AOP 生成動態(tài)的操作日志

3.1 動態(tài)模板

一提到動態(tài)模板辙售,就會涉及到讓變量通過占位符的方式解析模板,從而達到通過注解記錄操作日志的目的飞涂。模板解析的方式有很多種旦部,這里使用了 SpEL(Spring Expression Language,Spring表達式語言)來實現(xiàn)较店。我們可以先寫下期望的記錄日志的方式士八,然后再看下能否實現(xiàn)這樣的功能梁呈。

@LogRecord(content = "修改了訂單的配送地址:從“#oldAddress”, 修改到“#request.address”")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // 更新派送信息 電話,收件人、地址
    doUpdate(request);
}

通過 SpEL 表達式引用方法上的參數(shù),可以讓變量填充到模板中達到動態(tài)的操作日志文本內(nèi)容。 但是現(xiàn)在還有幾個問題需要解決:

  • 操作日志需要知道是哪個操作人修改的訂單配送地址。

  • 修改訂單配送地址的操作日志需要綁定在配送的訂單上,從而可以根據(jù)配送訂單號查詢出對這個配送訂單的所有操作。

  • 為了在注解上記錄之前的配送地址是什么阶捆,在方法簽名上添加了一個和業(yè)務(wù)無關(guān)的 oldAddress 的變量倍奢,這樣就不優(yōu)雅了叼架。

為了解決前兩個問題,我們需要把期望的操作日志使用形式改成下面的方式:

@LogRecord(
     content = "修改了訂單的配送地址:從“#oldAddress”, 修改到“#request.address”",
     operator = "#request.userName", bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // 更新派送信息 電話哥遮,收件人返咱、地址
    doUpdate(request);
}

修改后的代碼在注解上添加兩個參數(shù)牍鞠,一個是操作人,一個是操作日志需要綁定的對象萤晴。但是屯断,在普通的 Web 應(yīng)用中用戶信息都是保存在一個線程上下文的靜態(tài)方法中氧秘,所以 operator 一般是這樣的寫法(假定獲取當(dāng)前登陸用戶的方式是 UserContext.getCurrentUser())。

operator = "#{T(com.meituan.user.UserContext).getCurrentUser()}"

這樣的話趴久,每個 @LogRecord 的注解上的操作人都是這么長一串丸相。為了避免過多的重復(fù)代碼,我們可以把注解上的 operator 參數(shù)設(shè)置為非必填彼棍,這樣用戶可以填寫操作人灭忠。但是,如果用戶不填寫我們就取 UserContext 的 user(下文會介紹如何取 user )滥酥。最后更舞,最簡單的日志變成了下面的形式:

@LogRecord(content = "修改了訂單的配送地址:從“#oldAddress”, 修改到“#request.address”", 
           bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // 更新派送信息 電話,收件人坎吻、地址
    doUpdate(request);
}

接下來缆蝉,我們需要解決第三個問題:為了記錄業(yè)務(wù)操作記錄添加了一個 oldAddress 變量,不管怎么樣這都不是一個好的實現(xiàn)方式瘦真,所以接下來刊头,我們需要把 oldAddress 變量從修改地址的方法簽名上去掉。但是操作日志確實需要 oldAddress 變量诸尽,怎么辦呢原杂?

要么和產(chǎn)品經(jīng)理 PK 一下,讓產(chǎn)品經(jīng)理把文案從“修改了訂單的配送地址:從 xx 修改到 yy” 改為 “修改了訂單的配送地址為:yy”您机。但是從用戶體驗上來看穿肄,第一種文案更人性化一些,顯然我們不會 PK 成功的际看。那么我們就必須要把這個 oldAddress 查詢出來然后供操作日志使用了咸产。還有一種解決辦法是:把這個參數(shù)放到操作日志的線程上下文中,供注解上的模板使用仲闽。我們按照這個思路再改下操作日志的實現(xiàn)代碼脑溢。

@LogRecord(content = "修改了訂單的配送地址:從“#oldAddress”, 修改到“#request.address”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什么
    LogRecordContext.putVariable("oldAddress", DeliveryService.queryOldAddress(request.getDeliveryOrderNo()));
    // 更新派送信息 電話,收件人赖欣、地址
    doUpdate(request);
}

這時候可以看到屑彻,LogRecordContext 解決了操作日志模板上使用方法參數(shù)以外變量的問題,同時避免了為了記錄操作日志修改方法簽名的設(shè)計顶吮。雖然已經(jīng)比之前的代碼好了些社牲,但是依然需要在業(yè)務(wù)代碼里面加了一行業(yè)務(wù)邏輯無關(guān)的代碼,如果有“強迫癥”的同學(xué)還可以繼續(xù)往下看悴了,接下來我們會講解自定義函數(shù)的解決方案搏恤。下面再看另一個例子:

@LogRecord(content = "修改了訂單的配送員:從“#oldDeliveryUserId”, 修改到“#request.userId”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什么
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話汗菜,收件人、地址
    doUpdate(request);
}

這個操作日志的模板最后記錄的內(nèi)容是這樣的格式:修改了訂單的配送員:從 “10090”挑社,修改到 “10099”陨界,顯然用戶看到這樣的操作日志是不明白的。用戶對于用戶 ID 是 10090 還是 10099 并不了解痛阻,用戶期望看到的是:修改了訂單的配送員:從“張三(18910008888)”菌瘪,修改到“小明(13910006666)”。用戶關(guān)心的是配送員的姓名和電話阱当。但是我們方法中傳遞的參數(shù)只有配送員的 ID俏扩,沒有配送員的姓名可電話。我們可以通過上面的方法弊添,把用戶的姓名和電話查詢出來录淡,然后通過 LogRecordContext 實現(xiàn)。

但是油坝,“強迫癥”是不期望操作日志的代碼嵌入在業(yè)務(wù)邏輯中的嫉戚。接下來,我們考慮另一種實現(xiàn)方式:自定義函數(shù)澈圈。如果我們可以通過自定義函數(shù)把用戶 ID 轉(zhuǎn)換為用戶姓名和電話彬檀,那么就能解決這一問題,按照這個思路瞬女,我們把模板修改為下面的形式:

@LogRecord(content = "修改了訂單的配送員:從“{deliveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.userId}}”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什么
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話窍帝,收件人、地址
    doUpdate(request);
}

其中 deliveryUser 是自定義函數(shù)诽偷,使用大括號把 Spring 的 SpEL 表達式包裹起來坤学,這樣做的好處:一是把 SpEL(Spring Expression Language,Spring表達式語言)和自定義函數(shù)區(qū)分開便于解析报慕;二是如果模板中不需要 SpEL 表達式解析可以容易的識別出來深浮,減少 SpEL 的解析提高性能。這時候我們發(fā)現(xiàn)上面代碼還可以優(yōu)化成下面的形式:

@LogRecord(content = "修改了訂單的配送員:從“{queryOldUser{#request.deliveryOrderNo()}}”, 修改到“{deveryUser{#request.userId}}”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 更新派送信息 電話卖子,收件人略号、地址
    doUpdate(request);
}

這樣就不需要在 modifyAddress 方法中通過 LogRecordContext.putVariable() 設(shè)置老的快遞員了刑峡,通過直接新加一個自定義函數(shù) queryOldUser() 參數(shù)把派送訂單傳遞進去洋闽,就能查到之前的配送人了,只需要讓方法的解析在 modifyAddress() 方法執(zhí)行之前運行橱鹏。這樣的話搭幻,我們讓業(yè)務(wù)代碼又變得純凈了起來鲁森,同時也讓“強迫癥”不再感到難受了。

4. 代碼實現(xiàn)解析

4.1 代碼結(jié)構(gòu)

上面的操作日志主要是通過一個 AOP 攔截器實現(xiàn)的刊懈,整體主要分為 AOP 模塊、日志解析模塊、日志保存模塊虚汛、Starter 模塊匾浪;組件提供了4個擴展點,分別是:自定義函數(shù)卷哩、默認處理人蛋辈、業(yè)務(wù)保存和查詢;業(yè)務(wù)可以根據(jù)自己的業(yè)務(wù)特性定制符合自己業(yè)務(wù)的邏輯将谊。

4.2 模塊介紹

有了上面的分析冷溶,已經(jīng)得出一種我們期望的操作日志記錄的方式,那么接下來看看如何實現(xiàn)上面的邏輯尊浓。實現(xiàn)主要分為下面幾個步驟:

  • AOP 攔截邏輯

  • 解析邏輯

  • 模板解析

  • LogContext 邏輯

  • 默認的 operator 邏輯

  • 自定義函數(shù)邏輯

  • 默認的日志持久化邏輯

  • Starter 封裝邏輯

4.2.1 AOP 攔截邏輯

這塊邏輯主要是一個攔截器逞频,針對 @LogRecord 注解分析出需要記錄的操作日志,然后把操作日志持久化栋齿,這里把注解命名為 @LogRecordAnnotation苗胀。接下來,我們看下注解的定義:

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Inherited
@Documented
public @interface LogRecordAnnotation {
    String success();

    String fail() default "";

    String operator() default "";

    String bizNo();

    String category() default "";

    String detail() default "";

    String condition() default "";
}

注解中除了上面提到參數(shù)外瓦堵,還增加了 fail柒巫、category、detail谷丸、condition 等參數(shù)堡掏,這幾個參數(shù)是為了滿足特定的場景,后面還會給出具體的例子刨疼。


為了保持簡單泉唁,組件的必填參數(shù)就兩個。業(yè)務(wù)中的 AOP 邏輯大部分是使用 @Aspect 注解實現(xiàn)的揩慕,但是基于注解的 AOP 在 Spring boot 1.5 中兼容性是有問題的亭畜,組件為了兼容 Spring boot1.5 的版本我們手工實現(xiàn) Spring 的 AOP 邏輯。


切面選擇 AbstractBeanFactoryPointcutAdvisor 實現(xiàn)迎卤,切點是通過 StaticMethodMatcherPointcut 匹配包含 LogRecordAnnotation 注解的方法拴鸵。通過實現(xiàn) MethodInterceptor 接口實現(xiàn)操作日志的增強邏輯。

下面是攔截器的切點邏輯:

public class LogRecordPointcut extends StaticMethodMatcherPointcut implements Serializable {
    // LogRecord的解析類
    private LogRecordOperationSource logRecordOperationSource;
    
    @Override
    public boolean matches(@NonNull Method method, @NonNull Class<?> targetClass) {
          // 解析 這個 method 上有沒有 @LogRecordAnnotation 注解蜗搔,有的話會解析出來注解上的各個參數(shù)
        return !CollectionUtils.isEmpty(logRecordOperationSource.computeLogRecordOperations(method, targetClass));
    }

    void setLogRecordOperationSource(LogRecordOperationSource logRecordOperationSource) {
        this.logRecordOperationSource = logRecordOperationSource;
    }
}

切面的增強邏輯主要代碼如下:

@Override
public Object invoke(MethodInvocation invocation) throws Throwable {
    Method method = invocation.getMethod();
    // 記錄日志
    return execute(invocation, invocation.getThis(), method, invocation.getArguments());
}

private Object execute(MethodInvocation invoker, Object target, Method method, Object[] args) throws Throwable {
    Class<?> targetClass = getTargetClass(target);
    Object ret = null;
    MethodExecuteResult methodExecuteResult = new MethodExecuteResult(true, null, "");
    LogRecordContext.putEmptySpan();
    Collection<LogRecordOps> operations = new ArrayList<>();
    Map<String, String> functionNameAndReturnMap = new HashMap<>();
    try {
        operations = logRecordOperationSource.computeLogRecordOperations(method, targetClass);
        List<String> spElTemplates = getBeforeExecuteFunctionTemplate(operations);
        //業(yè)務(wù)邏輯執(zhí)行前的自定義函數(shù)解析
        functionNameAndReturnMap = processBeforeExecuteFunctionTemplate(spElTemplates, targetClass, method, args);
    } catch (Exception e) {
        log.error("log record parse before function exception", e);
    }
    try {
        ret = invoker.proceed();
    } catch (Exception e) {
        methodExecuteResult = new MethodExecuteResult(false, e, e.getMessage());
    }
    try {
        if (!CollectionUtils.isEmpty(operations)) {
            recordExecute(ret, method, args, operations, targetClass,
                    methodExecuteResult.isSuccess(), methodExecuteResult.getErrorMsg(), functionNameAndReturnMap);
        }
    } catch (Exception t) {
        //記錄日志錯誤不要影響業(yè)務(wù)
        log.error("log record parse exception", t);
    } finally {
        LogRecordContext.clear();
    }
    if (methodExecuteResult.throwable != null) {
        throw methodExecuteResult.throwable;
    }
    return ret;
}

攔截邏輯的流程:


可以看到劲藐,操作日志的記錄持久化是在方法執(zhí)行完之后執(zhí)行的,當(dāng)方法拋出異常之后會先捕獲異常樟凄,等操作日志持久化完成后再拋出異常聘芜。在業(yè)務(wù)的方法執(zhí)行之前,會對提前解析的自定義函數(shù)求值缝龄,解決了前面提到的需要查詢修改之前的內(nèi)容汰现。

4.2.2 解析邏輯

模板解析

Spring 3 提供了一個非常強大的功能:Spring EL挂谍,SpEL 在 Spring 產(chǎn)品中是作為表達式求值的核心基礎(chǔ)模塊,它本身是可以脫離 Spring 獨立使用的瞎饲。舉個例子:

public static void main(String[] args) {
        SpelExpressionParser parser = new SpelExpressionParser();
        Expression expression = parser.parseExpression("#root.purchaseName");
        Order order = new Order();
        order.setPurchaseName("張三");
        System.out.println(expression.getValue(order));
}

這個方法將打印 “張三”口叙。LogRecord 解析的類圖如下:


解析核心類:LogRecordValueParser 里面封裝了自定義函數(shù)和 SpEL 解析類 LogRecordExpressionEvaluator。

public class LogRecordExpressionEvaluator extends CachedExpressionEvaluator {

    private Map<ExpressionKey, Expression> expressionCache = new ConcurrentHashMap<>(64);

    private final Map<AnnotatedElementKey, Method> targetMethodCache = new ConcurrentHashMap<>(64);

    public String parseExpression(String conditionExpression, AnnotatedElementKey methodKey, EvaluationContext evalContext) {
        return getExpression(this.expressionCache, methodKey, conditionExpression).getValue(evalContext, String.class);
    }
}

LogRecordExpressionEvaluator 繼承自 CachedExpressionEvaluator 類嗅战,這個類里面有兩個 Map庐扫,一個是 expressionCache 一個是 targetMethodCache。在上面的例子中可以看到仗哨,SpEL 會解析成一個 Expression 表達式形庭,然后根據(jù)傳入的 Object 獲取到對應(yīng)的值,所以 expressionCache 是為了緩存方法厌漂、表達式和 SpEL 的 Expression 的對應(yīng)關(guān)系萨醒,讓方法注解上添加的 SpEL 表達式只解析一次。 下面的 targetMethodCache 是為了緩存?zhèn)魅氲?Expression 表達式的 Object苇倡。核心的解析邏輯是上面最后一行代碼富纸。

getExpression(this.expressionCache, methodKey, conditionExpression).getValue(evalContext, String.class);

getExpression 方法會從 expressionCache 中獲取到 @LogRecordAnnotation 注解上的表達式的解析 Expression 的實例,然后調(diào)用 getValue 方法旨椒,getValue 傳入一個 evalContext 就是類似上面例子中的 order 對象晓褪。其中 Context 的實現(xiàn)將會在下文介紹。

日志上下文實現(xiàn)

下面的例子把變量放到了 LogRecordContext 中综慎,然后 SpEL 表達式就可以順利的解析方法上不存在的參數(shù)了涣仿,通過上面的 SpEL 的例子可以看出,要把方法的參數(shù)和 LogRecordContext 中的變量都放到 SpEL 的 getValue 方法的 Object 中才可以順利的解析表達式的值示惊。下面看下如何實現(xiàn):

@LogRecord(content = "修改了訂單的配送員:從“{deveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.getUserId()}}”",
            bizNo="#request.getDeliveryOrderNo()")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什么
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話好港,收件人、地址
    doUpdate(request);
}

在 LogRecordValueParser 中創(chuàng)建了一個 EvaluationContext米罚,用來給 SpEL 解析方法參數(shù)和 Context 中的變量钧汹。相關(guān)代碼如下:


EvaluationContext evaluationContext = expressionEvaluator.createEvaluationContext(method, args, targetClass, ret, errorMsg, beanFactory);

在解析的時候調(diào)用 getValue 方法傳入的參數(shù) evalContext,就是上面這個 EvaluationContext 對象录择。下面是 LogRecordEvaluationContext 對象的繼承體系:

LogRecordEvaluationContext 做了三個事情:

  • 把方法的參數(shù)都放到 SpEL 解析的 RootObject 中拔莱。
  • 把 LogRecordContext 中的變量都放到 RootObject 中。
  • 把方法的返回值和 ErrorMsg 都放到 RootObject 中隘竭。

LogRecordEvaluationContext 的代碼如下:

public class LogRecordEvaluationContext extends MethodBasedEvaluationContext {

    public LogRecordEvaluationContext(Object rootObject, Method method, Object[] arguments,
                                      ParameterNameDiscoverer parameterNameDiscoverer, Object ret, String errorMsg) {
       //把方法的參數(shù)都放到 SpEL 解析的 RootObject 中
       super(rootObject, method, arguments, parameterNameDiscoverer);
       //把 LogRecordContext 中的變量都放到 RootObject 中
        Map<String, Object> variables = LogRecordContext.getVariables();
        if (variables != null && variables.size() > 0) {
            for (Map.Entry<String, Object> entry : variables.entrySet()) {
                setVariable(entry.getKey(), entry.getValue());
            }
        }
        //把方法的返回值和 ErrorMsg 都放到 RootObject 中
        setVariable("_ret", ret);
        setVariable("_errorMsg", errorMsg);
    }
}

下面是 LogRecordContext 的實現(xiàn)塘秦,這個類里面通過一個 ThreadLocal 變量保持了一個棧,棧里面是個 Map货裹,Map 對應(yīng)了變量的名稱和變量的值嗤形。

public class LogRecordContext {

    private static final InheritableThreadLocal<Stack<Map<String, Object>>> variableMapStack = new InheritableThreadLocal<>();
   //其他省略....
}

上面使用了 InheritableThreadLocal精偿,所以在線程池的場景下使用 LogRecordContext 會出現(xiàn)問題弧圆,如果支持線程池可以使用阿里巴巴開源的 TTL 框架赋兵。那這里為什么不直接設(shè)置一個 ThreadLocal<Map<String, Object>> 對象,而是要設(shè)置一個 Stack 結(jié)構(gòu)呢搔预?我們看一下這么做的原因是什么霹期。

@LogRecord(content = "修改了訂單的配送員:從“{deveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.getUserId()}}”",
        bizNo="#request.getDeliveryOrderNo()")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什么
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話,收件人拯田、地址
    doUpdate(request);
}

上面代碼的執(zhí)行流程如下:

看起來沒有什么問題历造,但是使用 LogRecordAnnotation 的方法里面嵌套了另一個使用 LogRecordAnnotation 方法的時候,流程就變成下面的形式:

可以看到船庇,當(dāng)方法二執(zhí)行了釋放變量后吭产,繼續(xù)執(zhí)行方法一的 logRecord 邏輯,此時解析的時候 ThreadLocal<Map<String, Object>>的 Map 已經(jīng)被釋放掉鸭轮,所以方法一就獲取不到對應(yīng)的變量了臣淤。方法一和方法二共用一個變量 Map 還有個問題是:如果方法二設(shè)置了和方法一相同的變量兩個方法的變量就會被相互覆蓋。所以最終 LogRecordContext 的變量的生命周期需要是下面的形式:

LogRecordContext 每執(zhí)行一個方法都會壓棧一個 Map窃爷,方法執(zhí)行完之后會 Pop <typo id="typo-18122" data-origin="掉" ignoretag="true">掉</typo>這個 Map邑蒋,從而避免變量共享和覆蓋問題。

默認操作人邏輯

在 LogRecordInterceptor 中 IOperatorGetService 接口按厘,這個接口可以獲取到當(dāng)前的用戶医吊。下面是接口的定義:

public interface IOperatorGetService {

    /**
     * 可以在里面外部的獲取當(dāng)前登陸的用戶,比如 UserContext.getCurrentUser()
     *
     * @return 轉(zhuǎn)換成Operator返回
     */
    Operator getUser();
}

下面給出了從用戶上下文中獲取用戶的例子:

public class DefaultOperatorGetServiceImpl implements IOperatorGetService {

    @Override
    public Operator getUser() {
    //UserUtils 是獲取用戶上下文的方法
         return Optional.ofNullable(UserUtils.getUser())
                        .map(a -> new Operator(a.getName(), a.getLogin()))
                        .orElseThrow(()->new IllegalArgumentException("user is null"));

    }
}

組件在解析 operator 的時候逮京,就判斷注解上的 operator 是否是空卿堂,如果注解上沒有指定,我們就從 IOperatorGetService 的 getUser 方法獲取了懒棉。如果都獲取不到御吞,就會報錯。

String realOperatorId = "";
if (StringUtils.isEmpty(operatorId)) {
    if (operatorGetService.getUser() == null || StringUtils.isEmpty(operatorGetService.getUser().getOperatorId())) {
        throw new IllegalArgumentException("user is null");
    }
    realOperatorId = operatorGetService.getUser().getOperatorId();
} else {
    spElTemplates = Lists.newArrayList(bizKey, bizNo, action, operatorId, detail);
}

自定義函數(shù)邏輯

自定義函數(shù)的類圖如下:

下面是 IParseFunction 的接口定義:executeBefore 函數(shù)代表了自定義函數(shù)是否在業(yè)務(wù)代碼執(zhí)行之前解析漓藕,上面提到的查詢修改之前的內(nèi)容陶珠。

public interface IParseFunction {

  default boolean executeBefore(){
    return false;
  }

  String functionName();

  String apply(String value);
}

ParseFunctionFactory 的代碼比較簡單,它的功能是把所有的 IParseFunction 注入到函數(shù)工廠中享钞。

public class ParseFunctionFactory {
  private Map<String, IParseFunction> allFunctionMap;

  public ParseFunctionFactory(List<IParseFunction> parseFunctions) {
    if (CollectionUtils.isEmpty(parseFunctions)) {
      return;
    }
    allFunctionMap = new HashMap<>();
    for (IParseFunction parseFunction : parseFunctions) {
      if (StringUtils.isEmpty(parseFunction.functionName())) {
        continue;
      }
      allFunctionMap.put(parseFunction.functionName(), parseFunction);
    }
  }

  public IParseFunction getFunction(String functionName) {
    return allFunctionMap.get(functionName);
  }

  public boolean isBeforeFunction(String functionName) {
    return allFunctionMap.get(functionName) != null && allFunctionMap.get(functionName).executeBefore();
  }
}

DefaultFunctionServiceImpl 的邏輯就是根據(jù)傳入的函數(shù)名稱 functionName 找到對應(yīng)的 IParseFunction揍诽,然后把參數(shù)傳入到 IParseFunction 的 apply 方法上最后返回函數(shù)的值。

public class DefaultFunctionServiceImpl implements IFunctionService {

  private final ParseFunctionFactory parseFunctionFactory;

  public DefaultFunctionServiceImpl(ParseFunctionFactory parseFunctionFactory) {
    this.parseFunctionFactory = parseFunctionFactory;
  }

  @Override
  public String apply(String functionName, String value) {
    IParseFunction function = parseFunctionFactory.getFunction(functionName);
    if (function == null) {
      return value;
    }
    return function.apply(value);
  }

  @Override
  public boolean beforeFunction(String functionName) {
    return parseFunctionFactory.isBeforeFunction(functionName);
  }
}

4.2.3 日志持久化邏輯

同樣在 LogRecordInterceptor 的代碼中引用了 ILogRecordService栗竖,這個 Service 主要包含了日志記錄的接口暑脆。

public interface ILogRecordService {
    /**
     * 保存 log
     *
     * @param logRecord 日志實體
     */
    void record(LogRecord logRecord);

}

業(yè)務(wù)可以實現(xiàn)這個保存接口,然后把日志保存在任何存儲介質(zhì)上狐肢。這里給了一個 2.2 節(jié)介紹的通過 log.info 保存在日志文件中的例子添吗,業(yè)務(wù)可以把保存設(shè)置成異步或者同步,可以和業(yè)務(wù)放在一個事務(wù)中保證操作日志和業(yè)務(wù)的一致性份名,也可以新開辟一個事務(wù)碟联,保證日志的錯誤不影響業(yè)務(wù)的事務(wù)妓美。業(yè)務(wù)可以保存在 Elasticsearch、數(shù)據(jù)庫或者文件中鲤孵,用戶可以根據(jù)日志結(jié)構(gòu)和日志的存儲實現(xiàn)相應(yīng)的查詢邏輯壶栋。

@Slf4j
public class DefaultLogRecordServiceImpl implements ILogRecordService {

    @Override
//    @Transactional(propagation = Propagation.REQUIRES_NEW)
    public void record(LogRecord logRecord) {
        log.info("【logRecord】log={}", logRecord);
    }
}

4.2.4 Starter 邏輯封裝

上面邏輯代碼已經(jīng)介紹完畢,那么接下來需要把這些組件組裝起來普监,然后讓用戶去使用贵试。在使用這個組件的時候只需要在 Springboot 的入口上添加一個注解 @EnableLogRecord(tenant = "com.mzt.test")。其中 tenant 代表租戶凯正,是為了多租戶使用的毙玻。

@SpringBootApplication(exclude = DataSourceAutoConfiguration.class)
@EnableTransactionManagement
@EnableLogRecord(tenant = "com.mzt.test")
public class Main {

    public static void main(String[] args) {
        SpringApplication.run(Main.class, args);
    }
}

再看下 EnableLogRecord 的代碼,代碼中 Import 了 LogRecordConfigureSelector.class廊散,在 LogRecordConfigureSelector 類中暴露了 LogRecordProxyAutoConfiguration 類淆珊。

@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Documented
@Import(LogRecordConfigureSelector.class)
public @interface EnableLogRecord {

    String tenant();

    AdviceMode mode() default AdviceMode.PROXY;
}

LogRecordProxyAutoConfiguration 就是裝配上面組件的核心類了,代碼如下:

@Configuration
@Slf4j
public class LogRecordProxyAutoConfiguration implements ImportAware {

  private AnnotationAttributes enableLogRecord;

  @Bean
  @Role(BeanDefinition.ROLE_INFRASTRUCTURE)
  public LogRecordOperationSource logRecordOperationSource() {
    return new LogRecordOperationSource();
  }

  @Bean
  @ConditionalOnMissingBean(IFunctionService.class)
  public IFunctionService functionService(ParseFunctionFactory parseFunctionFactory) {
    return new DefaultFunctionServiceImpl(parseFunctionFactory);
  }

  @Bean
  public ParseFunctionFactory parseFunctionFactory(@Autowired List<IParseFunction> parseFunctions) {
    return new ParseFunctionFactory(parseFunctions);
  }

  @Bean
  @ConditionalOnMissingBean(IParseFunction.class)
  public DefaultParseFunction parseFunction() {
    return new DefaultParseFunction();
  }

  @Bean
  @Role(BeanDefinition.ROLE_INFRASTRUCTURE)
  public BeanFactoryLogRecordAdvisor logRecordAdvisor(IFunctionService functionService) {
    BeanFactoryLogRecordAdvisor advisor =
            new BeanFactoryLogRecordAdvisor();
    advisor.setLogRecordOperationSource(logRecordOperationSource());
    advisor.setAdvice(logRecordInterceptor(functionService));
    return advisor;
  }

  @Bean
  @Role(BeanDefinition.ROLE_INFRASTRUCTURE)
  public LogRecordInterceptor logRecordInterceptor(IFunctionService functionService) {
    LogRecordInterceptor interceptor = new LogRecordInterceptor();
    interceptor.setLogRecordOperationSource(logRecordOperationSource());
    interceptor.setTenant(enableLogRecord.getString("tenant"));
    interceptor.setFunctionService(functionService);
    return interceptor;
  }

  @Bean
  @ConditionalOnMissingBean(IOperatorGetService.class)
  @Role(BeanDefinition.ROLE_APPLICATION)
  public IOperatorGetService operatorGetService() {
    return new DefaultOperatorGetServiceImpl();
  }

  @Bean
  @ConditionalOnMissingBean(ILogRecordService.class)
  @Role(BeanDefinition.ROLE_APPLICATION)
  public ILogRecordService recordService() {
    return new DefaultLogRecordServiceImpl();
  }

  @Override
  public void setImportMetadata(AnnotationMetadata importMetadata) {
    this.enableLogRecord = AnnotationAttributes.fromMap(
            importMetadata.getAnnotationAttributes(EnableLogRecord.class.getName(), false));
    if (this.enableLogRecord == null) {
      log.info("@EnableCaching is not present on importing class");
    }
  }
}

這個類繼承 ImportAware 是為了拿到 EnableLogRecord 上的租戶屬性奸汇,這個類使用變量 logRecordAdvisor 和 logRecordInterceptor 裝配了 AOP施符,同時把自定義函數(shù)注入到了 logRecordAdvisor 中。

對外擴展類:分別是IOperatorGetService擂找、ILogRecordService戳吝、IParseFunction。業(yè)務(wù)可以自己實現(xiàn)相應(yīng)的接口贯涎,因為配置了 @ConditionalOnMissingBean听哭,所以用戶的實現(xiàn)類會覆蓋組件內(nèi)的默認實現(xiàn)。

5. 總結(jié)

這篇文章介紹了操作日志的常見寫法塘雳,以及如何讓操作日志的實現(xiàn)更加簡單陆盘、易懂;通過組件的四個模塊败明,介紹了組件的具體實現(xiàn)隘马。

6. 參考資料

  • Canal
  • spring-framework
  • Spring Expression Language (SpEL)
  • ThreadLocal、InheritableThreadLocal妻顶、TransmittableThreadLocal三者之間區(qū)別
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末酸员,一起剝皮案震驚了整個濱河市,隨后出現(xiàn)的幾起案子讳嘱,更是在濱河造成了極大的恐慌幔嗦,老刑警劉巖,帶你破解...
    沈念sama閱讀 216,402評論 6 499
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件沥潭,死亡現(xiàn)場離奇詭異邀泉,居然都是意外死亡,警方通過查閱死者的電腦和手機,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 92,377評論 3 392
  • 文/潘曉璐 我一進店門汇恤,熙熙樓的掌柜王于貴愁眉苦臉地迎上來庞钢,“玉大人,你說我怎么就攤上這事屁置『缚洌” “怎么了仁连?”我有些...
    開封第一講書人閱讀 162,483評論 0 353
  • 文/不壞的土叔 我叫張陵蓝角,是天一觀的道長。 經(jīng)常有香客問我饭冬,道長使鹅,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,165評論 1 292
  • 正文 為了忘掉前任昌抠,我火速辦了婚禮患朱,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘炊苫。我一直安慰自己裁厅,他們只是感情好,可當(dāng)我...
    茶點故事閱讀 67,176評論 6 388
  • 文/花漫 我一把揭開白布侨艾。 她就那樣靜靜地躺著执虹,像睡著了一般。 火紅的嫁衣襯著肌膚如雪唠梨。 梳的紋絲不亂的頭發(fā)上袋励,一...
    開封第一講書人閱讀 51,146評論 1 297
  • 那天,我揣著相機與錄音当叭,去河邊找鬼茬故。 笑死,一個胖子當(dāng)著我的面吹牛蚁鳖,可吹牛的內(nèi)容都是我干的磺芭。 我是一名探鬼主播,決...
    沈念sama閱讀 40,032評論 3 417
  • 文/蒼蘭香墨 我猛地睜開眼醉箕,長吁一口氣:“原來是場噩夢啊……” “哼徘跪!你這毒婦竟也來了?” 一聲冷哼從身側(cè)響起琅攘,我...
    開封第一講書人閱讀 38,896評論 0 274
  • 序言:老撾萬榮一對情侶失蹤垮庐,失蹤者是張志新(化名)和其女友劉穎,沒想到半個月后坞琴,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體哨查,經(jīng)...
    沈念sama閱讀 45,311評論 1 310
  • 正文 獨居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點故事閱讀 37,536評論 2 332
  • 正文 我和宋清朗相戀三年剧辐,在試婚紗的時候發(fā)現(xiàn)自己被綠了寒亥。 大學(xué)時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片邮府。...
    茶點故事閱讀 39,696評論 1 348
  • 序言:一個原本活蹦亂跳的男人離奇死亡,死狀恐怖溉奕,靈堂內(nèi)的尸體忽然破棺而出褂傀,到底是詐尸還是另有隱情,我是刑警寧澤加勤,帶...
    沈念sama閱讀 35,413評論 5 343
  • 正文 年R本政府宣布仙辟,位于F島的核電站,受9級特大地震影響鳄梅,放射性物質(zhì)發(fā)生泄漏叠国。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點故事閱讀 41,008評論 3 325
  • 文/蒙蒙 一戴尸、第九天 我趴在偏房一處隱蔽的房頂上張望粟焊。 院中可真熱鬧,春花似錦孙蒙、人聲如沸项棠。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,659評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽香追。三九已至,卻和暖如春浑测,著一層夾襖步出監(jiān)牢的瞬間翅阵,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 32,815評論 1 269
  • 我被黑心中介騙來泰國打工迁央, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留掷匠,地道東北人。 一個月前我還...
    沈念sama閱讀 47,698評論 2 368
  • 正文 我出身青樓岖圈,卻偏偏與公主長得像讹语,于是被迫代替她去往敵國和親。 傳聞我的和親對象是個殘疾皇子蜂科,可洞房花燭夜當(dāng)晚...
    茶點故事閱讀 44,592評論 2 353

推薦閱讀更多精彩內(nèi)容