Post

EC2 인스턴스에 따른 웜업코드 주의점

EC2 인스턴스에 따른 웜업코드 주의점

서론

Spring Boot 애플리케이션을 EC2 t2.large에서 Blue-Green 방식으로 운영하고 있었다. 그런데 피크 타임에 메모리 사용률이 80-90%까지 치솟아서 스케일업을 결정했다.

문제는 여기서 시작되었다. 아무 문제 없이 잘 돌아가던 서버가 t2.xlarge로 바꾼 후 갑자기 DB 연결이 안 되기 시작했다. 처음에는 인스턴스 유형에 따른 드라이버 호환성 문제라고 생각했다. 근데 아니었다.

원인을 파고들다 보니 Java와 Spring의 초기 로딩 과정을 제대로 이해해야 했다. 결론부터 말하자면 스케일업으로 CPU가 증가하면서 생긴 DataSource 초기화 타이밍 문제였다.


본론

1. EC2 인스턴스 비교 및 vCPU 이해

먼저 상황을 정리하면 이랬다.

1
2
3
4
5
6
7
확인된 사실:

Large + 웜업 코드 있음:     정상 작동
XLarge + 웜업 코드 있음:    실패 (No suitable driver)
XLarge + 웜업 코드 제거:    정상 작동

결론: 웜업 코드가 XLarge에서만 문제를 일으킴

t2.large에서 t2.xlarge로 바꿨는데, 가장 눈에 띄는 차이는 vCPU다. 2개에서 4개로 늘었다. 이 부분을 기억해두면 나중에 이해가 쉬울 거다.

vCPU란 무엇인가

간단히 말하면 EC2는 하나의 물리 서버를 하이퍼바이저로 여러 가상 인스턴스로 쪼갠다. 여러 인스턴스가 하나의 물리 서버 CPU를 나눠 쓰는데, 이때 각 인스턴스에 할당되는 가상 CPU 단위가 vCPU다.

특히 T 시리즈는 CPU 크레딧 방식을 쓴다. 평소에는 낮은 베이스라인 성능으로 크레딧을 모으고, 필요할 때 모아둔 크레딧을 써서 vCPU를 최대로 돌릴 수 있다.

2. Java와 Spring Boot 애플리케이션 시작 과정

문제를 이해하려면 JVM과 Spring Boot가 어떻게 시작되는지 알아야 한다.

2.1 JVM 아키텍처

JVM은 크게 세 가지 주요 구성 요소로 이루어져 있다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
JVM Architecture
├─ Class Loader Subsystem
│  ├─ Bootstrap Loader
│  ├─ Extension Loader
│  └─ Application Loader
│
├─ Runtime Data Areas
│  ├─ Method Area (Metaspace)
│  ├─ Heap
│  └─ Stack
│
└─ Execution Engine
   ├─ Interpreter
   ├─ JIT Compiler
   └─ Garbage Collector

2.2 클래스 로딩의 3단계

클래스 로더는 다음 세 단계를 거쳐 클래스를 메모리에 올립니다.

첫 번째 단계: Loading (로딩)

ClassLoader가 .class 파일을 찾아서 바이너리 데이터를 읽고, Method Area에 클래스 정보를 저장합니다. 이때 Bootstrap ClassLoader는 java., javax. 같은 기본 클래스를, Extension ClassLoader는 jre/lib/ext의 확장 클래스를, Application ClassLoader는 우리 애플리케이션의 클래스를 로딩합니다.

두 번째 단계: Linking (링킹)

링킹은 다시 세 개의 하위 단계로 나뉩니다.

먼저 Verification에서는 .class 파일이 올바른 형식인지 검증합니다. Magic Number가 CAFEBABE인지, final 클래스를 상속하지 않았는지 등을 확인합니다.

다음 Preparation에서는 static 변수를 위한 메모리를 할당하고 기본값으로 초기화합니다. 예를 들어 int는 0으로, String은 null로 초기화됩니다. 주의할 점은 실제 값 할당은 다음 단계인 Initialization에서 이루어진다는 것입니다.

마지막으로 Resolution에서는 Symbolic Reference를 Direct Reference로 변환합니다. 문자열 형태의 클래스 이름을 실제 메모리 주소로 바꾸는 과정입니다.

