AOP攔截日志報錯llegalStateException: It is illegal to call this method if the current request is not in asynchronous mode

原文鏈接:https://my.oschina.net/mengzhang6/blog/2395893

關於一次AOP攔截入參記錄日志報錯的梳理總結

將服務發布到tomcat中后，觀察服務的運行狀態以及日志記錄狀況； 發現有如下一個問題：

2018-10-31 16:20:10,701 [] INFO  aspect.PayMethodLogAspectJ - rest 請求開始{1540974010700}:clazzName: com.yuantu.unified.pay.openapi.OpenApiRest, methodName:preOrder, 參數：[Ljava.lang.Object;@49ffa5bd
2018-10-31 16:20:10,790 [] INFO  aspect.PayMethodLogAspectJ - rest 返回結束{1540974010700}：:clazzName: com.yuantu.unified.pay.openapi.OpenApiRest, methodName:preOrder, 結果：{"msg":"subCorpNo{3701011318}","resultCode":"101","startTime":1540974010785,"success":false,"timeConsum":0},耗時毫秒數 89

 

日志中記錄入參並沒有詳細的記錄下來，而是記錄了一個Object,這樣的日志在將來的查詢問題的時候是不可用的，遂進行檢查代碼查找問題；

代碼如下：

 @Around("within(com.yuantu.unified.pay.openapi..*) || within(com.yuantu.unified.pay.rest..*)")
    public Object setCorporation(ProceedingJoinPoint joinPoint) throws Throwable {
        String classType = joinPoint.getTarget().getClass().getName();
        Class<?> clazz = Class.forName(classType);
        String clazzName = clazz.getName();
        String methodName = joinPoint.getSignature().getName();

        Long logId = System.currentTimeMillis();
        Object[] args = joinPoint.getArgs();
        String paramter = "";
        if (args != null) {
            try {
                paramter = JSON.toJSONString(args);
            } catch (Exception e) {
                paramter = args.toString();
            }
        }
        Long currentTime = System.currentTimeMillis();
        logger.info("rest 請求開始{" + logId + "}:clazzName: " + clazzName + ", methodName:" + methodName + ", 參數：" + paramter);
        Object proceed = Result.createFailResult();

        try {
            proceed = joinPoint.proceed(args);
        } catch (Exception e) {
            proceed = Result.createFailResult("系統異常，請及時與我們聯系，以便及時解決。錯誤類型：" + e.getClass().getName() +" 錯誤信息："+ e.getMessage());
            logger.error("rest 請求發生異常{" + logId + "}:clazzName: " + clazzName + ", methodName:" + methodName + ", 參數：" + paramter, e);
        }

        String result = "";
        if (proceed != null) {
            result = JSON.toJSONString(proceed);
        }
        Long timeDiff = System.currentTimeMillis() - currentTime;
        logger.info("rest 返回結束{" + logId + "}：:clazzName: " + clazzName + ", methodName:" + methodName + ", 結果：" + result + ",耗時毫秒數 " + timeDiff);
        return proceed;
    }

 

最初的觀察並沒有發現明顯的問題，因為paramter本身就是String類型； 后進行debug后，定位出問題所在位置： paramter = JSON.toJSONString(args); 在執行后報錯：java.lang.IllegalStateException: It is illegal to call this method if the current request is not in asynchronous mode (i.e. isAsyncStarted() returns false)

上網查詢資料后發現，是因為使用 Object[] args = joinPoint.getArgs(); 獲取入參的時候，args還包含了一些其他的內容，比如ServletRequest等，而這些入參並不能進行序列化，所以JSON.toJSONString時報錯；

改造后的方法為：

 Object[] args = joinPoint.getArgs();
        Object[] arguments  = new Object[args.length];
        for (int i = 0; i < args.length; i++) {
            if (args[i] instanceof ServletRequest || args[i] instanceof ServletResponse || args[i] instanceof MultipartFile) {
                //ServletRequest不能序列化，從入參里排除，否則報異常：java.lang.IllegalStateException: It is illegal to call this method if the current request is not in asynchronous mode (i.e. isAsyncStarted() returns false)
                //ServletResponse不能序列化 從入參里排除，否則報異常：java.lang.IllegalStateException: getOutputStream() has already been called for this response
                continue;
            }
            arguments[i] = args[i];
        }
        String paramter = "";
        if (arguments != null) {
            try {
                paramter = JSONObject.toJSONString(arguments);
            } catch (Exception e) {
                paramter = arguments.toString();
            }
        }
        logger.info("rest 請求開始{" + logId + "}:clazzName: " + clazzName + ", methodName:" + methodName + ", 參數：" + paramter);

 

將不能進行序列化的入參過濾掉，只要留下我們需要記錄的入參參數記錄到日志中即可。