Kotlin 환경에서 로그를 기록할 때 불필요한 문자열 연산을 방지하는 방법

요약: 이 글은 Java와 Kotlin 환경에서 SLF4J를 활용한 로깅 방식을 비교하며, 불필요한 문자열 연산 문제를 다룹니다. Parameterized Logging과 kotlin-logging을 활용한 대안을 제시하며, 성능과 가독성을 모두 고려한 최적의 로깅 방법을 탐구합니다. 또한, 성능 측정 결과를 통해 각 방식의 장단점을 분석하고, 상황에 맞는 로깅 방식 선택을 돕고자 합니다.

💡 리뷰어 한줄평

cdragon.cd 로그 남기는 것에 대한 제이든의 고민이 잘 느껴지는 글입니다. String 연산이 로깅에 얼마나 영향을 주는지 테스트로 증명해 주어 더욱 와닿았습니다.

yun.cheese Kotlin 서버 개발 시 발생하는 로깅 성능 저하, 이제 그만! 문자열 템플릿의 문제점을 해결하고 성능을 개선하는 방법을 알아보세요.

시작하며

안녕하세요. 카카오페이 MD플랫폼개발유닛 제이든입니다.

우리는 애플리케이션을 개발할 때 문제 해결, 상태 모니터링, 예외 추적 등 다양한 목적으로 로그를 기록합니다. Java와 Kotlin 개발 환경에서 가장 널리 사용되는 로깅 라이브러리인 SLF4J를 통해 DEBUG, INFO, ERROR 등 다양한 로그 수준으로 로그를 기록할 수 있습니다.

많은 Kotlin 개발자들이 SLF4J를 사용할 때 그 편리함으로 인해 문자열 템플릿(String Template)으로 로그 메시지를 구성합니다. 하지만 SLF4J와 함께 사용된 문자열 템플릿은 불필요한 문자열 연산을 유발하여 성능 저하를 야기할 수 있습니다.

본 글에서는 Java와 Kotlin에서 SLF4J를 사용할 때 어떤 경우에 불필요한 문자열이 발생하는지 살펴보고, Parameterized Logging과 kotlin-logging과 같은 대안을 통해 불필요한 문자열 연산을 방지하고 로깅 성능을 향상시키는 방법을 소개합니다.

SLF4J란?

Java와 Kotlin 환경에 대한 얘기를 하기 이전에 SLF4J에 대해 간략히 알아보겠습니다.

• SLF4J는 The Simple Logging Facade for Java의 약자입니다. java.util.logging, Log4j, logback 등 다양한 로깅 라이브러리/프레임워크의 파사드 또는 추상화를 제공합니다.

• SLF4J에 의존하지 않는 Log4j는 독립적인 환경에서 SLF4J 없이도 사용할 수 있습니다. 하지만 Log4j를 직접 사용할 경우 애플리케이션의 코드가 특정 환경에 종속됩니다. 또한 Log4j를 사용하지 않는 다른 개발자는 Log4j의 사용법을 추가로 익혀야 하는 번거로움이 발생합니다.

• SLF4J는 추상화되고 일관된 인터페이스를 제공하여 이러한 문제를 해결합니다. 그리고 다른 구현체로 변경 시 애플리케이션의 코드에 영향을 주지 않아 유연성을 높일 수 있는 장점도 있습니다.

Java 환경에서 SLF4J를 사용하는 방법

Java 환경에서 SLF4J를 사용하는 방법에 대해 먼저 알아보겠습니다.

String + 연산자 (Concatenation Operator)를 사용한 로그 기록 방법

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Wombat {
    final Logger logger = LoggerFactory.getLogger(Wombat.class);
    Integer t, oldT;

    public void setTemperature(Integer temperature) {
        oldT = t;
        t = temperature;
        logger.debug("Temperature set to" + t + "Old value was" + oldT);
    }
}

로그를 기록할 때 가장 간단한 방식은 Logger#debug(String)를 사용하는 것입니다.

문자열 Temperature set to, Old value was과 변수 t, oldT를 합쳐 하나의 문자열을 만들기 위해서 내부적으로 아래와 같은 과정을 거칩니다.

