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

 

将不能进行序列化的入参过滤掉，只要留下我们需要记录的入参参数记录到日志中即可。