Java

2 posts with the tag “Java”

System.out.println()의 동작 원리와 로깅 프레임워크

2025. 8. 5. - Last update: 2026. 6. 2.

hyoguoo

Backend Engineer

측정 환경: Corretto JDK 24 (macOS), 인용 코드는 JDK 24의 java.base 소스 기준

System.out.println()은 운영 코드에서 피해야 할 출력 방식인데, 성능 관점에서 다음과 같은 문제가 있다.

• 전역 락: JVM에 하나뿐인 System.out 인스턴스를 모든 스레드가 synchronized로 공유
• autoFlush: 줄마다 강제로 flush하여 write 시스템 콜이 라인 수만큼 반복
• 블로킹 IO: 출력이 끝날 때까지 호출 스레드가 대기

이 글은 그 비용을 내부 구현과 벤치마크로 분석한 뒤, 로깅 프레임워크가 이를 어떻게 해결하는지 살펴본다.

• System.out.println()의 내부 동작과 PrintStream의 스트림 계층 구조
• 그 동작 방식이 처리량에 미치는 영향을 벤치마크로 실측
• 버퍼링(immediateFlush)과 비동기(AsyncAppender)가 실제 서비스의 응답 시간·처리량에 만드는 차이
• 어떤 환경에서 무엇을 선택할지에 대한 트레이드오프

System.out과 PrintStream의 역할

PrintStream 클래스는 OutputStream을 상속받아 출력 스트림을 구현하며, 다양한 타입의 데이터를 출력할 수 있는 메서드를 제공한다.

void main() {
    System.out.println("Hello, World!");
}

System.out은 PrintStream 타입의 static 객체이며, println()을 포함한 다양한 출력 메서드를 제공하여 간편하게 콘솔에 데이터를 출력할 수 있다.

System.out의 초기화 과정과 PrintStream 인스턴스 생성

PrintStream을 import하거나 인스턴스를 생성 없이 System.out.println()을 바로 사용할 수 있는데, 그 이유는 다음과 같다.

• System 클래스는 java.lang 패키지에 포함되어 있으며, 기본적으로 import되는 패키지이기 때문에 별도 import 없이 사용 가능
• System 클래스 내부에 PrintStream 타입의 static 필드 out이 정의

public final class System {

    /* Register the natives via the static initializer.
     *
     * The VM will invoke the initPhase1 method to complete the initialization
     * of this class separate from <clinit>.
     */
    private static native void registerNatives();

    static {
        registerNatives();
    }

    private System() {
    }

    public static final PrintStream out = null;

    // ...
}

out은 처음에는 null로 선언되어 있지만, JVM이 초기화 과정에서 실제 PrintStream 객체로 할당하게 된다.

1. System.out은 Java 코드 상으로는 null로 선언되어 있으나, 이는 컴파일 시점 값
2. registerNatives()라는 native 메서드가 System 클래스 초기화 블록에서 호출
3. JVM의 initPhase1()에서 입출력 스트림을 직접 설정

이 작업은 Java 코드가 아닌 JVM 내부 native 코드에서 수행되며, 실제로는 메모리 상의 System.out 필드에 객체가 강제로 할당된다.

이때 initPhase1()이 만들어 주는 System.out의 실제 구성은 다음과 같다.

java.lang.System

private static PrintStream newPrintStream(OutputStream out, String enc) {
    if (enc != null) {
        return new PrintStream(new BufferedOutputStream(out, 128), true,
                Charset.forName(enc, UTF_8.INSTANCE));
    }
    return new PrintStream(new BufferedOutputStream(out, 128), true);
}

• 최하위 스트림은 표준 출력(stdout)에 연결된 FileOutputStream이며, 그 위를 128바이트 BufferedOutputStream이 래핑
• PrintStream은 autoFlush=true로 생성되며, 이 설정값이 뒤에서 다룰 성능 이슈의 핵심 원인이 됨

PrintStream의 스트림 계층 구조

println()이 호출한 문자열은 곧바로 OS로 나가지 않고, PrintStream 내부의 여러 계층을 거쳐 전달된다.

private PrintStream(boolean autoFlush, OutputStream out) {
    super(out);
    // ...
    this.charOut = new OutputStreamWriter(this, charset);
    this.textOut = new BufferedWriter(charOut);
    // ...
}

