[회고] "간헐적 메모리 장애" 삽질부터 트러블 슈팅까지

회고/일상 후기 회고

[회고] "간헐적 메모리 장애" 삽질부터 트러블 슈팅까지

민돌v 2023. 11. 2. 17:56

해당 글은 사수도 동료도 있었는데 없어진 1인 주니어 백엔드 개발자의
간헐적인 서버 메모리 장애 오류 (ShutDown) 삽질 회고입니다.

개발환경 [ Linux, Docker, Java 11, Spring 2.4.x ]

| 회고

안녕하십니까 여러분 🫡
제 블로그를 정기적으로 봐주시는 분이 얼마나 있을지 모르겠으나

상-당히 오랜만에 글을 쓰게 되었네요

그 동안 황금연휴로 (9.29 ~ 10. 09) 8박9일 말레이시아 여행을 다녀오기도 했고, 사내에서 잡고있던 장애 슈팅이 잘 풀리지 않아 번아웃이라는 핑계거리가 생겨버려서

이런저런 이유를 대며 개인공부를 살짝 손에서 놓았습니다

하지만 돌아왔다는건. 문제를 해결했다는 것..!!!

[목차]

직면한 문제 상황
그래서 뭐가 뭐가 문제의 원인일까? ✨
이제 어떻게 해결해야할까? ✨
OOM 모니터링 환경을 구축해보자
이제 메모리 누수를 해결해볼까? ✨
더 개선할 방법은 없을까?
트러블 슈팅의 과정 및 결과 정리
마무리 회고

직면한 문제 상황

포스팅 제목에서도 알 수 있다시피, 약 2달간 저는 간헐적인 메모리 장애와의 치열한 (~~혼자만의~~) 싸움을 했습니다.

📌 문제)

사실 이전부터 특정 서버가, 간헐적으로 죽는(Shut-Down) 현상이 목격되었습니다.
일정한 시간에 터지는 것도 아니고, 가끔 Out-of-Memory를 남길 때도 있고, 남기지 않을 때도 있는 곤란한 상황이었습니다.
(슈뢰딩거의 서버다운)
점점 이런 서버의 간헐적 shut-down이 업무시간 뿐만아니라, 새벽에도 터지고, 퇴근 직전에도 터지고, 연휴 전날에도 터지고.. 팝콘처럼 계속 터지는건 물론이고 그 주기도 점점 짧아져갔습니다.

기존에는, 스타트업의 특성상 이슈를 빠르게 쳐야했기 때문에, 다른 신규 기능 업무를 먼저 치고, 장애가 생겨 서버가 죽었을 때 살리자!
였지만.. 지금은 사내 서비스를 관리할 인원도 줄고 어느정도 여유시간이 생겨 더 늦기전에 본질적인 원인을 파악해보고자 했습니다.

더이상 죽고싶지 않았어요!

그래서 뭐가 원인일까?

먼저, 서버가 터졌을 때의 로그들을 분석해보기로 했습니다.

과정 1) 남겨진 로그 확인하기

📌 서버가 갑작스럽게 죽었을 때 봐볼만한 로그는 아래 3가지입니다.

was log (어플리케이션 로그)
dmesg (시스템 로그)
hs_err_pid{%pid}.log (톰캣이 비정상 종료되었을 때 생성되는 로그)

마침 추석 전날 새벽 03:30분경에 서버가 ShutDown 되어 3가지 로그를 확인해볼 수 있었습니다.

(1) 번 어플리케이션의 실행로그(was log)는 별도의 log 파일로 날짜마다 기록하고있었지만, 어느 시점(서버가 죽기 몆분전)부터 로그가 끊겨 어플리케이션이 다운될 당시의 로그는 기록되어있지 않았습니다.

(3) 번 로그(hs_err_pid.log) 또한, 톰캣의 비정상 종료이므로 로그가 남겨져있을 줄 알았지만, 마찬가지로 생성되지 않았습니다.

(2) 번로그(시스템로그) 에서는 다행히도 남겨진 것이 있었습니다.

과정 2) dmesg (시스템 로그) 확인

