JVM 배치 서비스의 14일 메모리 누수 — JSch SFTP가 Session을 흘리고 있었다
heap dump 분석으로 connection thread 누적을 찾기까지의 진단 보고서
운영 배치가 OOM Kill로 죽었다는 알람을 받은 게 시작이었습니다. 새벽 3시에 도는 cron 잡 도중 컨테이너가 갑자기 사라졌고, 그날 잡은 거기서 끝났습니다. 단발성 OOM이면 메모리 limit을 살짝 올리고 넘어가는 게 보통인데, CloudWatch 추이를 띄워보니 그렇게 단순하지 않더군요. 메모리가 14일 동안 거의 직선으로 차오르고 있었습니다. 일평균 +25 MiB. 그래프를 한참 들여다보다가 "이거 누수네"라는 결론이 떨어졌습니다. 거기서부터 약 1주에 걸친 진단이 시작됐습니다.
진행 기간: 약 1주 결과: 1순위 root cause(JSch session leak) 확정 + fix 배포. 부수 누수 시그니처(AspectJ + reflection inflation)에 대한 ROI 기반 후속 plan 정리.
TL;DR
운영 배치 컨테이너가 14일 동안 메모리 +351 MiB 단조 증가하다가 OOM Kill. heap dump 분석으로 SFTPUtils.destroy()의 SSH Session 미정리(JSch session leak)가 1순위 root cause로 확정됐습니다. 추가 보조 누수 시그니처(AspectJ ShadowMatchCache + JVM reflection inflation)도 관측되어 후속 ROI 순 액션 plan으로 정리했습니다.
이 글은 진단 워크플로(메트릭 → heap dump → MAT)와 JSch의 Session/Channel 구조, 그리고 잔여 누수에 대한 가설을 다룹니다.
1. 증상 — 메트릭부터 본 단조 증가
CloudWatch ECS/ContainerInsights 기준 14일 추이는 이랬습니다.
| 시점 | 메모리 사용량 | 한도 |
|---|---|---|
| 재기동 직후 | 635 MiB | 1024 MiB |
| 7일차 | 931 MiB | 1024 |
| 14일차 (OOM 직전) | 998 MiB | 1024 |
| 재기동 후 | 496 MiB | 1024 |
일평균 +25 MiB 단조 증가. 14일 누적 +351 MiB. cron 잡과 무관한 idle baseline 자체가 차오릅니다 — 누수 시그니처가 거의 교과서적이었습니다.
처음 이 그래프를 봤을 때 머릿속에서 정리한 판단은 셋이었습니다.
- 단조 증가 → 누수 의심. spike-then-recover면 GC 압박이지 누수는 아닐 수 있습니다.
- idle baseline이 올라감 → 잡 실행 시 잡힌 메모리가 잡 끝나도 안 풀리는 상태. 즉 누수 주체는 "잡이 만든 무언가"인데 GC가 회수하지 못하고 있습니다.
- 다른 서비스와 비교 → 같은 인프라/공통 라이브러리를 쓰는 다른 서비스의 7일 delta도 같이 봤습니다. 누수가 공통 라이브러리에서 오는지 / 배치 고유 코드에서 오는지를 좁히는 단서가 됩니다.
세 번째 단서로 일찌감치 "공통 라이브러리 vs 배치 고유 코드" 가설을 좁힐 수 있었던 게 결정적이었습니다.
2. 진단 절차 — 메트릭 → ECS Exec → heap dump → MAT
저는 다음 순서로 따라갔습니다. 비슷한 사고를 만나면 거의 그대로 재사용 가능한 워크플로라 정리해둡니다.
Step 1. CloudWatch로 누수 패턴 확정
위 표가 그것입니다. MemoryUtilized를 1시간 평균으로 7~14일 윈도우로 보면 누수면 거의 한눈에 보입니다.
aws cloudwatch get-metric-statistics --namespace ECS/ContainerInsights \
--metric-name MemoryUtilized \
--dimensions Name=ClusterName,Value=<cluster> Name=ServiceName,Value=batch \
--start-time $(date -u -v-7d +%Y-%m-%dT%H:%M:%SZ) \
--end-time $(date -u +%Y-%m-%dT%H:%M:%SZ) \
--period 3600 --statistics Average --output json
Step 2. ECS Exec 활성화
운영 컨테이너에 들어가서 jcmd로 heap dump를 떠야 합니다. ECS Fargate는 SSH가 없으니 ECS Exec(SSM 기반)을 씁니다. ecsTaskExecutionRole에 AmazonSSMManagedInstanceCore 정책을 attach하면 활성화됩니다. 로컬에는 session-manager-plugin 설치가 필요합니다.
이 인프라 셋업은 한 번 해두면 다른 서비스 진단에도 그대로 재사용 가능해서, 이번 사고의 부수 효과로 꽤 큰 가치가 있었습니다.
aws ecs execute-command --cluster <cluster> --task <ID> --container batch \
--command "/bin/sh" --interactive
Step 3. jcmd로 live heap dump
컨테이너 안에서:
jcmd <pid> GC.heap_dump /tmp/heap.hprof
생성된 hprof를 presigned URL을 통해 S3에 올리고 로컬로 다운로드합니다. 컨테이너 디스크가 작으면 dump 크기에 주의해야 합니다(보통 100~수백 MiB).
Step 4. Eclipse MAT headless 분석
GUI를 띄우지 않고도 leak suspects 리포트를 만들 수 있습니다.
./ParseHeapDump.sh /path/to/heap.hprof \
org.eclipse.mat.api:suspects \
org.eclipse.mat.api:overview \
org.eclipse.mat.api:top_components
리포트에서 가장 자주 본 뷰는 넷이었습니다.
- Leak Suspects — MAT이 자동 추정한 누수 주체 후보.
- Dominator Tree — 누가 누구를 잡고 있는지(retained heap이 큰 순).
- Thread Overview — 살아 있는 스레드와 각 스레드의 stack / local references.
- Class Histogram — 클래스별 인스턴스 수와 shallow/retained 메모리.
Step 5. 클래스 카운트로 leak source 좁히기
정상 baseline(다른 안정 서비스의 dump) vs 누수 서비스의 dump에서 의심 클래스의 카운트를 비교합니다. 누수가 있으면 특정 클래스가 비정상적으로 많거나, 평소 0개여야 할 스레드/객체가 살아 있습니다.
이번 케이스에서 결정적이었던 발견은 이거였습니다.
Connect thread Secureftp-...스레드 9개 alive (정상 시 0개)- 각 thread는
LaunchedURLClassLoader참조 유지, retained graph 수십 KB ~ MB - 운영 시간 비례 누적 (49시간 → 9개 → 14일이면 ~60-90개)
스레드 이름에 "Secureftp"가 박혀 있다는 게 단서였습니다. SFTP 관련 무언가가 끝나도 살아남고 있다는 뜻이니까요. 이 한 줄이 보이고 나서 다음 챕터로 직진할 수 있었습니다.
3. Root cause — JSch Session 미정리
코드를 열어보니 정말 깔끔하게 한 줄짜리 함정이 있었습니다.
public static void destroy(ChannelSftp channelSftp) {
if (channelSftp != null) {
channelSftp.disconnect(); // Channel만 disconnect
channelSftp.exit();
channelSftp = null;
}
}
JSch의 Session/Channel 모델
JSch의 SSH 객체 구조는 이렇습니다.
- Session = SSH 최상위 (TCP 소켓 + 인증). 내부적으로 connection thread 1개를 spawn.
- Channel = Session 위의 sub-stream (SFTP, Exec, Shell 등).
한 Session 안에 여러 Channel을 열 수 있습니다. 핵심은 — channel.disconnect()만 호출하면 Channel만 닫히고 Session(과 그 connection thread)은 alive 상태로 유지된다는 점입니다. 자원을 완전히 해제하려면 session.disconnect()를 명시적으로 호출해야 합니다.
저도 이 구조를 다시 들여다보기 전까진 "JSch에서 Channel을 닫으면 Session도 같이 정리되는 것"이라는 막연한 가정을 갖고 있었습니다. 라이브러리의 자원 해제 모델을 한 번 점검하는 게 얼마나 중요한지 다시 새기는 계기가 됐습니다.
호출 빈도 → 시간당 누수량 계산
- 1회 잡 실행에 SFTP 파일 6~12개 다운로드
- 매 파일마다
connect/destroy호출 → 매번 Session 1개 leak - 14일 운영 시 ~84-168 sessions 누적
각 Session은 connection thread 1개 + 그 thread의 stack/locals/ClassLoader 참조 = 수십 KB ~ MB의 retained graph를 동반합니다. 이게 일 +25 MiB의 idle baseline 증가로 나타났습니다.
Fix
public static void destroy(ChannelSftp channelSftp) {
if (channelSftp == null) return;
try {
Session session = channelSftp.getSession();
channelSftp.disconnect();
channelSftp.exit();
if (session != null && session.isConnected()) {
session.disconnect(); // ← 핵심: connection thread 종료
}
} catch (JSchException e) {
log.warn("SFTP session disconnect failed", e);
}
}
channel.getSession()으로 부모 Session을 얻고, 마지막에 session.disconnect()로 connection thread를 종료합니다.
검증 plan
- 배포 직후 ECS Exec로 컨테이너 진입 →
ps -ef | grep "Connect thread"로 SFTP 스레드 0개 확인 - 다음 cron 잡 실행 직후 동일 명령으로 0개 복귀 확인
- 1주일 CloudWatch
MemoryUtilized추이 평탄(이전 +25 MiB/일 → ≈0) 확인
4. 부수 발견 — heap dump가 보여준 두 번째 누수 시그니처
SFTP fix 한 줄로 끝나면 좋겠지만, dump를 좀 더 자세히 보면 다른 시그니처가 또 보였습니다. 1순위 누수를 잡았다고 만족하고 덮기엔 잔여 신호가 너무 명확했거든요.
| 항목 | 카운트 (49시간 task) | 정상 baseline | 평가 |
|---|---|---|---|
AspectJExpressionPointcut | 8 / 5.49 MB retained | 8 / 1-2 MB | AspectJ 매칭 캐시 누적 |
org.aspectj.weaver.reflect.ShadowMatchImpl | 35,418 | <1,000 | AspectJ ShadowMatchCache 누적 |
sun.reflect.GeneratedMethodAccessor | 1,227 | 50-200 | JVM reflection inflation 누적 (5-20배) |
Class instances | 18,224 | 8,000-12,000 | dynamic class 누적 |
Lambda 인스턴스 | 1,773 | 500-1,000 | lambda metafactory 캐시 누적 |
가설 — Spring AOP × Jackson reflection × JVM inflation 콤보
이 서비스에는 8개의 pointcut이 전 컨트롤러/Mapper에 광범위하게 적용되어 있습니다(Logging, Masking, Enc/Dec). 각 advice는 ObjectMapper.writeValueAsString(...) 등으로 reflection을 사용합니다.
JVM reflection inflation이라는 게 뭔지부터 잠깐 정리하면 — JVM 내부적으로 reflection 호출을 가속하는 메커니즘입니다.
Method.invoke()를 N번 이상(기본 15번) 호출하면 JVM이 reflection을 빠르게 하려고 그 method 호출 전용 bytecode class를 동적으로 만듭니다(sun.reflect.GeneratedMethodAccessorXX).- 이 클래스들은 영구적으로 ClassLoader에 매달려 있습니다. 한 번 만들어지면 ClassLoader가 살아 있는 한 회수되지 않습니다.
- 반복적으로 새로운 람다/익명 객체를 생성해
writeValueAsString을 호출하면 inflation 클래스가 계속 늘어납니다. - 같은 ClassLoader에 매달려 있으니 AspectJ의
ShadowMatchCache(어떤 advice가 어떤 join point에 매칭되는지의 캐시)도 비례해서 부풀어 오릅니다.
특히 WebClient.builder()를 호출 단위로 새로 만들거나, Jackson2JsonDecoder를 매번 신규 생성하는 코드 패턴이 이걸 강하게 트리거합니다.
즉시 처리 — Dockerfile 한 줄
-Dsun.reflect.inflationThreshold=2147483647
inflation을 사실상 무한대 threshold로 미루면 inflation 클래스가 안 만들어집니다. reflection 호출이 5-10% 느려지지만 체감 X. JVM 옵션 한 줄로 reflection 누적 ~30-40% 감소라는 가성비가 나옵니다.
같이 적용한 옵션은 이렇습니다.
ENTRYPOINT ["java",
"-XX:+UseContainerSupport",
"-XX:MaxRAMPercentage=75.0",
"-XX:+UseG1GC",
"-Dsun.reflect.inflationThreshold=2147483647",
"-XX:+ExitOnOutOfMemoryError",
"-XX:+HeapDumpOnOutOfMemoryError",
"-XX:HeapDumpPath=/tmp/heap-oom.hprof",
"-XX:MaxMetaspaceSize=192m",
"-jar", "./app.jar"]
-XX:+HeapDumpOnOutOfMemoryError로 다음 OOM 시 dump가 자동 캡처되도록 했습니다(예방 효과는 0%지만 다음 진단에 결정적입니다).
5. 후속 액션 — ROI 순서
| 순위 | 옵션 | 변경 위치 | 누수 감소 | 리스크 |
|---|---|---|---|---|
| ✅ 0 | SFTPUtils Session disconnect | 라이브러리 5줄 | ~30-50% | 거의 없음 |
| 🥇 1 | JVM reflection inflation 비활성 | Dockerfile 1줄 | ~30-40% | reflection 5-10% 느림 |
| 🥈 2 | OOM heap dump 자동 캡처 | Dockerfile 3줄 | 0% (예방) | /tmp 보존 위해 사이드카 필요 |
| 🥉 3 | POI HSSFWorkbook close | try-with-resources | 미미 (몇 MB/주) | 명백한 버그 fix |
| 4 | WebClient 싱글톤화 | 공통 라이브러리 5줄 | ~20-30% | 전 서비스 재배포 필요 |
| 5 | 정기 재시작 | EventBridge weekly | 누수 cap (땜빵) | 매주 1-2분 다운 |
| 6 | 메모리 한도 1024→2048 | task definition | 0% (시간 벌기) | Fargate 비용 ~2배 |
| 7 | LoggingAspect 직렬화 경량화 | 각 서비스 LoggingAspect | ~10-15% | CS 대응 영향 |
| 8 | APM 도입 (Datadog/NewRelic) | agent | 진단력 ↑↑ | 비용 |
핵심은 0 + 1 + 2를 한 PR로 묶어서 즉시 처리하고, 1~2주 모니터링 후 평탄화가 안 되면 4번을 진행하는 것입니다. 정기 재시작(5번)은 진짜 마지막 카드로 남겨두려고 합니다.
회고
이번 진단을 끝내고 머리에 남은 것들을 정리하자면:
- 메트릭은 누수를 보여주지 않습니다. 추세를 보여줄 뿐입니다. 누수인지 / GC 압박인지 / 일시적 spike인지 결정하는 건 사람의 몫입니다. 단조 증가 + idle baseline 차오름 = 누수, 이 두 조건의 매핑을 머릿속에서 빠르게 할 수 있어야 한다는 걸 다시 새겼습니다.
- dump 한 번에 다 안 보입니다. 1순위 누수를 fix하고도 잔여 시그니처가 남는 일이 흔합니다. 잔여 항목들을 ROI 순으로 plan하고, 측정 가능한 검증 단계를 두는 게 중요했습니다.
- JVM 옵션 한 줄이 코드 변경 수십 줄보다 효과적일 때가 있습니다.
-Dsun.reflect.inflationThreshold같은 것들은 모르면 평생 안 만지지만, 알면 1줄로 30% 감소입니다. heap dump를 정기적으로 떠 보면 이런 카드를 발견하게 됩니다. - 닫을 의무가 있는 자원은 try-with-resources 또는 try-finally. JSch처럼 stdlib
AutoCloseable이 아닌 라이브러리는 wrapper를 짜서라도Session.disconnect()까지 같이 보장하는 게 안전합니다. "이 라이브러리는 어디까지 자원을 자동으로 풀어주는가?"라는 질문을 처음부터 던지는 습관이 필요하다는 것.
이번 사건의 부수 효과로 다른 서비스의 진단에도 그대로 쓸 수 있는 인프라(ECS Exec + heap dump 워크플로) 가 영구 적용된 것은 보너스였습니다. 사고는 늘 한 가지를 고치고 끝나는 게 아니라, 다음 사고를 빨리 잡을 수 있는 도구 세트를 같이 남기는 것 같습니다.