검증을 위한 Logback 로그 출력 테스트 방법

로그 출력을 검증하는 것은 테스트 코드 작성 시 중요한 부분입니다. 특히, 로그 레벨에 따른 조건적인 출력을 검증할 때는 정확성이 요구됩니다. 이 문서는 Logback 라이브러리를 사용하여 로그 출력을 효과적으로 검사하는 방법을 설명합니다.

Appender란?

Appender는 Logback의 핵심 구성 요소로 로그 이벤트를 기록하는 역할을 합니다. 공식 문서에 따르면:

Logback은 로깅 이벤트를 작성하는 작업을 'appender'라고 불리는 컴포넌트에 위임합니다. Appender는 ch.qos.logback.core.Appender 인터페이스를 구현해야 합니다. - Logback 공식 문서

기본적으로, 스프링 부트에는 콘솔에 로그 이벤트를 출력하는 콘솔 Appender가 포함되어 있습니다.

로그 검사를 위한 사용자 정의 Appender 구현

로그 출력을 검사하기 위해서는 사용자 정의 Appender와 RecordCheckable 인터페이스를 구현해야 합니다. Logback 라이브러리는 리스트 형태로 이벤트를 기록하는 ListAppender를 제공합니다. 아래는 ListAppender를 확장하고 RecordCheckable 인터페이스를 구현한 예시 코드입니다.

ListAppender

import java.util.ArrayList;  
import java.util.List;  
import ch.qos.logback.core.AppenderBase;  

public class ListAppender<E> extends AppenderBase<E> {  
    public List<E> list = new ArrayList<E>();  

    protected void append(E e) {  
        list.add(e);  
    }  
}

RecordCheckable 인터페이스와 RecordCheckAppender 구현

import ch.qos.logback.classic.Level;  
import ch.qos.logback.classic.Logger;  
import ch.qos.logback.classic.spi.ILoggingEvent;  
import ch.qos.logback.core.read.ListAppender;  

interface RecordCheckable {  
    boolean isRecord(String message, Level level);  
}  

public class RecordCheckAppender extends ListAppender<ILoggingEvent> implements RecordCheckable {  
    public static RecordCheckAppender addAppender(Logger logger) {  
        RecordCheckAppender newAppender = new RecordCheckAppender();  
        logger.addAppender(newAppender);  
        newAppender.start();  
        return newAppender;  
    }  

    @Override  
    public boolean isRecord(String message, Level level) {  
        return this.list.stream()  
            .filter(iLoggingEvent -> iLoggingEvent.getLevel().equals(level))  
            .anyMatch(iLoggingEvent -> iLoggingEvent.getMessage().contains(message));  
    }  
}

테스트 코드에서의 사용

테스트를 진행하기 전에 테스트 대상 클래스의 Logger에 RecordCheckAppender를 추가합니다.

@BeforeEach  
void beforeEach() {  
    this.recordCheckAppender =  
        RecordCheckAppender.addAppender((Logger) LoggerFactory.getLogger(Foo.class));  
}

이제 아래와 같이 로그 레벨과 메시지를 통해 로그의 출력 여부를 검증할 수 있습니다.

@Test  
public void testAlertUnspecifiedAuthError() {  
    Foo foo = new Foo();
    foo.log();
    assertTrue(recordCheckAppender.isRecord("foo log가 출력되었습니다.", Level.WARN));  
}

위의 방법을 통해 로그 출력의 정확성을 테스트 코드 내에서 쉽고 명확하게 검증할 수 있습니다.

[Spring] Request Body 를 직접 읽을 때 주의할 점

들어가며

Filter 를 이용해 로그에 Request Body 를 기록하는 기능을 추가하자
기존 API의 Request Body가 비어있는 오류가 발생했다. 원인과 해결방안에 대해서 알아보자

예시 HTTP 코드

다음과 같은 테스트 HTTP API 코드가 있다고 하자

