解决AOP日志切面UT010034: Stream not in async mode问题

1,429 阅读3分钟

最近做了个功能,原来功能都是使用的restful模式接口,不牵涉Excel的数据导出功能,前两天团队的一小伙伴因管理后台需要个导出数据Excel的功能,导致我的日志切面功能无法解析HttpResponse的返回值。

java.lang.IllegalStateException: UT010034: Stream not in async mode

错误码如下:

2020-11-03 11:32:38.325 ERROR [XNIO-2 task-1] cn.xxx.core.exception.handler.GlobalExceptionHandler: 服务具体异常:
java.lang.IllegalStateException: UT010034: Stream not in async mode
	at io.undertow.servlet.spec.ServletOutputStreamImpl.isReady(ServletOutputStreamImpl.java:756) ~[undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at com.alibaba.fastjson.serializer.ASMSerializer_6_ServletOutputStreamImpl.write(Unknown Source) ~[na:na]
	at com.alibaba.fastjson.serializer.JSONSerializer.writeWithFieldName(JSONSerializer.java:360) ~[fastjson-1.2.73.jar:na]
	at com.alibaba.fastjson.serializer.ASMSerializer_5_StatHttpServletResponseWrapper.write(Unknown Source) ~[na:na]
	at com.alibaba.fastjson.serializer.ObjectArrayCodec.write(ObjectArrayCodec.java:103) ~[fastjson-1.2.73.jar:na]
	at com.alibaba.fastjson.serializer.JSONSerializer.write(JSONSerializer.java:312) ~[fastjson-1.2.73.jar:na]
	at com.alibaba.fastjson.JSON.toJSONString(JSON.java:769) ~[fastjson-1.2.73.jar:na]
	at com.alibaba.fastjson.JSON.toJSONString(JSON.java:707) ~[fastjson-1.2.73.jar:na]
	at com.alibaba.fastjson.JSON.toJSONString(JSON.java:672) ~[fastjson-1.2.73.jar:na]
	at cn.xxx.shopping.config.aspect.ActionAspect.before(ActionAspect.java:66) ~[classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_131]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_131]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_131]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_131]
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:626) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.aspectj.AspectJMethodBeforeAdvice.before(AspectJMethodBeforeAdvice.java:44) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:55) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:100) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
java.lang.IllegalStateException: UT010034: Stream not in async mode
	at cn.xxx.shopping.config.aspect.ActionAspect.around(ActionAspect.java:90) ~[classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_131]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_131]
	at io.undertow.servlet.spec.ServletOutputStreamImpl.isReady(ServletOutputStreamImpl.java:756)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_131]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_131]
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.serializer.ASMSerializer_6_ServletOutputStreamImpl.write(Unknown Source)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.serializer.JSONSerializer.writeWithFieldName(JSONSerializer.java:360)
	at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.serializer.ASMSerializer_5_StatHttpServletResponseWrapper.write(Unknown Source)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.aspectj.AspectJAfterAdvice.invoke(AspectJAfterAdvice.java:47) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.serializer.ObjectArrayCodec.write(ObjectArrayCodec.java:103)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.serializer.JSONSerializer.write(JSONSerializer.java:312)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.JSON.toJSONString(JSON.java:769)
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at com.alibaba.fastjson.JSON.toJSONString(JSON.java:707)
	at cn.xxx.shopping.api.merchant.order.controller.MerchantOrderController$$EnhancerBySpringCGLIB$$c658acff.exportRefundOrder(<generated>) ~[classes/:na]
	at com.alibaba.fastjson.JSON.toJSONString(JSON.java:672)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_131]
	at cn.xxx.shopping.config.aspect.ActionAspect.before(ActionAspect.java:66)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_131]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_131]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_131]
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:891) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:981) [spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:884) [spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) [javax.servlet-api-3.1.0.jar:3.1.0]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858) [spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [javax.servlet-api-3.1.0.jar:3.1.0]
	at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:124) [druid-1.2.1.jar:1.2.1]
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:90) [spring-boot-actuator-2.0.8.RELEASE.jar:2.0.8.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) [spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) [undertow-servlet-1.4.26.Final.jar:1.4.26.Final]

网上一通google后,解决方法如下:

import com.alibaba.fastjson.JSON;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang.ArrayUtils;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.Arrays;
import java.util.Enumeration;
import java.util.List;
import java.util.stream.Collectors;
import java.util.stream.Stream;

/**
 * 系统日志切面
 *
 * @author houxr
 */
@Component
@Aspect
@Slf4j
public class ActionAspect {
    /**
     * pointcut  all of the action all methods.
     * 配置切入点,该方法无方法体,主要为方便同类中其他方法使用此处配置的切入点
     */
    @Pointcut(value = "execution(* cn.xxxxx.shopping.api..*.*Controller..*(..))")
    public void aspect() {
    }