세 번째 단계: Initialization (초기화)

이 단계가 바로 핵심입니다. 부모 클래스부터 재귀적으로 초기화하고, static 초기화 블록을 실행하며, static 변수에 실제 값을 할당합니다.

2.3 Static Initializer의 중요성

JDBC 드라이버의 경우 static 블록에서 DriverManager에 자신을 등록합니다. 예를 들어 DriverSpy 클래스는 다음과 같이 구현되어 있습니다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
public class DriverSpy implements Driver {
    private static final String VERSION = "1.0";

    static {
        System.out.println("DriverSpy 클래스 초기화!");
        try {
            DriverManager.registerDriver(new DriverSpy());
        } catch (SQLException e) {
            throw new RuntimeException(e);
        }
    }

    private Connection connection;

    public DriverSpy() {
        System.out.println("DriverSpy 인스턴스 생성!");
    }
}

일반적으로 Class.forName() 메서드를 명시적으로 호출하면 해당 클래스가 로딩되고 static 블록이 실행됩니다. 하지만 우리 경우에는 log4jdbc 라이브러리가 백그라운드에서 비동기적으로 이 작업을 처리하고 있었습니다.

여기서 문제가 발생합니다. Spring이 JAR 파일을 스캔하고 log4jdbc.log4j2.properties 파일을 읽어서 PropertyConfigurator가 내부적으로 Class.forName()을 호출하는데, 이 작업이 “언제” 완료될지 보장되지 않습니다.

Large CPU에서는 전체적으로 처리가 느려서 웜업 코드가 실행될 때쯤이면 드라이버 로딩이 완료되어 있었습니다. 하지만 XLarge CPU에서는 Bean 생성이 너무 빨라서 웜업 코드가 드라이버 로딩보다 먼저 실행되는 Race Condition이 발생했습니다.

2.4 Spring Boot 애플리케이션 시작 순서

Spring Boot 애플리케이션은 다음과 같은 순서로 시작됩니다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
1. JVM 시작
   - java.* 클래스 로딩 (String, Object 등)
   - JVM 초기화

2. Spring Boot Launcher 실행
   - JarLauncher.main() 호출
   - Nested JAR 설정

3. SpringApplication.run() 호출
   - @SpringBootApplication 클래스 찾기

4. Environment 준비
   - application.properties 읽기
   - 프로파일 설정

5. ApplicationContext 생성 및 준비
   - Bean 정의 로딩
   - ComponentScan 실행

6. Bean 생성 및 초기화
   - 의존성 주입
   - @PostConstruct 실행

7. ApplicationReadyEvent 발행
   - @EventListener 실행

8. 애플리케이션 실행 중

2.5 상세 타임라인

애플리케이션이 시작될 때 무슨 일이 벌어지는지 시간 순서대로 정리해봤다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
[0.0초] JVM 시작
├─ java -jar myapp.jar 실행
├─ Bootstrap ClassLoader 초기화
└─ 기본 클래스 로딩 (Object, String, System 등)

[0.5초] JarLauncher 시작
├─ Spring Boot의 Nested JAR 구조 처리
│  ├─ BOOT-INF/classes (우리 코드)
│  └─ BOOT-INF/lib (의존성 jar들)
├─ ClassPath 설정
└─ Main 클래스 탐색 및 실행

[1.0초] SpringApplication 초기화
├─ SpringApplication 인스턴스 생성
├─ ApplicationContext 타입 결정
└─ Initializer와 Listener 로딩

[2.0초] Environment 준비
├─ application.properties 읽기
├─ application-database-prod.properties 읽기
│  └─ DriverSpy 설정 포함 (하지만 아직 적용 전)
└─ 프로파일 설정 완료

[3.0초] ApplicationContext 생성
├─ Spring Container 초기화
├─ BeanFactory 준비
├─ BeanDefinition Registry 준비
└─ 이벤트 발행자 초기화

[4.0초] ComponentScan 시작
├─ 패키지 스캔 (@Component, @Service 등)
├─ BeanDefinition 생성
└─ Registry에 등록

[5.0초] Auto-Configuration 처리
├─ DataSourceAutoConfiguration 실행
├─ DataSource Bean 생성
└─ 주의: Connection Pool은 아직 생성 안됨 (Lazy)
   └─ getConnection() 첫 호출 시 생성됨