@RestController
class TestController {
    companion object{
        val log:Logger=LoggerFactory.getLogger(this::class.java)
    }

    @PostMapping("/test/requestBody")
    fun test(@RequestBody message: Message): Message {
        return message
    }

    data class Message(
        val id: Long,
        val message: String
    )
}

이 경우 아래와 같은 테스트 코드를 실행하면 당연히 성공해야한다.

@SpringBootTest
@AutoConfigureMockMvc
class TestControllerTest {

    @Autowired
    private lateinit var mockMvc: MockMvc

    @Autowired
    private lateinit var objectMapper: ObjectMapper

    @Test
    fun `test endpoint should return correct message`() {
        val message = TestController.Message(1, "test")

        mockMvc.perform(
            post("/test/requestBody")
            .contentType(MediaType.APPLICATION_JSON)
            .content(objectMapper.writeValueAsString(message)
            )
            .accept(MediaType.APPLICATION_JSON))
            .andExpect(status().isOk)
            .andExpect(jsonPath("$.id", Matchers.`is`(message.id.toInt())))
            .andExpect(jsonPath("$.message", Matchers.`is`(message.message)))
    }

}

Request Body를 사용하는 필터 추가

Sentry (에러 모니터링 도구)에 Request Body를 기록하는 필터를 추가한다.
request 에서 request body를 읽어오는 모습을 볼 수 있다.

@Component
class RequestBodyLogger: OncePerRequestFilter() {

    val log: Logger=LoggerFactory.getLogger(this::class.java)
    override fun doFilterInternal(
        request: HttpServletRequest,
        response: HttpServletResponse,
        filterChain: FilterChain
    ) {
        Sentry.configureScope{scope ->
            scope.setExtra("requestBody",request.reader.lines().collect(Collectors.joining(System.lineSeparator())))
        }
        filterChain.doFilter(request,response)
    }
}

에러

필터를 추가하고 다시 테스트 코드를 실행하면 아래와 같은 에러를 마주친다.

java.lang.IllegalStateException: Cannot call getInputStream() after getReader() has already been called for the current request

이 에러는 @RequestBody 어노테이션을 처리하는 과정에서 request body의 getReader()가 이미 사용되었기 때문에 더 이상 request body를 읽어올 수 없다는 내용이다.

Servlet의 Request Body는 메모리에 저장하는 것이 아니라 BufferReader 또는 InputStream으로 처리된다. 즉, 한 번 소비가 되면
다른 곳에 저장하지 않는 이상 더 이상 데이터를 가져올 수가 없다.

따라서 필터에서 이미 소비가 되었기 때문에 컨트롤러에서 RequestBody를 해석하려고 하면 데이터를 읽어올 수 없기 때문에 에러가 발생한다.

해결방안

해결방안은 ContentCachingRequestWrapper를 사용하는 것이다.

ContentCachingRequestWrapper는 HttpServletRequest 에서 스트림이나 리더를 이용해 소비되는 데이터를 캐시에 저장해
byte array를 이용해 조회할 수 있도록 하는 래퍼 클래스이다.

이 클래스를 이용하면 필터에서 request body 데이터를 가져와도 이후에도 다시 데이터를 가져올 수 있다.

@Component
class RequestBodyLogger: OncePerRequestFilter() {

    val log: Logger=LoggerFactory.getLogger(this::class.java)
    override fun doFilterInternal(
        request: HttpServletRequest,
        response: HttpServletResponse,
        filterChain: FilterChain
    ) {
        //use cache wrapper for request
        val wrappedRequest = ContentCachingRequestWrapper(request)
        filterChain.doFilter(request,response)

        Sentry.configureScope{scope ->
            val buf=wrappedRequest.contentAsByteArray
            val length = min(buf.size, request.contentLength)
            scope.setExtra("requestBody", String(buf, 0, length, charset(request.characterEncoding)))
        }
    }
}