PrintStream은 생성 시 다음과 같이 중간 계층을 구성하며, 각 계층의 역할은 다음과 같이 구분된다.

계층	타입	역할
textOut	BufferedWriter	문자(char) 단위 버퍼링
charOut	OutputStreamWriter	내부 StreamEncoder로 Charset 인코딩
out	BufferedOutputStream	인코딩된 바이트를 모았다가 하위로 내보냄

flowchart TB
    P["println 호출"] --> T["textOut (BufferedWriter)"]
    T -->|" 문자 버퍼링 "| C["charOut (OutputStreamWriter / StreamEncoder)"]
    C -->|" Charset 인코딩하여 바이트화 "| O["out (BufferedOutputStream · 128B)"]
    O -->|" 버퍼가 차거나 flush될 때 "| F["FileOutputStream"]
    F -->|" write 시스템 콜 "| K[("커널 / OS")]

1. 문자열은 textOut에서 문자 버퍼에 저장
2. charOut에서 바이트로 인코딩
3. out의 바이트 버퍼를 거쳐 최종적으로 FileOutputStream이 write 시스템 콜을 통해 커널로 전달

System.out.println() 내부 구현 코드 분석

System.out.println("Hello, World!")처럼 문자열을 출력하면 println(String x)가 호출되며, 그 흐름은 다음과 같다.

public void println(String x) {
    if (getClass() == PrintStream.class) {
        writeln(String.valueOf(x));
    } else {
        // 하위 클래스 확장 시의 예외적 경로
        synchronized (this) {
            print(x);
            newLine();
        }
    }
}

getClass() == PrintStream.class 분기는 PrintStream을 그대로 쓰는 경우와 상속받아 오버라이드한 경우를 가르는 최적화 장치다.

• System.out은 JVM이 직접 생성한 순수 PrintStream 인스턴스이므로 항상 writeln() 경로로 실행
• 하위 클래스라면 오버라이드된 print()/newLine()이 호출되어야 하므로 별도 경로로 분기
• println(Object) 등 다른 오버로드도 동일한 구조로 writeln()을 호출

writeln(String s)의 상세 구현을 살펴보면 다음과 같다.

private void writeln(String s) {
    try {
        synchronized (this) {
            ensureOpen();
            textOut.write(s);
            textOut.newLine();
            textOut.flushBuffer();
            charOut.flushBuffer();
            if (autoFlush)
                out.flush();
        }
    } catch (InterruptedIOException x) {
        Thread.currentThread().interrupt();
    } catch (IOException x) {
        trouble = true;
    }
}

1. ensureOpen()
   • 스트림이 닫히지 않았는지 확인
   • 닫힌 경우 IOException 발생시켜 출력 중단
2. textOut.write(s) / textOut.newLine()
   • 문자열 및 줄바꿈 문자를 내부 문자 버퍼(BufferedWriter)에 쓰기 수행
   • 개행은 플랫폼에 맞는 \n, \r\n 등 줄바꿈 문자로 추가
   • 실제 출력은 하지 않고, 버퍼에만 저장
3. textOut.flushBuffer()
   • 문자 버퍼에 저장된 내용을 charOut으로 흘려보내 지정된 Charset으로 인코딩
   • 인코딩된 바이트 배열 데이터를 StreamEncoder 내부에 저장
4. charOut.flushBuffer()
   • StreamEncoder에 저장된 바이트 데이터를 최하위 출력 스트림 out으로 전달
   • 이 단계까지는 out의 바이트 버퍼에 쌓일 뿐, OS로 나가지는 않음
5. if (autoFlush) out.flush()
   • System.out은 autoFlush=true이므로 매 호출마다 out.flush()를 수행
   • 버퍼에 남은 데이터까지 강제로 비워 즉시 출력되도록 보장하며, 이때 native 메서드를 통해 실제 write 시스템 콜이 발생

성능 저하의 원인

println() 한 번의 호출은 동기화·인코딩·시스템 콜을 모두 포함하는 복잡한 경로를 거치면서, 서로 다른 비용이 한 줄마다 동시에 발생하기 때문에 매우 비싼 작업이 된다.

autoFlush=true: 한 줄마다 시스템 콜