여기서 주목할 점은 5초 시점이다. DataSource Bean은 만들어지지만, 실제 DB와 연결되는 Connection Pool은 나중에 필요할 때 생성된다. 이게 바로 Lazy Initialization 전략이다.

2.6 ApplicationContext 생성 과정

ComponentScan이 시작되면 패키지 내의 모든 클래스를 뒤진다. 예를 들어 UserService 클래스를 찾으면 BeanDefinition으로 변환하는데, 여기에 Bean 이름, 클래스 타입, scope, 의존성 같은 메타 정보가 다 들어간다.

Auto-Configuration은 조건부로 동작한다. @ConditionalOnClass나 @ConditionalOnMissingBean 같은 조건을 확인해서 필요한 Bean만 골라서 생성한다. DataSourceAutoConfiguration을 예로 들어보자.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
@Configuration
@ConditionalOnClass({ DataSource.class, EmbeddedDatabaseType.class })
public class DataSourceAutoConfiguration {

    @Bean
    @ConditionalOnMissingBean
    public DataSource dataSource(DataSourceProperties properties) {
        return DataSourceBuilder
            .create()
            .url(properties.getUrl())
            .driverClassName(properties.getDriverClassName())
            .username(properties.getUsername())
            .password(properties.getPassword())
            .build();
    }
}

여기서 주의할 점은 DataSource Bean은 생성되지만, 실제 Connection Pool은 아직 생성되지 않는다는 거다.

3. Bean 생성 및 의존성 주입

3.1 Bean 생명주기

Bean의 생명주기는 다음 단계를 거친다.

먼저 Instantiation에서 생성자가 호출된다. 그 다음 Populate Properties에서 @Autowired로 의존성이 주입된다. 이후 BeanNameAware, BeanFactoryAware 같은 Aware 인터페이스 메서드가 호출되고, @PostConstruct가 붙은 초기화 메서드가 실행된다. InitializingBean.afterPropertiesSet()과 Custom init-method도 이때 실행된다.

이제 Bean을 쓸 수 있다. 애플리케이션 종료 시에는 @PreDestroy, DisposableBean.destroy(), Custom destroy-method가 순서대로 실행된다.

3.2 @PostConstruct vs @EventListener

이 두 가지의 차이를 제대로 이해해야 한다.

@PostConstruct는 해당 Bean이 생성된 직후에 바로 실행된다. 의존성 주입이 끝나자마자 호출되기 때문에 다른 Bean들은 아직 생성 중일 수 있다.

@EventListener(ApplicationReadyEvent.class)는 모든 Bean 생성이 완료되고 ApplicationContext refresh가 끝난 후, 애플리케이션이 완전히 준비된 상태에서 실행된다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
@Component
public class MyBean {

    @PostConstruct
    public void init() {
        // 이 Bean 생성 직후 실행
        // 다른 Bean들은 아직 생성 중일 수 있음
    }

    @EventListener(ApplicationReadyEvent.class)
    public void ready() {
        // 모든 Bean 생성 완료 후 실행
        // 애플리케이션 사용 가능 상태
    }
}

실행 순서는 간단하다. init() → 나머지 Bean들 생성 → ready() 순서다.

4. 문제의 핵심: ApplicationReadyEvent 타이밍

4.1 Large vs XLarge 상세 타임라인 비교

실제로 두 인스턴스에서 어떤 차이가 있었는지 타임라인으로 비교해보자.

시나리오 1: Large 인스턴스 (느린 CPU) + 웜업 코드

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
[0초]   애플리케이션 시작
[10초]  Auto-Configuration
        └─ log4jdbc.properties 읽기 시작 (백그라운드)
[15초]  Bean 생성 (DataSource, JdbcTemplate 등)
[20초]  (백그라운드) DriverSpy 클래스 로딩 시작
[28초]  InfraWarmupComponent Bean 생성
[30초]  (백그라운드) DriverSpy static 블록 실행
        └─ DriverManager.registerDriver(new DriverSpy()) 완료
[30초]  ApplicationReadyEvent 발행
[32초]  warmUpInfrastructure() 실행
        └─ dataSource.getConnection() 호출
        └─ DriverManager.getDriver() 호출
        └─ DriverSpy 찾음! (이미 등록되어 있음)
