본문 바로가기
일/java

Java 비동기 서버 Trouble Shooting :: Heap MEM, Thread Pool

by blair2dev 2022. 2. 21.
  • Stress Test 
    • 컨슈밍 방법을 earliest 로 바꾸고 15일간 데이터를 한번에 땡겨 오도록 한다. 
  • 현상 관찰
    • 카프카 
      Offset commit with offsets {A.ETM.book-8=OffsetAndMetadata{offset=11364522, leaderEpoch=null, metadata=''}} failed org. apache.kafka.clients.consumer.RetriableCommitFailedException: Offset commit failed with a retriable exception. You should retry committing the latest consumed offsets. Caused by: org.apache.kafka.common.errors.DisconnectException: null 
    • MySQL 
      ### Error updating database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 39003ms.
      ### Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 39003ms. 
      at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30) at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:200) at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:185) at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source) 
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:434)
      ... 26 common frames omitted
      Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 39003ms.
      at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:82)
      atorg.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:84)
      at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:70)at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:337)at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:49)at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117)at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76)at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:198).. 31 common frames omittedCaused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 39003ms.at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:695)at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:158)at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:116)at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:79)... 39 common frames omitted 

    • 메모리 
      Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded 

힙이 부족할 때 OutOfMemoryError 스택이 부족할 떄 stackOverFlow가 뜬다고 한다.

https://haloworld.tistory.com/139 

따라서 힙 메모리 부족으로 메모리 에러가 뜨고 네트웍 스레드와 디비 커넥션 스레드의 연쇄 에러가 생겼던 것으로 추정한다.

 

java 실행 parameter 수정 

java -Xss256m -Xms32g -Xmx32g -XX:PermSize=50g -XX:MaxPermSize=80g -javaagent:${PROM_JMX_EXPORTER} =8779:${PROM_JMX_CONF} -jar UBAS.jar --spring.profiles.active=prod 

 

-Xss : 각 Thread에 할당되는 Stack size 설정 

-Xms : 초기 Heap size 설정
-Xmx : 최대 Heap size 설정
-Xmn : New 영역을 위한 Heap size 설정 

-XX:PermSize : 초기 Permanent size 설정 -XX:MaxPermSize : 최대 Permanent size 설정 

 

Xms, Xmx를 동일하게 세팅하는 이유 

init와 max사이에서 used 메모리가 committed까지 사용하게 되면, 신규 메모리 공간을 요구하는데 이 때 약 1초가량 jvm이 메모리 할당 중 멈춰버리는 경우가 있다. 그래서 Xms와 Xmx를 동일하게 주고 메모리를 확보한 상태에서 jvm을 기동시키곤 한다. 

 

 

java 메모리 구조

Heap = Edn + Survivor + Old
Non-Heap = Perm
Heap영역 : new 연산자로 생성된 객체와 배열을 저장하는 영역으로 GC 대상이 되는 영역이다. 

Eden : new 키워드를 통해서 객체가 처음 생성되는 공간
Survivor : CG가 수행될 때 살아있는 객체는 survivor영역으로 이동된다. (임시피난소) Old : survivor에서 일정시간 참조되는 객체들이 이동되는 공간 

Non-Heap영역 : 스택, 클래스 area, method area 등의 heap영역을 제외한 녀석들
Permanent : Class 메타정보, Method 메타정보, Static Object, 상수화된 String Object, Calss관련 배열 메타정보, JVM내부 객체와 최 적화컴파일러(JIT)최적화 정보 등 포함 

 

 

Java 8 이후에는 아래와 같이 바뀌었음 

 

Metaspace가 Native Area(=Native Memory, Off-Heap, Non-heap, Direct Memory 등)인 것에 주목하자.
Java 8부터 기존의 Permgen 메모리가 Metaspace로 바뀌면서 Native Memory에 할당되게 되었다.
Native Memory는 Heap 영역의 바깥인 Off-Heap 공간을 의미하는 것으로 쉽게 시스템의 기본 메모리라고 생각하면 된다. 