리눅스 환경이기에, dmesg 명령어로 서버가 죽었을 당시의 시스템로그를 살펴보았습니다.
dmesg 는 리눅스 커널에서 발생하는 다양한 메세지들을 출력해주는 명령어 입니다.
시스템로그로 커널에서 서버가 죽었을당시 OOM Killer 가 동작하는 것을 확인했습니다.

↓

👏🏻 문제 원인 추측

❗️ 커널에서 oom killer 가 발생했다는 것은 물리 서버의 가용메모리 자체가 부족해져서 프로세스에 할당할 메모리가 없다는 것!
❗️ 이 말은 즉슨, 어딘가에서 메모리를 계속 잡아먹고 있다는 것 (메모리 급증(틱) or 메모리 누수 의심)
❗️ hs_err_pid.log 가 기록되지 않는건, 톰캣의 비정상적인 오류로 서버가 죽는게 아닌, oom_killer 가 kill 명령어로 프로세스를 종료시키기 때문이라고 추측!
❗️was_log 가 도중에 끊겨 서버가 종료될 당시의 에러가 전부 기록되지 않는 원인은, 물리서버의 가용메모리 자체가 부족하게되어 어플리케이션 (톰캣)이 로그를 기록할 메모리조차 부족해진 것.. 이라고 추측되어집니다.

과정3) 서버 스펙 및 구축 환경 살펴보기

시스템로그를 살펴보았을 때 물리서버의 메모리 부족임을 확인할 수 있었습니다.
그럼 현재 환경이 메모리가 부족해서 증설해야하는 상황인지 살펴보겠습니다.

현재 저희 서버는 AWS 의 t2.micro 스팩의 물리서버(ec2)를 사용하고 있습니다.

vCPU 2개
메모리 4G

그리고 해당 서버에는 3개의 Docker 컨테이너에 3개의 어플리케이션을 각각 다른 포트로 이용하고있습니다.
즉, 메모리 4GB 스펙에 어플리케이션(jvm) 3개 돌아가 있는 상황입니다

음.. 애매합니다

대용량 배치성 어플리케이션, 혹은 실시간 크롤링, 순간적인 대규모 트래픽이 아닌이상 4GB의 메모리가 현재 상황에서 부족할 것이라고 생각되어지진 않았습니다.

또한, 현재 트래픽이 과거(6개월) 대비 크게 늘지 않았음에도 불구하고 메모리가 계속 급증하는게 단순하게 물리서버의 메모리가 적게 잡혀서인 것 같지는 않았습니다.

~~그리고 회사에 돈이 없었습니다.~~

Scale Up은 항상 마지막의 보류이니까요!

과정 4) 구축환경 뜯어보기

현재 메모리 사용률을 먼저 살펴보았습니다.

각 컨테이너가 사용하고있는 메모리는 각각 아래 사진과 같고, 3개의 어플리케이션이 정상적으로 실행중일 때 보통 100m~250m 정도의 가용메모리(버퍼캐시 제외)가 남아있습니다.

문제가 의심되는 어플리케이션은 server1 컨테이너에 올라가있는 JVM 이었습니다.
해당 어플리케이션은 내부 관리자 페이지의 API 를 담당하는 어플리케이션인데 레거시 코드가 다수 포진되어있고, 해당 서버에 제일 주요하게 사용되고, 가장 많이 혹은 가장 먼저 죽는 어플리케이션입니다.

↓

해당 컨테이너 환경에서 실행되는 JVM에 할당된 heap 메모리 사이즈를 확인해보았습니다.
아래 2가지 명령어를 이용해 jvm의 heap size를 확인할 수 있습니다.

java -XX:+PrintFlagsFinal -version 2>&1 | grep -i -E 'heapsize|permsize|version'

 java -XX:+PrintCommandLineFlags -version

각각의 도커들은 물리서버의 메모리를 공유하여 사용하고,
jvm 의 heap memory max size가 default 로 설정되어 "1GB" 의 메모리를 잡고있었습니다.

-XX:InitialHeapSize=64600640 (64mb)
-XX:MaxHeapSize=1033610240 (1033mb)