[35초]  "Database 웜업 완료 - 연결 성공"

결과: 정상 동작

시나리오 2: XLarge 인스턴스 (빠른 CPU, 약 4배) + 웜업 코드

1
2
3
4
5
6
7
8
9
10
11
12
13
14
[0초]    애플리케이션 시작
[2초]    Auto-Configuration
         └─ log4jdbc.properties 읽기 시작 (백그라운드, 여전히 느림)
[4초]    Bean 생성 (병렬 처리로 빠름)
[6초]    InfraWarmupComponent Bean 생성
[8초]    ApplicationReadyEvent 발행 (너무 빠름!)
[8.1초]  warmUpInfrastructure() 즉시 실행
         └─ dataSource.getConnection() 호출
         └─ DriverManager.getDriver() 호출
         └─ DriverSpy를 못 찾음! (아직 등록 안됨)
         └─ SQLException: No suitable driver
[10초]   (백그라운드) DriverSpy 등록 완료 (하지만 이미 늦음)

결과: 실패

시나리오 3: XLarge 인스턴스 + 웜업 제거

1
2
3
4
5
6
7
8
9
10
11
[0~8초]  동일하게 진행
[8초]    ApplicationReadyEvent 발행
         └─ 웜업 없음, 아무것도 실행 안함
[10초]   (백그라운드) DriverSpy 등록 완료
[15초]   첫 HTTP 요청 도착
         └─ dataSource.getConnection() 호출
         └─ DriverManager.getDriver() 호출
         └─ DriverSpy 찾음! (이미 등록되어 있음)
         └─ Connection 생성 성공

결과: 정상 동작

핵심은 이거다. XLarge에서는 Bean 생성이 너무 빨라서 웜업 코드가 드라이버 로딩보다 먼저 실행된다. 웜업을 제거하면 첫 요청까지 시간 버퍼가 생겨서 그동안 드라이버 로딩이 완료된다.

5. 문제 분석 및 해결

5.1 문제의 정확한 원인

핵심 원인은 비동기 클래스 로딩(Asynchronous Class Loading)이다.

log4jdbc.log4j2.properties 파일 처리는 백그라운드 스레드에서 비동기로 돌아간다. 언제 끝날지 보장이 안 된다. CPU 성능에 따라 완료 시점이 천차만별이다.

ApplicationReadyEvent는 “모든 Bean 생성 완료”를 의미하지, “모든 비동기 초기화 완료”를 의미하지 않는다. CPU가 빠르면 더 빨리 발생한다.

결과적으로 Race Condition이 생긴다. 웜업 코드와 드라이버 로딩이 경주하는 셈이다. Large에서는 전체가 느려서 드라이버가 먼저 골인했지만, XLarge에서는 웜업이 너무 빨라서 드라이버보다 먼저 달려나갔다.

5.2 왜 웜업 제거가 해결책인가?

웜업을 없애니까 다음 효과가 생긴다.

첫째, ApplicationReadyEvent에서 아무것도 안 하니까 드라이버 로딩과 경쟁할 일이 없다.

둘째, 첫 요청까지 시간 버퍼가 생긴다. 보통 애플리케이션 시작 후 5-10초 뒤에 첫 요청이 들어오는데, 그 사이에 드라이버 로딩이 끝난다.

셋째, Lazy Initialization의 원래 의도대로 동작한다. “필요할 때” 초기화하는 건데, 정작 필요할 때는 이미 모든 게 준비되어 있다.

타이밍을 비교해보면 명확하다.

웜업 있음:

  • 8.0초: ApplicationReadyEvent
  • 8.1초: 웜업 실행 → DB 연결 시도 → 실패 (드라이버 없음)
  • 10초: 드라이버 로딩 완료 (늦음)

웜업 없음:

  • 8.0초: ApplicationReadyEvent (아무것도 안함)
  • 10초: 드라이버 로딩 완료
  • 15초: 첫 요청 → DB 연결 시도 → 성공 (드라이버 있음)

5.3 다른 해결책들이 안 된 이유

문제를 해결하려고 여러 시도를 해봤지만 다 실패했다.

시도 1: -Dlog4jdbc.drivers 옵션