참고로 다음 키워드는 Metaspace와 같다.
(= Native Area, Native Memory, Off-Heap, Non-heap, Direct Memory 등 ) 

 

  • Java 어플리케이션은 크게 Heap과 Metaspace 두 공간을 활용하여 동작한다.
    그러므로 어플리케이션 메모리를 결정하기 위해서는
    단순히 Xmx(Heap 메모리 최대치를 결정하는 Java 옵션) 값만 생각하면 OOME에 빠지기 쉽다.
  • 실제로는 Xmx에 MaxMetaspace 값을 더하고Native Memory를 직접 할당받는 로직을 고려해서
    Heap + Metaspace 사용량을 할당해야 비교적 정확하다.
    추가로 프로그램에서 NIO(Non-blocking I/O)를 통해
  • https://goodgid.github.io/Java-8-JVM-Metaspace/

 

메모리 테스트 

메모리 파라미터를 바꿔가며 실제로 메모리가 부족한 것인지 알아본다. 서버 메모리 : 131GB
카프카 레코드 수 : 2,968,139,290 약 30억개 (retention : 15일) 

[root@napp01 bin]# ./kafka-run-class.sh kafka.tools.GetOffsetShell --broker-list kafkaBroker:9092 --topic A.ETM.shop --time -1 

A.ETM.shop:0:194719806 

A.ETM.shop:5:194732122 

A.ETM.shop:2:194724977 

A.ETM.shop:8:194714042 

A.ETM.shop:9:194729767 

A.ETM.shop:1:194727305 

A.ETM.shop:4:194717882 

A.ETM.shop:6:194721601 

A.ETM.shop:7:194725467 

A.ETM.shop:3:194726814 

[root@napp01 bin]# ./kafka-run-class.sh kafka.tools.GetOffsetShell --broker-list kafkaBroker:9092 --topic A.ETM.tour --time -1 

A.ETM.tour:0:24353276 

A.ETM.tour:5:24510574 

A.ETM.tour:8:24407123 

A.ETM.tour:2:24302693 

A.ETM.tour:9:24373260 

A.ETM.tour:4:25070734 

A.ETM.tour:1:24307360 

A.ETM.tour:6:24677115 

A.ETM.tour:7:24675827 

A.ETM.tour:3:24275619 

[root@napp01 bin]# ./kafka-run-class.sh kafka.tools.GetOffsetShell --broker-list kafkaBroker:9092 --topic A.ETM.ticket --time -1 

A.ETM.ticket:0:31079961 A.ETM.ticket:5:31076848 A.ETM.ticket:2:31078955 A.ETM.ticket:8:31079243 A.ETM.ticket:9:31077695 A.ETM.ticket:1:31080469 

A.ETM.ticket:4:31079378 

A.ETM.ticket:6:31078251 

A.ETM.ticket:7:31077922 

A.ETM.ticket:3:31079277 

[root@napp01 bin]# ./kafka-run-class.sh kafka.tools.GetOffsetShell --broker-list 10.66.1.146:9092,10.66.1.147:9092,10.66.1.148:9092 --topic A.ETM.inter --time -1 

A.ETM.inter:0:34064140 

A.ETM.inter:5:34063265 

A.ETM.inter:8:34064280 

A.ETM.inter:2:34064713 

A.ETM.inter:9:34063691 

A.ETM.inter:1:34065033 

A.ETM.inter:4:34062772 

A.ETM.inter:6:34061815 

A.ETM.inter:7:34063568 

A.ETM.inter:3:34063601 

[root@napp01 bin]# ./kafka-run-class.sh kafka.tools.GetOffsetShell --broker-list kafkaBroker:9092 --topic A.ETM.book --time -1 

A.ETM.book:0:12596746 A.ETM.book:5:12634571 A.ETM.book:8:12631081 A.ETM.book:2:12637217 A.ETM.book:9:12596962 A.ETM.book:1:12637479 A.ETM.book:4:12636491 A.ETM.book:6:12634423 A.ETM.book:7:12632147 A.ETM.book:3:12636905 

 

total : 2,968,139,290 

 

 

메모리 테스트 1 :: heap size : 32g 

java -Xss256k -Xms32g -Xmx32g -XX:MetaspaceSize=50g -XX:MaxMetaspaceSize=100g -javaagent:${PROM_JMX_EXPORTER} =8779:${PROM_JMX_CONF} -jar UBAS.jar --spring.profiles.active=prod 

Thread pool 대기 큐에 약 천만개가 쌓이다가 멈춤. 

 

리소스 조회

top
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

186380 root 20 0 49.8g 33.5g 14508 S 2296 26.7 208:47.42

 

java  메모리 사용량 조회

jmap -heap pid 

 