1. Integer 타입인 t와 oldT를 문자열로 변환하기 위하여 String.valueOf(t), String.valueOf(oldT)가 호출됩니다.
2. 4개의 문자열 조각(Temperature set to + String.valueOf(t) + Old value was + String.valueOf(oldT))을 합쳐 하나의 문자열로 만드는 String Concatenation 과정이 발생합니다.

• String Concatenation 과정은 최적화를 위해 JDK 버전에 따라 StringBuilder, StringConcatFactory 등이 사용될 수 있습니다.

위 과정들은 DEBUG 수준이 활성화되어 있지 않은 INFO, WARN, ERROR 등의 수준에서도 이루어져 불필요한 문자열 연산을 유발할 수 있습니다.

Parameterized Logging

그렇다면 불필요한 문자열 연산을 방지할 수 있는 방법은 무엇일까요?

What is the fastest way of (not) logging?에서 힌트를 얻을 수 있었는데요.

그 답은 Parameterized Logging 방식을 사용하는 것입니다.

logger.debug("Temperature set to {}. Old value was {}.", t, oldT);

이 방식은 위 예시 코드와 같이 String + 연산자 대신 {} Placeholder를 사용합니다.

Logger#debug(String, Object) 를 예시로, {} Placeholder는 DEBUG 수준이 활성화 되어 있을때만 값으로 치환되므로, 불필요한 String.valueOf() 호출과 String Concatenation 과정을 방지할 수 있습니다.

SLF4J 공식 문서에서는 String + 연산자를 사용하는 방식보다 Parameterized Logging 방식이 최소 30배 더 성능이 우수하다고 소개하고 있습니다.

Kotlin의 String Template에 대해서

다음으로는 Kotlin 환경에 대해 알아보겠습니다.

Kotlin 환경에서 SLF4J를 사용하는 방법에 대해 알아보기 이전에, Kotlin의 String Template에 대해 먼저 알아보도록 하겠습니다.

Kotlin 환경에서 문자열을 만들 때 dollar sign($)으로 구성된 Template Expression을 사용할 수 있습니다. 이는 String + 연산자를 사용하는 방식보다 훨씬 더 직관적이며 가독성이 좋은 문자열 생성 방식입니다.

공식 문서에 따르면 String Template은 다음과 같은 특성이 있습니다.

• Kotlin은 템플릿 표현식(Template Expression)을 문자열로 변환하기 위하여 .toString()을 호출합니다.
• 연산된 코드 조각들을 합쳐 하나의 문자열로 만드는 String Concatenation 과정이 발생합니다.

Kotlin 환경에서 SLF4J를 사용하는 방법

다음으로 Kotlin 환경에서 SLF4J를 사용하는 방법에 대해 알아보겠습니다.

String Template을 사용하여 로그를 기록하는 방법

class Wombat {
    private val logger: Logger = LoggerFactory.getLogger(Wombat::class.java)
    var t: Int? = null
    var oldT: Int? = null

    fun setTemperature(temperature: Int) {
        oldT = t
        t = temperature
        logger.debug("Temperature set to $t. Old value was $oldT")
    }
}

직관적이며 가독성이 좋은 특성으로 인해 String Template은 로그를 기록할 때도 사용됩니다.

이 방식은 다음의 단계를 거쳐 수행됩니다.

1. Int? 타입인 $t, $oldT를 문자열로 변환하기 위해 t.toString(), oldT.toString()이 호출됩니다.
2. 4개의 문자열 조각(Temperature set to, t.toString(), Old value was, oldT.toString())을 합쳐 하나의 문자열로 만드는 String Concatenation 과정이 발생합니다.

이 과정은 Java 환경에서 + 연산자를 사용했을 때와 유사하며, DEBUG 수준이 활성화되어 있지 않은 INFO, WARN, ERROR 수준에서도 이루어져 불필요한 문자열 연산을 유발할 수 있습니다.

그렇다면 Kotlin 환경에서 불필요한 문자열 연산을 방지할 수 있는 방법은 무엇일까요?

Parameterized Logging

Java 환경과 동일하게 Parameterized Logging을 사용하는 것입니다.

앞서 말씀드린 것처럼 Parameterized Logging을 사용하면 Logger가 로그를 기록하지 않아도 되는 경우 불필요한 문자열 연산을 방지할 수 있습니다.

