logback-spring.xml 설정

출처 : dadadamarine.github.io/java/spring/2019/05/01/spring-logging-xml.html

What is logback?

SLF4J의 native 구현체. 왜 SLF4J를 함께 사용해야 하는지에 대한 내용은 참조의 글을, 이 원리에 대한 내용은 참조의 글을 추천드립니다.

logback-core, hogback-classic, logback-access의 모듈로 구성

Maven dependency

<dependency> <groupId>net.rakugakibox.spring.boot</groupId> <artifactId>logback-access-spring-boot-starter</artifactId> <version>2.7.1</version> <scope>runtime</scope> </dependency> <dependencies> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>1.7.7</version> </dependency> </dependencies>

logback 설정파일

설정파일의 위치 및 종류

src/main/resources/ 아래에 위치한다. Spring boot 에서는 logback.xml로 설정하면 스프링 부트에대한 설정전에 로그백 설정이 되므로 제어 할 수가 없다.

따라서 logback-spring.xml을 이용하던지 property의 logging.config = classpath:logback-${spring.profiles.active}.xml을 통해 각 프로파일별로 logback 설정파일을 관리하도록 한다.

logback의 설정 항목

Level TRACE - DEBUG - INFO - WARN - ERROR 순으로 오른쪽으로 갈수록 높은레벨. 출력 레벨 이상의 로그만 출력한다.

Appendar

이벤트마다 로그를 기록하는 기능을 처리하는 객체. 로그의 출력위치, 출력 형식등을 설정한다. logback-core모듈에는 3가지 기본 Appender이 있다.

1. ConsoleAppender : 로그를 콘솔에 출력
2. FileAppender : 로그를 지정 파일에 기록
3. RollingFileAppender : FileAppender을 상속. 날짜와 용량등을 설정해서 패턴에 따라 로그가 각기 다른파일에 기록되게 할 수 있음.

Loback-classic 모듈을 이용하면 원격에 로그를 기록할 수도 있다.

Logger

실제 로그 기능을 수행하는 객체. 각 Logger마다 name을 통해 구분한다. 최상위 로거인 Root Logger를 설정하면 이를 계층적으로 활용 할 수 있다.

이에 대한 자세한 내용과 설정항목에 대한 더 자세한 내용은 참조에 자세히 나와있습니다.

logback 설정

property로 logging의 config를 선택해서 불러오도록 한다.

 

[application.properties]

spring.profiles.active=local

logging.config=classpath:logback-${spring.profiles.active}.xml

 

위의 소스는 빌드시에 기본적으로 local profile이 active되어 logback-local.xml 파일이 logback 설정으로 적용되도록 하였다.

배포환경에서는 argument로 prod를 제공하여 logback-prod.xml 파일로 설정하도록 한다. 즉 빌드파일 실행시에 java -jar -Dspring.profiles.active=prod 를 적용한다.

로컬 환경

logback-local.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%-5level] : %msg%n</pattern>
        </encoder>
    </appender>
    <root level="debug">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

배포 환경

logback-prod.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%-5level] : %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <file>mylog.txt</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- rollover daily -->
            <fileNamePattern>mylog-%d{yyyy-MM-dd}.%i.txt</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <!-- or whenever the file size reaches 100MB -->
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>[%-5level] %d{HH:mm:ss.SSS} %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>
    <root level="debug">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="ROLLING"/>
    </root>
</configuration>

 

콘솔에는 모든 log정보를 출력한다.

filter를 사용하여 INFO이상의 로그만 파일에 분산하여 저장하도록 하였다.

참조

1. JAVA에서 LogBack을 이용한 로깅(logging) – 사용법

----------------------------------------------------------

