스프링 프레임워크 Logback Telegram Log 자동화하기

1. Logback 데이터 전송 구조

---

슬랙과 디스코드에 이어서 마지막으로 텔레그램으로 Log를 받을 수 있도록 정리해 보겠습니다.

 

• 이전에 Logback 자동화와 관련된 2개의 제 글을 읽으셨다면 구조가 모두 비슷하다는 것을 알 수 있습니다.
• Logback 자체가 구현이 잘 되어있으므로, 개발자의 입장에서 핵심은 각 플랫폼에서 제공하는 비밀키(웹후크 주소), 봇과 appender 종속성을 추가하여 쉽게 구현하는 것입니다.
• 이번 시간에는 Logback을 Telegram으로 구현할 때 어떤 식으로 생각을 해서 구현해야 할까?에 초점을 맞춰서 글을 정리해 보겠습니다.

---

2. 종속성(dependency)

지난 2개의 Log 구현 글과, 서론에 제가 말한 것을 보았을 때 Logback에 의존하여 각종 플랫폼에 로그를 보내는 것이므로 모두 구조가 비슷하다는 것을 알았습니다. 그렇다면 저는, 구현에 앞서 간단하게 구글에 "스프링 Telegram appender"라고 검색하여 가장 첫 번째로 나온 깃허브를 참고하여 보았습니다. 그 결과, 대략적으로 Telegram, Logback 활용법과, 아래와 같이 telegram-logback이라는 이미 구현이 되어있는 Dependency를 찾을 수 있었습니다.

implementation 'com.github.paolodenti:telegram-logback:1.3.0'

 

그럼 해당 깃허브를 참고하여 구현해 볼까요?

아래와 같은 xml 형식의 샘플을 제공해 주고 있습니다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<appender name="TELEGRAM"
		class="com.github.paolodenti.telegram.logback.TelegramAppender">
		<botToken>123456789123456789123456789123456789123456789</botToken>
		<chatId>123456789</chatId>
		<Layout class="ch.qos.logback.classic.PatternLayout">
			<Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
		</Layout>
	</appender>

	<root level="error">
		<appender-ref ref="TELEGRAM" />
	</root>
</configuration>

 

위의 샘플을 보았을 때 Logback의 xml 구성에 대해서 처음 본다면 어렵겠지만 다른 플랫폼으로 미리 사용해 보았다면 구조 자체는 그렇게 어렵지 않겠죠? 내용을 더 보다 보니, 적힌 그대로의 값을 사용하지 말고, botToken과 chatId 두 개를 실제 값으로 교체해서 사용하라고 하네요.

 

botToken을 알면 chatId도 쉬울 것 같으니 botToken 먼저 진행해 볼게요~ botToken.. 무언가 텔레그램에 봇을 등록해서 토큰 값을 받아야 할 것 같죠? 바로 텔레그램 공식 사이트에 들어가서 찾아봅니다.

들어오자마자 바로 API -> Bot API가 보이네요.

 

조금 더 찾아보니(내용이 긴 관계로..) 아래와 같은 문서를 찾았고,

BotFather, creating and managing bots -> 봇을 생성하는 내용을 찾았습니다!

 

@BotFather라는 것을 사용해서 /newbot을 사용하면 봇을 만들 수 있다고 하네요. Slack, Discord와 또 다른 신기한 방법이네요!

 

그럼 한번 BotFather가 뭔진 모르겠지만 찾아볼까요?

디스코드에서 채팅방 검색창에 @BotFather를 검색한 뒤 클릭해 주세요. ( 파란색 체크 표시 확인 )

 

Start 클릭

 

 

그러면 뭐라고 설명을 해주는데 이미 알고 왔으므로, /newbot을 바로 전송합니다.

1. name: log-machine, 단순히 봇의 이름을 설정합니다.
2. username: log_bot, 이미 있는 username이라고 하네요.
3. username: IAmKorean_log_bot: 봇의 고유 이름을 설정하며 _bot으로 끝나야 합니다.
   중복이 안되어서 IAmKorean_log_bot처럼 복잡한 이름으로 바꾸었습니다.

HTTP API: 여기에 나오는 토큰 값을 잘 저장합니다. 역시 토큰 값답게 좀 있으면 영영 못 볼 예정입니다.

위의 토큰 값을 메모장에 잘 저장하셨다면 t.me/로 시작하는 파란 링크를 클릭해 줍니다. (봇과의 채팅방)

클릭하면 아래처럼 새로운 채팅방이 생기며, Start를 눌러 줍시다.

 

 

이제 왠지 스프링에서 구현만 하면 될 것 같죠?

xml 파일을 대략 설정하고  실행을 해보니 아래와 같은 에러가 발생합니다. 채팅방 Id 설정을 안 했군요.

 

 

이번에는 공식 문서에는 잘 안 나와서 블로그를 참고해 보았습니다.

아래의 가운데에 토큰 값을 넣고 접속하면 되다고 하는군요 한번 해볼까요? (대괄호는 빼주세요 ㅎㅎ)

https://api.telegram.org/bot[Bot_Token값]/getUpdates  

 

 

아래와 같이 result가 나오지 않는다면

 

아까 만들어졌던 봇 전용 채팅방에 들어와서 /start를 한 번 더 눌러서 채팅방이 갱신되게 해 줍니다.

 