    /**
     * 配置前置通知,使用在方法aspect()上注册的切入点
     * 同时接受JoinPoint切入点对象,可以没有该参数
     */
    @Before("aspect()")
    public void before(JoinPoint joinPoint) {
        log.info("the  request details:");
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        //log 请求内容
        log.info("请求url:  {}", request.getRequestURL().toString());
        log.info("请求方法:  {}", request.getMethod());
        String className = joinPoint.getSignature().getDeclaringTypeName();

        log.info("执行的类名: {}", "(" + className.substring(className.lastIndexOf(".") + 1) + ".java)");
        log.info("执行的方法名: {}", joinPoint.getSignature().getName());
       
        // ----start-切面入参过滤处理------
        // 去除Request或者Response对象
        Object[] joinPointArgs = joinPoint.getArgs();
        Stream<?> stream = ArrayUtils.isEmpty(joinPointArgs) ? Stream.empty() : Arrays.stream(joinPointArgs);
        List<Object> logArgs = stream.filter(arg -> (!(arg instanceof HttpServletRequest) && !(arg instanceof HttpServletResponse)))
                .collect(Collectors.toList());
        log.info("参数: {}", JSON.toJSONString(logArgs));
         // ---end-切面入参过滤处理----
        
        //log 方法参数
        Enumeration<String> enu = request.getParameterNames();
        while (enu.hasMoreElements()) {
            String paraName = enu.nextElement();
            log.info(paraName + ":    {}", request.getParameter(paraName));
        }
        try {
            log.info("当前登录用户ID={}", UserHolder.getUserId());
        } catch (Exception e) {
            log.error("获取登录用户异常", e);
        }
    }

    @Around("aspect()")
    public Object around(ProceedingJoinPoint jp) throws Throwable {
        Object[] args = jp.getArgs();
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        String method = request.getMethod().toLowerCase();

        try {
            //对于业务抛出异常的记录就处理
            long start = System.currentTimeMillis();
            Object rvt = jp.proceed(args);
            long end = System.currentTimeMillis();
            log.info("-----------------------------------");
            log.info("执行时间为[{}]ms", (end - start));
            log.info("-----------------------------------");

            if ("options".equals(method)) {
                return rvt;
            }
            //记录请求日志
            return rvt;
        } catch (Exception e) {
            log.error("记录请求日志error", e);
            //继续抛出异常
            throw e;
        }

    }

    /**
     * 配置后置通知,使用在方法aspect()上注册的切入点
     */
    @After(value = "aspect()")
    public void after() {

    }
}

2.问题复现: 原来日志切面代码是没有处理response的处理流过程。

```java
import com.alibaba.fastjson.JSON;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang.ArrayUtils;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.Arrays;
import java.util.Enumeration;
import java.util.List;
import java.util.stream.Collectors;
import java.util.stream.Stream;

/**
 * 系统日志切面
 *
 * @author houxr
 */
@Component
@Aspect
@Slf4j
public class ActionAspect {
    /**
     * pointcut  all of the action all methods.
     * 配置切入点,该方法无方法体,主要为方便同类中其他方法使用此处配置的切入点
     */
    @Pointcut(value = "execution(* cn.xxxxx.shopping.api..*.*Controller..*(..))")
    public void aspect() {
    }

    /**
     * 配置前置通知,使用在方法aspect()上注册的切入点
     * 同时接受JoinPoint切入点对象,可以没有该参数
     */
    @Before("aspect()")
    public void before(JoinPoint joinPoint) {
        log.info("the  request details:");
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        //log 请求内容
        log.info("请求url:  {}", request.getRequestURL().toString());
        log.info("请求方法:  {}", request.getMethod());
        String className = joinPoint.getSignature().getDeclaringTypeName();

        log.info("执行的类名: {}", "(" + className.substring(className.lastIndexOf(".") + 1) + ".java)");
        log.info("执行的方法名: {}", joinPoint.getSignature().getName());
        
        // -----有问题代码行------
        log.info("参数: {}", JSON.toJSONString( joinPoint.getArgs()));
        // ---------------------
        
        //log 方法参数
        Enumeration<String> enu = request.getParameterNames();
        while (enu.hasMoreElements()) {
            String paraName = enu.nextElement();
            log.info(paraName + ":    {}", request.getParameter(paraName));
        }
        try {
            log.info("当前登录用户ID={}", UserHolder.getUserId());
        } catch (Exception e) {
            log.error("获取登录用户异常", e);
        }
    }

    @Around("aspect()")
    public Object around(ProceedingJoinPoint jp) throws Throwable {
        Object[] args = jp.getArgs();
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        String method = request.getMethod().toLowerCase();

        try {
            //对于业务抛出异常的记录就处理
            long start = System.currentTimeMillis();
            Object rvt = jp.proceed(args);
            long end = System.currentTimeMillis();
            log.info("-----------------------------------");
            log.info("执行时间为[{}]ms", (end - start));
            log.info("-----------------------------------");

            if ("options".equals(method)) {
                return rvt;
            }
            //记录请求日志
            return rvt;
        } catch (Exception e) {
            log.error("记录请求日志error", e);
            //继续抛出异常
            throw e;
        }

    }

    /**
     * 配置后置通知,使用在方法aspect()上注册的切入点
     */
    @After(value = "aspect()")
    public void after() {

    }
}