블로그 이미지
평범하게 살고 싶은 월급쟁이 기술적인 토론 환영합니다.같이 이야기 하고 싶으시면 부담 말고 연락주세요:이메일-bwcho75골뱅이지메일 닷컴. 조대협


Archive»


 
 

스택 드라이버 로그로 로그 백앤드 구축하기

조대협 (http://bcho.tistory.com)


앞의 글에서까지 로그를 남기는 방법에 대해서 알아보았다. 이번 글에서는 로컬에 남긴 로그를 중앙으로 수집하여 모니터링할 수 있는 도구에 대해서 알아보고자 한다.

보통 로그 시스템은 오픈소스 기반의 ELK (Elastic search + Logstash + Kibana)를 많이 사용한다. 좋은 시스템이기는 하지만 러닝 커브가 있고, 구축과 운영에 노력이 들어간다.

대안으로는 클라우드 기반의 매니지드 서비스를 사용하는 방안이 있는데, 구글 클라우드의 스택드라이버 로깅이 사용이 편리하기 때문에 스택드라이버를 소개하고자 한다.

구글 클라우드의 스택드라이버는 로깅뿐만 아니라 모니터링, 에러 리포팅등 다양한 기능을 제공하는 운영용 도구 이다. 그 중에서 이 글에서는 스택드라이버 로깅만을 설명한다.


스택드라이버 로깅이 로그를 수집하는 방법은 크게, SDK를 사용하는 방법과, 로그 에이전트를 사용하는 방법 두가지가 있다. SDK를 이용하는 방법의 경우에는 잘 알려진 로깅 프레임웍과 잘 통합이 되는 장점을 가지고 있으나, 애플리케이션이 아닌 데이타 베이스나 웹서버와 같은 솔루션 로그 수집은 SDK를 사용할 수 없으니 불가능하고, 경우에 따라서 로깅 프레임워크가 지원되지 않는 경우가 있기 때문에, 이 글에서는 에이전트를 이용하는 방식에 대해서 설명한다.


SDK를 이용하는 방법은 자바는 SLF4J+Logback을 이용하면 되는데, 이글을 참고하면 된다. node.js 예제는 이글을 참고하기 바란다. 로깅 시스템의 개념에서 부터, 시스템을 확장하는 방법까지 자세하게 설명해놓았기 때문에, 두 글을 모두 읽어보는것을 추천한다.

스택드라이버 로그 에이전트

스택드라이버 로그 에이전트는 오픈소스 fluentd 기반으로 개발되었다. 파일뿐만 아니라 여러 데이타 소스에서 로그를 읽어서 클라우드나 데이타베이스로 데이타가 전송이 가능하다.

설치 방법은 이 문서에 잘 정리되어 있기 때문에, 별도로 설명하지 않는다. 단 주의할점은 스택드라이버 로그 에이전트는 AWS와 구글 클라우드에서만 사용이 가능하다.

스택드라이버 로그 에이전트를 설치하면 syslog등 디폴트로 시스템 로그를 수집한다. 디폴트로 수집하는 로그 리스트와 로그 파일의 경로는 이 문서 를 참고하면 된다.

 

스택 드라이버 로그 에이전트의 설정 정보는 /etc/google-fluentd/config.d 디렉토리에 저장되어 있다. 에이전트의 상태는

$ sudo service google-fluentd status

명령을 이용하면 현재 에이전트가 제대로 작동하는지 확인이 가능하다.

에이전트 테스트

설치후 디폴트로 syslog 로그를 수집하기 때문에, 테스트를 위해서는 syslog에 로그를 남겨보면 된다. logger 라는 리눅스 명령어는 syslog에 로그를 남기는 명령어이다.

$ logger “테스트 메세지"

를 남기면, syslog 파일에 저장이 되고, 이 로그는 자동으로 스택드라이버 에이전트에 의해서 서버로 전송이 된다.  아래는 hello terry 등의 문자열을 테스트로 남긴 예제이다.


구글 스택드라이버 로그 웹 콘솔에서 GCE VM Instance 카테고리를 선택해서 보면 아래와 같이 logger에 의해서 보낸 로그가 전달된것을 확인할 수 있다.



에이전트 설정

이 예제에서는 Spring Boot 애플리케이션에서 로그를 파일로 남긴 후에, 이 파일을 스택드라이버 로그 에이전트를 통해서 수집하는 시나리오를 구현한다. 아래 예제에 사용한 Spring Boot 소스코드는 이 링크에 있다. 스택 드라이버 로그 에이전트에 대한 설정 방법은 이 문서를 참고하면 된다.


새로운 로그 파일을 정의하기 위해서는 스택드라이버 로그 에이전트의 설정 파일을 추가해야 한다.

/etc/google-fluentd/config.d 디렉토리 아래 springboot 파일에 설정 정보를 아래와 같이 기술하고 저장한다.


<source>

   @type tail

   # Format 'none' indicates the log is unstructured (text).

   format json

   # The path of the log file.

   path /home/terrycho/log.out

   # The path of the position file that records where in the log file

   # we have processed already. This is useful when the agent

   # restarts.

   pos_file /var/lib/google-fluentd/pos/springboot-log.pos

   read_from_head true

   # The log tag for this log input.

   tag springboot

</source>


path 부분에 로그 파일의 위치를 지정한다. 여기서는 Spring boot 애플리케이션의 로그를 /home/terrycho/log.out 파일에 남기도록 하였기 때문에, 이 파일 경로를 지정한다. 그리고 pos_file은 로그 파일을 어디까지 읽었는지를 표시하는 파일인데, 위의 경로에 지정한다.

마지막으로 tag는 로그를 구별하기 위해서 주는 값으로 여기서는 springboot 라는 태그를 부여하였다.

이 tag를 이용하여 로그 이름은 "projects/[Project-ID]/logs/[tag]” 이름으로 정의된다. 예를 들어 구글 클라우드 프로젝트 이름이 myproject이고, 태그를 springboot로 지정하였으면, 이 로그의 이름은 “projects/myproject/logs/springboot”로 지정된다.

설정이 끝났으면

%sudo service google-fluentd restart

명령어를 이용하여 스택드라이버 로그 에이전트를 재시작한다. 그리고 curl 명령어를 이용하여 Spring boot 애플리케이션에 트래픽을 줘서 로그를 남기게 되면 아래와 같이 로그가 스택드라이버 콘솔로 전송된것을 확인할 수 있다.

애플리케이션에서 JSON으로 저장한 로그는 스택드라이버 로그 엔트리에서 jsonPayload 아래에 json 형태로 저장된다.


<그림. 로그 예제>


그리고, 이 예제는 Zipkin과 MDC를 통합하여 traceId를 넘기는 형태로 아래 화면은 같은 Trace Id로 들어온 요청만 쿼리한 결과이다. trace Id를 통해서 하나의 리퀘스트로 들어온 모든 로그들을 모아볼 수 있다. 아래 두 로그를 보면 jsonPayload > mdc > traceId가 같다.


< 그림. 동일 트레이스 ID로 추적한 결과 >

스택드라이버 로그는 Export 기능을 이용하여 빅쿼리나 클라우드 스토리지로 export가 가능한데, 아래 화면은 테스트용 VM 인스턴스의 로그만 빅쿼리로 export 하도록 설정하는 화면이다.


<그림. Log Export 지정>


이렇게 빅쿼리로 로그가 Export 되면 아래 그림과 같이 SQL을 이용해서 로그를 분석할 수 있다.



본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

스택드라이버 로깅을 테스트 하고자 로컬 환경에서 로그를 올리기 위해서 fluentd를 설치했는데

일단 설치는 서비스 어카운트를 다운 받아서 하면 되긴 하는데, 실행을 하고 로그를 전송하려면 아래와 같은 이유가 난다.

2019-04-02 01:20:36 +0900 [error]: #0 Failed to access metadata service:  error_class=Errno::EHOSTUNREACH error="Failed to open TCP connection to 169.254.169.254:80 (No route to host - connect(2) for \"169.254.169.254\" port 80)"
2019-04-02 01:20:36 +0900 [info]: #0 Unable to determine platform
2019-04-02 01:20:36 +0900 [error]: #0 Failed to set monitored resource labels for gce_instance:  error_class=RuntimeError error="Cannot construct a gce_instance resource without vm_id and zone"

169.254.169.254 로 호출을 하게 되어 있는데, 이게 구글 클라우드와 AWS IP대역에서만 호출할 수 있는듯.

이론적으로는 Fluentd를 사용하기 때문에, 다른 인프라에서도 될줄 알았는데. IP 대역을 막아놨네 그랴..

테스트 하려면 애플리케이션들도 같이 올려야 하는데...

도커로 말아서 AWS에서 올려보고 해야 쓰겄다. ㅜㅜ

 

본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

로깅 시스템 #5 - Spring boot에서 JSON 포맷 로깅과 MDC 사용하기

조대협 (http://bcho.tistory.com)


실제로 백앤드 애플리케이션을 자바로 개발할때는 스프링 부트를 사용하는 경우가 대부분이기 때문에 앞에서 적용한 JSON 로그 포맷과 MDC 로깅을 스프링 부트에 적용해보자

스프링 부트라고 해도, 일반 자바 애플리케이션에 대비해서 로그 설정 부분에 다른점은 없다.

아래와 같이 pom.xml에 logback과 json 의존성을 추가한다.


<!-- slf4j & logback dependency -->

<dependency>

<groupId>ch.qos.logback</groupId>

<artifactId>logback-classic</artifactId>

<version>1.2.3</version>

</dependency>


<dependency>

<groupId>ch.qos.logback.contrib</groupId>

<artifactId>logback-json-classic</artifactId>

<version>0.1.5</version>

</dependency>


<dependency>

<groupId>ch.qos.logback.contrib</groupId>

<artifactId>logback-jackson</artifactId>

<version>0.1.5</version>

</dependency>


<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-databind</artifactId>

<version>2.9.3</version>

</dependency>


다음 로그 포맷팅을 JSON으로 하기 위해서 아래와 같이 logback.xml 파일을 작성하여 main/resources 디렉토리에 저장한다. 이번 예제에서는 스프링 부트로 기동할 경우 스프링 부트 자체에 대한 로그가 많기 때문에, JSON 으로 엘리먼트 단위로 출력하면 줄바꿈이 많아서, 로그를 보는데 어려움이 있으니 엘리먼트 단위로 줄을 바꾸지 않도록 <prettyPrint> 옵션을 false 로 처리하고, 대신 이벤트마다는 줄을 바꾸는게 좋으니, <appendLineSeperator>를 true로 설정하였다.


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

<configuration>

   <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">

       <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">

           <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">

               <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSX</timestampFormat>

               <timestampFormatTimezoneId>Etc/UTC</timestampFormatTimezoneId>

               <appendLineSeparator>true</appendLineSeparator>


               <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">

                   <!--

                   <prettyPrint>true</prettyPrint>

                    -->`

               </jsonFormatter>

           </layout>

       </encoder>

   </appender>


   <root level="debug">

       <appender-ref ref="stdout"/>

   </root>

</configuration>


다음으로 아래와 같이 간단한 Controller를 작성하였다. /orders/{id} 형태의 REST API로 사용자 이름을 userid라는 키로 HTTP Header를 통해서 받도록 하였다.


package com.terry.logging.controller;

import org.springframework.web.bind.annotation.PathVariable;


import org.springframework.web.bind.annotation.RequestHeader;

import org.springframework.web.bind.annotation.RequestMapping;

import org.springframework.web.bind.annotation.RequestMethod;

import org.springframework.web.bind.annotation.RequestParam;

import org.springframework.web.bind.annotation.RestController;

import com.terry.logging.model.*;


import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

import org.slf4j.MDC;


@RestController

@RequestMapping("/orders")


public class OrderController {

Logger log = LoggerFactory.getLogger("com.terry.logging.controller.OrderController");

@RequestMapping(value="/{id}",method=RequestMethod.GET)

public Order getOrder(@PathVariable int id,

@RequestHeader(value="userid") String userid) {

MDC.put("userId", userid);

MDC.put("ordierId",Integer.toString(id));

Order order = queryOrder(id,userid);

log.info("Get Order");

MDC.clear();

return order;

}

Order queryOrder(int id,String userid) {

String name = "laptop";

Order order = new Order(id,name);

order.setUser(userid);

order.setPricePerItem(100);

order.setQuantity(1);

order.setTotalPrice(100);


log.info("product name:"+name);

return order;

}

}


userid와 orderid를 MDC에 넣어서 매번 로그때 마다 출력하도록 하였다.

아래 코드는 위에서 사용된 Order Value Class 내용이다.


package com.terry.logging.model;


public class Order {

public Order(int id,String item) {

this.item=item;

this.id = id;

}

public String getItem() {

return item;

}

public void setItem(String item) {

this.item = item;

}

public int getPricePerItem() {

return pricePerItem;

}

public void setPricePerItem(int pricePerItem) {

this.pricePerItem = pricePerItem;

}

public int getQuantity() {

return quantity;

}

public void setQuantity(int quantity) {

this.quantity = quantity;

}

public int getTotalPrice() {

return totalPrice;

}

public void setTotalPrice(int totalPrice) {

this.totalPrice = totalPrice;

}

String item;

int pricePerItem;

int quantity;

int totalPrice;

int id;

String user;

public String getUser() {

return user;

}

public void setUser(String user) {

this.user = user;

}

public int getId() {

return id;

}

public void setId(int id) {

this.id = id;

}

}



코드를 실행한후 REST API 클라이언트 도구 (여기서는 Postman을 사용하였다.)를 호출하면 브라우져에는 다음과 같은 결과가 출력된다.

그리고 로그는 아래와 같이 출력된다.


MDC를 이용한 저장한 컨택스트는 아래와 같이 JSON의 mdc 컨택스에 출력되었고, log.info()로 출력한 로그는 message 엘리먼트에 출력된것을 확인할 수 있다.

{"timestamp":"2019-03-25T15:16:16.394Z","level":"DEBUG","thread":"http-nio-8080-exec-2","logger":"org.springframework.web.servlet.DispatcherServlet","message":"Last-Modified value for [/orders/1] is: -1","context":"default"}

{"timestamp":"2019-03-25T15:16:16.395Z","level":"INFO","thread":"http-nio-8080-exec-2","mdc":{"ordierId":"1","userId":"terry"},"logger":"com.terry.logging.controller.OrderController","message":"product name:laptop","context":"default"}

{"timestamp":"2019-03-25T15:16:16.395Z","level":"INFO","thread":"http-nio-8080-exec-2","mdc":{"ordierId":"1","userId":"terry"},"logger":"com.terry.logging.controller.OrderController","message":"Get Order","context":"default"}


전체 소스코드는 https://github.com/bwcho75/javalogging/tree/master/springbootmdc 에 저장되어 있다.


이렇게 하면, 스프링 부트를 이용한 REST API에서 어떤 요청이 들어오더라도, 각 요청에 대한 ID를 Controller에서 부여해서, MDC를 통하여 전달하여 리턴을 할때 까지 그 값을 유지하여 로그로 출력할 수 있다.


그러나 이 방법은 하나의 스프링 부트 애플리케이션에서만 가능하고, 여러개의 스프링 부트 서비스로 이루어진 마이크로 서비스에서는 서비스간의 호출이 있을 경우 이 서비스간 호출에 대한 로그를 묶을 수 없는 단점이 있다.

예를 들어 서비스 A → 서비스 B로 호출을 하였을 경우에는 서비스 A에서 요청에 부여한 ID와 서비스 B에서 요청에 부여한 ID가 다르기 때문에 이를 묶기가 어렵다. 물론 HTTP 헤더로 ID를 전달하는 등의 방법은 있지만, 그다지 구성이 깔끔 하지 않다. 이렇게 마이크로 서비스에서 서비스간의 ID를 추적할 수 있는 방법으로 분산 환경에서 서비스간의 지연 시간을 측정하는 프레임웍으로 Zipkin이라는 프레임웍이 있다. 다음 글에서는 이 Zipkin을 로그 프레임웍과 연결해서 마이크로 서비스 환경에서 스프링 부트 기반으로 서비스간의 로그 추적을 어떻게할 수 있는지에 대해서 알아보도록 한다.


본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

로깅 시스템 #4 - Correlation id & MDC

조대협(http://bcho.tistory.com)

Correlation id

하나의 프로그램은 여러개의 메서드들로 조합이 된다. 하나의 요청을 처리하기 위해서는 여러개의 메서드들이 순차적으로 실행이 되는데, 멀티 쓰레드 프로그램에서 여러개의 쓰레드 동시에 각각의 요청을 처리할때, 각 메서드에 로그를 남기게 되면, 멀티 쓰레드 프로그램에서는 쓰레드들이 서로 컨택스트를 바꿔가며 실행이 되기 때문에, 로그 메시지가 섞이게 된다

아래 그림을 보자.


요청 A와 B가 호출되어 각각 다른 쓰레드에서 실행이 되었을때, 위의 그림과 같이 로그 메시지가 섞이게 된다. 이런 경우 요청 A에 대한 처리 내용을 확인하기 위해서 요청 A에 대한 로그만을 보고 싶을때 로그가 섞여 버려서 요청 A에 대한 로그만을 분리해내는 것이 어렵다.


이런 문제를 해결하기 위해서는 로그를 기록할때, 요청 마다 고유의 ID를 부여해서 로그를 기록하게 되면, 그 ID를 이용해서 각 요청마다의 로그를 묶어서 볼 수 있다.


위의 그림을 보면 요청 A에 대해서는 “1”이라는 ID를 지정하고, 두번째로 들어온 요청 B에 대해서는 “A”라는 ID를 지정하면, 이 ID로 각 요청에 대한 로그들을 묶어서 조회할 수 있다. 이를 Correlation ID라고 한다.

ThreadLocal

그러면 이 Correlation ID를 어떻게 구현해야 할까?

요청을 받은 메서드에서 Correlation ID를 생성한 후, 다른 메서드를 호출할때 마다 이 ID를 인자로 넘기는 방법이 있지만, 이 방법은 현실성이 떨어진다. ID를 넘기기 위해서 모든 메서드에 공통적으로 ID 필드를 가져야 하기 때문이다.

이런 문제는 자바에서는 ThreadLocal이라는 변수를 통해서 해결할 수 있다.

ThreadLocal을 쓰레드의 로컬 컨텍스트 변수로 Thread 가 존재하는 한 계속해서 남아 있는 변수이다.

무슨 이야기인가 하면, 작업 요청이 들어왔을때, 하나의 쓰레드가 생성이 되고 작업이 끝나면 쓰레드가 없어진다고 하면, 쓰레드가 살아있을 동안에, 계속 유지되는 변수이다. 즉 쓰레드가 생성되어 있는 동안에, 쓰레드 안에서 계속 참고해서 쓸수 있는 쓰레드 범위의 글로벌 변수라고 생각하면 된다.

그래서 요청을 처음 받았을때 Correlation ID를 생성하고, 이를 ThreadLocal에 저장했다가 로그를 쓸때 매번 이 ID를 ThreadLocal에서 꺼내서 같이 출력하면 된다. 이 개념을 그림으로 표현해보면 다음과 같다.


ThreadLocal의 ID 변수에 Correlation ID를 저장해놓고, 각 메서드에서 이 값을 불러서 로그 출력시 함께 출력하는 방법이다.

MDC

그러나 이걸 일일이 구현하기에는 불편할 수 있기 때문에, slf4j,logback,log4j2등의 자바 로그 프레임워크에서는 이런 기능을 MDC(Mapped Diagnostic Context)로 제공한다.

단순하게 CorrelationID 뿐만 아니라 map 형식으로 여러 메타 데이타를 넣을 수 있다. Correlation ID는 여러 요청을  묶을 수 는 있지만 다양한 요청에 대한 컨텍스트는 알 수 없다. 실행되는 요청이 어떤 사용자로 부터 들어온것인지, 또는 상품 주문시 상품 주문 ID를 넣는다던지, 요청에 대한 다양한 컨텍스트 정보를 MDC에 저장하고 로그 출력시 함께 출력하면 더 의미 있는 로그를 출력할 수 있다.


MDC를 사용한 코드를 작성해보자

이 예제에서는 slf4j와 logback을 사용한다. 아래처럼 logback과 json 관련 의존성을 pom.xml 에 정의한다.


<dependencies>

<dependency>

<groupId>ch.qos.logback</groupId>

<artifactId>logback-classic</artifactId>

<version>1.1.7</version>

</dependency>


<dependency>

<groupId>ch.qos.logback.contrib</groupId>

<artifactId>logback-json-classic</artifactId>

<version>0.1.5</version>

</dependency>


<dependency>

<groupId>ch.qos.logback.contrib</groupId>

<artifactId>logback-jackson</artifactId>

<version>0.1.5</version>

</dependency>


<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-databind</artifactId>

<version>2.9.3</version>

</dependency>

</dependencies>



그리고 로그를 json 포맷으로 출력하기 위해서 아래와 같이 logback.xml 을 작성하여, main/resources/logback.xml 로 저장한다.

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

<configuration>

   <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">

       <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">

           <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">

               <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSX</timestampFormat>

               <timestampFormatTimezoneId>Etc/UTC</timestampFormatTimezoneId>


               <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">

                   <prettyPrint>true</prettyPrint>

               </jsonFormatter>

           </layout>

       </encoder>

   </appender>


   <root level="debug">

       <appender-ref ref="stdout"/>

   </root>

</configuration>



다음 아래와 같이 간단하게 MDC를 테스트 하는 코드를 작성한다.

package com.terry.logging.logbackMDC;


import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

import org.slf4j.MDC;



public class App

{

   private static Logger log = LoggerFactory.getLogger(App.class);

   public static void main( String[] args )

   {

    log.info("Hello logback");

   

    MDC.put("userid", "terrycho");

    MDC.put("event", "orderProduct");

    MDC.put("transactionId", "a123");

    log.info("mdc test");

   

    MDC.clear();

    log.info("after mdc.clear");

   }

}


MDC를 사용하는 방법은 MDC에 값을 넣을때는 mdc.put(key,value)를 이용하여, 값을 넣고 지울때는  mdc.remove(key)를 이용해서 특정 키를 삭제한다. 전체를 지울때는 mdc.clear()를 사용한다. mdc에 저장된 내용은 logger를 이용해서 로그를 출력할때 마다 mdc 라는 element로 자동으로 함께 출력된다.

위의 예제를 보면 log.info(“hello logback”)으로 로그를 출력하였고 그 다음 mdc에 userid,event,transactionid 라는 키들로 값을 채운 다음에 log.info(“mdc test”)라는 로그를 출력하였다. 그리고 마지막에는 mdc를 모두 지운 후에 “after mdc clear”라는 로그를 출력하는 코드이다. 결과는 다음과 같다.


{

 "timestamp" : "2019-03-23T05:42:19.102Z",

 "level" : "INFO",

 "thread" : "main",

 "logger" : "com.terry.logging.logbackMDC.App",

 "message" : "Hello logback",

 "context" : "default"

}{

 "timestamp" : "2019-03-23T05:42:19.118Z",

 "level" : "INFO",

 "thread" : "main",

 "mdc" : {

   "event" : "orderProduct",

   "userid" : "terrycho",

   "transactionId" : "a123"

 },

 "logger" : "com.terry.logging.logbackMDC.App",

 "message" : "mdc test",

 "context" : "default"

}{

 "timestamp" : "2019-03-23T05:42:19.119Z",

 "level" : "INFO",

 "thread" : "main",

 "logger" : "com.terry.logging.logbackMDC.App",

 "message" : "after mdc.clear",

 "context" : "default"

}


첫번째 로그는 “Hello logback”이라는 메시지가 출력된 후에, 두번째 로그는 mdc 가 세팅되어 있기 때문에, mdc라는 element가 출력되는데, 그 안에 mdc에 저장한 event,userid,transactionid  값이 함께 출력되는 것을 볼 수 있다. 그리고 마지막에는 mdc를 clear 한후에, 로그를 출력하였기 때문에, 메시지만 출력이 되고 mdc 라는 element없이 출력된것을 확인할 수 있다.


slf4j+logback 을 사용할 경우에는 앞의 글에서 설명하였듯이 json으로 로그 출력시 message 문자열 하나면 json element로 출력할 수 있었다. 그래서 custom layout 등 다른 대체 기법을 사용하였는데, mdc를 사용하여 컨텍스트 정보를 넘기게 되면, slf4j와 logback의 제약 사항을 넘어서 json으로 여러 element를 로깅 할 수 있다.





본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

로그 시스템 #3 - JSON 로그에 필드 추가하기

조대협 (http://bcho.tistory.com)

JSON 로그에 필드 추가

앞에 예제에서 로그를 Json 포맷으로 출력하였다. 그런데, 실제로 출력된 로그 메세지는 log.info(“문자열") 로 출력한 문자열 하나만 json log의 message 필드로 출력된것을 확인 할 수 있다.

그렇지만, 단순한 디버깅 용도의 로그가 아니라 데이터를 수집하는 용도등의 로깅의 message라는 하나의 필드만으로는 부족하다. 여러개의 필드를 추가하고자 할때는 어떻게 할까? Json Object를 log.info(jsonObject) 식으로 데이터 객체를 넘기면 좋겠지만 불행하게도 slf4j에서 logging에 남길 수 있는 인자는 String  타입만을 지원하고, 데이터 객체를 (json 객체나, Map 과 같은 데이타형) 넘길 수 가 없다.

slf4j + logback

slf4j + logback 의 경우에는 앞에서 언급한것과 같이 로그에 객체를 넘길 수 없고 문자열만 넘길 수 밖에 없기 때문에, json 로그에 여러개의 필드를 넘겨서 출력할 수 가 없다. 아래는 Map 객체를 만든 후에, Jackson json 라이브러리를 이용하여, Json 문자열로 변경하여 slf4j로 로깅한 코드이다.

package com.terry.logging.jsonlog;


import java.util.Map;

import java.util.TreeMap;


import org.slf4j.Logger;

import org.slf4j.LoggerFactory;


import com.fasterxml.jackson.core.JsonProcessingException;

import com.fasterxml.jackson.databind.ObjectMapper;


public class Slf4j

{

private static Logger log = LoggerFactory.getLogger(Slf4j.class);

   public static void main( String[] args ) throws JsonProcessingException

   {

       Map<String,String> map = new TreeMap();

    map.put("name", "terry");

    map.put("email","terry@mycompany.com");

    String msg = new ObjectMapper().writeValueAsString(map);

    System.out.println("MSG:"+msg);

    log.info(msg);

   }

}

실행을 하면 message 엘리먼트 안에 json 문자열로 출력이 되는 것이 아니라 “ 등을 escape 처리하여 json 문자열이 아닌 형태로 출력이 된다.

{

 "thread" : "main",

 "level" : "INFO",

 "loggerName" : "com.terry.logging.jsonlog.Slf4j",

 "message" : "{\"email\":\"terry@mycompany.com\",\"name\":\"terry\"}",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1553182988,

   "nanoOfSecond" : 747493000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

}


그래서 다른 방법을 사용해야 하는데, 로그를 남길때 문자열로 여러 필드를 넘기고 이를 로그로 출력할때 이를 파싱해서 json 형태로 출력하는 방법이 있다.

log.info("event:order,name:terry,address:terrycho@google.com");

와 같이 key:value, key:value, ..  식으로 로그를 남기고, Custom Layout에서 이를 파싱해서 json 으로

{

 “key”:”value”,

 “key”:”value”,

 “key”:”value”

}

형태로 출력하도록 하면 된다. 이렇게 하기 위해서는 log message로 들어온 문자열을 파싱해서 json으로 변환해서 출력할 용도로 Layout을 customization 하는 코드는 다음과 같다.


{package com.terry.logging.logbackCustom;


import ch.qos.logback.classic.spi.ILoggingEvent;

import ch.qos.logback.contrib.json.classic.JsonLayout;


import java.util.Map;

import java.util.StringTokenizer;

import java.util.TreeMap;


import com.fasterxml.jackson.core.JsonProcessingException;

import com.fasterxml.jackson.databind.ObjectMapper;


public class CustomLayout extends JsonLayout {

   @Override

   protected void addCustomDataToJsonMap(Map<String, Object> map, ILoggingEvent event) {

       long timestampMillis = event.getTimeStamp();

       map.put("timestampSeconds", timestampMillis / 1000);

       map.put("timestampNanos", (timestampMillis % 1000) * 1000000);

       map.put("severity", String.valueOf(event.getLevel()));

       map.put("original_message", event.getMessage());

       map.remove("message");

       

       StringTokenizer st = new StringTokenizer(event.getMessage(),",");

       Map<String,String> json = new TreeMap();


       while(st.hasMoreTokens()) {

       String elmStr = st.nextToken();

       StringTokenizer elmSt = new StringTokenizer(elmStr,":");

       String key = elmSt.nextToken();

       String value = elmSt.nextToken();

       json.put(key, value);

       }

       

    String msg;

try {

msg = new ObjectMapper().writeValueAsString(json);

} catch (JsonProcessingException e) {

// TODO Auto-generated catch block

e.printStackTrace();

}

    map.put("jsonpayload", json);

   

   }

}


먼저 JsonLayout을 상속받아서 CustomLayout 이라는 클래스를 만든다. 그리고 addCustomDataToJsonMap 이라는 메서드를 오버라이딩한다. 이 메서드는 로그로 출력할 메시지와 각종 메타 정보(쓰레드명, 시간등)을 로그로 최종 출력하기 전에, Map객체에 그 내용을 저장하여 넘기는 메서드이다.

이 메서드 안에서 앞에서 로그로 받은 문자열을 파싱해서 json 형태로 만든다. 아래 코드가 파싱을 해서 파싱된 내용을 Map에 key/value 형태로 저장하는 코드이고


       StringTokenizer st = new StringTokenizer(event.getMessage(),",");

       Map<String,String> json = new TreeMap();


       while(st.hasMoreTokens()) {

       String elmStr = st.nextToken();

       StringTokenizer elmSt = new StringTokenizer(elmStr,":");

       String key = elmSt.nextToken();

       String value = elmSt.nextToken();

       json.put(key, value);

       }

다음 코드는 이 Map을 json으로 변환한 후, 이를 다시 String으로 변환하는 코드이다.


msg = new ObjectMapper().writeValueAsString(json);


그 후에 이 json 문자열을 jsonpayload 라는 json element 이름으로 해서, json 내용을 json으로 집어 넣는 부분이다.


map.put("jsonpayload", json);

   

그리고, 이 CustomLayout을 사용하기 위해서 src/main/logback.xml에서 아래와 같이 CustomLayout 클래스의 경로를 지정한다.


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

<configuration>

   <appender name="CONSOLE-JSON" class="ch.qos.logback.core.ConsoleAppender">

       <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">

           <layout class="com.terry.logging.logbackCustom.CustomLayout">

               <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">

                   <prettyPrint>true</prettyPrint>

               </jsonFormatter>

               <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSXXX</timestampFormat>

               <appendLineSeparator>true</appendLineSeparator>

           </layout>

       </encoder>

   </appender>


   <root level="info">

       <appender-ref ref="CONSOLE-JSON"/>

   </root>

</configuration>



설정이 끝난 후에, 로그를 출력해보면 다음과 같이 jsonpayload element 부분에 아래와 같이 json 형태로 로그가 출력된다.


{

 "timestamp" : "2019-03-22T17:48:56.434+09:00",

 "level" : "INFO",

 "thread" : "main",

 "logger" : "com.terry.logging.logbackCustom.App",

 "context" : "default",

 "timestampSeconds" : 1553244536,

 "timestampNanos" : 434000000,

 "severity" : "INFO",

 "original_message" : "event:order,name:terry,address:terrycho@google.com",

 "jsonpayload" : {

   "address" : "terrycho@google.com",

   "event" : "order",

   "name" : "terry"

 }

}


log4j2

log4j2의 경우 slf4+logback 조합보다 더 유연한데, log.info 와 같이 로깅 부분에 문자열뿐만 아니라 Object를 직접 넘길 수 있다. ( log4j2의 경우에는 2.11 버전부터 JSON 로깅을 지원 : https://issues.apache.org/jira/browse/log4j2-2190 )

즉 log.info 등에 json 을 직접 넘길 수 있다는 이야기다. 그렇지만 이 기능은 log4j2의 기능이지 slf4j의 인터페이스를 통해서 제공되는 기능이 아니기 때문에, slf4j + log4j2 조합으로는 사용이 불가능하고  log4j2만을 이용해야 한다.


log4j2를 이용해서 json 로그를 남기는 코드는 아래와 같다.


package com.terry.logging.jsonlog;


import java.util.Map;

import java.util.TreeMap;


import org.apache.logging.log4j.message.ObjectMessage;

import org.apache.logging.log4j.LogManager;

import org.apache.logging.log4j.Logger;


public class App

{

  private static Logger log = LogManager.getLogger(App.class);


   public static void main( String[] args )

   {

    Map<String,String> map = new TreeMap();

    map.put("name", "terry");

    map.put("email","terry@mycompany.com");

    ObjectMessage msg = new ObjectMessage(map);

    log.info(msg);

   }

}



Map 객체를 만들어서 json 포맷처럼 key/value 식으로 데이타를 넣은 다음에 ObjectMessage 객체 타입으로 컨버트를 한다. 그리고 로깅에서 log.info(msg)로 ObjectMessage 객체를 넘기면 된다.

그리고 아래는 위의 코드를 실행하기 위한 pom.xml 에서 dependency 부분이다.


<dependency>

<groupId>org.apache.logging.log4j</groupId>

<artifactId>log4j-slf4j18-impl</artifactId>

<version>2.11.2</version>

</dependency>

<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-core</artifactId>

<version>2.7.4</version>

</dependency>

<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-databind</artifactId>

<version>2.7.4</version>

</dependency>

<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-annotations</artifactId>

<version>2.7.4</version>

</dependency>


실행을 해보면 아래와 같이 json 포맷으로 메세지가 출력된 결과이다. message element를 보면, 위에서 넣은 key/value 필드인 email과, name 항목이 출력된것을 확인할 수 있다.


{

 "thread" : "main",

 "level" : "INFO",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : {

   "email" : "terry@mycompany.com",

   "name" : "terry"

 },

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",

 "instant" : {

   "epochSecond" : 1553245991,

   "nanoOfSecond" : 414157000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

}



본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

로그 시스템 #2- 자바 로그 & JSON 로그 포맷

조대협 (http://bcho.tistory.com)


앞 글에서 간단하게 자바 로깅 프레임워크에 대해서 알아보았다. 그러면 앞에서 추천한 slf4j와 log4j2로 실제 로깅을 구현해보자

SLF4J + log4j2

메이븐 프로젝트를 열고 dependencies 부분에 아래 의존성을 추가한다. 버전은 최신 버전을 확인하도록 한다. artifactid가 log4j-slf4j-impl 이지만, log4j가 아니라 log4j2가 사용된다.


<dependency>

<groupId>org.apache.logging.log4j</groupId>

<artifactId>log4j-slf4j-impl</artifactId>

<version>2.11.2</version>

</dependency>


다음 log4j2의 설정 정보 파일인 log4j2.properties 파일을 src/main/resources 디렉토리 아래에 다음과 같이 생성한다. Appender나, Layout등 다양한 정보 설정이 있지만 그 내용은 나중에 자세하게 설명하도록 한다.


appenders=xyz


appender.xyz.type = Console

appender.xyz.name = myOutput

appender.xyz.layout.type = PatternLayout

appender.xyz.layout.pattern = [MYLOG %d{yy-MMM-dd HH:mm:ss:SSS}] [%p] [%c{1}:%L] - %m%n


rootLogger.level = info


rootLogger.appenderRefs = abc


rootLogger.appenderRef.abc.ref = myOutput


그리고 아래와 같이 코드를 만든다.

LoggerFactory를 이용해서 Logger를 가지고 온다. 현재 클래스 명에 대한 Logger 를 가지고 오는데, 위의 설정 파일을 보면 rootLogger만 설정하였기 때문에, rootLogger가 사용된다.

package com.terry.logging.helloworld;


import org.slf4j.Logger;

import org.slf4j.LoggerFactory;



public class App

{

   private static Logger log = LoggerFactory.getLogger(App.class);

   public static void main( String[] args )

   {

       System.out.println( "Hello World!" );

       

       log.info("Hello slf4j");

   }

}



가저온 logger를 이용해서 log.info로 로그를 출력한다.

콘솔로 출력된 로그는 아래와 같다.

[MYLOG 19-Mar-18 23:07:01:373] [INFO] [App:71] - Hello slf4j


JSON 포맷으로 로그 출력

근래에는 시스템이 분산 구조를 가지고 있기 때문에 텍스트 파일로 남겨서는 여러 분산된 서비스의 로그를 모아서 보기가 어렵다. 그래서, 이런 로그를 중앙 집중화된 서버로 수집 및 분석하는 구조를 가지는데, 수집 서버에서는 이 로그들을 구조화된 포맷으로 저장하는 경우가 일반적이다. 각 로그의 내용을 저장 구조의 개별 자료 구조(예를 들어 테이블의 컬럼)에 맵핑해서 저장하는데, 이를 위해서는 로그가 JSON,XML 또는 CSV와 같은 형태로 구조화가 되어 있어야 한다.

이런 구조화된 로그를 structured logging 이라고 한다. 로그 엔트리 하나를 JSON에 포함해서 출력하는 방법에 대해서 알아본다.

slf4j + logback

SLF4 + logback을 이용하여 레이아웃을 JSON으로 출력하는 코드이다.


package com.terry.logging.logback;


import java.util.Map;

import java.util.TreeMap;


import org.slf4j.Logger;

import org.slf4j.LoggerFactory;


import com.fasterxml.jackson.core.JsonProcessingException;

import com.fasterxml.jackson.databind.ObjectMapper;


public class App

{

   private static Logger log = LoggerFactory.getLogger(App.class);

   public static void main( String[] args ) throws JsonProcessingException

   {


       log.info("hello log4j");

   }

}


pom.xml에 아래와 같이 logback과 json 관련 dependency를 추가한다.


<dependencies>

<dependency>

<groupId>ch.qos.logback</groupId>

<artifactId>logback-classic</artifactId>

<version>1.1.7</version>

</dependency>


<dependency>

<groupId>ch.qos.logback.contrib</groupId>

<artifactId>logback-json-classic</artifactId>

<version>0.1.5</version>

</dependency>


<dependency>

<groupId>ch.qos.logback.contrib</groupId>

<artifactId>logback-jackson</artifactId>

<version>0.1.5</version>

</dependency>


<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-databind</artifactId>

<version>2.9.3</version>

</dependency>

</dependencies>



마지막으로 src/main/resources.xml 파일을 아래와 같이 작성한다.  

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

<configuration>

   <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">

       <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">

           <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">

               <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSX</timestampFormat>

               <timestampFormatTimezoneId>Etc/UTC</timestampFormatTimezoneId>


               <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">

                   <prettyPrint>true</prettyPrint>

               </jsonFormatter>

           </layout>

       </encoder>

   </appender>


   <root level="debug">

       <appender-ref ref="stdout"/>

   </root>

</configuration>


아래는 출력 결과이다. message 필드에 로그가 출력 된것을 볼 수 있다.


{

 "timestamp" : "2019-03-19T07:24:31.906Z",

 "level" : "INFO",

 "thread" : "main",

 "logger" : "com.terry.logging.logback.App",

 "message" : "hello log4j",

 "context" : "default"

}


slf4j + log4j2

다음은 slft4+log4j2 를 이용한 예제이다.  logback과 크게 다르지는 않다.

아래와 같이 pom.xml 의 dependencies에 아래 내용을 추가하자. json layout은 jackson을 사용하기 때문에 아래와 같이 jackson에 대한 의존성도 함께 추가한다.


<dependency>

<groupId>org.apache.logging.log4j</groupId>

<artifactId>log4j-slf4j-impl</artifactId>

<version>2.11.2</version>

</dependency>

<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-core</artifactId>

<version>2.7.4</version>

</dependency>

<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-databind</artifactId>

<version>2.7.4</version>

</dependency>

<dependency>

<groupId>com.fasterxml.jackson.core</groupId>

<artifactId>jackson-annotations</artifactId>

<version>2.7.4</version>

</dependency>


다음 아래와 같이 log4j2.properties 파일을 src/main/resources 폴더에 저장한다.


status = info


appender.ana_whitespace.type = Console

appender.ana_whitespace.name = ana_whitespace

appender.ana_whitespace.layout.type = JsonLayout

appender.ana_whitespace.layout.propertiesAsList = false

appender.ana_whitespace.layout.compact = false

appender.ana_whitespace.layout.eventEol = true

appender.ana_whitespace.layout.objectMessageAsJsonObject = true

appender.ana_whitespace.layout.complete= true

appender.ana_whitespace.layout.properties= true


rootLogger.level = info

rootLogger.appenderRef.ana_whitespace.ref = ana_whitespace


위에 보면 layout.type을 JsonLayout으로 지정하였다. 기타 다른 필드에 대한 정보는

정보는 https://logging.apache.org/log4j/2.0/manual/layouts.html 를 참고하기 바란다.


그리고 아래와 같이 코드를 이용해서 info 레벨의 로그를 출력해보자

package com.terry.logging.jsonlog;

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;



public class App

{

private static Logger log = LoggerFactory.getLogger(App.class);

   public static void main( String[] args )

   {

       

       log.info("Hello json log");

       log.error("This is error");

       log.warn("this is warn");

   }

}


코드를 컴파일 하고 실행하면 아래와 같은 형태로 로그가 출력된다. 로그 출력 형태는 logback과는 많이 차이가 있다.


[

{

 "thread" : "main",

 "level" : "INFO",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : "Hello json log",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1552923302,

   "nanoOfSecond" : 38337000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

}

, {

 "thread" : "main",

 "level" : "ERROR",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : "This is error",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1552923302,

   "nanoOfSecond" : 109170000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

}

, {

 "thread" : "main",

 "level" : "WARN",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : "this is warn",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1552923302,

   "nanoOfSecond" : 109618000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

}


]


json을 여러가지 포맷으로 출력할 수 있다. 위의 로그를  잘보면 로그 시작과 끝에 json 포맷을 맞추기 위해서 “[“와 “]”를 추가하고, 로그 레코드 집합당 “,”로 레코드를 구별한것을 볼 수 있다. 만약에 “[“,”]”를 로그 처음과 마지막에서 제거하고, 로그 레코드 집합동 “,”를 제거하고 newline으로만 분류하고 싶다면 log4j2.properties 파일에서 appender.ana_whitespace.layout.complete = false로 하면 된다.

아래는 layout.complete를 false로 하고 출력한 결과 이다.


{ ←  이부분에 “[” 없음

 "thread" : "main",

 "level" : "INFO",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : "Hello json log",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1552923722,

   "nanoOfSecond" : 98574000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

} ←  이부분에 콤마가 없음

{

 "thread" : "main",

 "level" : "ERROR",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : "This is error",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1552923722,

   "nanoOfSecond" : 167047000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

}

{

 "thread" : "main",

 "level" : "WARN",

 "loggerName" : "com.terry.logging.jsonlog.App",

 "message" : "this is warn",

 "endOfBatch" : false,

 "loggerFqcn" : "org.apache.logging.slf4j.Log4jLogger",

 "instant" : {

   "epochSecond" : 1552923722,

   "nanoOfSecond" : 167351000

 },

 "contextMap" : { },

 "threadId" : 1,

 "threadPriority" : 5

} ←  이부분에 “]” 없음


그리고 로그파일을 보는데, JSON의 경우에는 위와 같이 각 element 마다 줄을 바꿔서 사람이 읽기 좋은 형태이기는 하지만, 대신 매번 줄을 바꾸기 때문에 검색이 어려운 경우가 있다. 그래서 로그 레코드 하나를 줄 바꿈 없이 한줄에 모두 출력할 수 있도록 할 수 있는데, appender.ana_whitespace.layout.compact = true로 주면 된다. 아래는 옵션을 적용한 결과 이다.

{"thread":"main","level":"INFO","loggerName":"com.terry.logging.jsonlog.App","message":"Hello json log","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","instant":{"epochSecond":1552923681,"nanoOfSecond":430798000},"contextMap":{},"threadId":1,"threadPriority":5}

{"thread":"main","level":"ERROR","loggerName":"com.terry.logging.jsonlog.App","message":"This is error","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","instant":{"epochSecond":1552923681,"nanoOfSecond":491757000},"contextMap":{},"threadId":1,"threadPriority":5}

{"thread":"main","level":"WARN","loggerName":"com.terry.logging.jsonlog.App","message":"this is warn","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","instant":{"epochSecond":1552923681,"nanoOfSecond":492095000},"contextMap":{},"threadId":1,"threadPriority":5}



본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

로그 시스템 #1 - 자바 로그 프레임웍

조대협 (http://bcho.tistory.com)

로그 시스템

로그 시스템은 소프트웨어의 이벤트를 기록 함으로써, 소프트웨어 동작 상태를 파악하고 문제가 발생했을때 이 동작 파악을 통해서 소프트웨어의 문제를 찾아내고 해결하기 위해서 디자인 되었다.

주로 로그 파일이라는 형태로 하나의 파일에 이벤트들을 기록하였다.


그러나 소프트웨어 스택이 OS, 미들웨어, 사용자 애플리케이션 (자바나 파이썬등으로 구현된 애플리케이션)으로 점점 다중화되고 시스템이 대형화 되면서 한대가 아니라 여러대의 서버에 로그를 기록하고 또한 마이크로 서비스 아키텍처로 인하여 서버 컴포넌트가 분산됨에 따라서 로그를 수집해야할 포인트가 많아지게 되었다. 이로 인해서 로그 시스템이 분산 환경을 지원해야 할 필요가 되었고, 단순히 파일로 로그를 기록하는 것만으로는 이러한 여러 시스템과 다중 계층에 대한 모니터링이 불가능하게 되었다.


또한 데이터 분석의 중요성이 대두됨에 따라서, 에러등의 동작 파악성의 로그 뿐만 아니라 사용자의 액티버티를 수집하여 데이터 분석에 사용하기 위해서 데이터 수집 역시 로그 시스템을 통하기 시작하였다.


그래서 몇개의 글에 걸쳐서 좋은 로그 시스템을 개발하기 위한 아키텍처에 대해서 설명하고자 한다.

좋은 로그 시스템이란

먼저 좋은 로그 시스템의 기본 개념을 정의 해보면 다음과 같다.

  • 로그 메시지는 애플리케이션의 동작을 잘 이해할 수 있도록 충분히 구체적이어야 한다.

  • 로그 메시지를 기록하는데 성능 저하가 없어야 한다.

  • 어떤 배포 환경이라도 로그를 수집하고 저장할 수 있도록 충분히 유연해야 한다. (분산 환경 지원, 대용량 데이타 지원등)

자바 로깅 프레임워크

각 프로그래밍 언어마다 고유의 로깅 프레임워크을 지원하지만, 특히 자바의 경우에는 그 프레임웍 수가 많고 발전된 모델이 많아서 자바 프레임워크를 살펴보고 넘어가고자 한다.  

자바는 역사가 오래된 만큼 많은 로깅 프레임웍을 가지고 있다. log4j, logback, log4j2,apache common logging, SLF4J 등 다양한 프레임워크 들이 있는데, 그 개념과 장단점을 알아보도록 하자.

SLF4J

SLF4J는 (Simple Logging Facade for Java)의 약자로 이름이 뜻하는 것과 같이 로깅에 대한 Facade 패턴이다. SLF4J는 자체가 로깅 프레임웍이 아니라, 다양한 로깅 프레임웍을 같은 API를 사용해서 접근할 수 있도록 해주는 추상화 계층이다. 그래서 다른 로그프레임웍과 같이 사용해야 하는데, 보통 Log4J, Logback, Log4J2등이 많이 사용된다. 즉 애플리케이션은 SLF4J API 인터페이스를 통해서 호출하지만, 실제로 호출되는 로깅 프레임웍은 다른 프레임웍이 호출된다는 이야기이다. 이렇게 추상화를 통해서 용도와 목적에 맞게 다른 로깅 프레임워크 으로 쉽게 전환이 가능함은 물론이고, 로깅에 필요한 코드들을 추상화해주기 때문에, 훨씬 쉽고 간단하게 로깅이 가능하다. apache common logging 역시, SLF4J와 같이 다른 로깅 프레임워크 들을 추상화 해주는 기능을 제공한다.



<그림 : SLF4J 가 다른 로깅 프레임웍을 추상화 하는 개념도 >

출처 source


그러나 SLF4J 이전에 개발된 레거시 시스템들의 경우에는 이러한 추상화 계층이 없어서 로그 프레임웍을 변경하고 있기 때문에 로깅 프레임웍을 교체하기가 어렵다. 이런 상황을 해결하기 위해서 SLF4J는 기존 로그 프레임웍에 대한 브릿지를 제공한다. 예를 들어 log4J로 개발된 로깅을 브릿지를 이용해서 SLF4J를 사용하도록 전환할 수 있다. 이런 구조는 레거시 로깅 시스템을 사용해서 개발된 시스템에 대해서, 로그 프레임웍에 대한 코드를 변경하지 않고, 뒷단에 로그 프레임웍을 변경할 수 있게 해주기 때문에, 로깅 프레임웍에 대한 마이그레이션을 쉽게 해준다.



<그림 : SLF4J 브릿지를 이용해서, 기존 로그 시스템을 연동 하는 개념도 >


자바 로깅 프레임워크

자바 로그 프레임웍에는 여러가지 종류가 있지만 그중에서 대표적을 사용되는 로그 프레임웍은 log4j,logback,log4j2 세가지 이다.

Log4J

Log4J는 이 중에서 가장 오래된 로그프레임웍으로 로그 프레임웍에 대한 초반 개념을 설정했다고 볼 수 있다. 현재는 개발이 중지되고, Log4J2로 새로운 버전으로 변경되었다.

Logback

아마 현재 국내에서 가장 널리 많이 사용되고 있는 로그 프레임워크일것이다. Log4J 개발자가 개발한 로그 프레임워크로 주로 Log4J 성능 부분에 대한 개선 작업이 많이 이루어 졌다. SLF4J와 네이티브로 연동이 가능하다.

Log4J2

가장 근래에 나온 프레임워크로 Logback 보다 후에 나오고, 가장 빠른 성능을 제공한다. Logback과 SLF4J사이의 연동 문제를 해결하였으며 비동기 로깅 ( asynchronous logging ) 을 제공하여, 특히 멀티 쓰레드 환경에서 높은 성능을 제공한다.



(source : https://logging.apache.org/log4j/2.x/performance.html )


또한 근래의 로깅 시스템들은 로그를 파일로 기록하기 보다는 ELK(Elastic Search)나 Kafka 등 외부 시스템으로 로그를 전송하여 모으는 형태를 많이 취하기 때문에 이에 대한 연동을 Appender를 통해서 제공한다.


제공되는 Appender는 다음과 같다.

  • Console

  • File, RollingFile, MemoryMappedFile

  • Flume, Kafka, JDBC, JMS, Socket, ZeroMQ

  • SMTP (emails on errors, woo!)

  • … much more


만약에 새로운 시스템을 개발한다면, Logback 보다는 그 다음 세대인 격인 Lob4j2를 사용하는 것을 권장한다.

본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

Zipkin을 이용한 MSA 환경에서 분산 트렌젝션의 추적 #1

조대협 (http://bcho.tistory.com)

개념

분산 트렌젝션이랑 여러개의 서비스를 걸쳐서 이루어 지는 트렌젝션을 추적하는 기능을 정의한다.

마이크로 서비스 아키텍쳐 (이하 MSA)와 같은 구조에서는 하나의 HTTP 호출이 내부적으로 여러개의 서비스를 거쳐서 일어나게 되는데, 그러면 어느 구간에서 병목이 생기는지 추적하기가 어려워진다.

아래 그림을 보면 클라이언트가 Service A를 호출하고, Service A 가 Service B,D 를, Service B가 Service C를 호출한다.


이렇게 트렌젝션이 여러 컴포넌트의 조합을 통해서 발생하기 때문에 Jennifer와 같은 전통적인 APM (Application Performance Monitoring) 도구를 이용해서 추적하기가 어렵기 때문에 별도의 분산 로그 추적 시스템이라는 것이 필요하다.

작동 원리

그러면 이러한 분산 로그는 어떻게 수집 및 추적하는 것일까? 통상적으로 Trace와 Span 이라는 개념을 사용한다.



클라이언트가 서버로 호출한 하나의 호출을 Trace라고 했을 때, 서비스 컴포넌트간의 호출을 Span이라고 한다.각 서비스 컴포넌트들은 하나의 클라이언트 호출을 추적하기 위해서 같은 Trace Id를 사용하고, 각 서비스간의 호출은 각각 다른 Span Id를 사용한다. 이렇게 함으로써 전체 트렌젝션 시간을 Trace로 추적이 가능하고, 각 서비스별 구간 시간은 Span으로 추적할 수 있다.

솔루션

이러한 분산 로그 추적을 위한 솔루션 중에 오픈소스로는 트위터에서 개발된 ZipKin(https://zipkin.io/) , Jagger(https://jaeger.readthedocs.io/en/latest/) , Opencensus(https://opencensus.io/) 등이 있는데, 이러한 분산 로그 추적은 구글의 Dapper 논문을 기초로 디자인 되어 개발되었다.

Zipkin

그 중에서, 가장 활성화 되어 있는 오픈소스 중 하나가 Zipkin인데, 오픈 소스 생태계가 활발해서 플러그인이나 부가적인 도구들이 많다.

전체적인 구조는 다음과 같다.


<그림 . Zipkin 아키텍쳐 >


지원 프로토콜

Zipkin으로 추적할 수 있는 분산 트렌젝션은 HTTP를 기본으로 지원하고 , 이외에도 많이 사용되는 리모트 프로토콜인 gRPC를 함께 지원한다.

클라이언트 라이브러리

Zipkin 클라이언트 SDK는 https://zipkin.io/pages/existing_instrumentations 에 있는데, Zipkin에서 공식적으로 지원하는 라이브러는 아래와 같이 C#, Go, Java, Javascript,Ruby,Scala 등이 있다.




이외에도 오픈 소스 커뮤니티에서 지원하는 라이브러리로 파이썬, PHP등 대부분의 언어가 지원이 가능하다.

Zipkin 라이브러리는 수집된 트렌젝션 정보를 zipkin 서버의 collector 모듈로 전송한다. 이 때 다양한 프로토콜을 사용할 수 있는데, 일반적으로 HTTP를 사용하고, 시스템의 규모가 클 경우에는 Kafka 큐를 넣어서 Kafka 프로토콜로 전송이 가능하다.

스토리지

Zipkin 클라이언트 SDK에 의해서 전송된 정보는 스토리지에 저장된다.

사용할 수 있는 스토리지는 다음과 같다

  • In-memory

  • MySQL

  • Cassandra

  • Elastic Search

메모리는 별도의 스토리지 설치가 필요없기 때문에 간단하게 로컬에서 테스트할 수 있는 정도로 사용하는 것이 좋고, MySQL은 소규모 서비스에 적절하다. 실제로 운영환경에 적용하려면 Cassandra나 Elastic Search를 저장소로 사용하는 것이 바람직하다.

대쉬 보드

이렇게 수집된 정보는 대쉬 보드를 이용하여 시각화가 가능하다. Zipkin 서버의 대쉬보드를 사용할 수 있고, Elastic Search 백앤드를 이용한 경우에는 Kibana를 이용하여 시각화가 가능하다.


Spring Sleuth

Zipkin 라이브러리 중에서 주목해서 살펴볼 부분은 Spring / Java 지원인데, Spring에서 Sleuth라는 모듈 이름으로 공식적으로 Zipkin을 지원하기 때문에, Spring (& Springboot) 연동이 매우 쉽다.

자바 애플리케이션에서 Trace 정보와 Span 정보를 넘기는 원리는 다음과 같다.


여러개의 클래스의 메서드들을 거쳐서 트렌젝션이 완성될때, Trace 정보와 Span 정보 Context가 유지가 되어야 하는데, 자바 애플리케이션에서는 쓰레드마다 할당되는 쓰레드의 일종의 전역변수인 Thread Local 변수에 이 Trace와 Span Context 정보를 저장하여 유지한다.


분산 트렌젝션은 HTTP나 gRPC로 들어오기 때문에, Spring Sleuth는 HTTP request가 들어오는 시점과 HTTP request가 다른 서비스로 나가는 부분을 랩핑하여 Trace와 Span Context를 전달한다.

아래 그림과 같이 HTTP로 들어오는 요청의 경우에는 Servlet filter를 이용하여, Trace Id와 Span Id를 받고 (만약에 이 서비스가 맨 처음 호출되는 서비스라서 Trace Id와 Span Id가 없을 경우에는 이를 생성한다.)

, 다른 서비스로 호출을 할 경우에는 RestTemplate 을 랩핑하여, Trace Id와 Span Id와 같은 Context 정보를 실어서 보낸다.



HTTP를 이용한 Trace와 Span 정보는 HTTP Header를 통해서 전달되는데


위의 그림과 같이 x-b3로 시작하는 헤더들과 x-span-name 등을 이용하여 컨택스트를 전달한다.

이렇게 ServletFilter와 RestTemplate을 Spring 프레임웍단에서 랩핑해줌으로써, 개발자는 별도의 트레이스 코드를 넣을 필요 없이 Spring을 이용한다면 분산 트렌젝션을 추적할 수 있도록 해준다.


다음글에서는 실제로 Spring Sleuth와 Zipkin을 이용하여 분산로그를 추적하는 예제를 구현해보도록 하겠다.


본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.


한시간에 만드는 대용량 로그 수집 시스템

조대협 (http://bcho.tistory.com)


정정 및 참고 내용

2017.1.24 몇가지 내용을 정정합니다.

https://cloud.google.com/logging/quota-policy 를 보면 스택드라이버 로깅에 쿼타 제한이 초당 500건/계정으로 잡혀있어서. 일반적인 경우는 최대 500 TPS의 성능을 낼 수 있습니다. 그 이상의 성능이 필요하면, 여러 계정을 사용해야 합니다 또는 구글에 별도의 쿼타 증설 요청을 해야 합니다.

하루에, 최대 2천5백만건의 로그를 하나의 프로젝트를 통해서 수집이 가능합니다.


또한 프리티어의 경우에는 한달에 로그를 5GB  까지 수집이 가능한데, 이게 넘으면 로그가 더이상 수집되지 않습니다. 그래서 아래 내용 처럼 빅쿼리로 Export를 해서 로그가 5GB 이상 스택드라이버에 저장되지 않도록 해야 합니다. (차기전에 데이타를 퍼나르는)

애플리케이션 로그 이외에도, VM 로그등도 이 5GB의 용량을 공유하기 때문에, VM 로그등도 차기전에 GCS로 퍼 나르거나 또는 구글 Support 티켓을 통하여 애플리케이션 로그 이외의 로그를 수집하지 않도록 별도 요청해야 합니다. (로그 저장 용량에 대해서 비용을 지불하면, 이런 제약은 없음)


백앤드 시스템에서 중요한 컴포넌트중의 하나가, 클라이언트로 부터 로그를 수집 및 분석하는 시스템이다.

오늘 설명할 내용은 500 TPS (Transaction Per Sec)가 넘는 대용량 로그 수집 및 분석 시스템을  managed 서비스를 이용하여, 쉽고 빠르게 구축할 수 있는 방법에 대해서 소개하고자한다.


일반적인 로그 수집 및 분석 시스템 아키텍쳐

일반적으로 클라이언트에서 로그를 수집하여 분석 및 리포팅 하는 시스템의 구조는 다음과 같다.


  • 앞단의  API 서버가 로그를 클라이언트로 부터 수집하고 데이타를 정재한다.

  • 로그 저장소가 순간적으로 많은 트래픽을 감당할 수 없는 경우가 많기 때문에, 중간에 Message Q를 넣어서, 들어오는 로그를 Message Q에 저장하여 완충을 한다.

  • 이 Message Q로 부터 로그를 Message Consumer가 순차적으로 읽어서 Log Storage에 저장한다.

  • 저장된 로그는 Reporting 툴을 이용하여 시각화 한다.


이런 구조 이외에도 API 서버에서 파일로 로그를 저장한 후,  Fluentd나, LogStash 등의 로그 수집기를 이용하는 방법등 다양한 아키텍쳐가 존재한다.


이런 시스템을 구축하기 위한 일반적인 솔루션들은 다음과 같다.


컴포넌트

솔루션


API 서버

node.js, ruby, php 등 일반적인 웹서버


Message Q

Rabbit MQ와 같은 일반적인 큐
Kafaka 와 같은 대량 큐

AWS SQS나 구글 Pub/Sub 같은 클라우드 큐


Message Consumer

Multi Thread(or Process) + Timer를 조합하여 메세지를 폴링 방식으로 읽어오는 애플리케이션 개발


Log Storage

Hadoop, HBase 와 같은 하둡 제품

Drill,Druid와 같은 SQL 기반 빅데이타 플랫폼

Elastic Search


Reporting

Zeppeline, Jupyter 와 같은 노트북류

Kibana



구조나 개념상으로는 그리 복잡한 시스템은 아니지만, 저러한 솔루션을 모두 배우고, 설치하고 운영하는데 시간이 들고, 각각의 컴포넌트를 구현해야하기 때문에 꽤나 시간이 걸리는 작업이다.


그러면 이러한 로그 수집 및 분석 작업을 클라우드 서비스를 이용하여 단순화 할 수 없을까?

스택 드라이버

스택 드라이버는 구글 클라우드의 모니터링, 로깅 및 애플리케이션 성능 분석등 모니터링 분야에서 다양한 기능을 제공하는 서비스 이다.

그중에서 스택드라이버 로깅은 구글 클라우드나 아마존 또는 기타 인프라에 대한 모니터링과, Apache, MySQL과 같은 써드 파티 미들웨어에 대한 로그 수집 및 모니터링을 지원하는데, 이 외에도, 사용자가 애플리케이션에서 로깅한 데이타를 수집하여 모니터링할 수 있다.



스택 드라이버와 빅쿼리를 이용한 로그 수집 분석 시스템 구현

스택 드라이버 로깅의 재미있는 기능중 하나는 로그 EXPORT 기능인데, 로그 데이타를 구글 클라우드 내의 다른 서비스로 로그 데이타를 내보낼 수 있다.


  • GCS (Google Cloud Storage)로 주기적으로 파일로 로그 데이타를 내보내거나

  • Pub/Sub이나 Big Query로 실시간으로 데이타를 내보낼 수 있다.


그렇다면 스택 드라이버를 통해서 빅쿼리에 로그 데이타를 직접 저장한다면 복잡한 Message Q나, Message Consumer 등의 구현도 불필요하고, 로그 저장도 복잡한 오픈 소스를 이용한 개발이나 운영도 필요 없이, 매니지드 서비스인 빅쿼리를 이용하여 간략하게 구현할 수 있다.

스택 드라이버 로깅을 이용한 로그 수집 시스템 구현


스택 드라이버 애플리케이셔 로깅 기능을 이용하여 클라이언트로 부터 로그를 수집하여 분석하는 시스템의 아키텍쳐를 그려 보면 다음과 같다.




API 서버를 이용하여 클라이언트로 부터 로그를 수집하고, API 서버는 스택 드라이버 로깅 서비스로 로그를 보낸다. 스택 드라이버 로깅은 Export 기능을 이용하여, 수집된 로그를 실시간으로 빅쿼리로 전송한다. 빅쿼리에 저장된 로그는 구글 데이타 스튜디오 (http://datastudio.google.com)이나 제플린, 파이썬 주피터 노트북과 같은 리포팅 도구에 의해서 시각화 리포팅이 된다.

API 서버쪽에서 스택 드라이버 로깅으로 로그를 보내는 부분을 살펴보자

아래는 파이썬 Flask 를 이용하여 로그를 스택 드라이버로 보내는 코드이다.


import uuid

from flask import Flask

from google.cloud import logging


app = Flask(__name__)

logging_client = logging.Client()

tlogger = logging_client.logger(‘my-flask-log’)

slogger = logging_client.logger('struct_log')

@app.route('/')

def text_log():

   logstring = "This is random log "+ str(uuid.uuid4())

   tlogger.log_text(logstring)

   return logstring


@app.route('/slog')

def struct_log():

   struct  = "This is struct log "+ str(uuid.uuid4())

   slogger.log_struct({

               'name':'myterry',

               'text':struct,

               'key' : 'mykey'})      

   return struct


if __name__ == '__main__':

   app.run('0.0.0.0',7001)

   

google.cloud 패키지에서 logging 모듈을 임포트한 다음에, 로깅 클라이언트로 부터

tlogger = logging_client.logger(‘my-flask-log’)

slogger = logging_client.logger('struct_log')

로 각각 “my-flask-log”와 “struct_log”라는 이름을 가지는 logger 둘을 생성한다.

(뒤에서 언급하겠지만, 이 로거 단위로, 로그를 필터링 하거나, 또는 이 로거 단위로 로그 메세지를 다른 시스템으로 export 할 수 있다.)


다음, 로그를 쓸 때는 이 logger를 이용하여 로그를 써주기만 하면 된다.

   tlogger.log_text(logstring)

는 텍스트로 된 한줄 로그를 쓰는 명령이고,

   slogger.log_struct({

               'name':'myterry',

               'text':struct,

               'key' : 'mykey'})  

는 JSON과 같이 구조화된 계층 구조를 로그로 쓰는 방식이다.

이렇게 개발된 로그 수집용 API 서버의 코드는 직접 VM을 만들어서 Flask 서버를 깔고 인스톨 해도 되지만  앱앤진을 사용하면 코드만 배포하면, Flask 서버의 관리, 배포 및 롤백, 그리고 오토 스케일링등 모든 관리를 자동으로 해준다. 앱앤진을 이용한 코드 배포 및 관리에 대한 부분은 다음 문서 http://bcho.tistory.com/1125 를 참고 하기 바란다.

스택 드라이버에서 로그 확인

코드가 배포되고, 실제로 로그를 기록하기 시작했다면 스택 드라이버에 로그가 제대로 전달 및 저장되었는지 확인해보자. 구글 클라우드 콘솔에서 스택 드라이버 로깅으로 이동한 다음 아래 그림과 같이 리소스를 “Global” 을 선택한 후, 앞에 애플리케이션에서 남긴 “my-flask-log”와 “struct-log” 만을 선택해서 살펴보자





다음과 같이 로그가 출력되는 것을 확인할 수 있으며, struct_log의 예를 보면 로그의 내용은 time_stamp  와 프로젝트 정보와 같은 부가 정보와 함께, 애플리케이션에서 남긴 로그는 “jsonPayload” 앨리먼트 아래에 저장된것을 확인할 수 있다.



빅쿼리로 Export 하기

스택 드라이버로 로그가 전달되는 것을 확인했으면, 이 로그를 빅쿼리에 저장해보자. Export 기능을 이용해서 가능한다. 아래와 같이 스택 드라이버 로깅 화면에서 상단의 “CREATE EXPORT”  버튼을 누른다.

다음 리소스 (Global)과 로그 (struct_log)를 선택한 다음에,



Sink Name에 Export 이름을 적고 Sink Service는 BigQuery를 선택한다. 다음으로 Sink Destination에는 이 로그를 저장할 Big Query의 DataSet 이름을 넣는다.

마지막으로 Create Sink를 누르면, 이 로그는 이제부터 실시간으로 BigQuery의 structlog라는 데이타셋에 저장이 되면 테이블명은 아래 그림과 같이 strcut_log_YYYYMMDD와 같은 형태의 테이블로 생성이 된다.




테이블 프리뷰 기능을 이용하여 데이타가 제대로 들어갔는지 확인해보자. 아래와 같이 위의 코드에서 저장한 name,key,text는 테이블에서 jsonPayload.name, jsonPayload.key, jsonPayload.text 라는 필드로 각각 저장이 되게 된다.



빅쿼리는 실시간으로 데이타를 저장할때는 초당 100,000건까지 지원이 가능하기 때문에 이 시스템은 100,000TPS 까지 지원이 가능하고, 만약에 그 이상의 성능이 필요할때는 로그 테이블을 나누면(Sharding) 그 테이블 수 * 100,000 TPS까지 성능을 올릴 수 있다. 즉, 일별 테이블을 10개로 Sharding 하면, 초당 최대 1,000,000 TPS를 받는 로그 서비스를 만들 수 있으며, 이 테이블 Sharding은 빅쿼리 테이블 템플릿을 사용하면 쉽게 설정이 가능하다. (정정 빅쿼리는 100K TPS를 지원하나, 스택 드라이버가 500 TPS로 성능을 제한하고 있음)


이렇게 저장된 로그는 빅쿼리를 지원하는 각종 리포팅 툴을 이용하여 시각화가 가능하다.

시각화 도구는

을 참고하기 바란다.


이렇게 간단하게, 코드 몇줄과 설정 몇 가지로 100,000 500 TPS 를 지원하는 로그 서버를 만들어 보았다.

스택 드라이버를 이용한 로그 분석 수집 시스템의 확장

이 외에도 스택 드라이버는 빅쿼리뿐 아니라 다른 시스템으로의 연동과 매트릭에 대한 모니터링 기능을 가지고 있어서 다양한 확장이 가능한데, 몇가지 흥미로운 기능에 대해서 살펴보도록 하자.


실시간 스트리밍 분석 및 이벤트 핸들링

스택 드라이버 로깅의 Export 기능은, 하나의 로그를 여러 연동 시스템으로 Export를 할 수 있다. 앞에서는 빅쿼리로 로그를 Export 하였지만, 같은 Log를 Dataflow에 Export 하였을 경우, 로그 데이타를 실시간 스트림으로 받아서, 실시간 스트리밍 분석이 가능하다.


구글 데이타 플로우에 대한 설명은 아래 링크를 참고하기 바란다.


또는 실시간 스트리밍이 아니라, 로그 메세지 하나하나를 받아서 이벤트로 처리하고자 할 경우, Pub/Sub 큐에 넣은 후에, 그 뒤에 GAE또는 Cloud function (https://cloud.google.com/functions/) 에서 메세지를 받는 구조로 구현이 가능하다.


로그 모니터링

스택 드라이버 로깅은 단순히 로그를 수집할 뿐만 아니라 훨씬 더 많은 기능을 제공한다.

앞에서 스택 드라이버 로깅을 이용한 로그 수집 시스템을 만드는 방법을 알아보았지만, 부가적인 몇가지 기능이 같이 제공되는데 다음과 같다.

필터를 이용한 특정 로그 핸들링

logger를 통해서 수집된 로그에는 필터를 걸어서 특정 로그만 모니터링할 수 있다.

예를 들어서 text 문자열에 “error” 가 들어간 로그나, latency가 1초이상인 로그와 같이 특정 로그만을 볼 수 있다.

다음은 jsonPayload.text 로그 문자열에 “-a”로 시작하는 문자열이 있는 로그만 출력하도록 하는 것이다.



이 기능을 사용하면, 로그 메세지에서 특정 로그만 쉽게 검색하거나, 특정 에러 또는 특정 사용자의 에러, 특정 ErrorID 등으로 손쉽게 검색이 가능해서 로그 추적이 용이해진다.

매트릭 모니터링

다음은 메트릭이라는 기능인데, 로그를 가지고 모니터링 지표를 만들 수 있다.

예를 들어 하루 발생한 에러의 수 라던지, 평균 응답 시간등의 지표를 정의할 수 있다.

이렇게 정의된 지표는 대쉬보드에서 모니터링이 가능하고 또는 이러한 지표를 이용하여 이벤트로 사용할 수 있다. 응답시간이 얼마 이상 떨어지면 오토 스케일링을 하게 한다던가 또는 이메일로 관리자에게 ALERT을 보낸다던가의 기능 정의가 가능하다.


매트릭 생성

지표 정의는 로그 화면에서 필터에 로그 검색 조건을 넣은 채로, CREATE METRIC 버튼을 누르면 사용자가 지표를 매트릭으로 정의할 수 있다.



대쉬 보드 생성


이렇게 정의된 매트릭은 스택 드라이버 대쉬 보드 화면에서 불러다가 그래프로 시각화가 가능한데, 다음 그림은 struct_log의 전체 수와를 나타내는 매트릭과, struct_log에서 log text에 “-a”를 포함하는 로그의 수를 나타내는 메트릭을 정의하여 차트로 그리는 설정이다.



위에 의해서 생성된 차트를 보면 다음과 같이 전체 로그 수 대비 “-a”  문자열이 들어간 로그의 수를 볼 수 있다.


지금까지 스택드라이버 로깅과 빅쿼리를 이용하여 간단하게 대용량 로그 수집 서버를 만드는 방법을 살펴보았다. 두개의 제품을 이용해서 로그 수집 시스템을 구현하는 방법도 중요하지만, 이제는 개발의 방향이 이러한 대용량 시스템을 구현하는데, 클라우드 서비스를 이용하면 매우 짧은 시간내에 개발이 가능하고 저비용으로 운영이 가능하다. 요즘 개발의 트랜드를 보면 이렇게 클라우드 서비스를 이용하여 개발과 운영 노력을 최소화하고 빠른 개발 스피드로 개발을 하면서, 실제로 비지니스에 필요한 기능 개발 및 특히 데이타 분석 쪽에 많이 집중을 하는 모습이 보인다.


단순히 로그 수집 시스템의 하나의 레퍼런스 아키텍쳐에 대한 이해 관점 보다는 전체적인 개발 트렌드의 변화 측면에서 한번 더 생각할 수 있는 계기가 되면 좋겠다.


본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.


Logentries를 인스톨하고 나니, 얼마후에 무료로 Community pack을 인스톨하라고 이메일이 왔다.

https://community.logentries.com/packs/heroku/





CPU,Memory와 같은 인프라 모니터링도 가능하고, 앱 모니터링도 가능한 플러그인이다.

설치 방법이 복잡해서 당장은 실행은 해보지는 않았지만 시간 날때 테스트할만한 가치는 있는듯


본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

Heroku에서 logentries를 이용하여 node.js 로그 모니터링 하기


조대협 (http://bcho.tistory.com)

 

Heroku에서 제공하는 로깅은 heroku logs –tail 명령을 이용해서 모니터링 할 수 있는데, 이 로그의 경우 최대 1500줄만 저장을 지원한다. 실제 운영 환경에서 1500줄의 로그란 부족해도 많이 부족한 양이다. 그래서 추가적인 서비스를 이용하는 것이 좋은데, 많은 로깅 서비스가 있지만, 간단하게 사용할 수 있는 로깅 서비스로 logentries 라는 서비스가 있다.

 



Figure 1 http://www.logentries.com

 

무료로 사용이 가능하고, 무료 사용시 최대 7일간의 로그를 저장해주고, 일 최대 33M 까지 로그를 저장할 수 있다.

가장 저렴한 Entry 플랜은 한달에 9$로 일 133M 로그를 최대 7일간 저장하고, 가장 비싼 Platium 플랜은 월 1399$로 일 최대 40GB의 로그를 최대 7일간 저장할 수 있게 해준다. (에러나 일반적인 시스템 로그라면, 왠만한 시스템이면 40GB정도면 충분하지 않나 싶다.)

 

그러면 앞서 작성하여 heroku에 배포한 node.js 애플리케이션에 이 logentires를 적용해 보자.

적용은 매우 간단하다. 명령창에서 간단하게 다음 명령을 실행하자

heroku addons:create logentries

 

명령을 실행하면 다음과 같이 logentries 가 설치되었다고 나온다.



Figure 2 logentries 설치

 

설치가 완료되었으면 이제 사용을 해보자. Heroku  대쉬 보드로 접속해서, 생성한 애플리케이션을 선택한다.



Figure 3 heroku dashboard에서 애플리케이션 선택

 

애플리케이션을 클릭해서 들어가면 하단 add-on 리스트에 logentries가 아래 그림과 같이 활성화가 되어 있는 것을 확인할 수 있다.



Figure 4 heroku 애플리케이션에서 add-onsLogentries가 설치된 화면

 

logentries를 클릭해서 들어가면, logentries를 이용한 로그 모니터링 화면이 나온다.

아래 그림과 같이 좌측에 “heroku”라는 Log set이 나오는데, 이를 클릭하고, 우측 상단에 “Live tail” 이라는 버튼을 누르면 현재 node.js의 로그를 실시간으로 보여준다. 실제로 해보면 heroku logs –tail 보다 약 1초 정도 지연이 발생한다.



Figure 5 logentries를 이용한 실시간 로그 모니터링

 

다음 화면은 node.js의 로그를 heroku logs –tail로 모니터링한 화면으로 위의 logentrieslive tail과 동일함을 확인할 수 있다.



Figure 6 heroku logs를 이용한 실시간 로그 모니터링

 

heroku 기본 로깅 시스템에 비해서 더 많은 로그를 볼 수 있는 것은 물론이고, 로그에 대한 검색이 가능하고, 특정 데이타를 기반으로 한 그래프등 다양한 기능을 지원한다.

본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.

Python 공부 노트 6. - Logging

프로그래밍/Python | 2013.01.21 19:21 | Posted by 조대협

http://docs.python.org/2/howto/logging-cookbook.html


# Add the log message handler to the logger

handler = logging.handlers.RotatingFileHandler(

              LOG_FILENAME, maxBytes=20, backupCount=5)

              

my_logger.addHandler(handler)

my_logger.debug('log message here....')


Logger

: 일종의 identifier로, 애플리케이션 마다 logger를 정하 수 있음


handler

: 파일 핸들러, 소켓 핸들러,  Rotating 파일 핸들러등,스트림 핸들러(Console 등)

※ DB Handler는 없는 듯 하고, 소켓 핸들러를 이용하면, 분산 시스템에서 중앙 집중화된 Logger를 만들 수 있음

(단, 로그 서버가 별도로 있는게 아니기 때문에, 분산 환경용 로거는 만들기 나름)


formater

: 핸들러 마다 붙일 수 있음


logging 메서드

: debug,info,warn,error,critical

: setLevel로 로그 출려 레벨 정함


단순 예제


import logging


logger = logging.getLogger("logging_sample")

logger.setLevel(logging.DEBUG)

# file log handler

fh = logging.FileHandler("/temp/python.log")

fh.setLevel(logging.ERROR)

# console log handler

ch = logging.StreamHandler()

ch.setLevel(logging.DEBUG)

#create formmater

formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

ch.setFormatter(formatter)

fh.setFormatter(formatter)

logger.addHandler(ch)

logger.addHandler(fh)


logger.debug("this is debugging")

logger.info("this is info")



본인은 구글 클라우드의 직원이며, 이 블로그에 있는 모든 글은 회사와 관계 없는 개인의 의견임을 알립니다.