Java+Groovy 그 치명적인 Memory leak
프롤로그
가끔씩 해킹관련한 드라마나 영화를 보면, 상대편 해커가 공공시설에 막 침입해서 전산망을 마비시키면, 갑자기 천재 주인공이 나타나서 그걸 다 막고 역으로 막 DDos공격까지 하고 막 그러네 헐... ㅋ
https://www.youtube.com/watch?v=EXE9NM9PmAs
그러나 현실은...
우선 저런 장면이 나오면, 저를 포함하여 제 주변에 저렇게 멋지고 깔끔하고 준수하고 댄디하면서 스마트한 개발자가 있는지 생각해보게 되고... 말도 안되는 장면들을 보며 현실 검증을 1도 안한 작가 및 피디들에게 투덜대게 됩니다...(내 옆에 소지섭이라니...)
뭐 저런 걸 다 양보한다고 해도 compiler를 필요로 하는 언어를 사용하는 개발자들은 우선 저런 순발력을 보여주기 어렵습니다...왜냐면 컴파일이 해야되거든~
그런 Java의 대안 Groovy?!
그런 측면에서 즉각적인 트러블 슈팅이나, 빠른 조치를 위한 언어로의 Java는 좋은 점수를 받기에 어려움이 있을 수 밖에 없습니다. (물론 개발과 운영을 겸하고 있는 대부분의 개발자들이 Java만을 하지는 않습니다. 또한 사족이지만, 제가 속해 있는 팀에도 Perl을 수준급으로 잘하시는 분들이 계신데, 정말 그 작업 속도와 순발력은 혀를 내두를 만 합니다. )
그렇기 때문에 groovy가 처음 나왔을 때 Java개발자 입장에서 Java의 약점을 보완하고 이끌어 나갈 수 있는 언어라고 생각했지만, 요 근래 트러블슈팅을 통해 알게된 Groovy의 취약점은 대고객 서비스에 사용하기에는 어려움이 있을 수도 있겠다라는 고정관념을 부여하기에는 충분했습니다.
그럼 지금부터는 제가 무엇때문에 이렇게까지 groovy에 대해 이야기를 하는지 Java + Groovy 조합에서 발생할 수 있는 이슈와 그 원인을 살펴보도록 하겠습니다.
ClassLoader와 parallelLockMap
통상적으로 main클래스가 실행되면, 우선 1차로 bootstrap classloader가 java.lang 패키지의 클래스들을 load하고, extension classloader가 java.ext.dirs($JAVA_HOME/lib/ext)에 존재하는 *.jar을 모두 load한 뒤, 세번째로 개발자가 정의한 클래스패스의 클래스들이 system classpath classloader에 의해 load되게 됩니다. 이 때 각 자식의 클래스로더는 이미 load된 클래스가 있는지 찾기 위해서 Delegation 패턴으로 super.loadClass()를 통해 원하는 클래스의 존재유무를 확인합니다.
그런데 아래의 소스를 보며 유심히 관찰해보면 아시겠지만, loadClass()에서 getClassLoadingLock() 메소드에서 return된 Object에 대해 synchronized를 걸고 있음을 알수 있는데,
1-1. ClassLoader.loadClass() --그나저나 브런치는 소스 Editor지원 안하냣!!!이는 Application단위에서의 Custom class loader와 같이 별도의 클래스로더에서 병렬적으로 클래스 loading이 동시에 일어날 때, 발생할 수 있는 Dead lock을 막기 위해 jdk7부터 등장하기 시작하였습니다.
1-2. getClassLoadingLock메소드그런데 문제는
Java 소스에서 GroovyEngineScript를 통해 script를 호출할 때, 아래와 같은 조건으로 호출이 된다면, Memory leak이 발생한다는 데 있습니다.
- 첫째, 지정된 몇개의 groovy script를 그대로 사용하는 것이 아니라 매 쓰레드마다 기 등록된 groovy script의 이미지를 clone하여 새로운 이름의 groovy script 파일로 만들어, 해당 clone된 스크립트를 GroovyScriptEngine을 이용하여 실행되도록 할때
- 둘째, Groovy script내에서 jvm classpath에 올라가 있는 객체에 대한 인스턴스를 생성하여 다시 java쪽 메소드를 지속적으로 호출하는 로직이 있을때.
그 이유는
Groovy script 내에서 기존 JVM에 올라가 있는 class의 인스턴스를 생성하는 로직이 있다면, 아래의 이미지 처럼 GroovyClassLoader에서 상위 클래스로더의 loadClass()를 호출하게 되는데,
1-3 GroovyClassloader.loadClass()메소드이 때 1-2 이미지에 파란색블록에 있는 것처럼 ConcurrentHashMap인 parallelLockMap에다가 매번 신규로 생성되는 Groovy script명 기반의 클래스명을 key로 putIfAbsent()를 하기 때문에, 신규클래스명인 경우에는 매번 put만 하게 되고 remove()를 호출하는 로직이 없기 때문에, 해당 JVM이 종료되지 않는 이상, 계속 parallelLockMap의 사이즈가 증가하게 됩니다.
즉, 위의 발생조건과 같은 구조로 되어 있는 경우에 있으면서 대량의 거래가 지속적으로 발생한다면, 어느정도 시간이 지났을 때는 Memory leak으로 인한 OOM은 피할 수가 없게 됩니다.
'에이 설마' 라고 생각하실 것 같아 아래와 같이 재현해보도록 하겠습니다.
재현
환경 및 조건
jdk1.8.0_92 + groovy 2.3.6
-Xms10m -Xmx18m -XX:MaxMetaspaceSize=30m -XX:+UseG1GC -Dgroovy.use.classvalue=true
Java에서 Thread를 400ms 기준으로 10개씩 생성하고 각 쓰레드는 groovy script를 호출하고 종료되도록 한다.
이때 원본이 되는 groovy script의 이미지를 떠서 새로운 이름으로 매번 생성한 뒤, GroovyScriptEngine 에서 해당 파일을 run()하도록 한다.
Groovy script에서는 java에서 정의한 Logging클래스의 인스턴스를 생성하여 해당 메소드 호출하여 logging처리가 되도록 한다.
VisualVM으로 heap memory상태와 thread 갯수를 체크한다.
jstat으로 메모리의 상태를 모니터링한다.
주기적으로 heapdump를 생성한다.
Groovy 스크립트에서는 그냥 로깅만 할뿐
PrintRunnabled.run()
@Override
public void run() {
Binding binding= new Binding();
long startDttm = System.currentTimeMillis();
StringBuilder sb = new StringBuilder();
sb.append("GroovyHandler_")
.append(Thread.currentThread().getName())
.append("_")
.append(startDttm)
.append(".groovy");
cloneFile(ORI_GROOVY_FILE_PATH, SPOOL_PATH+sb.toString());//groovy파일 복제
try {
Object rtnObj = gse.run(sb.toString(), binding);
} catch (ResourceException e) {
e.printStackTrace();
} catch (ScriptException e) {
e.printStackTrace();
}
deleteFile(SPOOL_PATH+sb.toString());//groovy파일 삭제
}
GroovyHandler.groovy
import eth.groovy.leak.log.Logging
Logging logger = new Logging()
String fullText = logger.converArrayToString("apple", "melon","grape", "banana")
logger.logging(fullText)
10분만의 죽음을 고객에게 알리지 말라...
약10분만에 Heap Memory가 다 차버림.jstat을 보면 아시겠지만, Full GC가 있어나도 old 영역이 제대로 빠지지가 않습니다. 왜냐하면, parallelLockMap에 저장된 string key값이 어마어마 하거든요!!!
장렬히 전사하기 40초 전! 빨간색으로 색칠된 Old영역을 주의깊게 보자.
목숨을 다해 임무를 수행하려고 한 쓰레드 군들에게 감사를!Heapdump분석
Heapdump분석을 통해서도 알수 있듯이, 3번째 예상원인이 ConcurrentHashMap에 저장된 String이라고 지목하고 있음을 알수 있습니다.
왼쪽이 테스트를 시작하고 얼마되지 않았을 때이며, 우측이 OOM으로 종료되기 직전의 parallelLockMap의 사이즈 변화입니다.
첨부하지는 않았지만, Suspect 1,2번도 Systemp class loader관련한 내용으로 결국 parallelLockMap과 관련되는 내용입니다.
실제 parallelLockMap의 사이즈 변화를 보시면 몇 십바이트 되지 않은 동적Script 명으로 인해 2배 가까이 증가됨을 알 수 있습니다. 우측이 OOM발생 전
실제 parallelLockMap의 key로 들어간 String value들을 보면 아래의 이미지와 같습니다. 실제 제가 groovy script를 clone하여 부여한 이름 'GroovyHandler_${Thread명}_${System.currentTimeMillis}' 값이 들어가 있는 것을 알 수 있습니다.
결론
Java+Groovy 조합으로 사용하는 것이 항상 문제를 일으키는 것은 아닙니다. 위의 작성한 조건처럼 매번 파일명이 바뀌는 Groovy스크립트를 호출하고 해당 스크립트안에서 기 로드된 클래스의 인스턴스를 생성할 때 Memory leak이 발생한다는 점을 말씀드리고 싶었습니다.
혹자는 이 글을 보고 '누가 이런 환경대로 쓰겠어요.' 할 수 있겠지만, 위의 환경이 실제 수억짜리 솔루션 제품의 환경이며 그걸 운영하면서 트러블 슈팅한 내용을 정리해본 것입니다.
솔루션업체 입장에서도 저렇게 한 이유를 찾아보자면 script 이미지를 clone하는 시점에 원하고자 하는 string을 더 넣거나, 아니면 하드코딩된 value를 다른 값을 치환하기 위함일텐데, 굳이 저렇게 했어야 했을까 하는 생각도 듭니다.
또한 업체 입장에서야 '에이 적이도 한달에 한번은 재기동하셔야지요'라고 하면서 Heap size를 엄청 늘리면 된다라고 할수 있겠지만, 운영도 하고 있는 담당자 입장에서는 폭탄을 안고 있는 심정이라 항상 불안 초조 서스펜스…뭐 그렇습니다. 해당 건이 아키텍처적인 문제이기 때문에 재기동말고는 답도 없는지라… 참 여러모로 아쉬운 점이 많은 제품입니다. (하고 싶은 말은 많지만...쩝)
해당 테스트가 JDK8으로 진행하긴 했지만, 그 이상 버전에서도 parallelLockMap처리가 달라지지 않은 것으로 알고 있기 때문에 아무쪼록 Java+groovy 조합으로 사용하실 때는 이런 risk를 감안하시어 개발하시기를 바래보며, 이만 줄여봅니다.
gitlab소스
https://gitlab.com/heracul/eth.groovy.leak.git
참고문헌
https://zeroturnaround.com/rebellabs/rebel-labs-tutorial-do-you-really-get-classloaders/2/https://www.baeldung.com/java-classloaders
