SpringBoot, Slack, Logback을 이용한 실시간 에러 모니터링 구현하기

보통 스타트업은 빠른 프로토타이핑을 통해 MVP(Minimum Viable Product) 로 시장에 진출합니다.

기능구현에 집중해서 개발하다보니 제대로된 테스트 코드가 없을 때도 있고, 얼마나 많은 에러가 발생할지 가늠하기 쉽지 않은 상황들이 대부분입니다.

에러는 언제든지 날 수 있다고 가정한다면 얼마나 빠르게 감지하고 Hotfix를 내보내느냐가 고객의 불편을 최소화 할 수 있는 방법이 아닐까 싶은데요,

이번 포스팅에서는 Spring 기반의 Application에 간단한 Filter와 Logback을 이용해 초기 시스템에서 간단히 사용할 수 있는 에러 모니터링 기능을 소개하고자 합니다.

1) 협업도구로 쓰고 있는 Slack의 특정 채널에 실시간으로 알람이 되었으면 좋겠다.

2) 급한대로 RDBMS의 테이블에도 에러 로그 데이터를 저장 하고싶다.

3) 에러가 난 시점에 사용자 정보, HttpRequest 파라미터 정보, User-Agent 정보 등을 함께 보고싶다. (에러가 난 것 보다 더 중요한 것은 어떤 환경에서 어떤 사용자가 에러를 겪고있는지 아는 것이 더 중요하기 때문에 꼭 수집해야 할 정보들입니다.)

위와 같은 요구사항을 만족하는 Spring Boot 기반의 간단한 Application을 만들어 보겠습니다. 버전은 다음과 같습니다.

1) SpringBoot 1.3.1

2) Spring Data JPA with H2

3) Jackson 2.6.4, Slack Webhook API, Apache Commons-IO

에러가 나는 시점의 사용자 정보와 HttpRequest 파라미터 정보, User-Agent 정보 수집을 위해해 몇몇 추가적인 작업이 필요합니다.

1. MultiReadableHttpServletRequestFilter 적용

POST혹은 PUT 등으로 HttpBody에 데이터를 담아 서버에 전송할 경우, HttpBody 정보는 Java HttpServletRequest의 InputStream으로 읽을 수 있습니다.

그런데 Java의 InputStream 특성상, 스트림을 한번 소비하면 재 사용이 불가능 하다보니 에러난 시점에 InputStream이 소비된 상태라면 HttpBody에 어떤 데이터가 담겨 있는지 확인할 수가 없습니다.

그래서 HttpServletRequest InputStream을 여러번 읽을 수 있도록 하는 Filter를 적용했습니다.

private ByteArrayOutputStream cachedBytes;
public MultiReadableHttpServletRequest(HttpServletRequest request) {
        super(request);
    }
@Override
    public ServletInputStream getInputStream() throws IOException {
        if (cachedBytes == null)
            cacheInputStream();
return new CachedServletInputStream();
    }
@Override
    public BufferedReader getReader() throws IOException {
        return new BufferedReader(new InputStreamReader(getInputStream()));
    }
private void cacheInputStream() throws IOException {
        cachedBytes = new ByteArrayOutputStream();
        IOUtils.copy(super.getInputStream(), cachedBytes);
    }
public class CachedServletInputStream extends ServletInputStream {
        private ByteArrayInputStream input;
public CachedServletInputStream() {
            input = new ByteArrayInputStream(cachedBytes.toByteArray());
        }
@Override
        public boolean isFinished() {
            return false;
        }
@Override
        public boolean isReady() {
            return true;
        }
@Override
        public void setReadListener(ReadListener listener) {
        }
@Override
        public int read() throws IOException {
            return input.read();
        }
    }
}
최초의 inputStream을 ByteArrayOutputStream에 복사해두고, 항상 복사된 ByteArrayOutputStream을 반환 하도록 했습니다.
2) MDC(Mapped Diagnostic Context) Filter 적용
MDC는 SLF4J API중 하나입니다. 자세한 내용은 Logback Documentation에 나와있습니다. 간단히 설명하면 ThreadLocal에 데이터를 넣고, 로그를 출력하는 시점에 넣은 데이터들을 맵핑 할 수 있게 해주는 ThreadLocal 유틸리티 정도로 생각하면 되겠습니다.
즉 MDC에다 어떠한 데이터를 넣으면 해당 HttpRequest(Thread)가 존재하는 동안 데이터가 유지되고, 만약 에러가 발생 한 상황이라면 MDC의 데이터들을 로그에 활용 할 수 있다는 의미입니다.
public class LogbackMdcFilter implements Filter {
@Override
    public void init(FilterConfig filterConfig) throws ServletException {
}
@Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        RequestWrapper requestWrapper = RequestWrapper.of(request);
// Set Http Header
        MDCUtil.setJsonValue(MDCUtil.HEADER_MAP_MDC, requestWrapper.headerMap());
// Set Http Body
        MDCUtil.setJsonValue(MDCUtil.PARAMETER_MAP_MDC, requestWrapper.parameterMap());
// If you use SpringSecurity, you could SpringSecurity UserDetail Information.
        MDCUtil.setJsonValue(MDCUtil.USER_INFO_MDC, HttpUtils.getCurrentUser());
// Set Agent Detail
        MDCUtil.setJsonValue(MDCUtil.AGENT_DETAIL_MDC, AgentUtils.getAgentDetail((HttpServletRequest) request));
// Set Http Request URI
        MDCUtil.set(MDCUtil.REQUEST_URI_MDC, requestWrapper.getRequestUri());
try {
            chain.doFilter(request, response);
        } finally {
            MDC.clear();
        }
    }