System.out의 최하위 스트림은 128바이트 BufferedOutputStream이지만, autoFlush=true 때문에 이 버퍼는 사실상 무효화된다.

• autoFlush=true는 매 println()마다 out.flush()를 호출하여, 버퍼가 채워지기도 전에 비우도록 강제
• 결국 줄 단위로 write 시스템 콜이 발생하여, 출력 라인 수만큼 시스템 콜도 반복
• 시스템 콜마다 사용자 모드에서 커널 모드로 전환하는 Mode Switch 비용이 누적

synchronized(this): 단일 인스턴스 전역 락

writeln() 전체가 synchronized (this) 블록으로 감싸져 있으며, 여기서 this는 애플리케이션 전체가 공유하는 단 하나의 System.out 인스턴스다.

• 모든 스레드가 동일한 객체 모니터를 두고 경쟁하므로, 출력 구간이 사실상 직렬화됨
• 한 스레드가 락을 쥔 채 IO를 수행하는 동안 나머지 스레드는 모니터 진입을 위해 대기
• 출력 순서는 보장되지만, 그 대가로 처리량이 저하

블로킹 IO: 출력 완료까지 스레드 대기

최하위 스트림의 write는 블로킹 IO이므로, 시스템 콜이 반환될 때까지 호출 스레드가 멈춰 있다.

• 콘솔/디스크 IO 속도는 CPU 연산보다 수십~수백 배 느림
• 락을 쥔 스레드가 블로킹된 동안 대기 중인 스레드들도 함께 멈추는 연쇄 지연 발생
• 톰캣처럼 다수의 요청 스레드가 동시에 출력을 시도하는 환경에서는 락 경합과 블로킹이 겹쳐 처리량이 급격히 저하

실측 - 출력 방식별 처리량 비교

세 비용이 만드는 실제 차이를 확인하기 위해, 100만 줄을 출력하는 벤치마크를 수행했다.

• 출력 대상을 /dev/null로 통일해 콘솔·디스크 렌더링 속도의 영향 제거
• autoFlush 여부와 스레드 수만 변수로 두고 나머지 조건은 동일하게 유지
• Corretto JDK 24, 측정 전 JIT 워밍업 수행

비교 대상은 autoFlush 설정만 다른 두 가지 출력 구성이다.

• sysoutLike: System.out과 동일한 128바이트 버퍼 + autoFlush=true
• buffered: 버퍼를 8KB로 키우고 autoFlush=false

각 구성을 두 가지 부하로 측정을 수행했다.

• 단일 스레드: 한 스레드가 100만 줄을 순차로 출력 (순수 출력 경로의 비용)
• 8 스레드 환경: 8개 스레드가 같은 스트림에 동시에 출력 (synchronized (this) 락을 두고 벌이는 경쟁 비용까지 포함)

public class PrintBenchmark {

    static final int TOTAL_LINES = 1_000_000;
    static final String LINE = "log line";

    public static void main(String[] args) throws Exception {
        // System.out과 동일한 구성: 128바이트 버퍼 + autoFlush=true
        PrintStream sysoutLike = new PrintStream(
                new BufferedOutputStream(new FileOutputStream("/dev/null"), 128), true);
        // 버퍼를 8KB로 키우고 autoFlush=false
        PrintStream buffered = new PrintStream(
                new BufferedOutputStream(new FileOutputStream("/dev/null"), 8192), false);

        warmUp(sysoutLike, buffered); // 측정 전 JIT 컴파일 유도

        report("PrintStream(128B + autoFlush)", sysoutLike);
        report("PrintStream(8KB)", buffered);
    }

    static void report(String name, PrintStream ps) {
        System.err.printf("%-30s 1T=%4dms  8T=%4dms%n", name, measure(1, ps), measure(8, ps));
    }

    // threads개의 스레드가 TOTAL_LINES를 나눠 출력하고, 전체 소요 시간(ms)을 반환
    static long measure(int threads, PrintStream ps) {
        int perThread = TOTAL_LINES / threads;

        long start = System.nanoTime();
        try (ExecutorService pool = Executors.newFixedThreadPool(threads)) {
            for (int t = 0; t < threads; t++) {
                pool.submit(() -> {
                    for (int i = 0; i < perThread; i++) {
                        ps.println(LINE);
                    }
                });
            }
        } // try 블록을 벗어날 때 close()가 모든 작업이 끝날 때까지 대기
        return (System.nanoTime() - start) / 1_000_000;
    }