여기서 중요한 점은 contentAsByteArray를 가져오기 전에 filterChain.doFilter를 호출해야한다는 것이다.

contentAsByteArray 데이터는 request가 리더나 버퍼를 통해서 데이터가 읽어질 때 중간에 데이터를 가로채 저장함으로써 조회가 가능하다.
따라서, request body를 조회하기 전에 contentAsByteArray 데이터를 조회하면 빈 값이 있으므로 filterChain.doFilter를 먼저 호출해야한다.

    /**
     * Return the cached request content as a byte array.
     * <p>The returned array will never be larger than the content cache limit.
     * <p><strong>Note:</strong> The byte array returned from this method
     * reflects the amount of content that has been read at the time when it
     * is called. If the application does not read the content, this method
     * returns an empty array.
     * @see #ContentCachingRequestWrapper(HttpServletRequest, int)
     */
    public byte[] getContentAsByteArray() {
        return this.cachedContent.toByteArray();
    }

Companion Object vs Inner Object

들어가며

companon object를 단순히 java의 static을 대체한다고만 하는 경우가 많아 좀 더 자세히 알아보도록 하자.

companon object 에 대한 정의는 공식 문서에서 확인할 수 있다.
공식문서에서는 원리보다는 용례에 대해 중점적으로 설명하고 있는데, 여기에서는 companon object의 원리와 inner object와의 차이에 대해서 알아보고자 한다.

예시코드

class CompanionObject {
    companion object{
        const val LIMIT=100
        fun add(a: Int,b: Int): Int = a+b
    }
}

class InnerObject {
    object Companion{
        const val LIMIT=100
        fun add(a: Int,b: Int): Int = a+b
    }
}

분석

바이트 코드를 살펴보면 static inner 클래스가 생성되는 것은 동일하지만, 인스턴스 선언방식과 상수의 위치 차이를 알 수 있다.

// CompanionObject.java
public final class CompanionObject {
   public static final int LIMIT = 100;
   @NotNull
   public static final Companion Companion = new Companion((DefaultConstructorMarker)null);

   public static final class Companion {
      public final int add(int a, int b) {
         return a + b;
      }

      private Companion() {
      }

      // $FF: synthetic method
      public Companion(DefaultConstructorMarker $constructor_marker) {
         this();
      }
   }
}

// InnerObject.java
public final class InnerObject {

   public static final class Companion {
      public static final int LIMIT = 100;
      @NotNull
      public static final Companion INSTANCE;

      public final int add(int a, int b) {
         return a + b;
      }

      private Companion() {
      }

      static {
         Companion var0 = new Companion();
         INSTANCE = var0;
      }
   }
}

자바에서 코틀린 companion object 호출

바이트 코드를 보면 알 수 있듯, 함수는 Companion 클래스 내부에 선언되어 있으므로 직접 호출이 불가능하다.
호출을 하려면 Companion 클래스까지 정의를 해야하는데 이는 java static 메서드의 정의와 상이하다.

import com.example.kotlinspring.companionobject.CompanionObject;

public class CompanionJavaTest {
    public static void main(String[] args) {
        int result = CompanionObject.add(1, 2); // 에러 발생
        int result = CompanionObject.Companion.add(1,2);
    }
}

직접 호출을 하기 위해서는 @JVMStatic 어노테이션을 코틀린에서 정의하면 된다.

class CompanionObject {
    companion object : Factory<CompanionObject>{
        const val LIMIT=100
        @JvmStatic fun add(a: Int,b: Int): Int = a+b
        override fun create(): CompanionObject = CompanionObject()
    }
}

이렇게 하면 아래처럼 바이트 코드에 static 함수가 생기고 이 함수는 Companion 클래스의 함수를 다시 호출한다.

public final class CompanionObject {
    public static final int LIMIT = 100;
    @NotNull
    public static final Companion Companion = new Companion((DefaultConstructorMarker) null);

    @JvmStatic
    public static final int add(int a, int b) {
        return Companion.add(a, b);
    }
    //중략...
}