오라클 java 문서(http://www.oracle.com/technetwork/java/ergo5-140223.html) 에 따르면, jvm을 server class로 실행하면 초기 heap size는 메모리의 1/64이고, 최대 heap size는 1/4 까지 늘어단다고 합니다.

📌 원인 파악

이상적인 흐름이라면 가용가능한 메모리가 고갈되어서 minor gc가 빠르게 돌아가든, full gc 가 돌아가든지 해서 메모리를 빠르게 확보해야하는 상황이지만
jvm 에 설정된 heap 메모리가 실제 가용가능한 메모리보다 높게 잡혀있어 Full GC가 동작하기전에 프로세스가 물리서버의 메모리를 모두 잡아먹는게 문제였습니다.
server1 컨테이너에서 해당 어플리케이션 jvm이 점유하고있던 heap 메모리가 300~400m 정도여서 heap size는 600~700m 의 여유가 있는데 실제 가용가능한 메모리는 100~200m 밖에 없으니 oom killer 가 발생한게 아닌가 생각되어집니다.
(점유중인 heap 메모리는 heap dump 후 eclipse mat 사용, 또는 jstat -gc 명령어로 확인할 수 있습니다.)

이제 어떻게 해결해야 할까?

✔️ 목표는 jvm 이 정상적으로 Full GC를 이용해 메모리 관리를 할 수 있도록 적절한 heap memory를 할당해주는 것입니다.

jvm 실행 옵션 중 -Xmx 를 사용하여 jvm heap max size를 설정할 수 있습니다.

IBM 의 Tuning JVMs (Java Virtual Machine) 이라는 글을 보았을 때 저장해둔건데 다시 찾을려니 못찾겠네요..
해당 글에서는, -Xmx 옵션을 사용할 때 가용가능한 메모리보다 max heap size가 크다면 심각한 성능저하를 일으킨다는 문장이 존재하였습니다.
실제로 jvm 이 사용하는 메모리가 물리서버의 가용메모리를 넘어섰을때 ec2 의 cpu 사용량이 급증하면서 서버가 다운되는 현상을 확인하였습니다.

✔️ 적절한 Max heap size 설정

현재 1024mb (1g) 가 최대 힙 사이즈이지만, 정상적인 상황에서 jvm 의 힙 사용량이 350~450m 을 점유 및 유지하고 있고, 이때 버퍼캐시를 제외한 물리서버의 가용 메모리가 100~200m 이므로, 최대 heap size는 550m 가 정도가 적당해 보였습니다.

이렇게 heap size를 조절해주고 nGrinder 를 사용한 부하테스트를 진행해보니 정상적으로 Full GC가 돌기 시작했습니다.
😂 하지만 운영환경에서는 또다른 문제가 발견되었습니다..!

이번에는 Full GC가 제 생각보다 너무 많이 돌면서, was 단에서 OOME(Out-Of-Memory Exception)이 터지더군요,,,

OOM 모니터링 환경을 구축해보자

저는 지금 사내 1인 개발자이기도 하고, 실시간으로 빠르게 장애를 대응할만한 경험도 지식도 부족하기 때문에 모니터링 환경이 무엇보다 시급했습니다.
서버가 죽기전에 장애를 대응하는게 제일 좋겠지요..!
그게 아니라면 죽은 후 트러블 슈팅이라도 제대로 할 수 있게 자료라도 남겨야겠져..!

OOM 모니터링을 위해 저는 아래 3가지 작업을 진행했습니다.

Dump 파일 기록
oom 발생시 Slack 알림메세지 전송
ec2 Docker Container 의 실시간 메모리 사용량 모니터링 (AWS agent)

1) oom 발생 시 기록 남기기 (dump)