    static void warmUp(PrintStream... streams) {
        for (int i = 0; i < 3; i++) {
            for (PrintStream ps : streams) {
                measure(1, ps);
            }
        }
    }
}

방식	단일 스레드	8 스레드 경합
PrintStream(buffer 128 + autoFlush, System.out 유사)	약 710ms	약 1060ms
PrintStream(buffer 8KB + autoFlush=false)	약 70ms	약 120ms

두 수치 모두 앞서 분석한 비용과 그대로 대응하는 결과를 보여준다.

• sysoutLike (710ms): autoFlush가 매 줄 out.flush()를 호출하면서, 출력 라인 수만큼 write 시스템 콜 발생
• buffered (70ms): autoFlush를 끄면 8KB 버퍼가 찰 때만 flush되어 시스템 콜 횟수 대폭 감소로, 단일 스레드 기준 약 10배 빠른 처리량 달성
• 8 스레드 경합: 두 구성 모두 느려지는데(710 → 1060, 70 → 120), 이는 synchronized (this) 락을 두고 벌이는 경쟁 비용과 블로킹 IO로 인한 연쇄 지연이 추가되기 때문

로깅 프레임워크에 위임

운영 환경에서는 버퍼링과 비동기 처리를 직접 구현하는 대신 Logback 같은 로깅 프레임워크를 사용한다.

항목	System.out.println	FileAppender(immediateFlush=true)
flush	autoFlush로 줄마다 syscall	동일(immediateFlush=true)
락	JVM에 하나뿐인 인스턴스의 전역 synchronized	어펜더별 ReentrantLock(격리·분리 가능)
출력 대상	FD 1(stdout) — 터미널·공유 파일 고정	지정 파일(분리·롤링 가능)
레벨·라우팅	없음 (항상 출력)	레벨·필터·로거별 라우팅
튜닝	autoFlush 고정	immediateFlush=false·AsyncAppender로 전환

성능을 좌우하는 두 어펜더는 다음과 같다.

• FileAppender: 8KB BufferedOutputStream으로 버퍼링 (immediateFlush=false면 줄마다 flush하지 않음)
• AsyncAppender: 로그 이벤트를 큐에 넣어 워커 스레드가 실제 IO를 처리하도록 비즈니스 스레드와 분리

flowchart TB
    A[비즈니스 스레드] -->|로그 이벤트| Q[ArrayBlockingQueue]
    Q --> W[Worker 스레드]
    W -->|위임| F[FileAppender]
    F -->|write 시스템 콜| OS[(커널)]

위 두 가지를 사용하는 Logback 설정 예시는 다음과 같다.

<configuration>
  <!-- 디스크로 쓰는 FileAppender: 내부적으로 8KB BufferedOutputStream에 버퍼링 -->
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>app.log</file>
    <!-- false면 버퍼가 찰 때까지 flush를 미뤄 시스템 콜을 줄임 (처리량 우선) -->
    <immediateFlush>false</immediateFlush>
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
    </encoder>
  </appender>

  <!-- FileAppender를 비동기로 감싸 실제 IO를 워커 스레드로 분리 -->
  <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="FILE"/>
    <queueSize>8192</queueSize>                   <!-- 로그 이벤트 큐 크기 -->
    <discardingThreshold>0</discardingThreshold>  <!-- 큐가 차도 어떤 레벨도 버리지 않음 -->
    <neverBlock>false</neverBlock>                <!-- 큐가 가득 차면 블로킹하여 이벤트 유실 방지 -->
  </appender>

  <root level="INFO">
    <appender-ref ref="ASYNC"/>
  </root>
</configuration>

• immediateFlush=false: 버퍼가 찰 때까지 flush를 미뤄 시스템 콜을 줄임(기본값 true는 비정상 종료 시 유실 방지를 우선)
• queueSize·neverBlock: 백프레셔(Backpressure)를 통제 — 큐가 가득 차면 블로킹(false)할지 이벤트를 버릴지(true) 선택
• discardingThreshold=0: 큐가 차도 INFO 이하 로그까지 보존(기본값 queueSize/5는 일부 drop)

실측 - 실제 서비스 환경의 응답 시간

