9osari.log
← All posts

[JPA] LAZY 컬렉션 전체 로딩과 동시 실행이 만든 OOM

운영 서버의 API가 하나씩 느려지더니 결국 대부분의 요청이 타임아웃으로 끝나는 일이 발생했다! 출근준비를 하는데, 센트리 알림이 수십개 와있었다..

처음에는 특정 API의 쿼리가 느린 문제라고 생각했다. 그런데 시간이 지나자 해당 기능과 관계없는 API까지 응답하지 않았다. 애플리케이션을 재시작하고 나서야 서버가 다시 요청을 처리했다.

더 난감했던 건 당시 내가 맡은 프로젝트에 OOM 이후의 자가 복구가 제대로 연결되어 있지 않았다는 점이다 ㅠㅠ. 프로세스가 사실상 멈춰도 스스로 재시작하지 않아 사람이 직접 애플리케이션을 다시 띄워야 했다.

일단 서버는 살렸지만 왜 케이스 몇 건이 바뀐 것만으로 애플리케이션 전체가 멈췄는지는 알 수 없었다. 더 헷갈렸던 건 나중에 발견한 문제의 연관관계에 이미 fetch = LAZY가 붙어 있었다는 점이다.

소거법으로 원인 좁히기

API 타임아웃만 놓고 보면 느린 쿼리, 외부 API 지연, 커넥션 풀 고갈, 스레드 고갈처럼 의심할 수 있는 게 많았다. 바로 코드를 고치기보다 관찰한 현상과 맞지 않는 후보부터 하나씩 지웠다.

특정 API만의 문제는 아니었다

가장 먼저 장애가 시작된 API와 최근에 바뀐 코드를 살펴봤다. 하지만 특정 쿼리 하나가 느린 문제라면 그 쿼리를 사용하는 요청이 주로 영향을 받아야 한다.

이번에는 애플리케이션 전체가 같이 느려졌다. 원인을 개별 API보다 모든 요청이 공유하는 자원으로 좁혔다.

특정 API만 느림
    → 해당 API의 쿼리나 외부 연동 의심

대부분의 API가 같이 느림
    → 메모리, CPU, 스레드, 커넥션 같은 공통 자원 의심

외부 상태 변경을 받아 처리하는 기능이라 연동 대상의 응답 지연도 의심했다. 하지만 애플리케이션을 재시작하면 다시 요청을 처리했고, 장애 시점에는 힙 사용량이 계속 올라가며 GC가 반복되고 있었다.

“혹시 상대 서버가 느린 건가?”라는 기대도 여기서 버렸다. 서버 프로세스 안에서 많은 객체가 만들어지거나, 생성된 객체가 오랫동안 회수되지 않는 경로를 찾아야 했다.

두 장애 직전의 공통점

평소에는 같은 기능을 사용해도 문제가 없었다. 한 번의 요청만으로 항상 터지는 코드라면 진작 문제가 됐어야 했다.

장애 직전 기록을 비교해보니 짧은 시간에 여러 케이스의 상태 변경이 몰렸다는 공통점이 있었다. 상태가 바뀔 때마다 조회용 데이터 동기화가 비동기로 실행되고 있었다.

그래서 두 가지를 중심으로 동기화 흐름을 따라갔다.

  1. 동기화 한 건이 메모리에 올리는 데이터의 범위
  2. 같은 동기화가 동시에 몇 건까지 실행되는지

여기서 케이스 하나를 처리하는 메서드가 TrackerdataRows 컬렉션을 순회하는 코드를 발견했다.

메서드의 입력은 caseId 하나였다. 하지만 Tracker는 회사 단위로 하나씩 존재했고, dataRows에는 그 회사의 조회용 행 전체가 연결되어 있었다.

입력                     실제 접근 범위
caseId 한 건      →      tracker.dataRows 전체

여기까지 좁히고 나니 범인이 거의 보였다. 이제 확인할 것은 하나였다.

fetch = LAZY인 컬렉션에서 stream()을 호출하면 실제로 어디까지 조회할까?

조회용 데이터를 평탄화하는 기능

원본 데이터는 여러 테이블과 계층으로 나뉘어 있었다. 조회할 때마다 이를 조합하면 비용이 크기 때문에, 화면에 필요한 값만 행 형태로 평탄화해 별도 테이블에 저장했다.

쉽게 말해 케이스가 바뀌면 조회용 테이블에서 그 케이스에 해당하는 부분만 다시 만드는 기능이다.