Heap Dump
Thread Dump
Tcp Dump ( → 네트워크 오류를 파악하기위한 덤프 파일입니다. 링크(https://thalals.tistory.com/463)로 대체합니다.)

✔️ OOM 발생할 경우에 힙덤프 파일 자동 생성하기

사실 OOM 은 Heap Dump가 최고입니다. Dump 파일에 유용한 정보를 담기 위해서는 장애 즉시, 그 시점에 따는게 제일 좋습니다.
이것 또한 Jvm 실행 옵션 "HeapDumpOnOutOfMemoryError" 를 이용해 OOM 발생시점에 덤프 파일을 생성할 수 있습니다.

(예시)

java -jar -Xms1024M -Xmx1024M 
		-XX:+HeapDumpOnOutOfMemoryError 
   		-XX:HeapDumpPath=src/main/resources/dump/heap/heapDump_$date.hprof //heapDump_$DATE.hprof
   		-XX:OnOutOfMemoryError="kill -15 %p" 
	 	-XX:NativeMemoryTracking=summary
   		application-0.0.1-SNAPSHOT.jar

Xms : 이 설정은 Java 힙의 초기 크기를 제어합니다
Xmx : Java 힙의 최대 크기를 제어합니다.
XX:+HeapDumpOnOutOfMemoryError : OOM이 발생할 경우에 힙덤프 파일을 생성을 한다
XX:HeapDumpPath : 힙덤프가 생성되는 폴더 경로를 지정한다
XX:OnOutOfMemoryError : OOM이 발생할 경우, 수행할 스크립트를 지정한다(보통은 OOM이 발생하면 애플리케이션이 다운되기 때문에 재시작 스크립트를 다시 수행하기도 한다)
-XX:NativeMemoryTracking=summary : heap 메모리가 아닌, native 메모리 모니터링을 위한 옵션

✔️ 쓰레드 덤프 기록하기

OOM 발생시 혹시 스레드가 교착상태(데드락, Dead Lock) 에 빠져있는지 확인하기 위해서는 스레드 덤프를 활용하여 알 수 있습니다.
Thread Dump 파일은 Jstack -l 명령어를 사용해 기록할 수 있습니다.
교착상태를 확인하기위해서는 적어도 5초단위로 3번을 나누어 기록하는게 좋다고 합니다.
저는 jvm 의 "OnOutOfMemoryError" 옵션을 통해 스크립트 파일을 별도로 만들어 실행하도록 해주었습니다.

java -jar -XX:OnOutOfMemoryError="thread_dump.sh"

thread_dump.sh

#!/bin/bash

echo "start slack alarm and record thread dump"

date=$(date +%Y)-$(date +%m)-$(date +%d)_$(date +%H):$(date +%M):$(date +%S)
pid=$(lsof -t -i:8080)


jstack -l $pid > src/main/resources/dump/thread/threadDump1_$date.txt
sleep 5

jstack -l $pid > src/main/resources/dump/thread/threadDump2_$date.txt
sleep 5

jstack -l $pid > src/main/resources/dump/thread/threadDump3_$date.txt
sleep 5

2) oom 발생 시 Slack 메세지 전송하기

그 다음으로 진행한 작업은 Slack 메세지 연동입니다.
현재 팀 메신저로 Slack 을 사용하고 있고 dump 파일을 기록한다고 하더라도, OOM 발생 시 즉각적인 대응을 위해 메신저 연동 작업을 진행했습니다.

이 작업 또한 "OnOutOfMemoryError" 옵션을 이용했고, 위의 Thread_dump.sh 스크립트 파일에 수정하여 진행했습니다.

Slack WebHook 을 이용해 api 요청으로 메세지를 전송할 수 있었습니다.

#!/bin/bash

echo "start slack alarm and record thread dump"

date=$(date +%Y)-$(date +%m)-$(date +%d)_$(date +%H):$(date +%M):$(date +%S)
pid=$(lsof -t -i:8080)

echo  $pid

json="{\"text\": \" *[Admin Server]*  \n\`OutOfMemory Exception\` 발생  \n발생 시간 : $date \"}"

my_slack_webhook="https://hooks.slack.com/services/{ slack webhook api key}"

curl -X POST -H 'Content-type: application/json' --data "$json" $my_slack_webhook


jstack -l $pid > src/main/resources/dump/thread/threadDump1_$date.txt
sleep 5

jstack -l $pid > src/main/resources/dump/thread/threadDump2_$date.txt
sleep 5

jstack -l $pid > src/main/resources/dump/thread/threadDump3_$date.txt
sleep 5

3) ec2 실시간 메모리 조회

추가적으로 AWS CloudWatch Agent 를 이용해서 1s, 5s, 10s ..등의 단위로 실시간 메모리 사용률과 점유율, 디스크 사용량 등의 모니터링 및 알람 설정을 진행하였습니다.

