heap dump 살펴보기

기존의 AWS EC2 1G 메모리를 사용하며 배포하고 도커로 실행했다. 조금 더 좋은 성능을 위해 Naver Cloud Plaform 의 크레딧을 받아서 standard의 2vCPU, 4GB Mem, 50GB Disk의 조금은 짱짱한 서버를 이용해서 테스트도 해보고 분석해봤다.

진짜 신나게 삼일을 때려댔는데 cpu사용률이 저렇게 나와서 기분이 좋았다. VisualVM을 이용해서 서버와 remote연결해주고 자세히 살펴 봤다. 

CPU같은 경우 테스트 했을 때 어느순간 급격히 치솟는 구간이 증가했다. 서버자체에서 알려주는 결과와는 조금 다른 모습이었다. 자세히 살펴봐야하는 구간은 heap과 Threads이다. 

 

생존 스레드만 확인했는데 10개가 블록킹 되면서 빨간색으로 park됐다고 알려준다. 참고로 톰켓 스레드 지정해준적 없는데 왜 10개가 수행되는지는 잘 모르갰다. 다른 스레드들은 다른 곳에서 수행중일까? 하지만 All Thread로 확인해도 다른 스레드는 보이지 않았다. Thread도 dump할 수 있는데 소름끼치는 사실을 발견했다. 

"RMI TCP Accept-8500" - Thread t@11
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:474)
        at java.net.ServerSocket.implAccept(ServerSocket.java:565)
        at java.net.ServerSocket.accept(ServerSocket.java:533)
        at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:394)
        at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:366)
        at java.lang.Thread.run(Thread.java:829)

   Locked ownable synchronizers:
        - None

VisualVM과 서버와 포트 연결할 때도 컨테이너 쓰레드가 사용된다.. 조금 생각해보면 너무나 당연한 소리였는데 처음에 보고 놀랬다. 

 

그리고 원격지에서 jstatd 백그라운드로 실행했는데 VisualGC가 실행이 계속 안됐어서 진짜 고통스러운 시간을 보냈다. 

결국 로컬에서 똑같은 jar 실행하고 구경했는데 보고나니까 더욱 원격에서 확인해보고 싶었다. 그럼 얼마나 좋을까.. 누가 이글을 보면 해결법을 알려줬으면 좋겠다.. 

 

두번째로 사용한 분석도구는 MAT인데 또 jdk버전 문제때문에 이클립스 plug-in으로 사용했다. 

전
```
NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC       MCMN     MCMX      MC     CCSMN    CCSMX     CCSC    YGC    FGC   CGC
     0.0 1003520.0  73728.0    0.0 6144.0  67584.0        0.0  1003520.0    55296.0    55296.0      0.0 1124352.0  85956.0      0.0 1048576.0  12024.0     21     0    12
```
후
```
NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC       MCMN     MCMX      MC     CCSMN    CCSMX     CCSC    YGC    FGC   CGC
     0.0 1003520.0  75776.0    0.0 1024.0  74752.0        0.0  1003520.0    53248.0    53248.0      0.0 1128448.0  92100.0      0.0 1048576.0  12280.0     37     0    12
```


전
```
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
 0.0   6144.0  0.0   6144.0 67584.0  10240.0   55296.0    31436.0   85956.0 83278.0 12024.0 11045.9     21    0.391   0      0.000  12      0.071    0.463
```
후
```
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
 0.0   1024.0  0.0   1024.0 74752.0   6144.0   53248.0    39912.3   92100.0 89245.1 12280.0 11211.7     37    0.677   0      0.000  12      0.071    0.748
```


전
```
S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  0.00 100.00  15.15  56.85  96.88  91.87     21    0.391     0    0.000    12    0.071    0.463
```
후
```
S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  0.00 100.00   8.22  74.96  96.90  91.30     37    0.677     0    0.000    12    0.071    0.748
```

 

OOM이 발생한 것은 아니지만 수동으로 heap dump도 요청에 따라 여러개 만들었는데 가장 큰 파일 사이즈가 1억 바이트 밖에 안됐어서 분석도구 열때 최대 사이즈 같은건 따로 지정안했다. 

고작 10분이니까 저정도지 원래 하루 이틀 기간을 잡고 테스트를 해야한다.