기존에는 삭제, 수정, 추가를 계산하는 로직이 Tracker 엔티티 안에 있었다.

@OneToMany(
    mappedBy = "tracker",
    fetch = FetchType.LAZY,
    cascade = CascadeType.ALL,
    orphanRemoval = true
)
private List<DataRow> dataRows = new ArrayList<>();

public void setDataRows(Long caseId, List<EventRawData> rawDataList) {
    List<DataRow> currentRows = dataRows.stream()
            .filter(row -> row.getCaseId().equals(caseId))
            .collect(Collectors.toList());

    // currentRows와 rawDataList를 비교해 삭제, 수정, 추가
}

코드만 보면 caseId로 필터링하니 해당 케이스의 행만 가져오는 것처럼 보인다. 나도 처음에는 그렇게 읽었다.

하지만 필터링이 실행되는 위치는 데이터베이스가 아니라 Java 애플리케이션이다. dataRows.stream()을 호출하는 순간 Hibernate는 지연 로딩 컬렉션을 초기화한다.

이때 실행되는 조회의 기준은 caseId가 아니라 연관관계의 주인인 tracker_id다.

select *
from data_row
where tracker_id = ?;

회사 전체 행을 DataRow 엔티티로 만든 뒤에야 Java의 filter()caseId에 해당하는 행을 고르고 있었다.

내가 원한 흐름은 이것이었다.

DB에서 특정 caseId의 행만 조회
    → 애플리케이션에서 diff 계산

실제 흐름은 반대였다.

회사 전체 행 조회
    → 전부 DataRow 엔티티로 생성
    → 영속성 컨텍스트에서 관리
    → 그중 특정 caseId만 Java로 필터링

결국 “필요한 부분만 업데이트한다”는 기능이 필요한 부분을 찾기 위해 회사 전체 행부터 읽고 있었다.

LAZY는 조회 범위를 줄여주지 않는다

코드를 처음 봤을 때는 LAZY를 확인하고 오히려 안심했다.

적어도 이 컬렉션을 처음부터 전부 가져오지는 않겠네.

이 생각은 반만 맞았다. FetchType.LAZY는 연관 데이터를 부모와 동시에 조회하지 않도록 시점을 늦추는 설정이다.

Tracker tracker = trackerRepository.findById(id).orElseThrow();

여기까지만 실행하면 dataRows를 조회하지 않는다. 하지만 트랜잭션 안에서 컬렉션에 처음 접근하면 Hibernate가 연관된 행을 가져온다.

tracker.getDataRows().stream();

LAZY가 보장하는 것은 조회 시점까지다.

반대로 다음은 보장하지 않는다.

LAZY조회 시점에 대한 설정이지 조회 범위에 대한 설정이 아니었다.

트랜잭션 밖에서 접근했다면 LazyInitializationException이 발생했을 수도 있다. 이번에는 트랜잭션이 열려 있었기 때문에 예외 없이 전체 컬렉션을 조회했다. 정상적으로 동작하는 것처럼 보인다는 점이 오히려 문제를 늦게 발견하게 만들었다.

동시 실행이 OOM으로 키웠다

전체 컬렉션을 한 번 로딩한다고 바로 OOM이 발생한 것은 아니었다. 평소에는 느리더라도 작업이 끝났다.

문제는 여러 케이스의 상태가 한꺼번에 바뀌면서 동기화 작업이 동시에 실행될 때 발생했다.

작업 1 ─┐
작업 2 ─┤
작업 3 ─┼─ 각각 회사 전체 DataRow 컬렉션 로딩
   ...  │
작업 N ─┘

같은 데이터를 여러 영속성 컨텍스트가 각각 보관

힙 사용량 급증 → GC 반복 → 전체 API 응답 지연

각 작업은 별도 트랜잭션에서 실행됐다. 조회된 엔티티는 영속성 컨텍스트가 참조하므로 작업이 끝나기 전까지 GC 대상이 되기 어렵다.

한 작업이 M개의 행을 불러오고 동시에 N개의 작업이 실행된다면, 메모리에는 순간적으로 N × M에 가까운 엔티티가 만들어질 수 있다. 여기에 Hibernate의 관리 정보와 컬렉션 상태도 함께 쌓인다.

결국 세 조건이 겹쳤다.

  1. 시간이 지날수록 커지는 @OneToMany 컬렉션
  2. 특정 케이스만 필요하지만 전체 컬렉션을 초기화하는 코드
  3. 같은 작업의 동시 실행

