아무거나 시도해보는 개발일지

Heap Memory

프로그램이 구동되기 위해서는, 먼저 메모리에 올라가야한다.

메모리는 크게 4가지 ( Code, Data, Heap, Stack ) 으로 나뉘어있다.

그중에서 동적으로 할당되고 해제되는 영역인, Heap Memory 관련해서 작성하려한다.

c에서는 malloc(), free() 등으로 할당과 해제를 반복하며,

java에서는 GC ( Garbage Collector ) 를 통해 자동으로 정리해준다.

2021.04.04 - [서버운영/자바 GC ( Garbage Collection )] - GC ( Garbage Collection )

Heap Dump

Heap Memory는 프로세스가 동작할때 최소/최대 메모리를 지정하며, 할당된 메모리 안에서 동적으로 운영된다.

그리고 할당된 메모리가 부족한 경우, OOM ( Out Of memory )가 발생하며 프로그램이 종료된다.

1) 메모리 누수로 인해 정리가 되지않아, 최대 메모리 사용량에 도달했을 때
2) 현재 남아있는 메모리보다 큰 리퀘스트가 들어왔을 때

OOM이 발생하면 그때의 Heap Memory 상태 스냅샷을 확보할수 있으며,

.hprof 확장자의 heap dump 파일로 저장된다.

-XX:-HeapDumpOnOutOfMemoryError : OOM 발생시 Heap dump 생성
-XX:HeapDumpPath                         : Heap dump 파일의 위치

OOM이 없더라도, 메모리 누수가 의심되거나 현재의 메모리 상태를 확인하고 싶을 때

jmap을 사용하여, 수동으로 Heap memory 상태를 dump 파일로 저장할 수도 있다.

jmap -dump:format=b,file=$PATH/$file.hprof $PID

Heap dump 분석

주로 Eclipse MAT ( Memory Analyzer Tool )을 사용한다.

사용전에 설치폴더 MemoryAnalyzer.ini 설정파일을 열어, 분석툴의 메모리를 정해주어야한다.

기본 1GB로 되어있지만, Heap dump 파일이 그보다 큰 경우 프로그램이 종료되기 때문이다.

이후에 파일을 넣어주면 아래와 같은 화면이 나온다.

문제로 예상되는 17번 쓰레드가, 전체 1.5GB 중에 94.54%를 차지하고 있었다.

웹로직 기반의 쓰레드이며, MAT는 char[]를 로드하려다가 문제가 발생한것으로 예상했다.

오브젝트 리스트를 살펴보면, MAT 예상대로 char 배열이 1.5GB 대부분을 차지중이었다.

해당 Thread dump 를 분석해보았다.

대략 분석해보면

1) OOM이 발생했고

2) Array, String Builder 즉 위의 Char[] =1.5GB 짜리를 String 으로 변환하려다 발생한 OOM?

   혹은 추가로 Char 배열이 들어오려다, 메모리가 부족해서 OOM이 발생한것으로 보인다

3) voc 관련한 소스코드쪽에서 유발된 것 같다

실제 분석결과, VOC 본문 ( content ) 작성 시

사용자가 프로그램 예약어를 사용해서 무한루프가 돌면서 내용 생성되는 문제가 있었다.

물론 Dump 분석으로는 정확한 유발지 및 원인을 찾기는 어렵지만,

이처럼 대략적인 방향을 잡을수있다.

Thread란

프로세스 내에서 실행되는 흐름의 단위
※ 프로세스 : 특정 서비스를 위해, OS내에서 메모리를 할당받아 수행되는 프로그램

하나의 프로세스에 여러개의 쓰레드가 존재할 수 있으며, 각 쓰레드는 아래의 상태값을 가진다.

① NEW : 스레드가 생성되었지만 스레드가 아직 실행할 준비가 되지 않았음
② RUNNABLE : 스레드가 실행되고 있거나 실행준비되어 스케쥴링은 기달리는 상태
③ WAITING : 다른 스레드가 notify(), notifyAll()을 불러주기 기다리고 있는 상태(동기화)
④ TIMED_WAITING : 스레드가 주어진 시간동안, 대기하고 있는 상태
⑤ BLOCK : 사용하고자하는 객체의 Lock이 풀릴때까지 대기하는 상태
⑥ TERMINATED : 스레드가 종료한 상태

JVM에 의해 관리되며, 설명해놓은 그림이 있어 가져와봤다.

