這篇文章主要介紹“如何優(yōu)雅打印接口調(diào)用時長 ”，在日常操作中，相信很多人在如何優(yōu)雅打印接口調(diào)用時長 問題上存在疑惑，小編查閱了各式資料，整理出簡單好用的操作方法，希望對大家解答”如何優(yōu)雅打印接口調(diào)用時長 ”的疑惑有所幫助！接下來，請跟著小編一起來學(xué)習(xí)吧！

創(chuàng)新互聯(lián)公司是一家專業(yè)提供衢江企業(yè)網(wǎng)站建設(shè),專注與網(wǎng)站設(shè)計制作、成都網(wǎng)站制作、H5響應(yīng)式網(wǎng)站、小程序制作等業(yè)務(wù)。10年已為衢江眾多企業(yè)、政府機(jī)構(gòu)等服務(wù)。創(chuàng)新互聯(lián)專業(yè)網(wǎng)站建設(shè)公司優(yōu)惠進(jìn)行中。

引言

優(yōu)雅的API設(shè)計不僅僅是代碼層面的書寫規(guī)范.幾乎不可能API開發(fā)完畢就能正常投入使用,更多的是對細(xì)節(jié)的打磨.例如接口的每次執(zhí)行時間,入?yún)⒍紩贏PI測試中反復(fù)的推敲

思考

如何設(shè)計一個方案使開發(fā)者能一目了然的可視化接口的處理時間以及入?yún)⑹欠裾_呢?

思路

首先想到的是Spring的AOP切面,現(xiàn)在我們編寫API接口,一般都會把接口寫在controller控制層里,按照不同的業(yè)務(wù),分為寫在不同業(yè)務(wù)包下的controller類中.大致的架構(gòu)如下: 按照這種控制層的編寫規(guī)范,只需要用切面找到每個業(yè)務(wù)包下的controller類,監(jiān)控類下面的每個方法的入?yún)⒑蛨?zhí)行時間,打印在log日志中便可以在控制臺中可視化每個接口的實時狀態(tài)了.

實踐

導(dǎo)包

    
    org.springframework.boot
    spring-boot-starter-web


     
    org.springframework.boot
    spring-boot-starter-aop

AOP核心

aop的核心在于切點和通知類型.結(jié)合我們所需要實現(xiàn)的方案,我們所關(guān)注的切點就是每個業(yè)務(wù)下控制層包的每個類方法. 通知的主要類型分為:

• 前置通知[Before advice]：在連接點前面執(zhí)行，前置通知不會影響連接點的執(zhí)行，除非此處拋出異常。

• 正常返回通知[After returning advice]：在連接點正常執(zhí)行完成后執(zhí)行，如果連接點拋出異常，則不會執(zhí)行。

• 異常返回通知[After throwing advice]：在連接點拋出異常后執(zhí)行。

• 返回通知[After (finally) advice]：在連接點執(zhí)行完成后執(zhí)行，不管是正常執(zhí)行完成，還是拋出異常，都會執(zhí)行返回通知中的內(nèi)容。

• 環(huán)繞通知[Around advice]：環(huán)繞通知圍繞在連接點前后，比如一個方法調(diào)用的前后。這是最強(qiáng)大的通知類型，能在方法調(diào)用前后自定義一些操作。環(huán)繞通知還需要負(fù)責(zé)決定是繼續(xù)處理join point(調(diào)用ProceedingJoinPoint的proceed方法)還是中斷執(zhí)行。

這里因為我們需要記錄入?yún)⒑徒涌谔幚頃r間,選用Before 前置通知和Around 環(huán)繞通知

定義切點

切面第一步,我們需要找準(zhǔn)切點 新建RuntimeMethod類,用@Aspect @Component修飾定義這是由spring管理的切面入口類,@Log4j2 注釋方便后續(xù)打印日志

@Aspect
@Component
@Log4j2
public class RuntimeMethod {
    //定義aopPoint私有方法,用@Pointcut修飾并標(biāo)識該切面的切點
    //以execution(* com.staging.business.*.controller.*.*(..))為例
    //execution()是切面的主體
    //第一個" * "符號,表示返回值的類型任意
    //com.staging.business表示AOP所切的服務(wù)的包名,即需要進(jìn)行橫切的業(yè)務(wù)類
    //包名后面的" .. ",表示當(dāng)前包及子包
    //之后的" * ",表示類名，*即所有類
    // .*(..) 表示任何方法名,括號內(nèi)表示參數(shù),兩個點表示匹配任何參數(shù)類型
    @Pointcut("execution(* com.staging.business.*.controller.*.*(..))")
    private void aopPoint() {
    } 
}