그다음, 아까의 주소에서 새로고침을 다시 한번 하면 아래처럼 2번째 메시지부터의 데이터 값이 나오고 여기서 id: 부분에 있는 숫자 값을 사용하면 됩니다.

 

 

3. 스프링 구현

초반에 디펜던시는 추가해 줬으므로, token 값부터 설정해 볼게요~

 

application.yml

logging:
  telegram:
    bot-token: 1234:abcdefghijklmnop
  config: classpath:logback-spring.xml

 

 

 

그다음은, 샘플 코드 및 지난 시간의 코드들을 참고하여 xml 파일을 작성해 보도록 할게요.

 

resources/logback-spring.xml

<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
    <springProperty name="TELEGRAM_BOT_TOKEN" source="logging.telegram.bot-token"/>
    <appender name="TELEGRAM" class="com.github.paolodenti.telegram.logback.TelegramAppender">
        <botToken>${TELEGRAM_BOT_TOKEN}</botToken>
        <chatId>12345678</chatId>
        <Layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
        </Layout>
    </appender>

    <appender name="ASYNC_TELEGRAM" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="TELEGRAM" />
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

    <!--Consol appender 설정-->
    <appender name="Console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>%d %-5level %logger{35} - %msg%n</Pattern>
        </encoder>
    </appender>

    <!--로그 레벨 지정-->
    <root level="INFO">
        <appender-ref ref="Console"/>
        <appender-ref ref="ASYNC_TELEGRAM" />
    </root>
</configuration>

 

 

그리고 실행을 시켜보니 왼쪽의 log.error을 6개 실행시켰을 때 오른쪽처럼 1개의 메시지만 텔레그램에 출력되었습니다.

 

 

텔레그램 자체에서 API 요청에 제한이 있나 싶어서 테스트를 해보았습니다.

3초에 한 번씩 로그 발생

 

5초에 한 번씩 로그 발생

 

봇(API)이 5초에 한 번씩만 활용 가능하다? 아무리 API 요청을 제한한다고 해도 비정상적인 값이라는 생각이 들었고,

처음에 보았던 깃허브 문서를 자세히 다시 정독해 보았습니다.

 

 

 

한글로 번역해 보니 아래와 같은 내용이 있었습니다. 5초에 한 번씩 보내진 걸로 보아 minInterval 값이 문제인 것 같죠?

 

 

일단 단계적으로 minInterval 값부터 5000(default) -> 0으로 변경해 보았습니다.

<springProperty name="TELEGRAM_BOT_TOKEN" source="logging.telegram.bot-token"/>
<appender name="TELEGRAM" class="com.github.paolodenti.telegram.logback.TelegramAppender">
    <botToken>${TELEGRAM_BOT_TOKEN}</botToken>
    <chatId>1952695583</chatId>
    <Layout class="ch.qos.logback.classic.PatternLayout">
        <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
    </Layout>
    <minInterval>
        0
    </minInterval>
</appender>

 

 

 

다시 스레드의 sleep 없이 세 번 정도 진행해 본 결과 아래의 결과들이 나왔습니다.

(중간) 첫 번째 시도, (오른쪽) 두 번째 시도

 

세 번째 시도

 

로그 기능으로서의 2가지의 치명적인 문제가 있었습니다.

1. 프로그래밍한 것과 순서가 다르게 로그가 텔레그램에 찍힌다.
2. 로그가 무시될 때도 있고 도착할 때도 있다. (매번 결괏값이 달라 예상할 수가 없다.)

 

 

해당 깃허브의 이슈를 참고하여 min interval 값이 0이면 메시지가 reordered, 재정렬? 될 수 있단 걸 확인했습니다.

하지만 해당 값을 조금이라도 올리면 sleep을 걸어주지 않는 이상 메시지가 1개씩 밖에 오지 않습니다.

 

그래서 nonBlocking을 false 값으로 설정해 보았습니다.

<springProperty name="TELEGRAM_BOT_TOKEN" source="logging.telegram.bot-token"/>
<appender name="TELEGRAM" class="com.github.paolodenti.telegram.logback.TelegramAppender">
    <botToken>${TELEGRAM_BOT_TOKEN}</botToken>
    <chatId>12345678</chatId>
    <Layout class="ch.qos.logback.classic.PatternLayout">
        <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
    </Layout>
    <minInterval>
        0
    </minInterval>

    <nonBlocking>
        false
    </nonBlocking>
</appender>

 

 

 

그 결과, 콘솔의 로그와, 텔레그램의 로그와 비교하였을 때 텔레그램에 찍히는 속도가 살짝(메시지 당 1초 이내) 버퍼링이 있었지만, 실제 로그에 찍힌 로그 발생 시간에는 문제가 없었으며, 순서가 정확하여 아까보다는 더 좋은 결과가 나왔습니다.

텔레그램에는 조금 지연이 있지만 어쨌든 로그 기록 결과로는 만족

 

 

이때 logback-spring.xml에서 AsyncAppender 태그를 적용하지 않고 바로 TelegramAppender만 적용시킨다면,

아래의 결과처럼 텔레그램에 메시지가 느리게 찍히는 속도만큼 실제 로그 속도도 지연돼서 찍히니 AsyncAppender를 꼭 적용시켜 주세요.

log.error 실행한 결과로써 오른쪽의 로그가 찍힌 시간을 확인해 보자