@Override
    public void destroy() {
}
}

HttpRequest의 Header, Body(Parameter), 사용자 정보, Agent 상세 정보등을 MDC에 넣도록 했습니다.
3) Filter 등록
2개의 필터가 순서대로 적용 될 수 있도록 FilterRegistrationBean을 생성합니다.
@Bean
public FilterRegistrationBean multiReadableHttpServletRequestFilterRegistrationBean() {
    FilterRegistrationBean registrationBean = new FilterRegistrationBean();
    MultiReadableHttpServletRequestFilter multiReadableHttpServletRequestFilter = new MultiReadableHttpServletRequestFilter();
    registrationBean.setFilter(multiReadableHttpServletRequestFilter);
    registrationBean.setOrder(1);
    return registrationBean;
}
@Bean
public FilterRegistrationBean logbackMdcFilterRegistrationBean() {
    FilterRegistrationBean registrationBean = new FilterRegistrationBean();
    LogbackMdcFilter logbackMdcFilter = new LogbackMdcFilter();
    registrationBean.setFilter(logbackMdcFilter);
    registrationBean.setOrder(2);
    return registrationBean;
}
이제 RDBMS와 Slack으로 로그를 전송할 Custom Logback Appender를 생성합니다.
public class CustomLogbackAppender extends UnsynchronizedAppenderBase<ILoggingEvent> {
private ErrorLogService errorLogService;
private LogConfig logConfig;
public CustomLogbackAppender() {
    }
public CustomLogbackAppender(ErrorLogService errorLogService, LogConfig logConfig) {
        this.errorLogService = errorLogService;
        this.logConfig = logConfig;
    }
@Override
    public void doAppend(ILoggingEvent eventObject) {
        super.doAppend(eventObject);
    }
@Override
    protected void append(ILoggingEvent loggingEvent) {
        if (loggingEvent.getLevel().isGreaterOrEqual(logConfig.getLevel())) {
            ErrorLog errorLog = getErrorLog(loggingEvent);
if (logConfig.getDatabase().isEnabled()) {
                if (logConfig.getSlack().isEnabled()) {
                    errorLog.setAlertYn("Y");
                }
                toDatabase(errorLog);
            }
if (logConfig.getSlack().isEnabled()) {
                toSlack(errorLog);
            }
        }
    }
private void toSlack(ErrorLog errorLog) {
        SlackApi slackApi = new SlackApi(logConfig.getSlack().getWebHookUrl());
List<SlackField> fields = new ArrayList<>();
SlackField message = new SlackField();
        message.setTitle("에러내용");
        message.setValue(errorLog.getMessage());
        message.setShorten(false);
        fields.add(message);
SlackField path = new SlackField();
        path.setTitle("요청 URL");
        path.setValue(errorLog.getPath());
        path.setShorten(false);
        fields.add(path);
SlackField date = new SlackField();
        date.setTitle("발생시간");
        date.setValue(errorLog.getErrorDatetime().format(DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss")));
        date.setShorten(true);
        fields.add(date);
SlackField profile = new SlackField();
        profile.setTitle("프로파일");
        profile.setValue(errorLog.getPhase());
        profile.setShorten(true);
        fields.add(profile);
SlackField system = new SlackField();
        system.setTitle("시스템명");
        system.setValue(errorLog.getSystem());
        system.setShorten(true);
        fields.add(system);
SlackField serverName = new SlackField();
        serverName.setTitle("서버명");
        serverName.setValue(errorLog.getServerName());
        serverName.setShorten(true);
        fields.add(serverName);
SlackField hostName = new SlackField();
        hostName.setTitle("호스트명");
        hostName.setValue(errorLog.getHostName());
        hostName.setShorten(false);
        fields.add(hostName);
SlackField userInformation = new SlackField();
        userInformation.setTitle("사용자 정보");
        userInformation.setValue(JsonUtils.toPrettyJson(errorLog.getUserInfo()));
        userInformation.setShorten(false);
        fields.add(userInformation);
SlackField headerInformation = new SlackField();
        headerInformation.setTitle("Http Header 정보");
        headerInformation.setValue(JsonUtils.toPrettyJson(errorLog.getHeaderMap()));
        headerInformation.setShorten(false);
        fields.add(headerInformation);
SlackField bodyInformation = new SlackField();
        bodyInformation.setTitle("Http Body 정보");
        bodyInformation.setValue(JsonUtils.toPrettyJson(errorLog.getParameterMap()));
        bodyInformation.setShorten(false);
        fields.add(bodyInformation);
SlackField agentDetail = new SlackField();
        agentDetail.setTitle("사용자 환경정보");
        agentDetail.setValue(JsonUtils.toPrettyJson(errorLog.getAgentDetail()));
        agentDetail.setShorten(false);
        fields.add(agentDetail);
String title = errorLog.getMessage();
if (logConfig.getDatabase().isEnabled()) {
            title = "상세 로그 보기 / [" + errorLog.getId() + "] ";
        }
SlackAttachment slackAttachment = new SlackAttachment();
        slackAttachment.setFallback("에러발생!! 확인요망");
        slackAttachment.setColor("danger");
        slackAttachment.setFields(fields);
        slackAttachment.setTitle(title);
        slackAttachment.setTitleLink("http://log.test.com");
        slackAttachment.setText(errorLog.getTrace());
SlackMessage slackMessage = new SlackMessage("");
        slackMessage.setChannel("#" + logConfig.getSlack().getChannel());
        slackMessage.setUsername(String.format("[%s] - ErrorReportBot", errorLog.getPhase()));
        slackMessage.setIcon(":exclamation:");
        slackMessage.setAttachments(Collections.singletonList(slackAttachment));
slackApi.call(slackMessage);
    }
private void toDatabase(ErrorLog errorLog) {
        errorLogService.save(errorLog);
    }
public ErrorLog getErrorLog(ILoggingEvent loggingEvent) {
        if (loggingEvent.getLevel().isGreaterOrEqual(logConfig.getLevel())) {
            ErrorLog errorLog = new ErrorLog();
            errorLog.setPhase("alpha");
            errorLog.setSystem("testSystem");
            errorLog.setLoggerName(loggingEvent.getLoggerName());
            errorLog.setServerName("localhost");
            errorLog.setHostName(getHostName());
            errorLog.setPath(MDCUtil.get(MDCUtil.REQUEST_URI_MDC));
            errorLog.setMessage(loggingEvent.getFormattedMessage());
            errorLog.setHeaderMap(MDCUtil.get(MDCUtil.HEADER_MAP_MDC));
            errorLog.setParameterMap(MDCUtil.get(MDCUtil.PARAMETER_MAP_MDC));
            errorLog.setUserInfo(MDCUtil.get(MDCUtil.USER_INFO_MDC));
            errorLog.setAgentDetail(MDCUtil.get(MDCUtil.AGENT_DETAIL_MDC));
if (loggingEvent.getThrowableProxy() != null) {
                errorLog.setTrace(getStackTrace(loggingEvent.getThrowableProxy().getStackTraceElementProxyArray()));
            }
return errorLog;
        }
return null;
    }
public String getHostName() {
        try {
            return ContextUtil.getLocalHostName();
        } catch (Exception e) {
            // ignored
        }
        return null;
    }
public String getStackTrace(StackTraceElementProxy[] stackTraceElements) {
        if (stackTraceElements == null || stackTraceElements.length == 0) {
            return null;
        }
StringBuilder sb = new StringBuilder();
        for (StackTraceElementProxy element : stackTraceElements) {
            sb.append(element.toString());
            sb.append("\n");
        }
        return sb.toString();
    }
}
이제 Slack에 새로운 채널을 추가하고, Incoming Webhook을 등록합니다.
저는 test라는 채널을 추가한 다음, Incoming Webhook을 Integration 했습니다.

Slack webHookUrl과 channel명을 Property에 설정했습니다.
spring.datasource.platform=h2
spring.datasource.jdbcUrl=jdbc:h2:mem:test
spring.datasource.user=sa
spring.jpa.hibernate.ddl-auto=create
spring.jpa.hibernate.naming_strategy=org.hibernate.cfg.ImprovedNamingStrategy
spring.jpa.database=H2
spring.jpa.show-sql=true
log.slack.enabled=true
log.slack.webHookUrl=https://hooks.slack.com/services/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
log.slack.channel=test
log.database.enabled=true
log.level=ERROR
CustomLogbackAppender를 Logback ROOT 로거에 등록합니다.
@Configuration
public class LogContextConfig implements InitializingBean {
@Autowired
    private LogConfig logConfig;
@Autowired
    private ErrorLogService errorLogService;
@Override
    public void afterPropertiesSet() throws Exception {
        LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
CustomLogbackAppender customLogbackAppender = new CustomLogbackAppender(errorLogService, logConfig);
customLogbackAppender.setContext(loggerContext);
        customLogbackAppender.setName("customLogbackAppender");
        customLogbackAppender.start();
        loggerContext.getLogger("ROOT").addAppender(customLogbackAppender);
    }
}
끝났습니다!
테스트할 Controller를 하나 생성하고 에러를 강제로 발생시켜 보겠습니다.
@RequestMapping(value = "/api/v1/test3", method = RequestMethod.POST)
public String responseFail2(
        @RequestParam(required = false) String value1,
        @RequestParam(required = false) String value2,
        @RequestParam(required = false) String value3,
        @RequestParam(required = false) String value4) {
    if (value1 == null || value1.equals("")) {
        throw new IllegalArgumentException("value is null");
    }
    return "fail";
}
자, 4개의 파라미터를 받는 POST API가 있는데, value1의 값이 없으면 에러가 나도록 했고요~
value1의 값을 비우고, 나머지 2,3,4의 값을 채운다음 요청을 했을 때, Slack으로 에러가 전송되고 value2,3,4의 값이 표시되는지 확인해봅니다.

Send를 누르자마자 Slack에 알람이 표시되었고, 다음과 같이 채널에 내용이 나왔습니다.

기대했던 대로 Stacktrace, 로그내용, MDC에 저장한 내용들까지 Slack으로 모두 전송되었네요.
log.database.enabled=true로 된 상황이라면 JDBC 연결을 통해 ERROR_LOGS 테이블에도 데이터가 쌓였을 것이고요.
그리고 SpringBoot를 사용한다면 EmbeddedServletContainerCustomizer Bean을 다음과 같이 등록하면 Http Error 코드들을 원하는 URL로 맵핑할 수 있고,
@Bean
public EmbeddedServletContainerCustomizer containerCustomizer() {
    return (container -> {
        ErrorPage error401Page = new ErrorPage(HttpStatus.UNAUTHORIZED, "/errors/401");
        ErrorPage error404Page = new ErrorPage(HttpStatus.NOT_FOUND, "/errors/404");
        ErrorPage error500Page = new ErrorPage(HttpStatus.INTERNAL_SERVER_ERROR, "/errors/500");
        container.addErrorPages(error401Page, error404Page, error500Page);
    });
}
@RequestMapping(value = "/errors/{code}")
@ResponseBody
public String errors(@PathVariable String code, ModelMap modelMap, HttpServletRequest httpServletRequest) {
    String uri = (String) httpServletRequest.getAttribute("javax.servlet.error.request_uri");
MDCUtil.set(MDCUtil.REQUEST_URI_MDC, uri);
modelMap.put("errorCode", code);
    modelMap.put("errorPage", uri);
logging(new Exception("Page Not Found"));
return "error";
}
404 페이지에 대한 에러로그 처리를 위와 같이 할 수도 있습니다.
정리해보면, 2개의 Servlet Filter (MultiReadableHttpServletRequest, LogbackMdcFilter), Logback Custom Appender, SlackApi 를 구현하면 큰 시간과 비용을 들이지 않고도 간단하게 에러로그를 실시간으로 확인 할 수 있는 시스템을 만들 수 있습니다.
소스코드 : https://github.com/brant-hwang/spring-logback-slack-notification-example