앞의 간단한 벤치마크는 단일 프로세스의 출력 경로 비용만 봤으므로, 이제 실제 웹 애플리케이션에서 로깅 프레임워크로 해결했을 때 동시 요청의 응답 시간이 어떻게 달라지는지 측정했다.

• Spring Boot + Tomcat에서 GET /log/{mode}?lines=200이 요청당 로그 200줄을 남기도록 구성
• 동시 100개 요청을 12초간 반복하며 요청 응답 시간 분포(p99)와 처리량(RPS)을 측정
• 기동 시 각 출력기를 미리 호출해 JIT를 워밍업한 뒤 측정
• immediateFlush=false는 버퍼 크기를 256B·8KB·64KB 세 가지로 나눠 비교
• 동일 인코더(타임스탬프·레벨·스레드 포함)로 같은 로그를 남겨, 버퍼·flush·async 등 출력 메커니즘만 변수로 둠
• System.out 구성은 128B 버퍼 + 매 이벤트 flush(autoFlush와 동일 동작)로 구성

@GetMapping("/log/{mode}")
public String log(@PathVariable String mode, @RequestParam(defaultValue = "200") int lines) {
    // 모드별 로거는 출력 메커니즘만 다르고 인코더(로그 포맷)는 동일
    /*
    sysout(128B+flush) /
    sync-true(8KB+flush) /
    sync-false-256·8k·64k /
    async
     */
    Logger lg = LOGGERS.get(mode);
    for (int i = 0; i < lines; i++) {
        lg.info("order processed id={} user={} amount={} status={}", i, "user-" + (i % 100), i * 13, "OK");
    }
    return "ok";
}

모드	RPS	p50	p99
System.out 구성(128B + autoFlush)	~900	~105ms	~190ms
FileAppender(flush=true, 8KB)	~930	~105ms	~180ms
FileAppender(flush=false, 256B)	~1360	~72ms	~145ms
FileAppender(flush=false, 8KB)	~4100	~23ms	~50ms
FileAppender(flush=false, 64KB)	~4300	~22ms	~45ms
AsyncAppender(flush=false, 8KB)	~4900	~20ms	~39ms

• 줄마다 flush하는 두 구성(System.out 구성, immediateFlush=true)이 가장 느리고 서로 거의 동일(~1000 RPS)
  • 트리거는 다르지만(autoFlush는 개행, immediateFlush는 매 이벤트) 둘 다 라인당 flush를 일으켜 write 시스템 콜이 라인 수만큼 발생한다는 비용 구조가 유사
  • 줄마다 강제로 flush되면 버퍼가 매번 비워져 여러 줄을 쌓지 못하므로, 버퍼 용량(128B·8KB)은 차이를 만들지 못함(줄 길이와 무관)
• 버퍼가 너무 작으면(256B) immediateFlush=false라도 개선폭이 작음
• 8KB에서 처리량이 약 4배로 뛰고(RPS 약 4100), 64KB는 추가 개선폭이 작음
• 빠른 로컬 디스크에서는 AsyncAppender가 큰 버퍼의 동기 구성과 큰 차이 없음
  • 비동기의 이점은 raw 처리량이 아니라, 다음 절에서 다룰 요청 스레드의 락·CPU·블로킹 비용 분리에 있음

비동기 분리가 효과를 내는 경우

AsyncAppender는 비즈니스 스레드를 출력 IO 경합에서 떼어내는데 장점이 있지만, 테스트 결과 상 아주 큰 차이를 보이지는 않았다.

• 버퍼링된 파일 출력은 write가 페이지 캐시로 즉시 반환되고 실제 디스크 기록은 커널이 백그라운드로 처리
• async의 강점은 인코딩·포맷 CPU, 그리고 블로킹 IO로 인한 대기 시간을 요청 스레드와의 분리
  • 이러한 비용이 응답 시간에 큰 영향을 주지 않는다면 async의 이점도 제한적

때문에 요청 스레드가 부담하던 출력 비용이 커지는 경우를 가정해보았다.

