log?
로그는 에러를 추적하는 데에 아주 중요하다.
단, 로그할 때 생기는 오버헤드가 사용에 지장을 줄 정도가 되면 안 된다.
로그를 남기는 작업을 로깅이라고 한다.
로그에는 다섯가지 단계가 있다.
trace < debug < info < warn < error
우측으로 갈 수록 중요하다.
로깅에는 여러 방법이 있다.
자바에선 System.out.println을, C/C++에선 printf를 찍어도 된다.
하지만 이렇게 하지 않는 이유는...
일단 매우 없어 보이고,
가장 중요한 이유로는 이것이 입출력 연산이기 때문이다.
운영체제에서 배웠듯 입력이나 출력을 하려면
OS에 인터럽트가 발생하고 커널 모드로 진입을 한 다음에 입출력을 진행하고 다시 사용자 모드로 돌아와야 한다.
즉... 그 동안 다른 일들이 모두 중지되게 된다.
일단 사용자에게 보여져야 하는 로그가 있는 반면
개발 도중 개발자가 시스템이 돌아가는 것을 확인하거나 에러를 발견하기 위해 쓰는 로그가 있다.
어플리케이션이 배포되었을 때 이런 개발자 용 로그는 출력되지 않아야 한다.
또한 위에서 말한 중요성으로 로그를 나누어 줘야 한다.
그리고 그냥 메시지 출력 뿐 아니라,
언제 어디서 메시지가 출력되는지를 알아야 한다.
몇날 며칠 몇시에 어디 클래스에서 에러가 났는지를 알아야 한다.
이러한 요구사항을 만족시키기 위해서
System.out.println 보다는 좀 더 체계화된 모듈이 필요한 것이다.
Slf4j
Slf4j 는 자바에 쓰이는 로깅 API이다.
API라는 것은, 이것만으론 로깅을 할 수 없다는 뜻이다. (중간에 있는 매개체라는 뜻이므로)
Slf 는 Simple Logging Facade 의 약자,
4j 는 for Java 의 약자이다.
따라서 Slf4j 는 Simple Logging Facade for Java 라는 뜻이다.
Facade?
Facade 는 정확히는 façade이다.
ç는 c같이 생겼지만 s로 발음한다.
그래서 영어의 경우 facade라고 쓰지만 파카드라고 쓰지 않고 파싸-ㄷ 라고 발음한다.
프랑스에서 온 단어로, 건물의 '정면'을 뜻한다.
파사드 패턴은 이름과 같이, 뒤의 복잡한 로직을 숨기고 앞에서 코드를 쓸 수 있게 하는 패턴이다.
여기서 이 '복잡한 로직'의 담당자만 갈아끼우면
실제 보이는 코드 (앞에서 개발자가 사용하는)를 바꾸지 않아도
여러 다른 로직으로 개발자가 하고자 하는 일을 진행할 수가 있다.
예를 들어 '로그 남기기'라는 것은 자주 쓰이는 일로, (로거 개발자가 아닌) 개발자의 입장에선 단순한 일이어야 할 것이다.
하지만 실제로는 단순하지 않다. 어떤 클래스에서 발생했는지, 시간은 어떻게 되는지, 문자열 패턴은 어떻게 되는지, 어떤 스레드를 사용할 것인지 등등 따져봐야 하고 성능에도 영향을 주지 않도록 최적화를 해야 한다.
따라서 이를 구현하기 위한 여러 클래스들이 있고 이 클래스를 사용하는 로직이 존재해야 하고,
이 로직은 구현 방법에 따라 A가 있을 수도 있고, B가 있을 수도 있다.
개발자가 A를 직접 쓰게 된다면, 이를 B로 바꾸기가 매우 곤란할 것이다. A를 쓰는 코드가 한 군데에 모여있다면 좋겠지만 상황에 따라 그렇지 않을 수도 있고, 그렇다고 해도 의존성이라거나 클래스 구조가 달라서 완전히 바꾸기가 까다로울 것이다.
이때 파사드 패턴을 이용하여 '로그 남기기'라는 사용자를 위한 로직을 추상화한 다음 사용자는 이 인터페이스만 쓰고, 인터페이스를 구현하는 구현체만 뺏다 꼈다 해주면 A에서 B로, B에서 A로 쉽게 바꿀 수 있다.
즉 개발자는 A나 B 같은 구현체가 아닌,
그 앞에 있는 인터페이스, '정면'만을 보게 된다.
Log4j, Logback, Log4j2
이들은 나온 순서대로이다.
이 중 Log4j는 2015년 개발이 중단이 되었다.
지금 Log4j라고 하면 Log4j2 를 가리킨다. (2버전)
Log4j 의 개발자들이 logback 을 만들었고,
log4j2 는 logback 를 보완한 최신 버전이다.
log4j2 는 멀티 스레딩 환경을 상정하고 개발되었기 때문에 스레드가 많아질 수록 성능이 비약적으로 높아진다.
따라서 많은 사람들이 logback에서 log4j2 로 갈아타고 있다고 한다.
단, log4j2 의 2.15 이전까지의 버전은 보안 취약점이 발견되었다. 해커가 취약점을 통해 원격으로 코드를 실행할 수 있다고 한다.
2.0 버전부터 2.15 이전까지 이런 똑같은 취약점 경고가 뜬다.
현재는 2.17.0까지 취약점 경고가 뜨는 상황이다.
2.17.1버전부터 없어졌고, 실제로 이 버전이 가장 사용자가 많다.
How to?
Dependency
gradle이나 maven 을 통해 의존성 라이브러리를 주입한다. (밑은 gradle)
implementation 'org.springframework.boot:spring-boot-starter-log4j2'단 spring-boot-starter-web이 기본적으로 logback을 사용하므로 여기서 로깅을 하는 모듈을 제외해줘야 한다.
Configurations {
all {
exclude group: 'org.springframework.boot', module: 'spring-boot-starter-logging'
}
}
현재 spring log4j2 는 버전 2.6.4로, log4j2 2.17.1 버전을 사용한다.
gradle에 특별히 버전을 명시하지 않으면 최신 버전을 사용하게 된다.
Configuration
로깅도 입맛에 맞게 설정할 수 있다.
로그 찍을 때의 문자열 패턴이나,
몇몇 레벨의 로그를 파일로 남기고 싶다면 해당 파일의 경로나 문자열 패턴 등을 설장할 수 있다.
이를 resouces 폴더의 log4j2.xml이란 파일로 해서 최상단에 넣으면 log4j2가 알아서 이 설정대로 동작한다.
<?xml version="1.0" encoding="UTF-8" ?>
<Configuration status="INFO">
<Properties>
<Property name="logFileName">log</Property>
<Property name="consoleLayout">%style{%d{ISO8601}} %highlight{%-5level} [%style{%t}{bright,blue}] %style{%C{1.}}{bright,yellow}: %msg%n%throwable</Property>
<Property name="fileLayout">%d [%t] %-5level %c(%M:%L) - %m%n</Property>
</Properties>
<Appenders>
<Console name="ConsoleLog" target="SYSTEM_OUT">
<PatternLayout pattern="${consoleLayout}" charset="UTF-8" disableAnsi="false"/>
</Console>
<RollingFile name="FileLog" fileName="logs/${logFileName}.log" filePattern="logs/${logFileName}-%d{yyyy-MM-dd-hh}.log">
<PatternLayout pattern="${fileLayout}" />
<Policies>
<TimeBasedTriggeringPolicy modulate="true" interval="1" />
</Policies>
<DefaultRolloverStrategy max="5" fileIndex="min" />
</RollingFile>
</Appenders>
<Loggers>
<Root level="info">
<AppenderRef ref="ConsoleLog" />
<AppenderRef ref="FileLog" />
</Root>
<Logger name="{특정 패키지 혹은 클래스}" level="ALL" additivity="false">
<AppenderRef ref="ConsoleLog" />
</Logger>
</Loggers>
</Configuration>Property는 변수이다.
name으로 변수명을 정하고 꺽쇠 안에 문자열을 정의하면 된다.
위에선 로그를 남긴 파일명의 이름과
콘솔에 찍을 로그의 레이아웃(색깔, 패턴 등)과 파일에 찍을 로그의 레이아웃이 명시되어 있다.
Appender
Appender는 로그를 남기는 형식이다.
ConsoleLog 라는 로그를 남기는 (더하는) 방법은 타겟을 시스템 출력으로 하며,
consoleLayout의 패턴으로 출력을 한다.
disableAnsi="false" 를 해주는 이유는 색깔을 표현하기 위함이다.
RollingFile
RollingFile 은 로그를 찍는 파일을 굴리는 것을 뜻한다.
파일을 굴린다는 건 주기적으로 이전 로그를 삭제하고 생성하는 것을 뜻한다.
파일에 찍는 로그의 레이아웃은 fileLayout으로 정했고,
정책은 1시간 동안의 로그를 남기며, 최대 5개의 파일을 굴리기로 하였다.
서버를 시작한 시간이 13시이고 지금이 17시라고 할 때,
"로그.log", "로그1.log", "로그2.log", ... "로그4.log"
이렇게 5개의 로그 파일이 있고 지금은 "로그.log"에 로깅을 하고 있다.
여기서 한 시간이 더 지나면 "로그4.log"는 지워지고 "로그.log"은 "로그1.log"로, "로그1.log"는 "로그2.log"로 이름이 바뀐다.
그리고 "로그.log"를 새로 생성하여 로깅하게 된다.
단, 이는 fileIndex가 min일 때의 이야기이다.
fileIndex가 max가 되면 로그4, 로그3, 로그2 ... 순서로 최신 로그가 된다.
Loggers
로그를 찍는 모듈을 정의한다.
루트는 전체를 정의한다.
전체 로그를 찍을 방식을 추가할 수 있다.
현재 루트에서 오는 (서버의 모든 로그) 로그는 콘솔과 파일에 찍히게 되어 있다.
레벨은 Info 이상만이다.
밑에서 내가 로그를 찍고 싶은 로거를 새로 정의할 수 있다.
특정 클래스 혹은 패키지에서 오는 로그들에 대해서
레벨과 장소를 정할 수 있다.
나는 이것을 내 소스들의 현재 디렉토리로 정해서
내가 생성하는 로그들에 대해선 모든 레벨(ALL)에 대해 찍히게 하였다.
만약 루트를 ALL로 하면 콘솔이 정말 복잡해지며
출력하는데 시간이 다 가서 서버 돌아가는 것도 엄청 느리다.
이렇게 로거를 분리하면 스프링 로그는 INFO 이상만 찍고
내가 개발하면서 찍는 로그는 전부 출력해줄 수 있다.
Slf4j on Spring
원래는...
logger를 일일히 설정해야 한다.
Logger 클래스를 로그를 찍고자 하는 클래스에서 멤버 변수로 선언하고
이의 멤버 메소드를 부르는 것이다.
-> 이는 의존성을 증가시키는 짓이다.
또한 반복되는 불필요한 작업이다.
스프링은 이를 허용하지 않는다.
@Slf4j를 달면 그 클래스에서는 log라는 변수로 로거 클래스를 이용할 수 있다.
물론 Slf4j를 사용하므로, log4j를 사용하는지, logback를 사용하는지는 중요하지 않다.
그래들이나 메이븐을 뜯어보지 않는 이상 무엇을 사용하는지 알아볼 수 없다....
다음과 같이 로그를 남길 수 있다.
log.trace("Trace");
log.debug("Debug");
log.info("Info");
log.warn("Warn");
log.error("Error");
JPA logging
스프링에선 기본적으로 JPA 로그가 뜨지 않는다.
정확히는 INFO 부터 뜬다.
설정에서 이 레벨을 Debug로 내려서 Debug 부터 뜨게 할 수 있다.
-
JPA의 (구현체인 하이버네이트)의 로그 레벨을 DEBUG로 낮춘다.
이렇게 하면 스프링에서 날리는 (스프링 - 스프링 데이타 JPA - JPA - 하이버네이트) 쿼리를 확인할 수 있다. -
1번만 하면 쿼리가 한 줄로 나오는데, 그러면 로그를 찍으나 마나이다. 이렇게 하면 줄바꿈도 되고 이쁘게 정렬되어서 나온다. 이는 스프링 jpa가 해주는 것이다.
-
1, 2번만 하면 무용지물인 것이, 실제 어떤 데이터를 얻어왔고 어떤 데이터를 보냈는지가 뜨지 않는다. JPA 쿼리는 기본적으로 ?로 뜬다.
그래서 이걸 보여주도록 org.hibernate.type.descriptor.sql의 로깅 레벨을 최하인 trace로 낮춘다.
이는 개발할 때보단 datajpatest 를 할 때 쓰면 좋을 것 같다.
개발할 때마다 저걸 찍으면 콘솔창이 매우 더러워진다.
