[펌]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 특성상, 스트림을 한번 소비하면 재 사용이 불가능 하다보니 에러난 시점에 HttpBody에 어떤 데이터가 담겨 있는지 확인 할 수가 없다.

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

코드는 대략 다음과 같다.

MultiReadableHttpServletRequest

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51

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의 데이터들을 로그에 활용 할 수 있다는 의미이다.

MDC Filter는 다음과 같다.

LogbackMdcFilter

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38

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을 생성했다.

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17

@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를 구현해보자.

CustomLogbackAppender

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182

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에 좀 이쁘게 보여주려고 SlackField들을 여러개 만들다보니 코드가 좀 길어졌다.

이제 Slack에 새로운 채널을 추가하고, Incoming Webhook을 등록하자.

나는 test라는 채널을 추가한 다음, Incoming Webhook을 Integration 했다.

Slack webHookUrl과 channel명을 Property에 설정해주었다.

application.properties

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15

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

 

이제 Logback ROOT Logger에 우리가 만든 CustomAppender를 등록해보자.

내가 만든 Appender는 Spring에 의존적인 부분들이 있다보니, logback.xml의 Appender에 바로 설정 하기는 쉽지 않을 것 같아 보인다.

간단한 Bean을 하나 만들고, 의존성을 주입 받아서 ROOT Logger에 등록하도록 했다.

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21

@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를 하나 생성하고 에러를 강제로 발생시켜보자.

Java

1 2 3 4 5 6 7 8 9 10 11

@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로 맵핑할 수 있고,

EmbeddedServletContainerCustomizer

Java

1 2 3 4 5 6 7 8 9

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

Java

1 2 3 4 5 6 7 8 9 10 11 12 13 14

@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 페이지에 대한 에러로그 처리를 위와 같이 할 수도 있다. ( 물론 샘플 코드라 “error” 라는 메시지를 화면에 찍히게 했지만, 실제 서비스에는 잘 디자인된 404 페이지를 사용자에게 보여주도록 하면 되겠다. )

 

정리해보면, 2개의 Servlet Filter (MultiReadableHttpServletRequest, LogbackMdcFilter), Logback Custom Appender, SlackApi 를 구현하면 큰 시간과 비용을 들이지 않고도 간단하게 에러로그를 실시간으로 확인 할 수 있는 시스템을 만들 수 있다.

테스트 소스코드는 Github에 모두 공개되어 있으니, 아직 로그알람이 없는 시스템을 운영중이라면 적극 검토 해보시기 바란다!

소스코드 : https://github.com/brant-hwang/spring-logback-slack-notification-example

출처: http://brantiffy.axisj.com/archives/451