// 어펜더의 출력 스트림을 `CipherOutputStream`으로 감싸 인코딩된 로그 바이트가 파일로 나가기 직전 호출 스레드에서 AES로 암호화
// 인코딩된 로그 바이트 → CipherOutputStream(AES) → 파일
void example() {
    Cipher cipher = Cipher.getInstance("AES/CTR/NoPadding");
    cipher.init(Cipher.ENCRYPT_MODE, key, new IvParameterSpec(iv));

    OutputStream target = new CipherOutputStream(
            new BufferedOutputStream(new FileOutputStream("app.log"), 8192), cipher);

    OutputStreamAppender<ILoggingEvent> appender = new OutputStreamAppender<>();
    appender.setEncoder(encoder);       // 다른 모드와 동일한 패턴 인코더
    appender.setImmediateFlush(false);  // 8KB 버퍼
    appender.setOutputStream(target);   // write 시 CipherOutputStream이 호출 스레드에서 암호화 수행
    appender.start();
}

동일 Spring 환경, 동시 100 요청·요청당 200줄로 측정 결과 다음과 같은 차이가 나타났다.

모드	RPS	p99
평문 FileAppender(false, 8KB)	~4100	~50ms
암호화 FileAppender(동기)	~1400	~105ms
암호화 AsyncAppender	~2970	~62ms

• 암호화는 AES-NI 가속이 있어도 매 이벤트 인코딩에 CPU가 들고, 그 비용이 어펜더 락 안에서 직렬화되어 평문 대비 처리량이 1/3로 하락
• AsyncAppender로 감싸면 그 암호화 CPU와 락을 워커 스레드로 떼어내 요청 스레드는 큐에 넣고 즉시 반환하므로, 처리량이 약 2배 상승

버퍼링과 비동기가 감수하는 비용

버퍼링과 비동기는 처리량을 높이는 대신, 로그를 즉시·확실히 남긴다는 보장을 일부 포기한다.

immediateFlush=false

• 비정상 종료 시 유실: 프로세스가 크래시되면 버퍼에 남은 로그가 디스크로 나가지 못하고 사라지며, 장애 직전 로그가 유실 가능
• 실시간성 저하: 버퍼가 찰 때까지 파일에 기록되지 않아 tail -f나 로그 수집기에 늦게 반영
• 큰 버퍼의 한계: 버퍼를 키울수록(8KB → 64KB) 처리량 이득은 줄어드는 반면, 유실 가능성과 지연 증가

AsyncAppender

• 큐 포화 시 선택: 큐가 가득 차면 neverBlock=false는 호출 스레드를 블로킹해 비동기 효과를 잃고, true는 이벤트를 버림
• 큐 사이즈에 따른 로그 폐기: 큐 여유가 그 아래로 떨어지면 TRACE·DEBUG·INFO가 버려짐(WARN·ERROR만 보존)
• 종료 시 유실: 셧다운 시 워커가 큐를 비우려 하지만 maxFlushTime(기본 1초)을 넘기면 남은 이벤트가 버려짐
• 큐와 워커 스레드의 메모리·관리 오버헤드: 큐 크기와 워커 수가 많아질수록 메모리 사용량과 관리 복잡도가 증가

정리

System.out.println()이 비싼 이유는 한 줄을 출력할 때마다 세 가지 비용이 동시에 발생하기 때문이다.

• autoFlush=true: write 시스템 콜로 인한 Mode Switch
• synchronized(this): 단일 System.out 인스턴스 락으로 출력이 직렬화
• 블로킹 IO: 락을 쥔 스레드가 대기하는 동안 다른 스레드까지 함께 지연

로깅 프레임워크는 어펜더별 락·레벨·롤링을 얻고, 그 위에서 튜닝할 수 있다는 데 의미가 있다.

• 버퍼링(immediateFlush=false): 줄마다 flush를 없애 시스템 콜 감소로 인한 처리량 증가
• 비동기(AsyncAppender): 출력 IO·락·CPU를 비용 높은 작업으로부터 요청 스레드를 분리하여, 출력 비용이 큰 경우에도 응답 시간 개선

출력 방식별로 정리하면 다음과 같다.

방식	동작	적합한 곳
System.out.println	autoFlush로 줄마다 syscall + 전역 락	로컬 디버깅
FileAppender(immediateFlush=true)	매 이벤트 flush — System.out과 동급	기본값 · 일반 로그량(크래시에도 유실 없음)
FileAppender(immediateFlush=false)	버퍼 찰 때만 flush → syscall 급감, 처리량 수 배	대량 로깅 — 처리량 위해 크래시 유실 감수
+ AsyncAppender	출력 IO·락·CPU를 워커 스레드로 분리	무거운 출력 비용·느린 디스크/네트워크·대량 로깅