Thread dump

프로세스에 수행중인 모든 쓰레드들의 상태를 스냅샷 수행

보통 아래 상황일때 Thread 분석을 한다.

1) 어플리케이션이 Hang 상태일 때

2) 서비스 처리가 늦어질 때

3) CPU 사용량이 높을 때

Thread Lock이 원인일수도, 여유 Thread가 없어서 일수도 있다.

SQL 지연일수도, 특정 코드 Stack 에서 막힌것일수도 있어 분석툴로 확인해야한다.

하지만 하나의 스냅샷만으로는 정확한 원인파악이 어렵다.

여러개의 스냅샷을 비교하며, 쓰레드의 변화상태를 통해야만 특정 쓰레드를 원인지을수 있다.

빠른시간내에 여러개 덤프를 떠서, 순간의 변화사항 분석이 필요하다

( Ex: 5초내 여러개 Thread dump 획득 )

생성방법

1) kill -3 $PID

2) jstack 활용

jps-v 로 PID를 확인 가능하며, ps -ef | grep 을 통해서도 특정 PID를 알 수 있다.

jstack $PID > log.txt

분석

일반적으로 쓰레드 덤프 구조는 아래와 같다

"pool-1-thread-13" prio=6 tid=0x000000000729a000 nid=0x2fb4 runnable [0x0000000007f0f000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)at java.net.SocketInputStream.read(SocketInputStream.java:129)at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)- locked <0x0000000780b7e688> (a java.io.InputStreamReader)at java.io.InputStreamReader.read(InputStreamReader.java:167)at java.io.BufferedReader.fill(BufferedReader.java:136)at java.io.BufferedReader.readLine(BufferedReader.java:299)- locked <0x0000000780b7e688> (a java.io.InputStreamReader)at java.io.BufferedReader.readLine(BufferedReader.java:362) 

쓰레드 이름: Thread-(Number) 혹은 pool-(number)-thread-(number)로 지정된 고유이름

우선순위 : 쓰레드의 우선순위

쓰레드 ID

쓰레드 상태

쓰레드 콜스택

저런 로그들이 쓰레드마다 존재하기에, 육안으로 구별하기는 힘들다.

보통 분석툴을 사용하여 변화사항을 비교한다.

분석툴

1) Ibm thread and monitor dump analyzer for java

