필터를 적용한 오류 페이지 요청 흐름

뚝딱이·2022년 8월 22일

스프링 MVC

목록 보기

22/23

ServletExController.java

: /error-ex로 요청이 오면 log와 함께 RuntimeException 예외를 발생시킨다.

@Slf4j
@Controller
public class ServletExController {

    @GetMapping("/error-ex")
    public void errorEx(){
        log.info("ServletExController");
        throw new RuntimeException("예외 발생!");
    }
}

WebServerCustomizer.java

: RuntimeException 예외가 발생하면 "/error-page/500" 요청 컨트롤러를 호출한다.

@Slf4j
@Component
public class WebServerCustomizer implements WebServerFactoryCustomizer<ConfigurableWebServerFactory> {

    @Override
    public void customize(ConfigurableWebServerFactory factory) {
        log.info("customize");
        ErrorPage errorPageEx = new ErrorPage(RuntimeException.class, "/error-page/500");

        factory.addErrorPages(errorPageEx);
    }
}

ErrorPageController.java

: /error-page/500 요청이 오면 오류 정보를 출력하고, error-page/500 view를 띄운다.

@Slf4j
@Controller
public class ErrorPageController {

    //RequestDispatcher 상수로 정의되어 있음
    public static final String ERROR_EXCEPTION = "javax.servlet.error.exception";
    public static final String ERROR_EXCEPTION_TYPE = "javax.servlet.error.exception_type";
    public static final String ERROR_MESSAGE = "javax.servlet.error.message";
    public static final String ERROR_REQUEST_URI = "javax.servlet.error.request_uri";
    public static final String ERROR_SERVLET_NAME = "javax.servlet.error.servlet_name";
    public static final String ERROR_STATUS_CODE = "javax.servlet.error.status_code";

    @RequestMapping("/error-page/500")
    public String errorPage500(HttpServletRequest request, HttpServletResponse response) {
        log.info("errorPage 500");
        printErrorInfo(request);
        return "error-page/500";

    }

    public void printErrorInfo(HttpServletRequest request) {
        log.info("ERROR_EXCEPTION: ex=", request.getAttribute(ERROR_EXCEPTION));
        log.info("ERROR_EXCEPTION_TYPE: {}", request.getAttribute(ERROR_EXCEPTION_TYPE));
        log.info("ERROR_MESSAGE: {}", request.getAttribute(ERROR_MESSAGE));
        log.info("ERROR_REQUEST_URI: {}", request.getAttribute(ERROR_REQUEST_URI));
        log.info("ERROR_SERVLET_NAME: {}", request.getAttribute(ERROR_SERVLET_NAME));
        log.info("ERROR_STATUS_CODE: {}", request.getAttribute(ERROR_STATUS_CODE));
        log.info("dispatchType={}", request.getDispatcherType());
    }

}

LogFilter.java

: Filter로 doFilter에선 log를 찍고 chain.doFilter를 통해 다음 filter를 호출한다. 하지만 이 예제에서는 다음 filter가 없으므로 서블릿을 호출한다. filter에서 예외가 터지면 서블릿을 호출하지 않는다.

@Slf4j
public class LogFilter implements Filter {
    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        log.info("log filter init");
    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        HttpServletRequest httpRequest = (HttpServletRequest) request;
        String requestURI = httpRequest.getRequestURI();

        String uuid = UUID.randomUUID().toString();

        try {
            log.info("REQUEST [{}] [{}] [{}]", uuid, request.getDispatcherType(), requestURI);
            chain.doFilter(request, response);
        } catch (Exception e) {
        	log.info("Exception");
            throw e;
        } finally {
            log.info("RESPONSE [{}] [{}] [{}]", uuid, request.getDispatcherType(), requestURI);
        }
    }

    @Override
    public void destroy() {
        log.info("log filter destroy");
    }
}

WebConfig.java

: Filter를 사용하기 위해 등록한다.

@Configuration
public class WebConfig implements WebMvcConfigurer {

    @Bean
    public FilterRegistrationBean logFilter() {
        FilterRegistrationBean<Filter> filterRegistrationBean = new FilterRegistrationBean<>();
        filterRegistrationBean.setFilter(new LogFilter());
        filterRegistrationBean.setOrder(1);
        filterRegistrationBean.addUrlPatterns("/*");
        filterRegistrationBean.setDispatcherTypes(DispatcherType.REQUEST, DispatcherType.ERROR);
        return filterRegistrationBean;
    }
}