결국 출력 방식의 선택은 raw 처리량 수치가 아니라, 어떤 IO 환경에서 무엇을 보장해야 하는지를 기준으로 판단해야 한다.

Tags:

• Java

`null`은 오버 로딩된 메서드 중 어떤 메서드를 호출할까?

2023. 9. 22. - Last update: 2024. 3. 10.

hyoguoo

Backend Engineer

실행 환경: Java 17

우선 해당 주제를 본격적으로 다루기 전에 아래의 코드를 보자. 아래 코드는 null을 참조하는 변수를 사용했을 때와, 리터럴 null을 사용했을 때 String.valueOf() 메서드의 동작을 보여준다.

class NullTest {

    public static void main(String[] args) {
        String s = null;
        String nullValue = String.valueOf(s);
        System.out.println(nullValue); // null, 정상 출력 ---- 1

        nullValue = String.valueOf(null); // NullPointerException ---- 2
        System.out.println(nullValue);
    }
}

1번 코드는 정상적으로 null을 출력하지만, 2번 코드는 NullPointerException이 발생하는 것을 확인할 수 있다. 디버깅 모드를 통해 호출 된 메서드를 추적했을 때, 두 라인은 서로 다른 메서드를 호출하고 있음을 알 수 있었다.

1. String.valueOf(s)

java.lang.String

public final class String {

    public static String valueOf(Object obj) {
        return (obj == null) ? "null" : obj.toString();
    }
}

String.valueOf(s)는 String.valueOf(Object obj)를 호출하는데, 이 메서드는 null 체크를 하는 것을 확인할 수 있다. 때문에 넘겨 받은 obj 값이 null이기 때문에 자연스럽게 "null"을 반환하게 된다.

2. String.valueOf(null)

하지만 직접 null을 넘겨 받은 경우에는 String.valueOf(char data[])를 호출하게 된다.

java.lang.String

public final class String {

    public String(char value[]) {
        this(value, 0, value.length, null); // 3. value.length에서 NullPointerException 발생
        // Exception in thread "main" java.lang.NullPointerException: Cannot read the array length because "value" is null
    }

    // 1. 메서드 호출 받음
    public static String valueOf(char data[]) {
        return new String(data); // 2. 위의 String(char value[])를 호출
    }
}

주석의 순번대로 코드가 실행되는데, 결국 3번에서 null인 값에서 length를 읽으려고 하기 때문에 NullPointerException이 발생하게 된다. 그렇다면 왜 null이 char data[] 타입이 아닌데 해당 메서드가 호출되는 것일까?

호출 메서드는 어떻게 결정되는가?

위 상황과 비슷하게 char data[] 타입과 Object o 타입을 파라미터로 갖는 메서드를 호출했을 때 어떤 메서드가 호출되는지 확인해보자.

class MethodCallTest {

    public static void main(String[] args) {
        testMethod(null); // char[] Param Method Called
    }

    public static void testMethod(char data[]) {
        System.out.println("char[] Param Method Called");
    }

    public static void testMethod(Object o) {
        System.out.println("Object Param Method Called");
    }
}

처음의 예제 코드와 같이 char[] Param Method Called가 출력된다. 그럼 null은 char[]과 특수한 관계가 있는 것일까? 그것도 아니다.

class MethodCallTest {

    public static void main(String[] args) {
        testMethod(null); // Object Param Method Called
    }

//    public static void testMethod(char data[]) {
//        System.out.println("char[] Param Method Called");
//    }

    public static void testMethod(Object o) {
        System.out.println("Object Param Method Called");
    }
}

char data[] 타입의 메서드를 주석 처리하고 실행해보면 Object Param Method Called가 출력된다. 즉, null은 char[]과 특수한 관계가 있는 것이 아니라, Object 보다는 char[] 타입이 더 높은 우선순위를 가진다고 추측해 볼 수 있다. 다른 타입들도 더 살펴보자.

class MethodCallTest {

    public static void main(String[] args) {
        testMethod(null); // no suitable method found for testMethod(<nulltype>)
    }

