为什么 Spring 拦截器调用了两次？答案

【问题标题】：Why Spring interceptor called twice?为什么 Spring 拦截器调用了两次？
【发布时间】：2015-11-18 16:00:12
【问题描述】：

为什么在这种情况下 Spring 拦截器会调用两次？

控制器

public class UserController
{
    @Resource(name="userDAO")
    private UserDAO userDAO;

    @RequestMapping("/user/registUser")
    public String registUser(HttpServletRequest request, Model model)
    {
        String message = "Regist User Page!";

        model.addAttribute("message", message);

        return "/user/registUser";
    }
}

拦截器

public class LoggerInterceptor extends HandlerInterceptorAdapter
{
    final protected Logger logger = LogManager.getLogger(LoggerInterceptor.class);

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception
    {
        logger.debug("===============================================START================================================");
        logger.debug("Request URI : " + request.getRequestURI());

        return super.preHandle(request, response, handler);
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception
    {
        logger.debug("================================================END=================================================");

        super.postHandle(request, response, handler, modelAndView);
    }
}

上下文-servlet.xml

<?xml version="1.0" encoding="UTF-8"?>

<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:context="http://www.springframework.org/schema/context"
       xmlns:mvc="http://www.springframework.org/schema/mvc"
       xsi:schemaLocation="http://www.springframework.org/schema/beans
       http://www.springframework.org/schema/beans/spring-beans-4.0.xsd
       http://www.springframework.org/schema/context
       http://www.springframework.org/schema/context/spring-context-4.0.xsd
       http://www.springframework.org/schema/mvc
       http://www.springframework.org/schema/mvc/spring-mvc.xsd">

    <context:component-scan base-package="com.mamoru.firstweb.*"/>

    <mvc:interceptors>
        <mvc:interceptor>
            <mvc:mapping path="/user/**"/>
            <bean id="loggerInterceptor" class="com.mamoru.firstweb.common.logger.LoggerInterceptor"/>
        </mvc:interceptor>
    </mvc:interceptors>

    <bean id="viewResolverTiles" class="org.springframework.web.servlet.view.UrlBasedViewResolver">
        <property name="viewClass" value="org.springframework.web.servlet.view.tiles3.TilesView"/>
        <property name="contentType" value="text/html; charset=UTF-8"/>
        <property name="order" value="1"/>
    </bean>

    <bean id="viewResolverJstl" class="org.springframework.web.servlet.view.UrlBasedViewResolver">
        <property name="viewClass" value="org.springframework.web.servlet.view.JstlView"/>
        <property name="contentType" value="text/html; charset=UTF-8"/>
        <property name="prefix" value="/jsp/"/>
        <property name="suffix" value=".jsp"/>
        <property name="order" value="2"/>
    </bean>

    <bean id="tilesConfigurer" class="org.springframework.web.servlet.view.tiles3.TilesConfigurer">
        <property name="definitions">
            <list>
                <value>/config/tiles/tiles-*.xml</value>
            </list>
        </property>
    </bean>

    <mvc:resources mapping="/res/**" location="/resources/" />

    <mvc:annotation-driven />

</beans>

我在这个项目中使用 Log4j2。日志在文本下。我想，也许 Interceptor 调用了两次。

日志

    [DEBUG] 13:43:17.693 [http-apr-8080-exec-9]  - ===============================================START================================================
[DEBUG] 13:43:17.693 [http-apr-8080-exec-9]  - ===============================================START================================================
[DEBUG] 13:43:17.695 [http-apr-8080-exec-9]  - Request URI : /user/registUser.do
[DEBUG] 13:43:17.695 [http-apr-8080-exec-9]  - Request URI : /user/registUser.do
[DEBUG] 13:43:17.709 [http-apr-8080-exec-9]  - ================================================END=================================================
[DEBUG] 13:43:17.709 [http-apr-8080-exec-9]  - ================================================END=================================================

为什么拦截器调用了两次？我只想调用一次拦截器。

我添加了我的 log4j2.xml。

    <?xml version="1.0" encoding="UTF-8"?>

<Configuration>
    <Appenders>
        <File name="FileLog" fileName="/logs/firstweb.log">
            <PatternLayout pattern="[%-5level] %d{HH:mm:ss.SSS} [%t] - %msg%n"/>
        </File>
        <Console name="ConsoleLog" target="SYSTEM_OUT">
            <!--<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>-->
            <PatternLayout pattern="[%-5level] %d{HH:mm:ss.SSS} [%t]  - %msg%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.mamoru.firstweb.common.logger.LoggerInterceptor" level="TRACE">
            <AppenderRef ref="FileLog"/>
            <AppenderRef ref="ConsoleLog"/>
        </Logger>
        <Root level="all">
            <AppenderRef ref="FileLog"/>
            <AppenderRef ref="ConsoleLog"/>
        </Root>
    </Loggers>
</Configuration>

【问题讨论】：

我会检查你的日志记录设置，看起来那很糟糕。
@M.Deinum 我上传了我的日志记录设置文件。
我猜你可以从Logger 元素中删除AppenderRef，因为你没有做任何与默认设置不同的事情......
基本上，您描述的行为记录在官方 Log4J2 文档中的here 中。您的日志记录设置基本上有错误。

标签： spring logging interceptor log4j2

【解决方案1】：

我们遇到了同样的拦截器被调用两次的问题，这是因为我们同时使用了 applicationContext.xml 和 @Configuration

public class RoutingInterceptor extends HandlerInterceptorAdapter {

    private static final Logger logger = LoggerFactory.getLogger(RoutingInterceptor.class);

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
        throws Exception {
            logger.info("Requested uri: {}", ((HttpServletRequest)request).getRequestURI());
            return true;
    }
}

【讨论】：