切面第二步,定義前置和環(huán)繞通知,并聲明通知的切點為aopPoint()

    /**
     * 功能描述: 前置通知
     */
    @Before("aopPoint()")
    public void before(JoinPoint joinPoint) throws Throwable {
        //在調(diào)用切面管理的接口前會進(jìn)入這里
    }

    /**
     * 功能描述: 環(huán)繞通知
     */
    @Around("aopPoint()")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {  
        //在before通知后會走入這里,直到返回result對象后,客戶端才可以拿到回參
        Object result = joinPoint.proceed();
        return result;
    }

前面兩步實現(xiàn)了兩個需要用到的通知并簡要說明了他的作用.接下來還需要使用到spring包中的ServletRequestAttributes對象用于獲取HttpServletRequest對象,獲取到我們想要的一些打印參數(shù).

    public void before(JoinPoint joinPoint) throws Throwable {
        //在調(diào)用切面管理的接口前會進(jìn)入這里
        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());
                }
            }
        }
        //參數(shù)依次代表請求方法,請求地址,參數(shù),頭參數(shù),調(diào)用時間
        log.info("-in- {} {} -{}{}",request.getMethod(),request.getRequestURI(),joinPoint.getArgs(),headers.toJSONString()}
    }

接口調(diào)用時間也能很輕松的在環(huán)繞通知中打印

    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;
    }

運行起來,調(diào)用API接口,我們都會輸出以下日志

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

測試完全沒有問題,當(dāng)然這不是最終版本,嘗試放在測試環(huán)境,調(diào)用的人多起來,就會非常混亂,類似下面的畫風(fēng)

    -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
    ......

可以看到問題出現(xiàn)在并發(fā)操作上,在同一時間調(diào)用多個接口時,日志會亂掉,這可不是我想要的結(jié)果.必須想辦法解決這個問題.翻閱資料,想到用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對象存儲參數(shù).這樣就可以方便的取出接口的必要參數(shù)
            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 {
         // 調(diào)用目標(biāo)方法
        Object result = joinPoint.proceed();
        String requestUrl = threadLocal.get().getT2();
        // 注意在out的時候,取出調(diào)用的接口名稱,這樣可以用接口名稱去方便過濾,就不用害怕日志錯亂的問題了.return回參在生產(chǎn)環(huán)境中盡量不要加進(jìn)去,因為是測試階段排查問題打的日志所以越詳細(xì)越好.
        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());
                }
            }
        }
        //此處追加了一個調(diào)用鏈的id,可返回客戶端,讓客戶端在下一次請求中帶入這個id,方法統(tǒng)計一個業(yè)務(wù)閉環(huán).
        String businessId = IdUtil.getSnowflake(1, 1).nextIdStr();
        //請求方法,請求地址,參數(shù),頭參數(shù),調(diào)用時間,調(diào)用鏈id
        threadLocal.set(Tuples.of(request.getMethod(), request.getRequestURI(), args, headers.toJSONString(), System.currentTimeMillis(), businessId));
    }

再看看使用此方案后的接口調(diào)用日志

2021-01-11 20:16:39.565 [http-nio-8080-exec-7] INFO  cn.mc.apd[86] - -in- GET /activityArea/getUserPrize -1348604735921459200
2021-01-11 20:16:39.565 [http-nio-8080-exec-7] INFO  cn.mc.appod[90] - Method arguments:[1] -1348604735921459200
2021-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""} -1348604735921459200
2021-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

到此，關(guān)于“如何優(yōu)雅打印接口調(diào)用時長 ”的學(xué)習(xí)就結(jié)束了，希望能夠解決大家的疑惑。理論與實踐的搭配能更好的幫助大家學(xué)習(xí)，快去試試吧！若想繼續(xù)學(xué)習(xí)更多相關(guān)知識，請繼續(xù)關(guān)注創(chuàng)新互聯(lián)網(wǎng)站，小編會繼續(xù)努力為大家?guī)砀鄬嵱玫奈恼拢?/p>
分享文章：如何優(yōu)雅打印接口調(diào)用時長
文章分享：http://weahome.cn/article/iipoeo.html