해당 설정으로 인해 CPU 사용량 뿐만 아니라, 메모리 사용률이 일정 퍼센트를 넘어갈 떄 슬랙으로 알림이 오도록 연동할 수 있었습니다.

4) 그 외의 사용했던 도구들

heap dump 분석

분석툴
- Ecplise mat
메모리 사용량 ui 모니터링 툴
- VisualVm (로컬환경에서 쓰기 편함)
- jconsole
리눅스 환경이라면 jmap -dump 옵션을 이용해 heap dump 파일을 생성할 수 도 있습니다.
ex) jmap -dump:file=파일이름.hprof {$pid}

Thread dump 분석

분석툴
- https://fastthread.io/
실시간 thread 모니터링
- VisualVm

GC 분석

로그 기록
- jvm 실행 옵션 "-xlog:gc" 를 설정해주면 어플리케이션 실행중 동작되는 GC 로그를 파일로 기록해둘 수 있습니다.
- 예시)

-verbose:gc \
-XX:+PrintGCDetails \
-XX:+PrintGCDateStamps \
-Xlog:gc=debug:file=파일경로/gc_$date.log:time,uptime,level,tags:filecount=50,filesize=100m \
-XX:+UseGCLogFileRotation \
-XX:GCLogFileSize=1m \
-XX:NumberOfGCLogFiles=100 \

분석툴
- https://gceasy.io/
실시간 gc 모니터링
- VisualVm의 VisualGC 플러그인을 다운받으면 GC 동작과정 모니터링이 가능합니다.
- 리눅스 환경이라면, jstat -gcutil 옵션으로 콘솔로 GC 동작 현황 모니터링이 가능합니다.
  ex) jstat -gcutil pid 3s(표출 주기)

이제 메모리 누수를 해결해 볼까? (Memory Leak)

이제 모든 준비가 끝났습니다. 터져줘 OOM!

heap dump 파일은 eclipse의 mat 프로그램을 사용하여 분석할 수 있습니다.
mat 을 사용하면 dump 파일에서 memory Leak 이 의심되는 부분을 분석해줍니다.

저는 "java.util.concurrent.ConcurrentHashMap" 객체에서 상당히 많은 메모리를 차지하고 있었습니다.
mat 을 사용하면 해당 객체의 outgoing reference 와 incoming reference 를 추적할 수 있습니다.

추적 후 의심가는 API 를 특정할 수 있었고, WAS log 에서도 request 로그만 있고 response는 로그는 없다는 걸 확인했습니다.
또한 해당 API 의 사용부분을 찾아보니 1만건도 안되는 데이터를 불러오는데 26초나 걸리더군요

✔️ 메모리누수 리팩토링

막상 레거시 부분을 까보니, 수정하기에는 상당히 쉬운 상황이었습니다.
List<> 의 요소로 HashMap<> 이 들어가고 다시 그 value 값으로 HashMap<>을 넣고 있더군요.

원인

다 쓴 참조 - obsolete reference
즉, GC 가 동작하더라도 Map 에서 내부 객체에대한 참조를 계속 가지고있기 때문에 GC의 대상이 되지않아 heap memory를 잡아먹게되는 구조입니다.

얼추 아래와 비슷한 상황이었습니다.

List<HashMap<String, Object>> get2() {

    List<HashMap<String, Object>> list = new ArrayList<>();

    for (int i = 0; i < 500000; i++) {

        HashMap<String, Object> e = new HashMap<>();

        e.put("key1", "value1");
        e.put("key2", "value2");
        e.put("key3", "value3");

        HashMap<String, Object> a = new HashMap<>();
        a.put("key1", "value1");
        a.put("key2", "value2");
        a.put("key3", "value3");

        e.put("HashMap", a);
        
        list.add(e);
    }

    return ResponseEntity.ok(list);

}

해결방안

간단합니다. Map 객체를 사용하고 난 후 해당 참조를 null 로 초기화시켜주면 참조를 잃어버리므로 GC의 대상이 됩니다.
혹은, Reference 클래스의 SoftReference 와 WeekReference 클래스를 사용하면 해당 클래스가 특정 시점에 GC 의 대상이되도록 할 수 있습니다.
Map 은 WeakRefence 를 사용한 WeakHashMap이 존재합니다.
혹은 Map을 아예 사용하지 않는 방법도 있겠죠