하지만 {} Placeholder를 사용하므로 String Template을 사용하는 경우보다 가독성이 떨어집니다. 또한 3개 이상의 인자를 사용하는 경우 매우 작은 비용이지만 Object[]의 생성 비용이 발생합니다.

그렇다면 직관적이고 가독성이 좋은 String Template을 사용하면서 불필요한 문자열 연산을 방지할 수 있는 방법이 있을까요?

매번 해당 로그 레벨이 활성화되었는지 확인한다..?

그 방법은 간단합니다. Logger가 해당 로그의 수준이 활성화되었는지 확인하고, 활성화되어 있을 때만 로그를 기록하면 됩니다.

DEBUG 수준을 예시로, logger.isDebugEnabled()를 통해 DEBUG 수준이 활성화되었는지를 확인할 수 있습니다.

if (logger.isDebugEnabled()) {
    logger.debug("Temperature set to $t. Old value was $oldT")
}

하지만 이러한 방법은 몇 가지 단점이 존재합니다.

• 로그를 기록하는 코드가 비즈니스 로직에 집중하는 것을 방해하며, 코드의 가독성을 떨어뜨릴 수 있습니다.
• 만약 Logger가 DEBUG 수준에서 활성화되어 있다면, 아래와 같이 활성화되었는지 여부를 판단하는 코드가 불필요하게 두 번 실행됩니다.
  • logger.isDebugEnabled()
  • logger.debug() 내부

kotlin-logging에 대해

kotlin-logging은 오로지 Kotlin으로 개발되었고, Kotlin을 위한 로깅 라이브러리입니다.

kotlin-logging을 사용하기 위해서는 slf4j-api 의존성을 추가해야 합니다. 만약 Spring Boot를 사용하신다면 slf4j-api 의존성이 이미 포함되어 있어 추가할 필요가 없습니다. Logger를 정의할 때 클래스 이름, Logger 이름을 지정하는 등의 Boilerplate Code가 필요 없는 장점을 갖고 있습니다.

kotlin-logging에서 Logger를 정의하는 방법

kotlin-logging에서는 다양한 방법으로 Logger를 정의할 수 있습니다.

Logger의 이름을 명시적으로 지정하는 방법

val logger = KotlinLogging.logger("My Logger")
logger.debug { "name : ${logger.name}" } // name : My Logger

Logger의 이름은 위와 같이 명시적으로 지정할 수 있습니다. 클래스의 외부, 내부 어느 곳에서 정의하더라도 지정한 이름을 갖습니다.

Logger의 이름을 명시적으로 지정하지 않는 방법

// 클래스 외부에 top level 필드로 정의
private val logger = KotlinLogging.logger { }

class LoggingTest {
    fun logName() {
        // name : org.example.Main
        logger.debug { "name : ${logger.name}" }
    }
}

클래스 외부에 top level 필드로 정의하는 경우 패키지와 파일 이름을 합쳐 Logger의 이름이 결정됩니다. 예를 들어 패키지 이름이 org.example이고 파일의 이름이 Main.kt인 경우 Logger의 이름은 org.example.Main이 됩니다.

// 클래스 내부에 인스턴스 필드로 정의
class LoggingTest {
    val logger = KotlinLogging.logger {}
    fun logName() {
        // name : org.example.LoggingTest
        logger.debug { "name : ${logger.name}" }
    }
}

// 클래스 내부에 companion object로 정의
class LoggingTest {
    companion object {
        val logger = KotlinLogging.logger {}
    }

    fun logName() {
        // name : org.example.LoggingTest
        logger.debug { "name : ${logger.name}" }
    }
}

클래스 내부에 Logger를 생성하는 경우, 인스턴스 필드와 Companion object인 경우 모두 패키지와 클래스 이름을 합쳐 Logger의 이름이 결정됩니다. 예를 들어 패키지 이름이 org.example이고 클래스의 이름이 LoggingTest인 경우 loggerName은 org.example.LoggingTest가 됩니다.

그렇다면 어떤 방식으로 Logger를 정의하는 것이 좋을까요?