JVM 옵션에 -Djdbc.drivers=net.sf.log4jdbc.sql.jdbcapi.DriverSpy를 추가하면 시작할 때 드라이버를 로드할 수 있을 거라고 생각했다. 하지만 Spring Boot의 Nested JAR 구조에서는 안 먹힌다.

왜냐하면 DriverManager는 System ClassLoader를 쓰고, DriverSpy는 Spring Boot ClassLoader를 쓴다. ClassLoader가 분리되어 있어서 서로 못 찾는다. 일반 JAR에서는 되는데 Spring Boot에서는 안 되는 이유다.

시도 2: LD_LIBRARY_PATH 설정

export LD_LIBRARY_PATH=/usr/lib/jvm/.../lib 이런 식으로 환경 변수를 설정해봤다. Native Library 경로 문제인가 싶어서였다.

근데 이건 완전히 방향이 틀렸다. LD_LIBRARY_PATH는 .so 파일 같은 Native Library용이고, JDBC 드라이버는 순수 Java로 만든 .jar 파일이다. 전혀 관련이 없는 설정이었다.

시도 3: log4jdbc.auto.load.popular.drivers=true

log4jdbc 설정 파일에 자동 로딩 옵션을 켜면 될 거라고 생각했다. 근데 확인해보니 이미 true로 설정되어 있었다.

설정이 문제가 아니었다. “무엇을” 로드할지는 맞는데, “언제” 로드되는지가 문제였다. 비동기 처리 타이밍 이슈는 설정만으로 해결이 안 된다.

6. 결론

6.1 전체 흐름 요약

정리하자면 이렇다.

Spring Boot가 시작되면서 JVM과 ClassLoader가 초기화된다. 1-3초 사이 Spring Container가 만들어지고, 3-5초에 ComponentScan이 돌아간다. 5-8초에 Bean들이 생성되는데 DataSource, JdbcTemplate, InfraWarmupComponent 같은 Bean들이 이때 만들어진다. 8초에 ApplicationReadyEvent가 발행된다.

동시에 백그라운드에서는 log4jdbc.properties 파일을 처리하고 DriverSpy 클래스를 로딩한다. Static Block이 실행되면서 DriverManager에 등록하는 작업도 진행된다.

문제는 웜업 코드가 드라이버 등록보다 먼저 실행된다는 거였다. 해결책은 간단했다. 웜업을 없애서 시간 버퍼를 확보하는 것.

6.2 정리

이번 트러블슈팅에서 배운 것들을 정리해봤다.

ApplicationReadyEvent는 “모든 준비 완료”가 아니다

ApplicationReadyEvent는 모든 Bean이 생성되고 의존성 주입이 끝난 상태다. ApplicationContext를 쓸 수 있다. 하지만 비동기 초기화는 여전히 진행 중일 수 있고, 백그라운드 작업은 안 끝났을 수도 있다. 외부 라이브러리 초기화는 전혀 보장 안 된다.

Static Initializer는 “처음 사용” 시점에 실행된다

Static Block은 클래스를 처음 쓸 때 실행된다. Class.forName() 명시적 호출, 인스턴스 생성, Static 멤버 접근할 때 말이다. JAR 파일 스캔만으로는 안 되고, 설정 파일 읽는다고 되는 것도 아니다. Bean 생성만으로도 안 될 수 있다.

Lazy Initialization은 양날의 검이다

빠른 시작, 필요한 것만 초기화, 메모리 절약은 좋다. 하지만 첫 사용 시 느리고, 초기화 실패가 런타임에 터지며, 타이밍 예측이 안 된다는 게 문제다.

웜업 코드의 역설

웜업 코드는 빠른 첫 응답, Cold Start 방지, 사전 초기화를 위한 거다. 근데 실제로는 너무 일찍 초기화를 시도해서 Race Condition을 만든다. CPU 성능에 따라 동작이 완전히 달라진다.

성능 향상이 오히려 버그를 드러낸다

Large CPU에서는 느려서 우연히 타이밍이 맞아 떨어졌다. 버그가 숨어있었던 거다. XLarge CPU에서는 빨라서 타이밍 윈도우가 좁아지면서 Race Condition이 확실하게 드러났다. 어쩌면 이게 더 나았다. 문제를 발견할 수 있었으니까.

This post is licensed under CC BY 4.0 by the author.