스프링에서 데이터에베이스에 연결해 테스트를 진행할 때는 로컬에 설치하거나 H2 인메모리 데이터베이스를 테스트 코드와 같이 실행시키는 등 다양한 방법이 있다. 이번에는 TestContainer를 이용해서 테스트 코드를 실행할 떄 MySQL 컨테이너를 실행시키고 연결해 통합테스트코드를 수행하는 방법에 대해서 알아보자. 완성된 프로젝트 코드는 링크에서 찾을 수 있다.

준비

도커 설치

MySQL 컨테이너를 실행시키기 위해선 당연히 컨테이너 실행 도구가 필요하다. 이 중 가장 대표적인 도커를 설치해보자. 링크를 통해 OS에 맞는 도커를 설치하도록 한다.

환경 변수 설정

To run Testcontainers-based tests, you need a Docker-API compatible container runtime, such as using Testcontainers Cloud or installing Docker locally. During development, Testcontainers is actively tested against recent versions of Docker on Linux, as well as against Docker Desktop on Mac and Windows. These Docker environments are automatically detected and used by Testcontainers without any additional configuration being necessary.

TestContainer가 설치된 컨테이너 실행도구를 찾기 위해서는 정보를 알려주어야 한다. TestContainer는 기본적으로 도커를 알아서 찾아 연결하려고 한다. 도커 설치 후 따로 설정을 하지 않는 이상 테스트 컨테이너를 위해 추가적으로 설정해야할 일은 없다. 만약 컨테이너 실행 도구를 도커로 사용하지 않거나 추가 설정이 필요하다면, 링크를 참고하자.

Gradle 종속성 추가

스프링 프로젝트에서 테스트 코드 실행시 도커를 활용하기 위해서는 TestContainer 모듈이 필요하다. 아래 종속성 코드를 참고해 필요한 모듈을 추가하도록 한다.

dependencies {
    implementation 'org.springframework.boot:spring-boot-starter-data-jpa'
    implementation 'org.springframework.boot:spring-boot-starter-web' // 예시 웹 서비스 용
    runtimeOnly 'com.mysql:mysql-connector-j'
    testImplementation 'org.springframework.boot:spring-boot-starter-test'
    testImplementation 'org.testcontainers:junit-jupiter' //테스트 컨테이너를 Junit 테스트 라이프사이클에 활용하기 위한 모듈
    testImplementation "org.testcontainers:mysql:1.19.1" //MySQL 컨테이너를 테스트에 활용하기 위한 모듈
    testImplementation 'io.rest-assured:rest-assured' //API 테스트를 위한 모듈
}

예시 웹 서비스 구현

테스트를 위해서 고객 정보를 저장하고 조회하는 서비스를 간단하게 구현해보자

학생 스키마 정의

resources/schema.sql에 MySQL 에 정의할 학생 테이블 스키마 DDL을 작성하자

CREATE TABLE students
(
    id    BIGINT AUTO_INCREMENT NOT NULL,
    name  VARCHAR(255)          NULL,
    age   INT                   NOT NULL,
    email VARCHAR(255)          NULL,
    CONSTRAINT pk_students PRIMARY KEY (id)
);

학생 엔티티 정의

학생의 이름과 이메일을 저장하는 엔티티를 아래와 같이 정의하자.

package com.example.testcontainermysql.domain;  

import jakarta.persistence.*;  

@Entity  
@Table(name = "students")  
public class Student {  

    @Id  
    @GeneratedValue(strategy = GenerationType.IDENTITY)  
    private Long id;  

    private String name;  
    private int age;  
    private String email;  

    // 기본 생성자  
    public Student() {  
    }  
    // 모든 필드를 포함한 생성자  
    public Student(String name, int age, String email) {  
        this.name = name;  
        this.age = age;  
        this.email = email;  
    }  

    // getter와 setter 메소드  
    public Long getId() {  
        return id;  
    }  