단건 처리에서는 숨어 있던 비효율이 동시 실행을 만나 OOM으로 커진 것이다.

필요한 행만 직접 조회

해결 방법은 전체 컬렉션에 접근하지 않고 처음부터 trackerIdcaseId에 해당하는 행만 조회하는 것이었다.

변경 전에는 전체 컬렉션을 초기화한 뒤 Java에서 필터링했다.

List<DataRow> currentRows = tracker.getDataRows().stream()
        .filter(row -> row.getCaseId().equals(caseId))
        .collect(Collectors.toList());

변경 후에는 작업 범위를 쿼리에 그대로 표현했다.

List<DataRow> currentRows =
        dataRowRepository.findByTrackerIdAndCaseId(
                tracker.getId(),
                caseId
        );
select *
from data_row
where tracker_id = ?
  and case_id = ?;

삭제, 수정, 추가를 계산하는 로직은 그대로 유지했다. 중요한 변화는 알고리즘이 아니라 입력 데이터의 범위를 회사 전체에서 케이스 하나로 줄인 것이었다.

기존 행은 조회할 때 영속 상태가 되므로 수정은 dirty checking으로 반영했다. 삭제와 추가는 리포지토리를 통해 명시적으로 처리했다.

엔티티의 책임을 옮긴 이유

처음 구현에서는 Tracker가 자신의 dataRows를 직접 관리했다. 연관관계 편의 메서드와 cascade, orphanRemoval을 활용할 수 있어 객체지향적으로 자연스러워 보였다.

하지만 여기에는 숨은 전제가 있었다.

애그리거트가 자신의 컬렉션을 메모리에 올려도 괜찮을 만큼 작다.

dataRows는 시간이 지날수록 계속 증가하는 데이터였다. 전체 컬렉션을 탐색해야만 로직을 수행할 수 있다면, 데이터가 쌓일수록 애그리거트 하나를 다루는 비용도 함께 커진다.

이번에는 필요한 행을 직접 조회하기 위해 diff 로직을 동기화 서비스로 옮겼다. 엔티티가 모든 자식 컬렉션을 통해 변경을 통제하는 모양은 약해졌지만, 실제 작업 단위만 메모리에 올릴 수 있게 됐다.

메모리에 올릴 수 없는 경계를 애그리거트 경계로 잡았다면 모델을 다시 볼 신호일 수 있다.

조회 범위를 테스트로 남기기

삭제, 수정, 추가 결과만 테스트하면 나중에 전체 컬렉션을 다시 사용하는 코드로 돌아가도 테스트가 통과할 수 있다.

이번 장애의 핵심은 결과가 아니라 조회 범위였다. 그래서 전체 컬렉션을 건드리지 않는 것도 테스트에 포함했다.

@Test
@DisplayName("대상 케이스 행만 조회하고 전체 컬렉션에는 접근하지 않는다")
void queriesOnlyTargetRows() {
    when(dataRowRepository.findByTrackerIdAndCaseId(
            TRACKER_ID,
            CASE_ID
    )).thenReturn(Collections.emptyList());

    service.applyDataRows(tracker, CASE_ID, Collections.emptyList());

    verify(dataRowRepository)
            .findByTrackerIdAndCaseId(TRACKER_ID, CASE_ID);
    verify(tracker, never()).getDataRows();
}

기존 동작도 나눠서 검증했다.

이 테스트가 OOM을 직접 재현하지는 않는다. 대량 데이터를 만들어 메모리 사용량을 검증하는 테스트는 느리고 환경의 영향을 많이 받는다. 대신 OOM을 만든 구조적 원인인 “전체 컬렉션 접근”을 금지하는 회귀 테스트로 남겼다.

OOM이 다시 발생해도 살아나도록

전체 컬렉션 로딩을 제거해 이번 OOM의 원인은 고쳤다. 그래도 메모리 문제는 다른 코드에서 다시 발생할 수 있다.

원인 수정과 별개로, 같은 일이 생겼을 때 서비스가 최소한 스스로 다시 일어날 수 있는 안전망도 필요했다.

Docker 설정에는 이미 다음 옵션이 있었다.

restart: unless-stopped

그런데 이 옵션은 컨테이너 프로세스가 종료되어야 동작한다.