예외 발생 흐름

WAS ➡ 필터 ➡ 서블릿 ➡ 인터셉터 ➡ 컨트롤러(예외발생)

WAS ⬅ 필터 ⬅ 서블릿 ⬅ 인터셉터 ⬅ 컨트롤러(예외발생)

WAS /error-page/500 다시 요청 ➡ 필터 ➡ 서블릿 ➡ 인터셉터 ➡ 컨트롤러➡ View

처음 웹브라우저는 http://localhost:8080/error-ex를 요청한다. /error-ex 요청이 들어왔으므로 ServletExController가 실행되는데, 필터가 있으므로 이전에 필터가 적용된다. LogFilter필터가 적용된 후 ServletExController가 실행되어 RuntimeException예외가 발생한다.
컨트롤러에서 예외가 발생했으므로 다시 역순으로 오류는 거슬러 올라간다. 이 예제에선 인터셉터가 없으므로 인터셉터를 지나 서블릿을 거쳐 다시 필터를 거친 후 WAS까지 올라간다.
WAS에선 WebServerCustomizer를 통해 RuntimeException에 관한 오류 페이지 경로를 찾아서 내부에서 오류 페이지를 호출한다. 이 때 WAS는 오류 페이지를 단순히 다시 요청만 하는 것이 아니라, 오류 정보를 request 의 attribute 에 추가해서 넘겨준다. 필터가 다시 호출되고, 서블릿을 지나 컨트롤러를 호출한 후 view를 보여준다.

주의해야할 점은 1번에서 예외가 발생한 컨트롤러와 3번의 컨트롤러는 다른 컨트롤러라는 점이다.

결과 log

이번엔 결과 Log를 통해 더 자세하게 알아보자.

2022-08-22 16:17:51.673  INFO 9612 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-08-22 16:17:51.673  INFO 9612 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-08-22 16:17:51.676  INFO 9612 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 2 ms
2022-08-22 16:17:51.694  INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter    : REQUEST [d004f5a0-7b1a-4688-bfaa-c73f698c11f5] [REQUEST] [/error-ex]
2022-08-22 16:17:51.740  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ServletExController        : ServletExController
2022-08-22 16:54:10.667  INFO 1192 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter    : Exception
2022-08-22 16:17:51.759  INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter    : RESPONSE [d004f5a0-7b1a-4688-bfaa-c73f698c11f5] [REQUEST] [/error-ex]
2022-08-22 16:17:51.774 ERROR 9612 --- [nio-8080-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.RuntimeException: 예외 발생!] with root cause