    public void setId(Long id) {  
        this.id = id;  
    }  

    public String getName() {  
        return name;  
    }  

    public void setName(String name) {  
        this.name = name;  
    }  

    public int getAge() {  
        return age;  
    }  

    public void setAge(int age) {  
        this.age = age;  
    }  

    public String getEmail() {  
        return email;  
    }  

    public void setEmail(String email) {  
        this.email = email;  
    }  

    // toString 메소드  
    @Override  
    public String toString() {  
        return "Student{" +  
                "id=" + id +  
                ", name='" + name + '\'' +  
                ", age=" + age +  
                ", email='" + email + '\'' +  
                '}';  
    }  
}

학생 레포지토리 정의

학생 정보를 저장, 조회하는 레포지토리를 정의하자.

package com.example.testcontainermysql.domain;  

import org.springframework.data.jpa.repository.JpaRepository;  

public interface StudentRepository extends JpaRepository<Student, Long> {  
}

학생 컨트롤러 정의

학생 정보를 조회하는 컨트롤러를 정의하자.

package com.example.testcontainermysql.api;

import com.example.testcontainermysql.domain.Student;
import com.example.testcontainermysql.domain.StudentRepository;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

import java.util.List;

@RestController
public class StudentController {
    private final StudentRepository studentRepository;

    public StudentController(StudentRepository studentRepository) {
        this.studentRepository = studentRepository;
    }

    @GetMapping("/student/all")
    List<Student> findAll(){
        return studentRepository.findAll();
    }
}

테스트

테스트 리소스 설정

test/resources/spring.yaml에 테스트시 사용할 스프링 설정을 정의하자. 아래와 같이 정의하면 이전에 정의한 학생 스키마를 MySQL에 자동으로 전달해 학생 테이블을 생성한다.

spring:  
  sql:  
    init:  
      mode: always

테스트 코드 작성

이제 MySQL 컨테이너를 실행시키고 예시 학생 데이터를 생성한 다음 API를 통해 학생 데이터를 조회하는 테스트 코드를 작성해보자. 테스트 코드의 역할을 주석을 참고해보자.

package com.example.testcontainermysql;  

import static io.restassured.RestAssured.given;  
import static org.hamcrest.Matchers.hasSize;  

import com.example.testcontainermysql.domain.Student;  
import com.example.testcontainermysql.domain.StudentRepository;  
import io.restassured.RestAssured;  
import io.restassured.http.ContentType;  
import java.util.List;  
import org.junit.jupiter.api.AfterAll;  
import org.junit.jupiter.api.BeforeAll;  
import org.junit.jupiter.api.BeforeEach;  
import org.junit.jupiter.api.Test;  
import org.springframework.beans.factory.annotation.Autowired;  
import org.springframework.boot.test.context.SpringBootTest;  
import org.springframework.boot.test.web.server.LocalServerPort;  
import org.springframework.test.context.DynamicPropertyRegistry;  
import org.springframework.test.context.DynamicPropertySource;  
import org.testcontainers.containers.MySQLContainer;  

/**  
 * 1. 통합 테스트를 위해 임의의 포트 번호를 할당한 웹 어플리케이션을 실행합니다.  
 */@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)  
class StudentControllerTest {  

    //현재 서버의 포트 번호  
    @LocalServerPort  
    private Integer port;  

    /**  
     * 2. 도커 이미지 명을 명시해 컨테이너를 정의합니다.  
     */    static MySQLContainer<?> mysql = new MySQLContainer<>(  
            "mysql:8.0.35"  
    );  

    /**  
     * 3. 테스트 전, 컨테이너를 실행합니다, 이미지가 없다면 풀링을 먼저 수행합니다.  
     */    @BeforeAll  
    static void beforeAll() {  
        mysql.start();  
    }  

    /**  
     * 4. 테스트 후, 컨테이너를 종료합니다.  
     */    @AfterAll  
    static void afterAll() {  
        mysql.stop();  
    }  