JVM에서 OutOfMemoryError가 발생했다고 프로세스가 반드시 바로 종료되는 것은 아니다. 일부 스레드는 죽었지만 JVM은 남아 있을 수 있고, 메모리가 부족한 상태에서 GC만 반복하며 요청을 받지 못할 수도 있다.

이번 장애가 딱 그랬다.

OutOfMemoryError 발생

JVM은 살아 있지만 요청 처리는 불가능

컨테이너 프로세스는 종료되지 않음

Docker의 restart 정책도 동작하지 않음

헬스체크가 실패해 컨테이너가 unhealthy 상태가 되더라도 일반적인 Docker Compose의 restart 정책은 unhealthy만으로 컨테이너를 재시작하지 않는다. JVM이 확실하게 종료되어야 했다.

그래서 다음 JVM 옵션을 추가했다.

-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/app/logs
-XX:+ExitOnOutOfMemoryError

이제 OOM이 발생하면 힙 덤프를 남긴 뒤 JVM이 종료되고, 컨테이너의 재시작 정책이 작동한다.

OutOfMemoryError 발생

힙 덤프 저장

JVM 프로세스 종료

restart: unless-stopped 정책으로 컨테이너 재시작

처음에는 “Docker 재시작 옵션이 있는데 왜 안 살아나지?” 싶었다. 문제는 Docker가 아니라 재시작의 전제인 프로세스 종료가 일어나지 않았던 것이었다.

물론 이 설정이 OOM 자체를 해결해주는 것은 아니다. 잘못된 전체 컬렉션 로딩을 그대로 두고 재시작만 추가하면 서버가 죽고 살아나기를 반복할 뿐이다.

그래서 두 조치의 역할을 분리했다.

  1. 필요한 행만 조회해 이번 장애의 원인을 제거
  2. 예상하지 못한 OOM이 발생하면 JVM을 종료하고 컨테이너를 재시작

첫 번째는 원인 해결이고, 두 번째는 장애가 영구 정지로 이어지지 않게 하는 안전망이다.

힙 크기만 늘리지 않은 이유

힙 크기를 늘리면 당장의 장애 빈도는 줄일 수 있다. 하지만 전체 컬렉션을 작업 수만큼 중복 로딩하는 구조는 그대로 남는다. 데이터와 동시 실행 수가 증가하면 결국 같은 한계에 다시 도달한다.

@BatchSize나 fetch join도 해결책이 아니었다. 쿼리 횟수나 조회 시점은 바꿀 수 있지만, 필요하지 않은 행까지 엔티티로 만드는 조회 범위는 줄어들지 않는다.

Java의 stream()을 반복문이나 parallelStream()으로 바꾸는 것도 마찬가지다. Java 컬렉션을 최적화하기 전에 어떤 행을 SQL로 조회하고 있는지부터 봐야 했다.

정리

이번에는 LAZY가 붙어 있으니 연관 데이터도 필요한 만큼만 조회될 거라고 막연히 생각했다.

하지만 LAZY는 조회를 미룰 뿐이다. 컬렉션에 접근하면 연관된 데이터 전체를 가져오며, 그 뒤에 실행하는 Java의 filter()는 SQL에 아무 영향도 주지 않는다.

단건 처리에서 눈에 띄지 않던 비효율은 동시 실행되면서 OOM으로 커졌다. 한 번의 작업이 얼마나 많은 데이터를 읽는지만 볼 게 아니라, 같은 작업이 동시에 몇 개까지 실행될 수 있는지도 같이 봐야 했다.

이번에 기억할 것은 네 가지다.

  1. LAZY는 조회 시점만 늦춘다. 조회 범위는 쿼리로 제한해야 한다.
  2. 크기가 계속 커지는 @OneToMany 컬렉션을 엔티티에서 순회하고 있다면 경계를 의심한다.
  3. 성능 장애의 회귀 테스트는 결과뿐 아니라 문제가 된 접근 방식도 검증해야 한다.
  4. 장애 원인을 제거하는 것과 장애에서 자동으로 회복하는 것은 별개의 문제다.

이번에는 전체 컬렉션 로딩이라는 원인을 제거했고, 예상하지 못한 OOM이 다시 발생해도 서비스가 영구히 멈추지 않도록 복구 경로를 만들었다. 장애 원인을 고치는 것과 다음 장애를 견디게 만드는 것, 둘 다 필요했다.

···
← PREV [리팩토링] 같은 차수 계산인데 결과가 달랐던 이유