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


Archive»


 
 

2019년 샌프란시스코 구글 NEXT 2019에서 발표한 로깅 시스템에 대한 강의 입니다.

구글 스택 드라이버 로깅에 대한 소개와, 삼성전자가 어떻게 스택 드라이버 툴을 이용해서 Devops로 적응했는지에 대한 사례입니다.

영어 컨텐츠 입니다.



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

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

조대협 (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을 이용해서 로그를 분석할 수 있다.



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

Spring Boot + slf4j + MDC + Zipkin

 

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

 

아래 예제는 MDC를 이용해서 여러 메서드간의 컨텍스트를 연결하는 것을 확장해서, 서로 다른 프로세스와 서버간에 로그를 연결하는 방법이다. 서로 다른 프로세스 또는 서버간에 컨텍스트를 전달하려면 HTTP 헤더등을 통해러 리모트로 컨텍스트를 전달해야 하는데, 이를 가능하게 하는 오픈소스로 Zipkin이 있다. (자세한 설명은 이글을 참고하기 바란다. )

Zipkin은 원래 분산 로그 추적용으로 개발된 오픈소스가 아니라 원래 목적은 분산 시스템에서 각 구간별 레이턴시(지연시간)을 측정해서 구간별 소요 시간을 측정하는 트레이스용도로 개발이 되었지만, 구간별 소요 시간을 측정하기 위해서는 각 개별 서비스를 연결해야 하기 때문에, 트레이스 ID가 필요하게 되었고, 트레이스 ID를 로그에 같이 저장하였기 때문에, 부가적인 효과로 분산 로그 추적에도 사용할 수 있다.

Zipkin을 Spring Boot와 연결하는 방법은 오픈소스인 Spring Sleuth를 이용하면 쉽게 된다.

 

아래 예제는 앞의 글인  Spring Boot에서 MDC를 사용하는 예제에 Zipkin 연동만을 추가한 예제이다.

Spring Boot로 간단한 REST API를 구현한후, 로깅을 하는 예제이다. 로거는 slf4j와 logback을 사용하였고,  MDC를 이용해서 userId와 같은 컨택스트 정보를 넘기도록 하였고, JSON 포맷으로 로그를 출력하였다. 마이크로 서비스와 같은 분산 서비스간에 로그 추적성을 제공하기 위해서 ZipKin 라이브러리를 사용하였다. 스프링에서는 ZipKin 라이브러리 통합을 Spring Sleuth를 통해서 지원하기 때문에, Spring Sleuth와 Zipkin을 연결하여 코드를 작성하였다. 전체 코드는 여기를 참고하면 된다.

 

아래는 Spring Boot에서 Zipkin을 사용하기 위해서 메이븐 pom.xml에 의존성을 추가한 내용이다.

<dependency>

<groupId>org.springframework.boot</groupId>

<artifactId>spring-boot-starter-web</artifactId>

</dependency>

<dependency>

<groupId>org.springframework.cloud</groupId>

<artifactId>spring-cloud-starter-sleuth</artifactId>

<version>2.1.1.RELEASE</version>

</dependency>

<dependency>

<groupId>org.springframework.cloud</groupId>

<artifactId>spring-cloud-starter-zipkin</artifactId>

<version>2.1.1.RELEASE</version>

</dependency>

<dependency>

<groupId>org.springframework.boot</groupId>

<artifactId>spring-boot-starter-test</artifactId>

<scope>test</scope>

</dependency>

<dependency>

<groupId>com.google.cloud</groupId>

<artifactId>google-cloud-logging-logback</artifactId>

<version>0.84.0-alpha</version>

</dependency>


<!-- slf4j & logback 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>

<코드.pom.xml >

 

다음은 logback 로거를 사용하기 위해서 logback에 대한 설정을 한 logback.xml이다. JSON 포맷으로 로깅을 하도록 설정 하였다.

 

<?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="info">

       <appender-ref ref="stdout"/>

   </root>

</configuration>

<코드. /resources/logback.xml >

 

Zipkin을 사용할 경우, 트레이스 정보를 zipkin 서버로 전송해야 하는데, 이를 위해서 zipkin 서버에 대한 정보를 설정해야 한다. 보통 zipkin 에이전트가 로컬에서 돌기 때문에, 포트만 지정하면 된다. 아래와 같이 zipkin 서버에 대한 포트를 8081로 지정하였고, 이 애플레케이션의 이름을 zipkin-server1으로 지정하였다. 이 예제에서는 zipkin을 분산로그 추적용으로만 사용하였기 때문에, 실제로 zipkin 서버 에이전트는 실행하지 않았다.

server.port = 8081

spring.application.name = zipkin-server1

<코드. /resources/application.properties >

 

다음은 Spring Boot의 REST API Controller 코드의 일부이다.

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

<코드. /resources/application.properties >

 

Spring Sleuth를 사용하게 되면 자동으로 Zipkin 코드를 의존성 주입 (Dependency Injection)을 이용해서 코드에 삽입해주는데, 이때 몇가지 제약사항이 있다. Spring Boot로 들어오는 트래픽은 Servlet Filter를 통해서 의존성 주입을 하는데, Spring Boot에서 다른 서비스로 나가는 트래픽의 경우에는 Rest Template 이나, Feign Client 와 같은 특정한 방법만을 지원한다. 지원되는 라이브러리의 범위에 대해서는 이 링크를 참고하기 바란다.

 

위의 예제는 HTTP Header에서 들어온 userId를 MDC 컨텍스트에 저장하는 예제이다.

위의 REST 서비스를 호출해보면 다음과 같은 결과가 나온다.

<그림. PostMan을 통해서 REST 요청과 응답을 받은 화면 >

 

그리고, 호출후에 나온 로그는 다음과 같다.

 

{  

  "timestamp":"2019-04-14T05:49:52.573Z",

  "level":"INFO",

  "thread":"http-nio-8081-exec-1",

  "mdc":{  

     "traceId":"270b7b7b5a8d4b5c",

     "spanId":"270b7b7b5a8d4b5c",

     "spanExportable":"false",

     "X-Span-Export":"false",

     "ordierId":"1",

     "X-B3-SpanId":"270b7b7b5a8d4b5c",

     "X-B3-TraceId":"270b7b7b5a8d4b5c",

     "userId":"terry"

  },

  "logger":"com.terry.logging.controller.OrderController",

  "message":"Get Order",

  "context":"default"

}

<코드. /resources/application.properties >

 

위의 결과와 같이 MDC 부분에, Zipkin이 자동으로 traceId를 선언해서 삽입해 준다. MDC에 저장한 userId도 위처럼 한꺼번에 출력되는 것을 확인할 수 있다.

 

Spring Sleuth는 slf4j를 사용하는 경우에만 MDC 컨텍스트에 트레이스 ID를 넣어주기 때문에, 다른 자바 로깅 프레임웍을 slf4j없이 사용하는 경우 자동으로 트레이스 ID를 넣어주지 않기 때문에 이점을 주의하기 바란다.

(참고 : "Adds trace and span ids to the Slf4J MDC, so you can extract all the logs from a given trace or span in a log aggregator.")

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

로깅 시스템 #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을 로그 프레임웍과 연결해서 마이크로 서비스 환경에서 스프링 부트 기반으로 서비스간의 로그 추적을 어떻게할 수 있는지에 대해서 알아보도록 한다.


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

로그 시스템 #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를 사용하는 것을 권장한다.

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


쿠버네티스 #15

모니터링 3/3 구글 스택드라이버를 이용한 모니터링

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



구글 클라우드 쿠버네티스 스택드라이버 모니터링

쿠버네티스 모니터링 시스템을 구축하는 다른 방법으로는 클라우드 서비스를 사용하는 방법이 있다. 그중에서 구글 클라우드에서 제공하는 스택 드라이버 쿠버네티스 모니터링에 대해서 소개하고자한다.

https://cloud.google.com/monitoring/kubernetes-engine/


현재는 베타 상태로, 구글 클라우드 쿠버네티스 서비스 (GKE)에서만 지원이 되며, 쿠버네티스 버전 1.10.2 와 1.11.0 (또는 그 상위버전)에서만 지원이 되고, 모니터링 뿐 아니라, 쿠버네티스 서비스에 대한 로깅을 스택드라이버 로깅 서비스를 이용해서 함께 제공한다.


스택드라이버 쿠버네티스 모니터링을 설정하는 방법은 간단하다. 쿠버네티스 클러스터를 설정할때, 아래 그림과 같이 Additional features 항목에서 “Try the new Stackdriver beta monitoring and Logging experience” 항목을 체크하면 된다.



클러스터를 생성한 후에, 구글 클라우드 콘솔에서 Monitoring 메뉴를 선택한 후에



스택드라이버 메뉴에서 Resources 메뉴에서 아래 그림과 같이 Kubernetes 메뉴를 선택하면 쿠버네티스 모니터링 내용을 볼 수 있다.



모니터링 구조

스택드라이버 쿠버네티스 모니터링의 가장 큰 장점 중의 하나는 단순한 단일 뷰를 통해서 대부분의 리소스 모니터링 과 이벤트에 대한 모니터링이 가능하다는 것이다.

아래 그림이 스택드라이버 모니터링 화면인데, “2”라고 표시된 부분이 시간에 따른 이벤트이다. 장애등이 발생하였을 경우 아래 그림과 같이 붉은 색으로 표현되고, 3 부분을 보면, 여러가지 뷰 (계층 구조)로 각 자원들을 모니터링할 수 있다. 장애가 난 부분이 붉은 색으로 표시되는 것을 확인할 수 있다.



<출처 : https://cloud.google.com/monitoring/kubernetes-engine/observing >


Timeline에 Incident가 붉은 색으로 표시된 경우 상세 정보를 볼 수 있는데, Timeline에서 붉은 색으로 표시된 부분을 누르면 아래 그림과 같이 디테일 이벤트 카드가 나온다. 이 카드를 통해서 메모리,CPU 등 이벤트에 대한 상세 내용을 확인할 수 있다.



<출처 : https://cloud.google.com/monitoring/kubernetes-engine/observing >


반대로 정상적인 경우에는 아래 그림과 같이 이벤트 부분에 아무것도 나타나지 않고, 모든 자원이 녹색 동그라미로 표시되어 있는 것을 확인할 수 있다.


개념 구조

쿠버네티스 모니터링중에 어려운 점중의 하나는 어떤 계층 구조로 자원을 모니터링 하는가 인데, 이런점을 해결하기 위해서 구글 스택드라이버 쿠버네티스 모니터링은 3가지 계층 구조에 따른 모니터링을 지원한다. 모니터링 화면을 보면 아래와 같이 Infrastructure, Workloads, Services 와 같이 세가지 탭이 나오는 것을 볼 수 있다.



어떤 관점에서 클러스터링을 모니터링할것인가인데,

  • Infrastructure : 하드웨어 자원 즉, node를 기준으로 하는 뷰로,  Cluster > Node > Pod > Container 의 계층 구조로 모니터링을 제공한다.

  • Workloads : 워크로드, 즉 Deployment를 중심으로 하는 뷰로 Cluster > Namespace > Workload (Deployment) > Pod > Container 순서의 계층 구조로 모니터링을 제공한다.

  • Services : 애플리케이션 즉 Service 를 중심으로 하는 뷰로 Cluster > Namespace > Service > Pod > Container 계층 순서로 뷰를 제공한다.

Alert 에 대한 상세 정보

각 계층 뷰에서 리소스가 문제가 있을 경우에는 앞의 동그라미가 붉은색으로 표시가 되는데,  해당 버튼을 누르게 되면, Alert 에 대한 상세 정보 카드가 떠서, 아래 그림과 같이 이벤트에 대한 상세 정보를 확인할 수 있다.


<출처 : https://cloud.google.com/monitoring/kubernetes-engine/observing >

결론

지금까지 간단하게 쿠버네티스에 대한 모니터링과 로깅에 대해서 알아보았다. 프로메테우스나 그라파나와 같은 최신 기술을 써서 멋진 대쉬 보드를 만드는 것도 중요하지만 모니터링과 로깅은 시스템을 안정적으로 운영하고 장애전에 그 전조를 파악해서 대응하고, 장애 발생시에는 해결과 향후 예방을 위한 분석 및 개선 활동이 일어나야 한다. 이를 위해서 모니터링과 로깅은 어디까지나 도구일 뿐이고, 어떤 지표를 모니터링 할것인지 (SLI : Service Level Indicator), 지표의 어느값까지를 시스템 운영의 목표로 삼을 것인지 (SLO : Service Level Object)를 정하는 프렉틱스 관점이 더 중요하다.  이를 구글에서는 SRE (Site Reliability Engineering)이라고 하는데, 이에 대한 자세한 내용은 https://landing.google.com/sre/book.html 를 참고하기 바란다.

이런 프렉틱스를 구축하는데 목적을 두고, 모니터링을 위한 툴링등은 직접 구축하는 것보다는 클라우드에서 제공하는 스택 드라이버와 같은 솔루션이나 데이타독(Datadog)와 같은 전문화된 모니터링 툴로 구축을 해서 시간을 줄이고, 프렉틱스 자체에 시간과 인력을 더 투자하는 것을 권장한다.



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

구글 스택드라이버를 이용한 애플리케이션 로그 모니터링

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

스택드라이버 소개

스택드라이버는 구글 클라우드에서 서비스로 제공되는 시스템 로그 및 모니터링 시스템이다. CPU,메모리사용량과 같은 하드웨어에 대한 정보에서 부터 웹서버나 OS와 같은 미들웨어 및 애플리케이션 로그를 수집, 검색 및 분석할 수 있으며, 여러 오픈 소스 (MongoDB, CouchDB, Redis - https://cloud.google.com/monitoring/agent/plugins/ )등에 대한 모니터링도 가능하다.

구글 클라우드 뿐 아니라, AWS에 대한 모니터링을 통합으로 지원하는 등, 상당히 많은 기능을 가지고 있다.

이 글에서는 스택드라이버를 이용하여 애플리케이션 로그를 수집하고 이를 분석하는 방법에 대해서 설명하고자 한다.

자바를 기반으로 애플리케이션 로깅을 설명한다. 자바 애플리케이션에서 스택드라이버로 로그를 남기는 방법은 여러가지가 있으나, 일반적으로 자바 프로그래밍 언어에서 많이 사용하는 로깅 프레임웍은 SL4J 를 이용한 로깅과, 스택드라이버 SDK를 이용하여 JSON 형태로 로그를 저장하는 방법에 대해서 알아보도록 한다.

API 인증

스택 드라이버를 사용하기 위해서는 로그 API에 대한 인증이 필요하다. 인증에는 여러가지 방법이 있는다. 사용이 쉬운 방법을 설명한다.

로컬 환경 또는 타 환경에서 인증

로컬 개발환경이나 클라우드에서 인증을 하는 방법은 서비스 어카운트 (Service Account)를 사용하는 방법이 있다. 서비스 어카운트는 구글 클라우드 콘솔에서  IAM 메뉴에서 생성할 수 있다. 서비스 어카운트 메뉴를 아래와 같이 선택한 다음.


상단 메뉴에서 Create Service Account  버튼을 누르고 서비스 어카운트 생성한다.


서비스 어카운트에는 서비스 어카운트의 권한을 설정할 수 있는데, Project Owner로 설정하면 모든 권한을 다 가질 수 있고, 여기서는 로깅 권한만을 줄것이기 때문에, Logs Writer 권한만을 지정한다.


계정 생성을 하면 json 파일이 다운로드 된다.

이 파일은 환경 변수 GOOGLE_APPLICATION_CREDENTIALS 에 파일 경로를 지정해주면 된다.

예시 $ export GOOGLE_APPLICATION_CREDENTIALS=/Users/terrycho/keys/terrycho-sandbox-projectowner.json




구글 클라우드 VM 내에서 인증

구글 클라우드 VM내에서 자바 코드를 실행할 경우 VM 자체에 API 접근 권한을 부여할 수 있다. 보통 운영환경에서는 이 방법이 권장된다.

아래와 같이 VM 생성시 “Identity and API access” 에서 API 접근 권한을 주면 된다. Set access for each API를 써서 Logging write 권한만을 줄 수 있고, 아니면 Allow full access to all Cloud APIs 를 이용해서 전체 API에 대한 권한을 줄 수 도 있다.




SL4J를 이용한 로깅

sl4j를 이용한 로깅은, 기존의 sl4j 로거를 그대로 사용하기 때문에 코드 변환이 거의 없고, 단지 maven 에서 라이브러리 의존성을 스택드라이버 로거로만 변경해주면 되기 때문에 별도의 학습이 필요없고 사용법이 단순하다는 장점이 있다. sl4j 로깅은 단순하다.

의존성 추가

먼저  pom.xml 에 아래와 같은 의존성을 추가 한다.

<dependency>
<groupId>com.google.cloud</groupId>       <artifactId>google-cloud-logging-logback</artifactId> <version>0.30.0-alpha</version>
</dependency>

logback.xml

다음 필요에 따라서 sl4j에 대한 설정을 위해서 logback.xml 을 추가 설정할 수 있다. 여기서 로깅 레벨등을 지정할 수 있으나, sl4j에 대한 내용이기 때문에 별도로 설명하지는 않는다.

자주 실수 하는 부분이 logback.xml은 클래스 패스의 경로내에 들어가 있어야 하는데 다른 방법으로는 자바 옵션으로 -Dlogback.configurationFile 으로 logback.xml 경로를 설정하면 된다.



코드

코드를 보자

package com.google.example.stackdriver;


import org.slf4j.Logger;

import org.slf4j.LoggerFactory;



public class App {

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

 

 public static void main(String[] args) {

   logger.info("My Hello Log4j");

 }

}


코드는 간단하다. logger를 선언한 후에, .info, .error, .warning 등의 메서드로 텍스트 문자열을 남기면 된다.


자바 로거 연동은 sl4j이외에도 java.util.logging 도 연동이 가능하다. 자세한 내용은 https://cloud.google.com/logging/docs/setup/java 를 참고하기 바란다.

Logger를 이용한 로깅

sl4j는 사용이 간편한 반면에 텍스트 문자열로 로깅이 되기 때문에, 구조화된 정보 (JSON)이나 여러 필드를 가지는 로그를 남기기가 쉽지 않다는 단점을 가지고 있다. 스택드라이버 전용 SDK를 사용하면, JSON등 다양한 포맷으로 로그를 쉽게 남길 수 있다. (sl4j의 경우에도 LoggingEnahncer를 사용하면 가능하기는 하다)


전체 코드는 다음과 같다.


package com.google.example.stackdriver;

import com.google.cloud.MonitoredResource;

import com.google.cloud.logging.LogEntry;

import com.google.cloud.logging.Logging;

import com.google.cloud.logging.LoggingOptions;

import com.google.cloud.logging.Payload.JsonPayload;

import com.google.cloud.logging.Payload.StringPayload;

import com.google.cloud.logging.Severity;

import java.util.Collections;

import java.util.HashMap;

import java.util.Map;


public class LogWithLabel {

 //https://cloud.google.com/logging/docs/reference/libraries

 final static String LOG_NAME="terry-tutorial";

 /** Expects a new or existing Stackdriver log name as the first argument.*/

 public static void main(String... args) throws Exception {


   // Instantiates a client

   Logging logging = LoggingOptions.getDefaultInstance().getService();


   // The data to write to the log

   String text = "Hello, world!";

   Map<String, Object> jsonMap = new HashMap<String, Object>();

   jsonMap.put("elapsedtime", 11);

   

   for(int i=0;i<1000;i++){

    jsonMap.put("count", i);

   LogEntry entry

    //= LogEntry.newBuilder(StringPayload.of(text))

    // 한페이로드만 사용이 가능함. 오버라이드됨.

    = LogEntry.newBuilder(JsonPayload.of(jsonMap))

.setSeverity(Severity.ERROR)

       .setLogName(LOG_NAME)

       .setResource(MonitoredResource.newBuilder("global").build())

       .addLabel("instancename", "instance-1")

       .build();

   // Writes the log entry asynchronously

   logging.write(Collections.singleton(entry));

   }


   System.out.printf("Logged: %s%n", text);

 }

}


먼저 Logging 객체를 가지고 와야 한다. 별도의 설정 없이 다음과 같이 설정하면 되고, 프로젝트 및 인증은 앞에서 설정한 Service Account 파일의 정보를 그대로 사용한다.

Logging logging = LoggingOptions.getDefaultInstance().getService();


이 예제는 JSON 포맷으로 데이타를 저장하는 방법인데, 단순하게 1 레이어의 JSON을 저장하도록 하였다. Map을 이용하여 jsonMap을 정의하고, put을 이용하여 key, value 값을 저장한다.


   String text = "Hello, world!";

   Map<String, Object> jsonMap = new HashMap<String, Object>();

   jsonMap.put("elapsedtime", 11);


다음 로그를 저장하기 위해서는 LogEntry 객체를 이용해야 하는데, LogEntry는 LogEntry.newBuilder(PayLoad)를 이용하여 생성한다. Text 로그를 저장하는 TextPayLoad를 사용하거나 다른 페이로드도 있지만 여기서는 JsonPayLoad를 사용하였다.

LogEntry.newBuilder(JsonPayload.of(jsonMap))


다음 로그 Serverity (INFO,ERROR,WARNING)는 setServerity로 정할 수 있다. 스택 드라이버 로그는 정보 구조에서 계층 구조를 가질 수 있는데, 다음과 같은 개념을 가지고 있다.

리소스

리소스는 이 로그가 어떤 자원에 속하는지를 정의한다. 예를 들어, VM, 빅쿼리와 같이 어떤 인프라에 속하는지를 정의할 수 있는데, 애플리케이션의 경우 일반적으로 “global” 리소스로 정의한다.

리소스 명은 setResource메서드를 이용해서 지정이 가능하다.

라벨

다음 로그에 라벨을 달 수 있다. 예를 들어 이 리소스가 VM인데, 어떤 VM인지 식별을 하기 위해서 키를 name, 값을 인스턴스명 등으로 지정할 수 있다. 또는 개발/운영 환경인지를 구별하기 위해서 env 라는 키를 이용해서 환경에 따라 값을 dev,qa,prod 등으로 달 수 있다. 하나의 로그에는 여러개의 라벨을 붙이는 것이 가능하다. 라벨은 키,밸류 형태로 .addLabel(키,값)으로 추가가 가능하다.

로그 이름

로그 이름은 로그를 그룹핑할 수 있는데, 애플리케이션 종류등으로 그룹핑을할 수 있다. 이 로그는 사용자 로그, 게임 로그 등으로 그룹핑이 가능하다. 그룹 명을 setLogName으로 지정이 가능하다.


아래는 리소스를 global, 로그 이름을 LOG_NAME, 라벨에 instancename을 키로, instance-1이라는 값을 지정한 코드 예제이다.

       .setLogName(LOG_NAME)

       .setResource(MonitoredResource.newBuilder("global").build())

       .addLabel("instancename", "instance-1")

로그 확인

로그는 구글 클라우드 콘솔에서 STACKDRIVER > Logs 항목에서 확인이 가능하다.


위 그림과 같이 메뉴로 진입한 후에, 로그를 볼 수 있다.


리스트 박스에서 첫번째 박스는 리소스를 선택하는 화면으로 애플리케이션 로그는 앞의 예제에서 리소스를 global로 선택하였기 때문에, global을 선택한다. 그리고 두번째는 로그 이름을 고르는 화면인데, 앞에 예제에서 terry-tutorial로 로그 이름을 지정하였기 때문에 terry-tutorial을 선택한다.

다음 위의 화면에서 버튼을 누르면 실시간으로 로그를 볼 수 있는데, 통상 1분이내의 딜레이가 소요된다고 보면 된다.

로그에서 각 항목을 펼쳐보면 디테일을 볼 수 있다. 아래는 하나의 디테일인데, 중요한 부분은 timestamp에서 시간이 기록되고, serverity에 에러 레벨이 기록된다. 그리고 앞에서 지정한 Json PayLoad가 jsonPayLoad 라는 항목으로 들어간다.  라벨은 labels라는 항목에 키/밸류 형식으로 지정이 되는 것을 볼 수 있다.


로그 검색 및 필터링

스택드라이버의 강력한 기능중 하나가 로그에 대한 검색과 필터링인데, 스택 드라이버 콘솔 상단 화면에서 필터링(검색) 조건을 넣으면 각 필드 값에 따라서 다양한 형태로 로그 검색이 가능하다.


이 조건은 resource가 global이고, 그중에서 jsonPayload.count 가 900 보다 큰 로그만을 추출하는 방법이다. (Advanced filter를 사용하엿음)

표현식이 어렵지 않으니, https://cloud.google.com/logging/docs/view/advanced_filters 를 참고하면 손쉽게 로그 검색이 가능하다.

EXPORT

스택 드라이버의 다른 장점 중의 하나는 저장된 로그를 다른 시스템으로 EXPORT할 수 있는데, 크게 다음 3가지로 EXPORT가 가능하다.

  • GCS (파일) : Google Cloud Storage에 파일로 로그를 저장이 가능하다.

  • Pub/Sub (실시간 스트리밍) : 실시간으로 로그를 Pub/Sub 큐로 저장이 가능하다. Pub/Sub 뒤에 컨슈머를 둬서 다양한 처리가 가능하고 (알럿등) Apache Beam (Dataflow)연동을 통해서 실시간으로 로그를 분석 하는 것이 가능하다

  • BigQuery (데이타 베이스) : 실시간으로 데이타를 대용량 데이타 베이스는 빅쿼리에 저장하여 다양한 쿼리 및 시각화가 가능하다.


로그 EXPORT는 상단 메뉴의 CREATE EXPORT 버튼을 이용하면 EXPORT 정의가 가능하다.


이때 흥미로운 점은 로그 EXPORT시 필터에 조건을 걸어놓으면, 필터에 맞는 조건에 있는 로그만 EXPORT가 된다. 즉 로그 레벨이 CRITICAL한 로그만 Pub/Sub으로 로깅해서 알럿을 보내는 것과 같은 작업이 가능하게 된다.

빅쿼리로 EXPORT

그럼 그중에서 빅쿼리로 로그를 EXPORT하는 방법에 대해서 알아보기로 한다.

빅쿼리로 EXPORT하기 위해서는 CREATE EXPORT를 누른 후에, 로그 SINK 명을 지정하고 데이타셋을 지정해야 하는데, 데이타셋을 새로 생성하면 된다.


이 예제에서는 필터를 추가하여 label에서 instancename이 “instance-1”인 로그만 빅쿼리로 저장하도록 EXPORT 설정을 하였다.


http://bigquery.google.com에 들어가면 앞에 지정한 이름으로 데이타셋이 생긴것을 확인할 수 있고, 테이블명은 앞에서 지정한 로그명인 terry_tutorial 로 지정된것을 확인할 수 있다.

다음은 로그 시간과, JsonPay로드의 elapsedtime과, count 값을 조회하는 쿼리와 결과 이다.



쿼리 결과




데이타 스튜디오를 이용한 로그 시각화

이렇게 빅쿼리에 저장된 데이타는 구글 데이타 스튜디오를 이용하여 손쉽게 시각화가 가능하다.

https://datastudio.google.com에 접속한 후에, Start New Report에서 Blank Report 만들기를 선택한다.

새로운 리포트 화면이 나오면 우측 하단의

를 선택하여 빅쿼리 테이블과 연결을 한다.


좌측 커넥터를 선택하는 화면에서 BigQuery를 선택한후


MY PROJECT에서 내 프로젝트를 고르고, 데이타셋과 테이블은 선택한다.


다음으로 상단의 CONNECT 버튼을 눌러서 테이블을 연결한다. 또는 프로젝트를 선택하는 대신 CUSTOM QUERY를 누르면, 직접 SQL을 써서 특정 필드만 조회할 수 있다.


여기서는 전체 테이블을 불러오는 것으로 진행하도록 한다.

다음 화면에서는 필드 선택 및 제거, 그리고 타입 설정등이 가능하다.


적절하게 사용할 필드를 선택하고, 타입을 지정한후, 우측 상단의 ADD TO REPORT를 선택한다.

타임 스탬프는 일반적으로 일단위로 컨버팅 되기 때문에, 세밀한 로그를 원하면 분단위 등으로 변경하거나 커스텀 쿼리를 이용해서 초단위 값으로 컨버팅하기를 권장한다.

다음 메뉴에서 그래프나 표를 선택하여 적절하게 그리고, X 축은 Deminsion에 설정한다. 아래는 Dimension을 timestamp로 선택하고, Y축은 Metric 값으로 jsonPayload.count를 준 예이다.



혹시 테이블을 그린후에 데이타가 나오지 않는 경우가 있는데, 이 경우는 대부분 DataStudio의 Time zone과 빅쿼리에 저장된 Time이 맞지 않아서, 쿼리 범위에서 제외되는 경우인데, 이 경우는 그래프의 Property에서 날짜 범위를 다음과 같이 조정해주면 된다.



이외에도 다양한 기능이 있는데, 다음 문서들을 참고하기 바란다.



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


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

조대협 (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”  문자열이 들어간 로그의 수를 볼 수 있다.


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


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


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

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")



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