내가 적용한 것

저는 (3)번 방법, Map 을 아예 사용하지 않았습니다.
현재 코드에서는 Map 객체를 단순히 DB 데이터를 담는 용도로 사용하고 있기 때문에, Map 을 사용할 이유가 전혀 없었습니다.
JVM 설계자들의 Weak Generational Hypothesis 에 의한 메모리 설계에 의고하여 Data 를 담는 DTO 객체를 사용해 1회성 객체로 해당 역할을 대체하는게 좋다고 판단했습니다.

더 개선할 방법은 없을까?

❓어플리케이션들이 메모리 자체를 덜 사용하도록 할 수는 없을까?

애초에 어플리케이션이 실행될 때 기본적으로 1500m 가까이 메모리를 잡아먹는게 좀 많은게 아닌가라는 생각이 들었습니다.
"mvn spring-boot:run" 시 돌아가는 Runcher 프로세스가 생각보다 많은 메모리를 잡아먹고 있더군요

현재 배포 상황

현재는 스크립트 파일로 프로젝트 루트 폴더에서 mvn spring-boot:run 명령어를 실행시키는 구조입니다.
mvn spring-boot:run 명령어는 "spring-boot-starter-web" 종속성만이 pom,xml 에 추가되어있다면 플러그인은 pom 구성을 읽고 pom.xm에 추가되어있는 모든 외부 종속성을 톰캣이 시작할 때 다운로드 및 초기화합니다.

개선 후

아무런 설정을 하지 않은 채, maven 으로 빌드한 프로젝트 jar 혹은 war 파일은 외부 종속성 라이브러리들이 포함되어있지만
Spring Boot 공식 Docs 를 보았을 때, 특정 플러그인 설정으로 모든 종속성이 포함된 jar 파일을 만들 수 있었습니다.
https://docs.spring.io/spring-boot/docs/current/maven-plugin/reference/htmlsingle/#packaging.repackage-goal.parameter-details.executable

<plugin>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-maven-plugin</artifactId>
    <configuration>
        <executable>true</executable>
    </configuration>
</plugin>

↓

👏🏻 결과

어플리케이션 실행시 메모리 점유율 1500m 애서 → 580m 로 약 61% 감소하였습니다.
이로인해 줄였던 heap size도 다시 1gb 로 늘릴 수 있어 GC 효율또한 챙겨갈 수 있었습니다.

정리

✔️ 문제 원인

하나의 물리서버(ec2) 에 docker container 3개로 3개의 어플리케이션 (jvm) 이 구동되고 있다.
각각의 도커들은 물리서버의 메모리를 공유하여 사용하고, jvm 의 heap memory, 혹은 가용가능한 메모리가 default 로 설정되어 “1GB” 의 메모리를 잡고있다.
- 1024mb (1g) 가 최대 힙 사이즈이지만, 정상적인 상황에서 jvm 의 힙 사용량이 350~450m 을 유지
- 이때 물리서버의 가용 메모리가 100~200m 이므로, 최대 heap size는 550m 가 정도가 적당해 보인다.
실제로는, 어플리케이션 실행중 메모리가 부족하여 Full GC 가 돌아야하는 상황이지만, jvm 에 설정된 heap 메모리가 실제 가용가능한 메모리보다 높게 잡혀있어 정상적으로 Full GC가 돌아 메모리를 확보하기 전에 물리서버의 가용 메모리가 고갈되어 docker 자체가 먹통이 된다.
- -XX:InitialHeapSize=64600640 (64mb)
- -XX:MaxHeapSize=1033610240 (1033mb)
jvm 의 Heap Size를 어느정도 낮추어 full gc 가 정상적으로 동작하도록 설정한다.
1. 이유1) 속도가 중요한 클라이언트 어플리케이션 서버가 아니기 때문에
2. 이유2) 서버개발자가1인으로써 실시간 대응이 어렵기 때문에 성능저하보다는 장애 빈도를 줄이고자 했음
  ↓