2) fastThread ( https://fastthread.io/ )

분석예시

※ 해당부분은 타 블로그에서 분석한 내용을 가져와 서술하였습니다. - CPU 사례

( https://d2.naver.com/helloworld/10963 )

앞선 케이스에서는 튜닝 포인트가 없다. 또한 GC 튜닝은 권장되지 않는 작업이다.

하지만 극단적인 케이스에서는, GC로 인한 서비스 순단을 최소화 할 수 있다.

- 튜닝이 필요한 케이스?

GC 시간 및 주기를 파악해보고, 정상여부 확인

- 튜닝 대상

1. Old 영역으로 넘어가는 객체 최소화 

Full GC는 Minor GC에 비해 5~10배 이상 오래걸린다.

그래서 Old 영역에서의 GC보다는, New 영역안에서 이루어지는 GC만으로 메모리 관리하는 것이 가장 좋다.

2. Full GC 시간 단축

GC시에는 stop-the-world 로 인해 프로세스가 멈추므로 , GC 시간을 최소화 하는것이 좋다

특히 Full GC는 시간이 오래걸리기때문에, 연계 프로세스에서 타임아웃이 걸릴수도 있다.

Old 영역의 크기를 잘 조절하여 GC 시간을 관리하여야 한다.

Old 영역을 줄인다

=> Full GC 시간은 줄어드나, 횟수가 증가함. 남은 Old 영역보다 많은 객체가 들어올 경우 OOM 발생

Old 영역을 늘린다

=> Full GC 횟수는 줄어드나, 시간이 증가함

- 튜닝 작업

※ 각 시스템, 서버, 프로그램 마다 변수가 다양하기 때문에 정해진 값이나, 권고 값은 없다.

   설정값 변경후에, 모니터링을 하며 ( 최소 24시간 ) 맞는 값을 찾아가야한다.

1. GC 방식 결정

• Serial GC - 적은 메모리와 CPU 코어수가 작을 때 유리
• Parallel GC - 메모리와 코어수가 많을때 유리. Serial과 다르게 다중 스레드 처리
• Concurrent Mark & Sweep GC(이하 CMS) - 응답속도가 매우 빠르나, 메모리와 코어를 가장 많이 잡아먹는다.
• G1(Garbage First) GC - Young / Old 에 개념이 없고, 객체별로 객체 할당 및 GC가 이루어짐. JDK 7 버전부터 적용

자세한 내용은 ( d2.naver.com/helloworld/1329 ) 참조

2. 메모리 설정

먼저, 힙 메모리의 크기를 정해준다.

다음으로 할당된 메모리중에서 , New/Old 영역의 비율을 결정해준다.

3. 설정값 적용 후, 모니터링하며 값들을 수정한다.

#참조

d2.naver.com/helloworld/37111

GC 분석 방법에는 여러가지가 있다.

1. gceasy

- 별도 프로그램 설치없이, ( gceasy.io/ ) 접속 후에 로그파일을 올리기만 하면된다.

2. IBM JAVA Garbage Collector ( PMAT )

- 다운로드 : www.ibm.com/support/pages/node/1109973

- 실행 : java -Xmx1g -jar ga458.jar

- File -> Open verbosegc 수행후 gc.log 파일을 넣어주면 아래와 같이 요약본이 나온다.

- 표로 GC를 Timestamp 별로 정리해서 볼수도 있다.

- 그래프로 시간대별 GC 수행시간 / 수행전후 메모리 사용량 등을 확인할 수 있다.

- GC 비율 및 수행시간 확인

Minor GC : 4922회 수행/ 평균 10ms

Full GC : 27회 수행 / 평균 310ms 수행

3. Java VisualVM

- Jdk1.6 부터 bin 밑에 존재하는 JVM 분석 툴

- visualvm.github.io/에서 따로 내려받을수도 있다.

4. HP Jmeter

- HP에서 제공하는 분석툴

- m.blog.naver.com/PostView.nhn?blogId=bumsukoh&logNo=110142702864&proxyReferer=https:%2F%2Fwww.google.com%2F

gc.log 분석하는 방법을 작성해보려한다.

JVM 기동옵션은 아래와 같다.

GC 로그파일은 아래와 같다.

- Minor GC

한줄씩 분석해보면,

{Heap before GC invocations=1 (full 0):

- invocations=1 : 프로세스가 구동되고, 발생한 GC의 횟수

- full 0 : 발생한 Full GC 횟수

 PSYoungGen      total 354304K, used 315392K [0x00000007a8000000, 0x00000007c0000000, 0x00000007c0000000)
 PSYoungGen      total 354304K, used 19963K [0x00000007a8000000, 0x00000007c0000000, 0x00000007c0000000)

- Young Generation이 354,304KB 중에 315,392KB 사용중 -> 19,963KB 사용

  eden space 315392K, 100% used [0x00000007a8000000,0x00000007bb400000,0x00000007bb400000)
  from space 38912K, 0% used [0x00000007bda00000,0x00000007bda00000,0x00000007c0000000)
  to   space 38912K, 0% used [0x00000007bb400000,0x00000007bb400000,0x00000007bda00000)
  
  eden space 315392K, 0% used [0x00000007a8000000,0x00000007a8000000,0x00000007bb400000)
  from space 38912K, 51% used [0x00000007bb400000,0x00000007bc77ede8,0x00000007bda00000)
  to   space 38912K, 0% used [0x00000007bda00000,0x00000007bda00000,0x00000007c0000000)

- Eden 영역 100% 사용으로 인한 GC 발생으로 보임.

- GC후에 Survivor From 영역으로 이동. Eden 0% 사용

 ParOldGen       total 2228224K, used 0K [0x0000000720000000, 0x00000007a8000000, 0x00000007a8000000)
  object space 2228224K, 0% used [0x0000000720000000,0x0000000720000000,0x00000007a8000000)
 Metaspace       used 11772K, capacity 12066K, committed 12160K, reserved 1060864K
  class space    used 1284K, capacity 1401K, committed 1408K, reserved 1048576K

- New 영역에 대한 Minor GC 였으므로, Old 영역은 변화가 없음

4.788: [GC (Allocation Failure) [PSYoungGen: 315392K->19963K(354304K)] 315392K->19979K(2582528K), 0.0095085 secs] [Times: user=0.14 sys=0.02, real=0.01 secs] 

GC 결과 요약

- GC ( Allocation Failure ) : GC 발생이유. 메모리 할당 실패로 인한 GC발생

- Young 영역 정리 ( 315,392KB -> 19,963KB , 354,304KB 정리 )

- 0.0095초 소요

- Full GC

- from 영역의 Full로 인한 Full GC

- Old 영역이 107KB -> 38,122KB 로 증가

- GC 소요시간은 0.053초 정도. Minor GC 의 5배 정도 시간이다. ( 0.3초까지 걸리기도 함 )

GC로 인해, 시스템에 장애가 올수도 있으므로 모니터링 및 관리가 필요하다.

※ 오랫동안 Full GC 발생하는 경우

1. Full GC 시간동안 Stop the world로 인해, 서비스가 중지되고

2. 그동안 쌓여있던 Queue로 인한 서비스 부하

※ Old 영역이 작게 할당되있을 경우

Old 영역이 작다면, Full GC의 수행시간이 짧아질수 있다.

그러나 계속 사용되는 객체 양에비해, Old 영역이 작다면 OOM이 발생할 것이다.

관리 옵션

JVM 기동 시, 자원 관련한 옵션들을 간단하게 정리해보았다.

-Xms , -Xmx : Heap 메모리 초기 할당값, 최대값 ( OS에서 프로세스에 할당해주는 값 )

-XX:NewSize : New 영역의 초기 할당값

-XX:MaxNewSize : New 영역의 최대값

-XX:NewRatio : New / Old 영역의 비율

-XX:SurvivorRatio : New / Survivor 영역의 비율

-XX:+UseParallelGC : 다중 스레드로 GC를 수행한다

모니터링 옵션

- GC 수행결과를 출력한다.

-XX:PrintGCDetail : GC에 대한 상세 정보를 출력

-XX:PrintGCTimeStamps : GC 수행시간에 대한 정보 출력

-XX:PrintHeapAtGC : GC시에 힙메모리 정보 출력

- OOM ( Out of Memory )발생시 , 당시에 Heap 메모리 사용량을 파일로 떨어트린다.

※ Heap 메모리 사용량과 동일한 용량으로 파일이 생성되므로, F/S 여유공간을 꼭 확인할 것

-XX:-HeapDumpOnOutOfMemoryError : OOM 발생시 Heap dump 생성

-XX:HeapDumpPath                         : Heap dump 파일의 위치

# 참조

waspro.tistory.com/340 ( GC 옵션 )

www.holaxprogramming.com/2013/07/20/java-jvm-gc/ ( JVM 기동 옵션 )

GC , 가비지 컬렉션 이란?

자바 프로세스가 동적으로 할당했던 메모리 영역중에, 필요없는 영역을 해제하는 기능

=> GC가 없다면, 더이상 사용하지 않는 잉여객체들이 메모리를 모두 차지해

     OOM ( Out of Memory ) 가 발생하면서 프로세스가 종료될 것.

- 장점

1. 프로그래머 입장에서 완벽하게 메모리 관리를 하지 않아도 된다.

  => 바라보고 있는 포인터, 언제 어떤 메모리를 해제할지 신경쓰지 않아도 됌

2. 불필요한 자원을 해제하여, 메모리 초과 방지

- 단점

1. GC 과정속에서 비용이 발생한다.

2. GC의 타이밍을 결정할 수 없다.

  => GC시에 stop-the-world 현상이 발생하여, 서비스 순단이 있을수 있다.

※ stop-the-world : GC 실행시, 자원을 해제하기 위해 JVM이 어플리케이션 실행을 멈추는 것

프로세스

GC의 대상은 크게 Eden, Survivor From/To, Old 영역이고, 대상에 따라 Minor, Full GC 로 구분할 수 있다.

Minor GC

1. 새로 생성된 객체가 Eden 영역에 할당된다.

2. Eden 영역에서 GC가 일어나고, 계속 사용하는 객체들은 Survivor From 영역으로 이동한다.

3. 다음 GC가 일어날때, From 영역의 객체들은 Survivor To 영역으로 이동한다.

4. Survirvor From 영역은 Clear 해지고, 계속되는 GC속에 살아남은 객체들은 Old 영역으로 옮겨진다.

Full GC

1. Old 영역에서 수행되는 GC를 Full GC라 하며, Minor GC 보다 시간이 더 소요된다.