技術標籤：controller呼叫controller

引言

優雅的API設計不僅僅是程式碼層面的書寫規範.幾乎不可能API開發完畢就能正常投入使用,更多的是對細節的打磨.例如介面的每次執行時間,入參都會在API測試中反覆的推敲

思考

如何設計一個方案使開發者能一目瞭然的視覺化介面的處理時間以及入參是否正確呢?

思路

首先想到的是Spring的AOP切面,現在我們編寫API介面,一般都會把介面寫在controller控制層裡,按照不同的業務,分為寫在不同業務包下的controller類中.大致的架構如下:

按照這種控制層的編寫規範,只需要用切面找到每個業務包下的controller類,監控類下面的每個方法的入參和執行時間,列印在log日誌中便可以在控制檯中視覺化每個介面的實時狀態了.

實踐

導包

org.springframework.boot    spring-boot-starter-weborg.springframework.boot    spring-boot-starter-aop複製程式碼

AOP核心

aop的核心在於切點和通知型別.結合我們所需要實現的方案,我們所關注的切點就是每個業務下控制層包的每個類方法. 通知的主要型別分為:

• 前置通知[Before advice]：在連線點前面執行，前置通知不會影響連線點的執行，除非此處丟擲異常。
• 正常返回通知[After returning advice]：在連線點正常執行完成後執行，如果連線點丟擲異常，則不會執行。
• 異常返回通知[After throwing advice]：在連線點丟擲異常後執行。
• 返回通知[After (finally) advice]：在連線點執行完成後執行，不管是正常執行完成，還是丟擲異常，都會執行返回通知中的內容。
• 環繞通知[Around advice]：環繞通知圍繞在連線點前後，比如一個方法呼叫的前後。這是最強大的通知型別，能在方法呼叫前後自定義一些操作。環繞通知還需要負責決定是繼續處理join point(呼叫ProceedingJoinPoint的proceed方法)還是中斷執行。

這裡因為我們需要記錄入參和介面處理時間,選用Before 前置通知和Around 環繞通知

定義切點

切面第一步,我們需要找準切點 新建RuntimeMethod類,用@Aspect @Component修飾定義這是由spring管理的切面入口類,@Log4j2 註釋方便後續列印日誌