2021-04-02 13:21:36.398  INFO 17652 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
20210402 13:21:36.398 [main] INFO o.h.e.t.j.p.i.JtaPlatformInitiator - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform] 
2021-04-02 13:21:36.864  INFO 17652 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
20210402 13:21:36.864 [main] INFO o.s.o.j.LocalContainerEntityManagerFactoryBean - Initialized JPA EntityManagerFactory for persistence unit 'default' 
2021-04-02 13:21:41.600  WARN 17652 --- [           main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
20210402 13:21:41.600 [main] WARN o.s.b.a.o.j.JpaBaseConfiguration$JpaWebConfiguration - spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 
2021-04-02 13:21:44.277  INFO 17652 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
20210402 13:21:44.277 [main] INFO o.s.s.c.ThreadPoolTaskExecutor - Initializing ExecutorService 'applicationTaskExecutor' 
2021-04-02 13:21:45.944  INFO 17652 --- [           main] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page: ServletContext resource [/index.html]
20210402 13:21:45.944 [main] INFO o.s.b.a.w.s.WelcomePageHandlerMapping - Adding welcome page: ServletContext resource [/index.html] 
2021-04-02 13:21:51.766  INFO 17652 --- [           main] wam.app.ServletInitializer               : Started ServletInitializer in 35.944 seconds (JVM running for 50.461)
20210402 13:21:51.766 [main] INFO w.a.ServletInitializer - Started ServletInitializer in 35.944 seconds (JVM running for 50.461) 
2021-04-02 13:21:52.697  INFO 17652 --- [           main] org.apache.jasper.servlet.TldScanner     : 적어도 하나의 JAR가 TLD들을 찾기 위해 스캔되었으나 아무 것도 찾지 못했습니다. 스캔했으나 TLD가 없는 JAR들의 전체 목록을 보시려면, 로그 레벨을 디버그 레벨로 설정하십시오. 스캔 과정에서 불필요한 JAR들을 건너뛰면, 시스템 시작 시간과 JSP 컴파일 시간을 단축시킬 수 있습니다.
20210402 13:21:52.697 [main] INFO o.a.j.s.TldScanner - 적어도 하나의 JAR가 TLD들을 찾기 위해 스캔되었으나 아무 것도 찾지 못했습니다. 스캔했으나 TLD가 없는 JAR들의 전체 목록을 보시려면, 로그 레벨을 디버그 레벨로 설정하십시오. 스캔 과정에서 불필요한 JAR들을 건너뛰면, 시스템 시작 시간과 JSP 컴파일 시간을 단축시킬 수 있습니다. 
2021-04-02 13:21:52.900  INFO 17652 --- [           main] org.apache.coyote.ajp.AjpNioProtocol     : 프로토콜 핸들러 ["ajp-nio-8009"]을(를) 시작합니다.
20210402 13:21:52.900 [main] INFO o.a.c.a.AjpNioProtocol - 프로토콜 핸들러 ["ajp-nio-8009"]을(를) 시작합니다. 
2021-04-02 13:21:52.905  INFO 17652 --- [           main] org.apache.catalina.startup.Catalina     : 서버가 [48,392] 밀리초 내에 시작되었습니다.
20210402 13:21:52.905 [main] INFO o.a.c.s.Catalina - 서버가 [48,392] 밀리초 내에 시작되었습니다. 
2021-04-02 13:21:53.119  INFO 17652 --- [nio-8080-exec-1] o.a.c.c.C.[Catalina].[localhost].[/]     : Initializing Spring DispatcherServlet 'dispatcherServlet'
20210402 13:21:53.119 [http-nio-8080-exec-1] INFO o.a.c.c.C.[.[.[/] - Initializing Spring DispatcherServlet 'dispatcherServlet' 
2021-04-02 13:21:53.121  INFO 17652 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
20210402 13:21:53.121 [http-nio-8080-exec-1] INFO o.s.w.s.DispatcherServlet - Initializing Servlet 'dispatcherServlet' 
2021-04-02 13:21:53.124  INFO 17652 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 2 ms
20210402 13:21:53.124 [http-nio-8080-exec-1] INFO o.s.w.s.DispatcherServlet - Completed initialization in 2 ms 

위의 첫 라인은 default 로그 형식

아래는 logback-spring.xml 설정에 따른 로그이다. 다음과 같이 설정했다.

<encoder>

    <pattern>%d{yyyyMMdd HH:mm:ss.SSS} [%thread] $-3level %logger{5} - %msg %n</pattern>

</encoder>

 

다음과 같이 logback-spring.xml 설정을 고쳐 보았다.

<pattern>%d{yyyyMMdd HH:mm:ss.SSS} [%thread] $-13level %logger{10} - %msg %n</pattern>

 

logger는 java의 package를 몇단계까지 보여줄지를 나타내는 듯 하다.

2021-04-02 13:28:51.300  INFO 9596 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect
20210402 13:28:51.300 [main] INFO o.h.d.Dialect - HHH000400: Using dialect: org.hibernate.dialect.PostgreSQL10Dialect 
2021-04-02 13:28:55.681  INFO 9596 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
20210402 13:28:55.681 [main] INFO o.h.e.t.j.p.i.JtaPlatformInitiator - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform] 
2021-04-02 13:28:56.237  INFO 9596 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
20210402 13:28:56.237 [main] INFO o.s.o.j.LocalContainerEntityManagerFactoryBean - Initialized JPA EntityManagerFactory for persistence unit 'default' 
2021-04-02 13:29:01.207  WARN 9596 --- [           main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
20210402 13:29:01.207 [main] WARN o.s.b.a.o.j.JpaBaseConfiguration$JpaWebConfiguration - spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 
2021-04-02 13:29:03.157  INFO 9596 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
20210402 13:29:03.157 [main] INFO o.s.s.c.ThreadPoolTaskExecutor - Initializing ExecutorService 'applicationTaskExecutor' 
2021-04-02 13:29:04.351  INFO 9596 --- [           main] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page: ServletContext resource [/index.html]
20210402 13:29:04.351 [main] INFO o.s.b.a.w.s.WelcomePageHandlerMapping - Adding welcome page: ServletContext resource [/index.html] 
2021-04-02 13:29:09.573  INFO 9596 --- [           main] wam.app.ServletInitializer               : Started ServletInitializer in 35.404 seconds (JVM running for 50.659)
20210402 13:29:09.573 [main] INFO w.a.ServletInitializer - Started ServletInitializer in 35.404 seconds (JVM running for 50.659) 
2021-04-02 13:29:10.132  INFO 9596 --- [           main] org.apache.jasper.servlet.TldScanner     : 적어도 하나의 JAR가 TLD들을 찾기 위해 스캔되었으나 아무 것도 찾지 못했습니다. 스캔했으나 TLD가 없는 JAR들의 전체 목록을 보시려면, 로그 레벨을 디버그 레벨로 설정하십시오. 스캔 과정에서 불필요한 JAR들을 건너뛰면, 시스템 시작 시간과 JSP 컴파일 시간을 단축시킬 수 있습니다.
20210402 13:29:10.132 [main] INFO o.a.j.s.TldScanner - 적어도 하나의 JAR가 TLD들을 찾기 위해 스캔되었으나 아무 것도 찾지 못했습니다. 스캔했으나 TLD가 없는 JAR들의 전체 목록을 보시려면, 로그 레벨을 디버그 레벨로 설정하십시오. 스캔 과정에서 불필요한 JAR들을 건너뛰면, 시스템 시작 시간과 JSP 컴파일 시간을 단축시킬 수 있습니다. 
2021-04-02 13:29:10.403  INFO 9596 --- [           main] org.apache.coyote.ajp.AjpNioProtocol     : 프로토콜 핸들러 ["ajp-nio-8009"]을(를) 시작합니다.
20210402 13:29:10.403 [main] INFO o.a.c.a.AjpNioProtocol - 프로토콜 핸들러 ["ajp-nio-8009"]을(를) 시작합니다. 
2021-04-02 13:29:10.409  INFO 9596 --- [           main] org.apache.catalina.startup.Catalina     : 서버가 [48,336] 밀리초 내에 시작되었습니다.
20210402 13:29:10.409 [main] INFO o.a.c.s.Catalina - 서버가 [48,336] 밀리초 내에 시작되었습니다. 
2021-04-02 13:29:10.681  INFO 9596 --- [nio-8080-exec-1] o.a.c.c.C.[Catalina].[localhost].[/]     : Initializing Spring DispatcherServlet 'dispatcherServlet'
20210402 13:29:10.681 [http-nio-8080-exec-1] INFO o.a.c.c.C.[.[.[/] - Initializing Spring DispatcherServlet 'dispatcherServlet' 
2021-04-02 13:29:10.683  INFO 9596 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
20210402 13:29:10.683 [http-nio-8080-exec-1] INFO o.s.w.s.DispatcherServlet - Initializing Servlet 'dispatcherServlet' 
2021-04-02 13:29:10.686  INFO 9596 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 2 ms
20210402 13:29:10.686 [http-nio-8080-exec-1] INFO o.s.w.s.DispatcherServlet - Completed initialization in 2 ms