메모리 파라미터를 32g 로 주었을 때 전체 메모리의 26.7% 이상으로 올라가지 않고 프로세스 중단되었고 jmap 으로 heap 메모리 조회시 99% 로 나왔다.
CPU 사용률은 2200% 이지만 코어수가 32개이므로 부족하지 않아보임. 

 

 

메모리 테스트 2 :: heap size : 120g 

파라미터를 서버 메모리 최대치에 근사하게 주고 다시 실험해보았다. 

java -Xss256k -Xms120g -Xmx120g -XX:MetaspaceSize=50g -XX:MaxMetaspaceSize=80g -javaagent:/root /jmx_prometheus_javaagent-0.15.0.jar=8779:/root/kafka-2_0_0.yml -jar UBAS.jar --spring.profiles.active=prod 

대기 중인 작업이 3천만 까지 오르다 멈춤 

 

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 

 

13502 root 20 0 141.0g 119.1g 4356 S 2037 94.8 91:53.26

 

메모리 파라미터를 120g 로 주었을 때 전체 메모리의 약 95% 이상으로 올라가지 않고 프로세스 중단되었고 jmap 으로 heap 메모리 조회시 99% 로 나왔다.

 

 

공통 

DB 서버의 리소스는 테스트간에 변화가 미미했음 (2% 내외) -> DB 의 문제가 아님

 

 

CONCLUSION

현상 : 

earliest로 프로세스를 실행시키면 수 분내로 프로세스가 프리징 걸린다. 

원인 유추 : 

java 실행시 heap 메모리 할당 을 높이면 높이는 대로 full 이 난다. (top, jmap 으로 확인 하였음) 따라서 메모리 full이 프로세스 프리징의 주 원인. 

프로세스 메모리 모니터링화면에서 보면 힙 사이즈 늘리는 만큼 비례하며 커지는 것이 "현재 대기중인 작업"이다. 따라서 데이터 병목이 걸리는 구간 은 thread 생성 전의 자바 스레드 큐이다. 

 

메모리 부족 해결책 강구 : 

 

물리 메모리 추가? : heap 사이즈를 늘리면 늘리는대로 순식간에 full이 나기 때문에 메모리를 매우 많이 늘려야 해결책이 될 수 있을 것으로 보인다. 131gb 에 3000만까지 버텨주니 30억개에 대응하기 위해서 단순계산으로 13TB 의 메모리가 필요할 것 으로 보임. 

분석 스레드 수 증가? : 분석 스레드의 수를 늘려도 데이터가 그쪽으로 이동했을 뿐이니 메모리가 들고있는 데이터의 총량이 변하지 않으므로 메모리 풀 해결 책은 안될 것 같음 

세션 만료 시간 단축? : 메모리 해소를 해주는 로직은 세션 만료 뿐인데 30분 기다려야 하고 그전에 무조건 full 되므로, 세션 만료 시간을 줄이는 방법이 있지 만 그러면 정책이 달라지므로 힘들듯. 

컨슈머 속도 조절? : 대기 스레드 레코드 수에 따라 수집 모듈의 속도를 줄이면 해결책이 될 수 있을 것으로 보임 

 

결론 : 

해결책을 강구 해본 결과
1. 컨슈머 속도 조절로직 추가

다량 데이터 유입에 대한 대응책으로 스레드 풀 대기 작업 수에 대응하는 컨슈머 속도 조절 로직 추가가 필요해 보인다. 

대기 작업수의 값를 수집 모듈에서 받아서 이 값에 따라 컨슈머 속도를 조절하는 로직 추가 필요 

 

2. 자바 스레드 큐의 MAX수치를 조절 

아래 setQueueCapacity(Integer.MAX_VALUE) 이 값이 자바 스레드 큐 (현재 대기중인 작업) 의 맥스 값을 정의 한다. 

이 큐 값이 지정값을 넘어가면 setMaxPoolSize 에 지정된 갯수 (200) 까지 워커스레드의 갯수를 증가시킨다. 

따라서 현재 값으로는 20억이 넘어야 워커 스레드 수가 200 으로 증가 되는데 

현재 메모리 용량으로는 3000만이 한계이다.  

큐사이즈를 적절히 낮추고 워커스레드 수를 높여서 처리를 더 빠르게 한다면 성능향상에 도움이 될 것이다.

 

 

 

 

 

 

저작자표시

'일 > java' 카테고리의 다른 글

java 동시성 제어  (0) 2022.02.09
Java Spring Boot Multi Threading  (0) 2022.01.11

관련글

티스토리툴바