프로젝트를 진행하며 시스템에서 남기는 로그를 일반적으로 생각하는 로컬 디스크가 아닌 원격지 서버에 남기는 방식을 구현한 사례가 있어 이 경험을 공유하고자 글을 작성하였습니다.
우리가 만드는 소프트웨어는 다양한 로그를 남기고 있습니다. 아마도 99% 이상의 소프트웨어는 어딘가에 로그를 남기고 있을 것이라고 감히 추측해 봅니다. 우리는 눈으로 직접 확인하지 않으면 믿지 못하는 경향이 있습니다. 저의 경우도 제가 작성한 코드가 단위 테스트를 통과하는 것보다 로그 한 줄 혹은 콘솔 출력을 직접 확인하는 것이 더 믿음직 스럽기도 합니다. (물론 단위테스트가 중요하지 않다는 얘기는 아닙니다.)
실제로 프로젝트 진행 중에 고객사의 요구사항 중 하나가 기존 시스템은 너무 많은 로그(1일 수십~수백 기가 단위)를 생성하고, 관리하고 있어 스토리지가 감당이 안되니 이러한 문제를 해결 해보고자 하는 요청이 있었습니다. 그래서 차기 시스템을 새롭게 설계하면서 최소한의 필요한 로그만 적재하고 모니터링이나 장애에 대응하기 위해서는 다른 접근 방법을 시도하려 하였으나...
개발, 운영자 분들의 거센 반발을 받았던 적도 있었지요... 여러 시스템과 팀들이 협업하는 관계에서는 ‘내 코드는 잘 돌고 있다!’ 라고 강하게 주장할 수 있는 근거 자료(면피용?)가 로그였던 것입니다. 개발자들에게 가장 익숙한 방법 이기도 했고요. 저도 장애가 발생했다는 연락을 받으면 본능적으로 로그 파일부터 이것 저것 열어서 확인하는 것을 보면 로그는 분명 소프트웨어의 중요한 요소임은 틀림 없는 것 같습니다. 많은 분들이 저와 비슷할 거라 생각합니다.
운영 측면에서도 누가, 언제, 어떤 입력 값을 가지고, 어떤 서비스를 요청했고, 어떤 결과를 응답 받았는지, 처리 시간은 얼마나 걸렸는지 등의 사용 기록을 남기기 위해 요긴하게 사용되는 것이 로그 입니다. 또한 요즘같은 빅데이터 시대에는 이러한 것들이 분석의 기초 자료로써 활용되기도 하겠지요.
logback + slf4j
자바 오픈소스 로깅 프레임워크(개인적으로는 라이브러리에 가깝다고 생각 하지만 여기저기서 프레임워크, 라이브러리 혼용되어 불리기 때문에 이 글에서는 프레임워크라 하겠습니다.) 하면 가장 먼저 log4j가 떠오릅니다. 저도 가장 많이 사용 했었고 프로젝트 할 때마다 고민도 없이 선택 했습니다. 익숙하며 사용하기도 매우 쉽고 수많은 곳에서 이미 검증된 프레임워크 이기 때문입니다.
그러나 최근에 진행했던 프로젝트에서는 logback(구현체)이라는 오픈소스 프레임워크를 slf4j(인터페이스, Simple Logging Facade for Java)와 함께 사용 했습니다. 사실 log4j로도 충분 했습니다만... 다른 로깅 프레임워크를 도입 해보고자 하는 욕구도 있었고, logback을 주저없이 선택할 수 있었던 이유는 바로 log4j를 만든 사람(Ceki)이 따로 나와서 log4j를 좀 더 개선하고, 기능을 추가하여 logback을 만들었기 때문입니다. log4j와 많이 비슷합니다. (log4j를 사용하셨던 분들이라면 거의 무리 없이 도입할 수 있습니다.) 내부 아키텍처 또한 log4j에서 크게 변경되지 않았고 logback도 이미 수많은 유명 오픈소스 프로젝트에서 사용되면서 검증이 되었습니다.
logback, slf4j와 관련된 개선점이나 사용중인 오픈소스 프로젝트를 살펴보시고자 한다면 관련 홈페이지를 참조 바랍니다.
그리고 어떤 분이 logback 관련해서 잘 정리해 주신 것 같아 그 블로그도 함께 공유해 봅니다.
http://beyondj2ee.wordpress.com/2012/11/09/logback-사용해야-하는-이유-reasons-to-prefer-logback-over-log4j/
logback을 이용한 Remote Logging
프로젝트를 진행하면서 각 서버들의 서비스 사용 기록(누가, 언제, 어떤 입력값으로, 어떤 서비스를 요청 했고, 어떤 응답을 받았는지, 처리 성공/실패여부 등) 로그를 남겨야 한다는 요구사항이 있었습니다. 이는 실제로 고객 전화 응대를 위한 기록 이기도 하고 자체적으로 시스템 별 서비스 사용량 통계를 내기 위한 중요한 자료였습니다.
AS-IS 시스템에서는 각 서버들이 자신의 로컬 디스크에 로그를 적재하고 각 서버마다 개별적으로 개발된 로그를 분석하는 데몬(프로세스)이 동작하며 이를 DB에 저장하는 구조를 가지고 있었습니다.
- 각 서버에서 실제 서비스도 제공하며 대량의 로그 적재와 분석을 모두 수행
- 각 서버마다 제각각으로 로그를 남기기 때문에 필요한 경우에 이 로그를 한군데로 모으기 번거로움
- 각 서버마다 로그 분석 데몬이 동작하기 때문에 데몬 배포의 어려움
- 서비스를 제공하는 서버의 디스크 저장 공간은 아주 넉넉하지는 않았으며 일정 기간 유지해야하는 로그가 많은 경우 디스크 풀(full)을 방지하기 위해 항상 관리 해야 함
그래서 차기 시스템에서는 다음과 같은 전략을 가지고 로그 시스템을 설계하였습니다.
- 서비스 사용 기록과 같은 대용량 로그는 로컬 디스크에 적재하지 않고 로그 서버로 전송한다.
- 로그를 전송할 때에는 실제 서비스에 영향이 없어야 하며 비동기(Async) 방식으로 동작해야 한다.
- 로그 서버는 각 서버로부터 수신한 로그를 자신의 로컬 디스크에 적재한다.
- 로그 서버에는 각 서버로부터 수신한 로그를 분석해서 DB에 적재하기 위한 데몬이 동작한다.
- 각 팀이 로그분석기 데몬을 쉽게 개발할 수 있도록 플랫폼에서는 로그 분석 프레임워크를 제공한다.
- 디버그, 트레이스 로그는 각 서버별로 스토리지 사용량에 문제가 없는 선에서 적절하게 롤링하고 삭제하며 자유롭게 적재한다.
다음 그림은 프로젝트를 진행하면서 새롭게 구성한 로그 시스템의 큰 구조 입니다.
AS-IS와의 큰 차이점이라면 대용량 로그의 적재를 로그 서버에 위임하여 역할을 분리 했다는 점, 비슷한 유형의 로그가 한군데로 통합 되었고, 개별적으로 동작하던 로그 분석 및 DB적재 데몬이 로그서버로 통합되어 관리하기 유리해졌다는 장점이 있습니다. 부가적으로 거의 비슷한 로그 분석기 데몬 들을 각 팀에서 쉽게 개발할 수 있도록 프레임워크를 제공하였습니다.
그러면 logback을 이용하여 Remote Logging을 어떻게 구현했는지 알아보겠습니다.
로그 클라이언트 작성 및 설정
각 서버(로그 클라이언트) 작성시 logback + slf4j를 사용하기 위해 pom.xml에 다음과 같이 의존관계를 설정합니다.
<dependencies>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>1.0.7</version>
</dependency>
</dependencies>
위와 같이 설정 되었으면 하위 의존관계에 있는 logback-core와 slf4j-api가 함께 추가 될 것입니다.
Maven을 사용하지 않으면 여기서 http://logback.qos.ch/download.html 필요한 jar파일 3개(logback-classic, logback-core, slf4j-api) 를 다운로드 받아 클래스 패스에 추가해 주시기 바랍니다. 다운로드 받은 압축 파일 내에 필요한 파일들이 존재할 것입니다.
[참고] 현재(2014년 1월 28일) 최신 버전은 logback-classic, logback-core 1.0.13, slf4j-api-1.7.5
로그 적재는 일반적인 방식으로 slf4j 인터페이스를 이용하여 Logger 인스턴스를 가져와 필요한 곳에서 사용하면 됩니다.
...
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
...
..
.
private static Logger logger = LoggerFactory.getLogger("MLS_LOGGER");
...
Logger 인스턴스를 가져올 때는 log4j를 사용할 때와 비슷하게 클래스나 클래스 풀 패키지명 또는 특정 이름으로 가져올 수 있습니다. 이 이름이 logback.xml의 logger 설정과 매핑 됩니다. 예제는 특정 이름 ‘MLS_LOGGER’ 라는 이름으로 Logger 인스턴스를 가지고 왔습니다.
그리고 로그를 남기는 위치에서는 다음과 같이 필요한 로그레벨로 남기도록 구현하면 됩니다. 로그 레벨(trace, debug, info, warn, error)과 관련된 내용은 이 글에서는 생략하겠습니다.(예제에서는 info 레벨로 적재함)
...
// discriminator 값으로 디렉토리 경로가 만들어짐
String discriminatorValue = bizCode + "/" + logType + "/" + instanceCode;
// MDC에 값을 저장
MDC.put("discriminator", discriminatorValue);
// 로깅!!
logger.info(“로그 내용...”);
// MDC클리어
MDC.clear();
...
여기까지는 소스코드 상에서 로그를 남기도록 구현한 부분이고 실제로 이 로그가 어떻게 남을지는 logback 설정 파일(logback.xml)의 logger(예제에서는 ‘MLS_LOGGER’)에 어떤 Appender를 달았는가 에 따라 달라집니다. 그리고 logger에 Appender를 여러개를 등록하는 것도 물론 가능합니다.
log4j와 마찬가지로 logback도 다양한 기본 Appender를 제공하고 있습니다. ConsoleAppender, FileAppender, RollingFileAppender, SocketAppender, SSLSocketAppender, SMTPAppender, DBAppender등 이름에서 알 수 있듯이 콘솔, 파일, 소켓, 메일, DB 등 로그를 적재할 방법에 따라 기본으로 제공되는 Appender를 사용해서 쉽게 적용할 수 있습니다.
자세한 설명은 Manual 참조 http://logback.qos.ch/manual/appenders.html
로그서버로 전송하기 위해서는 Appender 이름에서 알 수 있듯이 SocketAppender를 사용하면 해당 로그를 간단하게 로그서버로 전송할 수 있습니다. 아래는 클라이언트에서 가지고 있는 logback.xml 설정 파일의 일부입니다.
<appender name="SOCKET" class="co.qos.logback.classic.net.SocketAppender">
<RemoteHost>${logserver.host}</RemoteHost>
<Port>${logserver.port}</Port>
<reconnectionDelay>10000</reconnectionDelay>
<includeCallerData>false</includeCallerData>
</appender>
<logger name="MLS_LOGGER" level="INFO">
<appender-ref ref="SOCKET" />
</logger>
여기까지 설정 되었으면 ‘MLS_LOGGER’ 라는 이름으로 가져온 로거 인스턴스가 남기는 로그는 SocketAppender에 의해 설정된 로그 서버로 전송될 것입니다.
실제 프로젝트에서는 프로젝트의 요구사항에 맞게 AsyncSocketAppender라는 사용자 정의 Appender를 새로 구현했습니다. 로그서버와의 통신 장애에 의해 전송 실패한 로그는 큐(Queue)에 담아놓고 지속적으로 재시도 하도록 하고 큐도 꽉 찬 경우는 로컬 디스크에 적재하는 등의 업무에 특화된 형태로 구현 하였습니다. 이처럼 입맛에 맞게 확장 구현 가능하니 Appender 관련 API를 잘 참조해 보시면 좋을 것 같습니다.
각 서버(로그 클라이언트)에서 로그를 남기고 SocketAppender까지 달아 주었으면 원격지에 로그를 받아줄 로그 서버가 필요하겠지요?
로그서버 설정 및 실행
logback에는 기본적으로 제공해주는 SimpleSocketServer 라는 로그서버가 이미 제공되고 있습니다. 이를 기동하기 위해서는 로그 클라이언트에서 사용했었던 동일한 3개 jar 파일(logback-classic, logback-core, slf4j-api)만 있으면 됩니다.
원격지 서버에서는 jar 파일들을 클래스 패스해 추가해 주신 다음에 콘솔에서 다음과 같이 명령을 수행하면 간단하게 로그서버가 실행 됩니다.
java ch.qos.logback.classic.net.SimpleSocketServer {port} {로그설정 xml 파일 경로}
- {port} : 로그서버가 제공하는 포트
- {로그설정 xml 파일 경로} : 로그서버의 동작로그 및 로그 클라이언트로 수신한 로그를 어떻게 적재할 지 설정하는 xml파일
로그설정 xml 파일 일부를 살펴 보도록 하겠습니다.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="true">
...
<appender name="MLS_SIFT_APPENDER" class="ch.qos.logback.classic.sift.SiftingAppender">
<discriminator>
<key>discriminator</key>
<defaultValue>NA</defaultValue>
</discriminator>
<sift>
<appender name="MLS_${discriminator}_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>/LOG/logs/logserver1/mls/domain/${discriminator}_current</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>/LOG/logs/logserver1/mls/domain/${discriminator}[%d{yyyy-MM-dd_HH-mm}].log</fileNamePattern>
</rollingPolicy>
<layout class="ch.qos.logback.classic.PatternLayout">
<pattern>%message%n</pattern>
</layout>
</appender>
</sift>
</appender>
<appender name="LOGSERVER_APPENDER" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>../logs/info.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>../logs/info[%d{yyyy-MM-dd}].log</fileNamePattern>
<maxHistory>3</maxHistory>
</rollingPolicy>
<layout class="ch.qos.logback.classic.PatternLayout">
<Pattern>[%date][%-5level][%logger]-%message%n</Pattern>
</layout>
</appender>
<logger name="MLS_LOGGER" level="INFO">
<appender-ref ref="MLS_SIFT_APPENDER" />
</logger>
<logger name="com.xxx.ndds.frame.logserver" level="INFO">
<appender-ref ref="LOGSERVER_APPENDER" />
</logger>
...
...
<root level="OFF">
</root>
</configuration>
로그서버의 로깅 설정 방식은 클라이언트에서 logback.xml 파일을 작성하는 것과 동일합니다. 앞서 보신 클라이언트 예제에서 'MLS_LOGGER'라는 이름으로 로그를 작성하여 SocketAppender를 통하여 로그서버로 전송된 로그는 로그서버의 설정에서 동일한 이름 을 선언하여 사용할 수 있습니다. 로그서버에 수신된 로그는 이제 로그 서버측의 Appender 설정에 의해서 쓰여질 것이고, 위의 예제에서는 SiftingAppender와 RollingFileAppender를 통하여 로그서버의 로컬 디스크에 설정된 디렉토리, 시간 별로 적재 될 것입니다.(참고로 discriminator라는 값은 클라이언트에서 MDC라는 곳에 담았던 변수로 각 서버 인스턴스별로 디렉토리를 구분지어 적재하기 위해 사용되었습니다.)
[참고]SimpleSocketServer 커스터마이징
실제 프로젝트에서는 로그서버를 이중화 구성하고 앞에 L4스위치를 붙여 사용하다 보니 L4의 주기적인 Health Check 요청이 비정상적으로 종료되어 쌓이는 문제가 있어 아래와 같이 이를 무시하도록 SimpleSocketServer를 참고하여 일부 수정 하였습니다.
아래는 커스터마이징 한 로그서버 Thread의 run() 메소드 중 일부 입니다.(거의 SimpleSocketServer와 동일하게 작성되었고 L4요청은 무시하는 로직이 추가되었습니다.
try {
logger.debug("Listening on port " + port);
serverSocket = new ServerSocket(port);
while (!closed) {
logger.debug("Waiting to accept a new client.");
Socket socket = serverSocket.accept();
// L4요청은 무시
if (l4Config.isL4Socket(socket)) {
logger.debug("Health check from L4(" + socket.getInetAddress() + ") will be ignored...");
try {
socket.getInputStream().close();
socket.close();
} catch (IOException e) {
logger.error("Exception occured while closing L4 Socket...", e);
}
continue;
}
SocketNode newSocketNode = new SocketNode(this, socket, lc);
logger.info("Connected {}", newSocketNode);
synchronized (socketNodeList) {
socketNodeList.add(newSocketNode);
}
new Thread(newSocketNode).start();
}
} catch (Exception e) {
if (closed) {
logger.info("Exception in run method for a closed server. This is normal.");
} else {
logger.error("Unexpected failure in run method", e);
}
}
정리
지금까지 프로젝트에 적용했던 실제 소스코드를 바탕으로 logback을 이용한 원격지 로깅을 구현했던 사례를 간단히 살펴보았습니다.
로그 시스템 구조를 심플하게 가져가기 위해 로그가 적재되는 스토리지를 클라이언트에서 직접 NAS로 연결하는 방법도 고민해 보았으나 고객사의 보안관련 정책 때문에 이는 어려운 상황 이었습니다. 그래서 여러 요구사항을 만족 시키면서 가능한 방향으로 선택한 것이 이 글의 내용인 Remote Logging 입니다.
로그를 로컬 디스크가 아닌 원격지에 남긴다는 것은 개인적으로 새로운 시도였습니다. 설계가 복잡하다거나 구현에 난이도가 있는 것은 아니지만 해보지 않았던 방법이기 때문에 걱정도 있었고, 일단 로그 서버가 잘 버텨줄 것인가에 대한 의구심도 있었습니다. 그래서 실제 적용하기 전에 시스템에서 남기는 일반적인 로그 사이즈로 로그 서버 부하테스트를 해본 결과 1000 TPS 정도는 무난하게 처리하는 것을 확인하고는 적용하기로 결정 했습니다. (그 이상은 테스트 하지 않았지만 어느정도는 충분이 커버할 것 같습니다.) 사실 로그서버는 로그를 수신하여 파일로 적재하는 과정만 수행하기 때문에 별로 하는 일이 없습니다. 로그서버가 바쁜 상황에서도 CPU, MEMORY는 항상 넉넉하게 남아 있었고요. 실제로 적용해서 잘 동작하고 있는 것을 보면 괜히 흐믓 하네요...
로그를 원격지에 남기는 상황을 자주 접하지는 않을 것 같습니다만 응용한다면 충분히 다른 목적으로도 활용 가능하리라 봅니다. 저에게는 좋은 경험이었고 이 글을 여기까지 읽으신 분들은 비슷한 솔루션이 필요할 때 한번 떠올려 보셔도 좋을 것 같습니다.
이상 logback과 slf4j를 이용한 Remote Logging에 대해 살펴 보았습니다.
감사합니다.