    public static void testMethod(int i) {
        System.out.println("int Param Method Called");
    }

    public static void testMethod(long i) {
        System.out.println("Integer Param Method Called");
    }

    // ...
    // char, byte, short, int, long, float, double, boolean
}

당연하게도 원시 타입은 null을 가질 수 없기 때문에 일치하는 메서드가 없다는 에러가 발생한다. 그럼 null이 호출할 수 있는 메서드는 참조(주소) 타입 인자의 메서드만 호출할 수 있는 것으로 추측할 수 있다.

class Test {

    int x;
    int y;
}

class MethodCallTest {

    public static void main(String[] args) {
        testMethod(null); // reference to testMethod is ambiguous
    }

    public static void testMethod(Object o) {
        System.out.println("Object Param Method Called");
    }

    public static void testMethod(char data[]) {
        System.out.println("char[] Param Method Called");
    }

    public static void testMethod(Test t) {
        System.out.println("Test Param Method Called");
    }

    public static void testMethod(String s) {
        System.out.println("String Param Method Called");
    }

    public static void testMethod(int... i) {
        System.out.println("int... Param Method Called");
    }

    public static void testMethod(Integer i) {
        System.out.println("Integer Param Method Called");
    }
}

위의 메서드들은 단일로 존재했을 때 전부 호출 될 수 있는 메서드들인데, 동시에 존재하는 경우 호출할 수 있는 메서드가 많아 모호하다는 에러 메시지가 발생한다.

reference to testMethod is ambiguous
  both method testMethod(int...) in MethodCallTest and method testMethod(java.lang.Integer) in MethodCallTest match

그 중 int ...i 타입과 Integer i 두 개의 메서드에 대해 언급하면서 에러 메시지가 발생했는데, 두 타입이 더 null과 관련이 있는 것일까? 아니다, 그 이유는 다시 아래의 코드와 에러 메시지를 보면 알 수 있다.

class Test {

    int x;
    int y;
}

class MethodCallTest {

    public static void main(String[] args) {
        testMethod(null); // reference to testMethod is ambiguous
    }

    public static void testMethod(Object o) {
        System.out.println("Object Param Method Called");
    }

    public static void testMethod(int... i) {
        System.out.println("int... Param Method Called");
    }

    public static void testMethod(Integer i) {
        System.out.println("Integer Param Method Called");
    }

    public static void testMethod(char data[]) {
        System.out.println("char[] Param Method Called");
    }

    public static void testMethod(Test t) {
        System.out.println("Test Param Method Called");
    }

    public static void testMethod(String s) {
        System.out.println("String Param Method Called");
    }
}

reference to testMethod is ambiguous
  both method testMethod(Test) in MethodCallTest and method testMethod(java.lang.String) in MethodCallTest match

에러 메시지를 다시 살펴 보면 Test 타입과 String 타입이 언급되는 것을 볼 수 있다. 결국 특정 타입이 아닌, 완전히 일치하는 타입이 없어 null을 호출 할 수 있는 메서드를 탐색하게되고, 마지막 두 타입에 대해 모호하다는 에러 메시지가 발생한 것으로 추측해 볼 수 있다.

결론

1. null은 원시 타입을 제외한 모든 타입의 인자로 호출 당할 수 있다.
2. null은 Object 타입으로도 호출 당할 수 있다.
3. Object가 아닌 참조 타입 메서드가 존재하면 더 높은 우선순위를 가진다.
4. 만약 Object 타입을 제외한 참조 타입 메서드가 두 개 이상 존재하면 refrence to method is ambiguous 에러가 발생하게 된다.
5. 에러 메시지는 null을 호출 할 수 있는 메서드를 탐색하다가 마지막 두 가지 타입에 대해 모호하다는 에러 메시지가 발생한 것으로 추측해 볼 수 있다.

다소 애매한 결과라고 볼 수 있지만, 사실 null 타입을 그대로 넣는 일은 거의 없기 때문에 이러한 상황은 잘 발생하지 않을 것이라고 생각한다. 다시 한 번 null을 사용할 때는 주의 해야 한다는 것을 체감할 수 있었고, null 자체를 파라미터로 넘기는 것을 지양하는 것이 좋을 것 같다.

Tags:

• Java