    /**  
     * 5. 통합 테스트에서 동적으로 데이터베이스 관련 프로퍼티를 정의합니다. 이를 통해, JPA가 어떤 데이터베이스 연결 정보를 알 수 있습니다.  
     * @param registry  
     */  
    @DynamicPropertySource  
    static void configureProperties(DynamicPropertyRegistry registry) {  
        registry.add("spring.datasource.url", mysql::getJdbcUrl);  
        registry.add("spring.datasource.username", mysql::getUsername);  
        registry.add("spring.datasource.password", mysql::getPassword);  
    }  

    @Autowired  
    StudentRepository studentRepository;  

    /**  
     * 6. 각 테스트 수행 전, 학생 테이블을 초기화합니다.  
     */    @BeforeEach  
    void setUp() {  
        RestAssured.baseURI = "http://localhost:" + port;  
        studentRepository.deleteAll();  
    }  

    /**  
     * 7. 예시 데이터를 입력 후, API 테스트를 수행합니다.  
     */    @Test  
    void shouldGetAllStudents() {  
        List<Student> customers = List.of(  
                new Student("foo", 11, "john@mail.com"),  
                new Student("bar", 12, "dennis@mail.com")  
        );  
        studentRepository.saveAll(customers);  

        given()  
                .contentType(ContentType.JSON)  
                .when()  
                .get("/student/all")  
                .then()  
                .statusCode(200)  
                .body(".", hasSize(2));  
    }  
}

테스트 코드 실행

이제 테스트 코드를 실행하면 아래와 같이 컨테이너가 실행되는 모습을 볼 수 있다.

컨테이너 재활용하기

만약 위와 같은 테스트 코드가 여러개라면 어떨까? 각 테스트 클래스가 실행될 때마다 컨테이너를 시작하고 종료하기를 반복할 것이다. 이는 테스트의 멱등성을 보장하지만, 똑같은 환경에서 읽기만 수행하는 테스트가 여러개 있을 경우에는 하나의 컨테이너만 사용해도 된다. 하나의 컨테이너만 사용하면 컨테이너를 시작하고 종료하는 시간을 줄일 수 있기 때문에 매우 효과적이다.

설정

컨테이너 재사용을 위해서는 .testcontainers.properties파일 설정이 필요하다. 이 파일은 MAC OS 기준으로 /Users/<사용자명>/.testcontainers.properties에 위치해 있다. 여기에 testcontainers.reuse.enable=true를 추가해주면 된다.

코드 수정

테스트를 위해 StudentControllerTest와 똑같은 클래스 StudentControllerTest2, StudentControllerTest3을 만들어보자.

새로 만든 코드에서 afterAll 메서드를 삭제하고 컨테이너를 생성하는 코드를 다음과 같이 수정하자.

static MySQLContainer<?> mysql = new MySQLContainer<>(  
        "mysql:8.0.35"  
).withReuse(true);

이렇게하고 테스트 코드를 수행하면 아래 로그처럼 컨테이너를 재활용하는 것을 확인할 수 있다!

2023-11-14T15:44:34.462+09:00  INFO 69374 --- [    Test worker] tc.mysql:8.0.35                          : Reusing container with ID: 81a0dea4b23a4239dfad1b4d2c587d118a98d2bcf463155479563ebfc6c2e608 and hash: 97a15af525be79af393ee3c604797b631872c409
2023-11-14T15:44:34.463+09:00  INFO 69374 --- [    Test worker] tc.mysql:8.0.35                          : Reusing existing container (81a0dea4b23a4239dfad1b4d2c587d118a98d2bcf463155479563ebfc6c2e608) and not creating a new one

Reference

  1. 시작 가이드, https://testcontainers.com/guides/testing-spring-boot-rest-api-using-testcontainers/
  2. General Container runtime requirements, https://java.testcontainers.org/supported_docker_environment/

+ Recent posts