java.lang.RuntimeException: 예외 발생!
	at example.practice.exception.servlet.ServletExController.errorEx(ServletExController.java:14) ~[main/:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at example.practice.exception.filter.LogFilter.doFilter(LogFilter.java:26) ~[main/:na]

2022-08-22 16:17:51.788  INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter    : REQUEST [7dc86a50-4ae0-4a6a-865b-f34c6c7460a1] [ERROR] [/error-page/500]
2022-08-22 16:17:51.799  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : errorPage 500
2022-08-22 16:17:51.802  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_EXCEPTION: ex=

java.lang.RuntimeException: 예외 발생!
	at example.practice.exception.servlet.ServletExController.errorEx(ServletExController.java:14) ~[main/:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at example.practice.exception.filter.LogFilter.doFilter(LogFilter.java:26) ~[main/:na]
    
2022-08-22 16:17:51.806  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_EXCEPTION_TYPE: class java.lang.RuntimeException
2022-08-22 16:17:51.808  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_MESSAGE: Request processing failed; nested exception is java.lang.RuntimeException: 예외 발생!
2022-08-22 16:17:51.808  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_REQUEST_URI: /error-ex
2022-08-22 16:17:51.808  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_SERVLET_NAME: dispatcherServlet
2022-08-22 16:17:51.809  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_STATUS_CODE: 500
2022-08-22 16:17:51.809  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : dispatchType=ERROR
2022-08-22 16:17:52.456  INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter    : RESPONSE [7dc86a50-4ae0-4a6a-865b-f34c6c7460a1] [ERROR] [/error-page/500]

로그를 한 줄씩 분석해보자

2022-08-22 16:17:51.694 INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter : REQUEST [d004f5a0-7b1a-4688-bfaa-c73f698c11f5] [REQUEST] [/error-ex]
: 요청이 들어오자 Filter가 적용되어 REQUEST 로그가 찍혔다. chain.doFilter가 실행되어 서블릿이 호출된다. 서블릿이 호출된 후 컨트롤러가 호출된다.

2022-08-22 16:17:51.740 INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ServletExController : ServletExController
: ServletExController가 호출된 것을 볼 수 있다. ServletExController에서 예외가 터져 다시 서블릿으로, Filter로 올라간다.

2022-08-22 16:54:10.667 INFO 1192 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter : Exception
: chain.doFilter 중, 즉 Filter가 적용되고 있는 과정에서 예외가 터졌기 때문에 Filter에서 catch를 했다.

022-08-22 16:17:51.759 INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter : RESPONSE [d004f5a0-7b1a-4688-bfaa-c73f698c11f5] [REQUEST] [/error-ex]
: 예외가 터졌기 때문에 try문이 끝나고 finally문이 실행되었다. 이제 WAS로 간다.

2022-08-22 16:17:51.774 ERROR 9612 --- [nio-8080-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.RuntimeException: 예외 발생!] with root cause
java.lang.RuntimeException: 예외 발생!
	at example.practice.exception.servlet.ServletExController.errorEx(ServletExController.java:14) ~[main/:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at example.practice.exception.filter.LogFilter.doFilter(LogFilter.java:26) ~[main/:na]

: 예외가 발생되었다. 위의 로그를 보면 Controller에서 Servlet으로, Servlet에서 Filter까지 오류가 전달된 것을 확인할 수 있다. 이제 WAS에선 오류 정보를 확인해 오류 페이지를 호출한다. 즉, Filter부터 Servlet, Controller를 거쳐 View까지 호출한다.

2022-08-22 16:17:51.788 INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter : REQUEST [7dc86a50-4ae0-4a6a-865b-f34c6c7460a1] [ERROR] [/error-page/500]
: Filter가 다시 호출된 것을 볼 수 있다. 이땐 Dispatcher Type이 Error인 것을 확인할 수 있다. Filter를 거쳐 서블릿, 후에 컨트롤러를 호출한다.

2022-08-22 16:17:51.799 INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController : errorPage 500
: 오류 페이지 컨트롤러가 호출되었다.

2022-08-22 16:17:51.802  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_EXCEPTION: ex=

java.lang.RuntimeException: 예외 발생!
	at example.practice.exception.servlet.ServletExController.errorEx(ServletExController.java:14) ~[main/:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) ~[tomcat-embed-core-9.0.65.jar:4.0.FR]
	at example.practice.exception.filter.LogFilter.doFilter(LogFilter.java:26) ~[main/:na]
    
2022-08-22 16:17:51.806  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_EXCEPTION_TYPE: class java.lang.RuntimeException
2022-08-22 16:17:51.808  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_MESSAGE: Request processing failed; nested exception is java.lang.RuntimeException: 예외 발생!
2022-08-22 16:17:51.808  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_REQUEST_URI: /error-ex
2022-08-22 16:17:51.808  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_SERVLET_NAME: dispatcherServlet
2022-08-22 16:17:51.809  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : ERROR_STATUS_CODE: 500
2022-08-22 16:17:51.809  INFO 9612 --- [nio-8080-exec-1] e.p.e.servlet.ErrorPageController        : dispatchType=ERROR

: 오류 컨트롤러에서 오류 정보까지 모두 출력해주었다. 그 후 View를 호출한다.
2022-08-22 16:17:52.456 INFO 9612 --- [nio-8080-exec-1] e.practice.exception.filter.LogFilter : RESPONSE [7dc86a50-4ae0-4a6a-865b-f34c6c7460a1] [ERROR] [/error-page/500]
: View가 호출되었으므로 Filter는 종료된다.

뚝딱이

백엔드 개발자 지망생

이전 포스트

Spring Type Converter

다음 포스트