이렇게 했더니 full gc 가 너무 많이 돌더라(linux: jstat gcutil 실시간 모니터링)
- 원인 1) 비효율적인 레거시 코드
  1. DB CRUD의 전체 공통화 및 추상화로 인한 불필요한 query connection 다수 발생
  2. 같은 이유로 인한 2중~3중 반복문
- 원인 2) HashMap< String, HashMap<> > 사용으로인한 메모리 누수
  1. JVM 설계자들의 Weak Generational Hypothesis 에 의거하여 Data를 담는 용도로 Map 을 사용할 이유가 없음 → DTO 분리
mvn spring-boot:run 으로 실행시 Runcher process 가 생각보다 많은 메모리를 잡아먹음

✔️ 문제 해결

HashMap 을 사용하지 않고, DTO 객체를 반환 → 메모리 누수 개선
각각의 테이블조회하고 1 : N 관계는 다시 반복문으로 개별 query를 날리던 query 문 개선 (대략 1만 쿼리? → 1개 쿼리)
join 후 어플리케이션 단의 Stream group by 및 중복제거 로직으로 기능개선 (QueryDsl transform 과 성능비교 후 채택)
mvn run 커멘드 동작방식을 jar 로 변경 → 메모리 점유량 감소 → jvm Heap Size 확보

✔️ 결과

2s 700ms (local 에서는 1m40s 걸림) → 230ms(local은 300ms) 로 조회 속도 개선
간헐적인 메모리 성능 장애 개선 및 메모리 점유율 61% 감소 (1500m → 580m)
GC 빈도 성능 개선
TPS 성능개선
- 개선 전 - 너무 낮은 TPS 로 부하 테스트 자체가 불가, vuser per agent 를 1자리수로 잡아도 마찬가지 To Many ERROR 로 테스트 불가
- 개선 후
  - Agent(1), Vuser (100) 10분
    - TPS : 25
    - ERROR : 0
    - Successful Test : 14,613
    - 🔥 테스트하는동안 OOME는 발생하지 않음…!

마무리

글을 최대한 문제해결 과정의 이상적인 순서대로 정리해보고자 노력했지만, 2달간의 트러블 슈팅이 이렇게 순탄하지만은 않았습니다.
OOM에 대한 대응도 처음이고, Dump 파일의 존재도 몰랐기 때문에 장애 원인파악 삽질에 대해 정말 굉장히 많은 "삽질"을 했습니다.

전혀 상관없는 부분을 파헤쳐보기도 하고, 빙빙 돌아 1달전 부하테스트 했던 자료를 꺼내 비교해보기도 했습니다.

많은 문서를 찾아보았고, 자료를 참고하여 [가설 → 테스트 → 검증 → 실패] 의 반복작업이었습니다.

심지어 dmesg 의 oom killer 는 이 글을 쓰면서 확인이나 한번 해보자는 느낌이었는데 정확하게 들어맞아 허무하기도 했습니다...
이걸 처음부터 확인했다면 얼마나 좋았을까하는 생각에,, 현타가 오기도하고, 그러기에 더욱더 꼼꼼히 적아야겠다는 생각이 들기도 했습니다.

대용량 부하 처리도, Scale-out 없고 비동기 처리같은 화려한 작업은 아니지만, 누군가에게 혹은 몆년후의 나에게 도움이 되길 바라며 글을 정리해 보았습니다.

23년 2월경에 적어놓은건데 1개의 작업이라도 마무리 지을 수 있어서 기쁘네요

더 좋은 해결 방법, 더 편한 모니터링 방법, 경험 혹은 피드백 주신다면 감사하겠습니다 :)

끝!

참고

'회고 > 일상 후기 회고' 카테고리의 다른 글

[YOUTHCON'23] 유스콘 2023 오프라인 참가 후기 (2)	2023.08.28
넥스트스텝 ATDD with Spring 수료 회고 (0)	2023.08.21
2022년 회고. 26살, 내가 개발자가 되기까지의 기록 (7)	2023.01.25
모의면접 (0)	2021.12.04
데브코스에 떨어졌다. 나만의 일정을 계획하자 (0)	2021.07.28

현재글[회고] "간헐적 메모리 장애" 삽질부터 트러블 슈팅까지

힘차게, 열심히 공대생