사용법에 대한 문서와 Issue#364에서는 클래스 외부에 top level 필드로 이름을 명시하지 않는 정의에 대한 방법을 권장하고 있습니다. 이는 Logger를 정의할 때 불필요한 Boilerplate Code를 방지하며 가장 간단하게 정의할 수 있고 메모리 관리 측면에서 효율적인 장점을 갖고 있습니다.

Logger를 어디에 어떻게 정의하는지는 Code Style에 관한 내용으로 다양한 의견이 있을 수 있습니다. 하지만 1개의 인스턴스당 1개의 Logger를 갖는 클래스 내부에 인스턴스 필드로 정의방식은 메모리 사용 측면에서 비효율적일 수 있으므로 추천하지 않습니다.

Logger를 정의하는 방법에 대해 조금 더 알아보고 싶으신 분은 All Examples를 참고하시면 좋을 것 같습니다.

kotlin-logging과 String Template을 사용한 로그 기록 방법

다음으로는 정의한 Logger를 사용하여 로그를 기록하는 방법에 대해 알아보겠습니다.

logger.debug { "Temperature set to $t. Old value was $oldT" }

위 코드는 내부적으로 아래와 같이 동작합니다.

if (logger.isDebugEnabled()) {
    logger.debug("Temperature set to $t. Old value was $oldT")
}

Logger가 활성화되었는지 확인하는 코드인 isDebugEnabled()를 통해 활성화되어 있지 않을 때 불필요한 문자열 연산을 방지할 수 있습니다.

logger.error(exception) { "a $fancy message about the $exception" }

또한 ERROR 로그를 기록할 때는 위와 같이 error(Throwable?, () -> Any?)를 사용할 수 있습니다.

성능 측정

성능 측정은 다음과 같은 방식으로 진행하였습니다.

성능 측정 방식

• 10만 건의 DEBUG 로그를 파일에 적재하는 테스트를 10번 실행하고, 실행 시간의 평균값을 비교한다.

• Logger의 DEBUG 수준이 활성화/비활성화된 경우를 각각 측정한다.

• log는 파일에 기록하기 위하여 RollingFileAppender를 사용한다.

• 성능 측정 환경

  • Kotlin v2.0.20
  • slf4j-api : v2.0.16
  • logback-classic : v1.5.11
  • kotlin-logging : v7.0.0

성능 측정 결과

SLF4J로 로그를 기록할 때 Kotlin String Template을 사용한 경우, DEBUG 레벨이 활성화되어 있지 않을 때 불필요한 문자열 연산이 발생하는 것을 알 수 있었습니다. DEBUG 레벨이 활성화되어 있지 않을 때 Parameterized Logging을 사용한 경우가 kotlin-logging보다 더 좋은 성능을 보여주었습니다. kotlin-logging을 사용한 경우 String Template을 함께 사용한다면 불필요한 문자열 연산을 방지하면서 가독성 좋은 로그를 기록할 수 있습니다.

따라서 성능을 가장 우선시한다면 kotlin-logging을 사용하는 대신 Logback 등의 라이브러리 환경에서 Parameterized Logging을 사용하는 것이 좋을 것으로 예상됩니다. 대신 가독성을 우선시하되 불필요한 문자열 연산 방지도 고려한다면 kotlin-logging도 좋은 선택지가 될 것으로 예상됩니다.

이 성능 측정 결과는 제한적인 상황에서의 결과이므로 각자의 애플리케이션 상황에 따라 결과가 달라질 수 있습니다.

Parameterized Logging vs. kotlin-logging

Parameterized Logging과 kotlin-logging의 특징을 요약하면 다음과 같습니다.

마치며

불필요한 문자열 연산이 애플리케이션의 성능에 미치는 영향이 사소하다고 여겨질 수도 있습니다. 하지만 사소하기에 문제로서 인식하지 못하고 많은 분들이 쉽게 지나칠 수 있습니다.

로깅 성능을 향상하기 위하여 Parameterized Logging을 우선 고려하되, 가독성이 중요하다면 kotlin-logging을 활용해 보는 건 어떨까요? 이 글이 그 문제를 인식하고 더 좋은 성능의 애플리케이션을 만드는 데에 조금이나마 도움이 되었으면 합니다.

읽어주셔서 감사합니다.