@[email protected]@Log4j2public class RuntimeMethod {    //定義aopPoint私有方法,用@Pointcut修飾並標識該切面的切點    //以execution(* com.staging.business.*.controller.*.*(..))為例    //execution()是切面的主體    //第一個" * "符號,表示返回值的型別任意    //com.staging.business表示AOP所切的服務的包名,即需要進行橫切的業務類    //包名後面的" .. ",表示當前包及子包    //之後的" * ",表示類名，*即所有類    // .*(..) 表示任何方法名,括號內表示引數,兩個點表示匹配任何引數型別    @Pointcut("execution(* com.staging.business.*.controller.*.*(..))")    private void aopPoint() {    } }複製程式碼

切面第二步,定義前置和環繞通知,並宣告通知的切點為aopPoint()

    /**     * 功能描述: 前置通知     */    @Before("aopPoint()")    public void before(JoinPoint joinPoint) throws Throwable {        //在呼叫切面管理的介面前會進入這裡    }    /**     * 功能描述: 環繞通知     */    @Around("aopPoint()")    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {          //在before通知後會走入這裡,直到返回result物件後,客戶端才可以拿到回參        Object result = joinPoint.proceed();        return result;    }複製程式碼

前面兩步實現了兩個需要用到的通知並簡要說明了他的作用.接下來還需要使用到spring包中的ServletRequestAttributes物件用於獲取HttpServletRequest物件,獲取到我們想要的一些列印引數.

    public void before(JoinPoint joinPoint) throws Throwable {        //在呼叫切面管理的介面前會進入這裡        ServletRequestAttributes requestAttributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();        HttpServletRequest request = requestAttributes.getRequest();        Enumeration e = request.getHeaderNames();        JSONObject headers = new JSONObject();        if (null != e) {            while (e.hasMoreElements()) {                String headerName = e.nextElement();                Enumeration headerValues = request.getHeaders(headerName);                while (headerValues.hasMoreElements()) {                    headers.put(headerName, headerValues.nextElement());                }            }        }        //引數依次代表請求方法,請求地址,引數,頭引數,呼叫時間        log.info("-in- {} {} -{}{}",request.getMethod(),request.getRequestURI(),joinPoint.getArgs(),headers.toJSONString()}    }複製程式碼

介面呼叫時間也能很輕鬆的在環繞通知中列印

    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {          long begin=System.currentTimeMillis();        //在before通知後會走入這裡,直到返回result物件後,客戶端才可以拿到回參        Object result = joinPoint.proceed();        long end= System.currentTimeMillis();        log.info("-out -time:{}ms", end - begin}        return result;    }複製程式碼

執行起來,呼叫API介面,我們都會輸出以下日誌

    -in- GET /user/info -id=123  header:{"content-length":"0",......}    -out- -time:91ms    ......複製程式碼

測試完全沒有問題,當然這不是最終版本,嘗試放在測試環境,呼叫的人多起來,就會非常混亂,類似下面的畫風

    -in- GET /user/info -id=123  header:{"content-length":"0",......}    -in- GET /teacher/info -id=123  header:{"content-length":"0",......}    -out- -time:91ms    -in- GET /user/info -id=321  header:{"content-length":"0",......}    -out- -time:191ms    ......複製程式碼

可以看到問題出現在併發操作上,在同一時間呼叫多個介面時,日誌會亂掉,這可不是我想要的結果.必須想辦法解決這個問題.翻閱資料,想到用ThreadLocal執行緒區域性變數以及Tuple元組物件解決這個問題.接下來改造程式碼. 在RuntimeMethod類中定義一個私有變數ThreadLocal.

    private ThreadLocal> threadLocal = new ThreadLocal<>();複製程式碼

再改造通知部分

    @Before("aopPoint()")    public void before(JoinPoint joinPoint) throws Throwable {        //列印請求體        ServletRequestAttributes requestAttributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();        if (null != requestAttributes) {            //在loadingThreadLocal用ThreadLocal和Tuple物件儲存引數.這樣就可以方便的取出介面的必要引數            loadingThreadLocal(requestAttributes, joinPoint.getArgs());                log.info("-in- {} {} -{}",                        threadLocal.get().getT1(),                        threadLocal.get().getT2(),                        threadLocal.get().getT6());                log.info("Method arguments:{} -{}",                        threadLocal.get().getT3(),                        threadLocal.get().getT6());                log.info("Request header:{} -{}",                        threadLocal.get().getT4(),                        threadLocal.get().getT6());        }    }        @Around("aopPoint()")    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {         // 呼叫目標方法        Object result = joinPoint.proceed();        String requestUrl = threadLocal.get().getT2();        // 注意在out的時候,取出呼叫的介面名稱,這樣可以用介面名稱去方便過濾,就不用害怕日誌錯亂的問題了.return回參在生產環境中儘量不要加進去,因為是測試階段排查問題打的日誌所以越詳細越好.        log.info("-out- {} return:{} -time:{}ms -{}", requestUrl, JSONObject.toJSONString(result), System.currentTimeMillis() - threadLocal.get().getT5(), threadLocal.get().getT6());        //接口出參處理        return delReturnData(result);    }        private void loadingThreadLocal(ServletRequestAttributes requestAttributes, Object[] args) {        HttpServletRequest request = requestAttributes.getRequest();        Enumeration e = request.getHeaderNames();        JSONObject headers = new JSONObject();        if (null != e) {            while (e.hasMoreElements()) {                String headerName = e.nextElement();                Enumeration headerValues = request.getHeaders(headerName);                while (headerValues.hasMoreElements()) {                    headers.put(headerName, headerValues.nextElement());                }            }        }        //此處追加了一個呼叫鏈的id,可返回客戶端,讓客戶端在下一次請求中帶入這個id,方法統計一個業務閉環.        String businessId = IdUtil.getSnowflake(1, 1).nextIdStr();        //請求方法,請求地址,引數,頭引數,呼叫時間,呼叫鏈id        threadLocal.set(Tuples.of(request.getMethod(), request.getRequestURI(), args, headers.toJSONString(), System.currentTimeMillis(), businessId));    }複製程式碼

再看看使用此方案後的介面呼叫日誌

2021-01-11 20:16:39.565 [http-nio-8080-exec-7] INFO  cn.mc.apd[86] - -in- GET /activityArea/getUserPrize -13486047359214592002021-01-11 20:16:39.565 [http-nio-8080-exec-7] INFO  cn.mc.appod[90] - Method arguments:[1] -13486047359214592002021-01-11 20:16:39.566 [http-nio-8080-exec-7] INFO  cn.mc.app.tood[93] - Request header:{"content-length":"0","idfa":"00000",x-nondec-sign":"d93207ba","host":"80""} -13486047359214592002021-01-11 20:16:39.593 [http-nio-8080-exec-7] INFO  cn.mc.app.tools.interceptor.RuntimeMethod[126] - -out- /activityArea/getUserPrize return:{"code":0,"data":{"userActivePrizeRec":"0","message":"成功"} -time:28ms複製程式碼

後記

至此一套簡化版的介面入參和介面時長統計方案齊活.大家需要注意的是,此方法會導致冗餘日誌過多儘量規避在生產環境中使用,可在類頭部加入@Profile({"dev", "test"})指定環境.在生產環境中排查可使用阿里爸爸的Arthas或者zipkin鏈路追蹤解決.切記,此方案只是方便排查測試時期錯誤入參和介面時間過長問題

作者：DailyPractice
連結：https://juejin.cn/post/6916486557587210248
來源：掘金