제목 : 솔라리스에서 GC 로그 이상현상 문의.
글쓴이: 김기호(parankiho) 2007/05/10 11:50:06 조회수:427 줄수:116
모 사이트에 WAS 관련 지원중 발생한 문제입니다.
제가 솔라리스 JVM을 한번도 사용해 본적이 없어서 문의 드립니다.
아래 로그를 보시면 시작하자마자 Full GC 이고
계속해서 Full GC 라고 GC Log에 찍힙니다.
(아래 로그는 일부이지만 처음부터 끝까지 아래와 동일하다고 보시면 됩니다.)
하지만 보시다시피 Old, 즉 Tenured Generation 의 사용량은 거의 없습니다.(10% 미만)
자세히 보면, Old나 New 영역이 조금씩 증가하기만 하는데도 무조건 Full GC 라고 기록이 됩니다.
JVM 셋팅은 Incremental GC 등의 옵션을 사용한것도 아니고 default 입니다.
Heap 의 초기값을 1GB로 잡았으니, 기본 설정대로
New 에 300정도 Old 에 700 정도가 할당이 되어서 시작하는데
왜 Full GC 라고 찍히는지 이해가 가질 않는 군요.
(메모리 크기에 비해 시간이 0.3초 정도인걸로 봐서는 정말 Full GC 인듯 한데..)
perm size 의 경우는 확인결과 32m 이상 늘어나지 않는걸 확인했습니다만..
게다가 HP 나 IBM 처럼 상세한 GC 내역을 보여주는 옵션(HP의 경우 -Xverbosegc:file)도 없는 듯 합니다.
마지막으로 WAS 재기동시 HP 의 경우는 GCLog가 프로세스 아이디에 따라 새로 생성되는데
솔라리스의 경우 기존 GCLog를 덮어써버리는군요(뒤에 추가되는것도 아니고)
정리하자면
1. Full GC 상황이 아닌데 Full GC 라고 보여진다. 혹시 솔라리스의 기본 GC 정책의 특별함이 있는지?
아니면 어떤 이유로 Full GC 가 발생하는건지
2. 솔라리스 JVM 에서 상세한 GC Log 를 찍는 옵션이 있는지.
있다면 무었인지
3. WAS 재기동시(즉, JVM의 재실행) 기존 GC Log 를 덮어쓰지 않는 방법이 있는지.
입니다.
많은 초/중/고수분들의 도움 부탁드립니다.....
=========================================================
Solaris 10
jdk : 1.4.2_11 (64bit)
was : jeus 4.2.2.3
jvm memory option : -Xms1024 -Xmx1024 -XX:PermSize=32m -XX:MaxPermSize=64m
==========================================================
0.000: [Full GC {Heap before GC invocations=0:
Heap
def new generation total 339264K, used 25335K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 7% used [0xffffffff31c00000, 0xffffffff334bdf50, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 0K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 0% used [0xffffffff47150000, 0xffffffff47150000, 0xffffffff47150200, 0xffffffff71c00000)
compacting perm gen total 65536K, used 9230K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 14% used [0xffffffff71c00000, 0xffffffff72503820, 0xffffffff72503a00, 0xffffffff75c00000)
0.000: [Tenured: 0K->3715K(699072K), 0.1251362 secs] 25335K->3715K(1038336K), [Perm : 9230K->9230K(65536K)] Heap after GC invocations=1:
Heap
def new generation total 339264K, used 0K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 0% used [0xffffffff31c00000, 0xffffffff31c00000, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 3715K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 0% used [0xffffffff47150000, 0xffffffff474f0c80, 0xffffffff474f0e00, 0xffffffff71c00000)
compacting perm gen total 65536K, used 9230K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 14% used [0xffffffff71c00000, 0xffffffff72503820, 0xffffffff72503a00, 0xffffffff75c00000)
} , 0.1253746 secs]
4.257: [Full GC {Heap before GC invocations=1:
Heap
def new generation total 339264K, used 78520K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 23% used [0xffffffff31c00000, 0xffffffff368ae0b0, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 3715K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 0% used [0xffffffff47150000, 0xffffffff474f0c80, 0xffffffff474f0e00, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18388K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72df5268, 0xffffffff72df5400, 0xffffffff75c00000)
4.257: [Tenured: 3715K->14119K(699072K), 0.2477265 secs] 82235K->14119K(1038336K), [Perm : 18388K->18388K(65536K)] Heap after GC invocations=2:
Heap
def new generation total 339264K, used 0K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 0% used [0xffffffff31c00000, 0xffffffff31c00000, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 14119K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 2% used [0xffffffff47150000, 0xffffffff47f19ec8, 0xffffffff47f1a000, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18388K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72df5268, 0xffffffff72df5400, 0xffffffff75c00000)
} , 0.2479585 secs]
64.509: [Full GC {Heap before GC invocations=2:
Heap
def new generation total 339264K, used 3455K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 1% used [0xffffffff31c00000, 0xffffffff31f5fe20, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 14119K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 2% used [0xffffffff47150000, 0xffffffff47f19ec8, 0xffffffff47f1a000, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18514K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72e14a48, 0xffffffff72e14c00, 0xffffffff75c00000)
64.510: [Tenured: 14119K->14201K(699072K), 0.1542504 secs] 17575K->14201K(1038336K), [Perm : 18514K->18514K(65536K)] Heap after GC invocations=3:
Heap
def new generation total 339264K, used 0K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 0% used [0xffffffff31c00000, 0xffffffff31c00000, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 14201K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 2% used [0xffffffff47150000, 0xffffffff47f2e608, 0xffffffff47f2e800, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18514K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72e14a48, 0xffffffff72e14c00, 0xffffffff75c00000)
} , 0.1544700 secs]
==============================
From parankiho
MailTo : parankiho@naver.com
==============================
제목 : Re: 설명할 내용은 많은데, 정리가 잘 안되네요.
글쓴이: 벌레사냥꾼(guest) 2007/05/11 13:00:21 조회수:285 줄수:121
결론적으로 말씀드리면, GC튜닝이 필요한 상황입니다.
GC가 발생하는 기준은 여러가지가 있습니다.
Minor GC같은 경우는 eden영역이 100%인 경우이고 Full GC인 경우는 좀 복잡합니다.
김기호님이 생각하시는 Full GC는 GC로그상에서 Tenured GC라고 출력되는 경우입니다.
즉 Tenured영역(old)에 대해 GC가 필요하다고 판단되는 경우 발생하는 GC입니다.
로그에서 Full GC라고 찍힌 것은 GC가 전체 영역에 대해 발생했다는 것이지 Old영역이 부족해서 Old영역에 대해 수행했다는 것이 아닙니다.
원인은 여러가지 이기때문에 분석을 좀더 해야겠지만, System.gc()호출이라든지, GC파라미터에 의해 GC가 구동된 것이 대부분입니다.
제가 얼뜻보기에는, s영역이 작은 것이 원인인듯 싶습니다.
그럼, GC튜닝은 어떻게 하느냐...
다를 GC라면 튜닝에 상당한 노하우가 필요하겠지만, Default GC라면 생각보다 쉽습니다.
Default GC의 원리는 생략하도록 하겠습니다.
튜닝의 포인트는 다음과 같습니다.
WAS와 프레임워크와 같이 상시적으로 유지되는 객체는 Old영역에, 서비스(업무) 인스턴스는 New영역에 배치시킴으로써
Minor GC만 발생시킴으로써 Long Pause를 없애고, GC의 Old영역 Scan작업을 없앰으로써 Overhead를 제거한다.
사실 원래 young/old의 설계 개념에 최대한 충실한 것 뿐이지요.
1. old 영역의 크기를 정합니다.
old는 위에서 정의한 상시적으로 유지되는 객체의 크기를 추정해서 해당 대비 4배 정도를 잡습니다.
Tenured영역의 50%를 넘어설 때, 첫 Tenured GC가 발생합니다. 튜닝이 제대로 되면 40%에서 유지시킬 수 있습니다.
2. new에서 old로 넘어가기 위한 threadhold를 증가 시킵니다.
정확한 파라미터 명칭은 기억이 안납니다.
new영역(young영역이라고도 하죠)은 eden과 survivor영역(s1, s2영역으로 다시 구분)으로 구성되는데, 최초 객체 생성시 eden에 생성이 됩니다.
eden영역이 꽉차면, minor gc가 발생하고 살아남은 객체들은 survivor영역(s1으로 가정하겠습니다.)으로 이동합니다.
다시 eden영역이 꽉차면, minor gc가 발생하고 eden영역에서 살아남은 객체와 s1에서 살아남은 객체가 s2영역으로 이동합니다.
다시 eden영역이 꽉차면, minor gc가 발생하고 eden영역에서 살아남은 객체와 s2에서 살아남은 객체가 s1으로 이동하죠
즉, 영원히 살아남는 객체는
eden->s1->s2->s1->s2->s1->s2->.......-> old
의 순으로 이동합니다.
survivor영역에서 old로 언제 이동시키는가?
이 결정에 대해 Default GC는 두가지 파라미터를 제공합니다.
s1과 s2의 이동횟수 쓰레스홀드값(기본 31)과 s1영역의 사용량의 쓰레스 홀드(기본값 기억이 안나네요)입니다.
이 파라미터를 사용해서 eden영역과 s1 영역의 크기는 다음과 같이 예측 가능합니다.
이동횟수를 1회로 잡고 eden영역와 s1영역을 동일하게 잡습니다.
old영역은 충분히 커야합니다.
이후 부하를 가해 변화량을 측정합니다.
eden에서 살아남은 객체가 s1으로 가기 때문에
gc후 살아남은 s1의 메모리 크기는 minor gc시 객체의 생존율입니다.
이동횟수가 1이기 때문에 minor gc발생후, s1영역에서 old로 바로 진입히기 때문에 old영역의 증가율이 s1에서 생존율입니다.
각각
p1, p2라고 하면
메모리 추이는 다음과 같은 것입니다.
p1*x
p1*x + p2*p1*x
p1*x + p2*p1*x + p2*p2*p1*x
.
.
p1*p2*x + p2*p1*x + ....p2^n*p1*x
n이 무한대로 가면 p1x(1-p2)입니다.
x는 eden영역의 크기이고, p1*x*(1-p2)는 s1, s2의 크기입니다.
p1과 p2는 위에서 설명한 방법으로 구한 값들중에 가장 큰값을 적용시키고 만일의 경에에 대비해 20%정도 더 확보합니다.
이로써, eden, survivor, old영역의 크기를 구했고 실제 파라미터를 적용하면 됩니다.
위의 값을 정확히 구해고, 이동횟수를 충분히 크게(예를 들어 1024정도?) 잡으면, 1024회의 minor GC를 거치고 살아남아야 old영역에 들어가게 되고, s영역이 부족해서 old영역으로 들어가지는 않습니다.
예전 튜닝한 후, old영역을 살펴보면
********************
*
*
*
*
같은 그래프가 그려져야 합니다.
그리고, 부하를 24시간 가한 환경에서 Tunured, FullGC는 발생해서는 안되고요.
향후 시스템 증설에 대비해 여유 공간을 확보하시면 됩니다.
다른 GC에 비해 TPS는 떨어지지만 튜닝하기 쉬워서 저도 Default GC를 선호하긴합니다만, BMT같은 경우는 어쩔수 없이 삽질하고 있습니다.
글로 설명하기 상당히 어려워서 내용이 잘 전달되었는지 잘 모르겠네요.
제목 : Re: 설명할 내용은 많은데, 정리가 잘 안되네요.
글쓴이: 김기호(parankiho) 2007/05/11 13:36:38 조회수:266 줄수:126
로그에서 Full GC라고 찍힌 것은 GC가 전체 영역에 대해 발생했다는 것이지 Old영역이 부족해서 Old영역에 대해 수행했다는 것이 아닙니다.
원인은 여러가지 이기때문에 분석을 좀더 해야겠지만, System.gc()호출이라든지, GC파라미터에 의해 GC가 구동된 것이 대부분입니다.
제가 얼뜻보기에는, s영역이 작은 것이 원인인듯 싶습니다.
--->>>>>
우선 친절한 답변에 감사드립니다..
new 에서 s1이나 s2로의 이동없이 계속 Full GC라고 발생하는 부분에 대해 이상하다고 생각했었는데
결국엔 제가 가지고 있던 Full GC에 대한 개념이 약간 잘못된 듯 하군요.
Old 영역에 대한 GC만이 Full GC라고 생각했는데... 흠..
제가 무지해서 답변해주신 내용과 매칭이 잘 되지 않는데
귀찮으시더라도 좀 더 자세히 알려주셨으면 합니다.
-----------------------------------------
1. old 영역의 크기를 정합니다.
old는 위에서 정의한 상시적으로 유지되는 객체의 크기를 추정해서 해당 대비 4배 정도를 잡습니다.
Tenured영역의 50%를 넘어설 때, 첫 Tenured GC가 발생합니다. 튜닝이 제대로 되면 40%에서 유지시킬 수 있습니다.
-----------------------------------------
로그를 보시면 아시겠지만 Tenured 즉, Old 영역의 사용량이 5%도 넘지 않으면서 Tenured GC 가 발생을 합니다.
위에 첨부한 로그는 처음부분이긴 합니다만. 저런 형태로 new 부분만 20-30%로 왔다갔다합니다.
------------------------------------------
2. new에서 old로 넘어가기 위한 threadhold를 증가 시킵니다.
정확한 파라미터 명칭은 기억이 안납니다.
new영역(young영역이라고도 하죠)은 eden과 survivor영역(s1, s2영역으로 다시 구분)으로 구성되는데, 최초 객체 생성시 eden에 생성이 됩니다.
eden영역이 꽉차면, minor gc가 발생하고 살아남은 객체들은 survivor영역(s1으로 가정하겠습니다.)으로 이동합니다.
--------------------------------------------
eden 영역이 꽉차지 않는다면(또는 일정량-50%정도 이하인경우) minor gc 역시 발생하지 말아야 하는걸로 알고 있습니다.
또한 로그에서와 같이 eden 이 50%는 고사하고 20% 수준임에도 발생하는게 너무 이상합니다.
- 특정한 옵션을 부여하지 않은 default gc 알고리즘이라는게 중요합니다.
가장 이상하게 생각하는 부분의 로그를 보면.
(원문의 로그 중, 마지막 부분입니다.)
4.257: [Full GC {Heap before GC invocations=1: ----->>>>>>(1번)
Heap
def new generation total 339264K, used 78520K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 23% used [0xffffffff31c00000, 0xffffffff368ae0b0, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 3715K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 0% used [0xffffffff47150000, 0xffffffff474f0c80, 0xffffffff474f0e00, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18388K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72df5268, 0xffffffff72df5400, 0xffffffff75c00000)
4.257: [Tenured: 3715K->14119K(699072K), 0.2477265 secs] 82235K->14119K(1038336K), [Perm : 18388K->18388K(65536K)] Heap after GC invocations=2:
Heap
def new generation total 339264K, used 0K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 0% used [0xffffffff31c00000, 0xffffffff31c00000, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 14119K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 2% used [0xffffffff47150000, 0xffffffff47f19ec8, 0xffffffff47f1a000, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18388K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72df5268, 0xffffffff72df5400, 0xffffffff75c00000)
} , 0.2479585 secs] --->>>>>>(2번)
64.509: [Full GC {Heap before GC invocations=2: --->>>>>>(3번)
Heap
def new generation total 339264K, used 3455K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 1% used [0xffffffff31c00000, 0xffffffff31f5fe20, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 14119K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 2% used [0xffffffff47150000, 0xffffffff47f19ec8, 0xffffffff47f1a000, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18514K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72e14a48, 0xffffffff72e14c00, 0xffffffff75c00000)
64.510: [Tenured: 14119K->14201K(699072K), 0.1542504 secs] 17575K->14201K(1038336K), [Perm : 18514K->18514K(65536K)] Heap after GC invocations=3:
Heap
def new generation total 339264K, used 0K [0xffffffff31c00000, 0xffffffff47150000, 0xffffffff47150000)
eden space 329024K, 0% used [0xffffffff31c00000, 0xffffffff31c00000, 0xffffffff45d50000)
from space 10240K, 0% used [0xffffffff45d50000, 0xffffffff45d50000, 0xffffffff46750000)
to space 10240K, 0% used [0xffffffff46750000, 0xffffffff46750000, 0xffffffff47150000)
tenured generation total 699072K, used 14201K [0xffffffff47150000, 0xffffffff71c00000, 0xffffffff71c00000)
the space 699072K, 2% used [0xffffffff47150000, 0xffffffff47f2e608, 0xffffffff47f2e800, 0xffffffff71c00000)
compacting perm gen total 65536K, used 18514K [0xffffffff71c00000, 0xffffffff75c00000, 0xffffffff75c00000)
the space 65536K, 28% used [0xffffffff71c00000, 0xffffffff72e14a48, 0xffffffff72e14c00, 0xffffffff75c00000)
} , 0.1544700 secs]
4.257 초에 어떤 이유에선가 Full GC 가 발생했습니다.(1번참조)
그 결과로 (2번)에서 Full GC 가 끝나면서 eden 0%, s1 0%, s2 0%, tenured 2% 인 상태로 Full GC가 끝났습니다.
(Perm 은 제외하고 설명하겠습니다.)
그럼 64.509초(3번)에서 Full GC 가 발생한다는건 적어도 어떤 변화는 있어야 한다고 생각하는데.
(2번) 상태와의 차이란 eden 영역이 1%로 증가했다는 것 밖에 없습니다.
즉, 고작 eden 1%를 지우기 위해서
64.510: [Tenured: 14119K->14201K(699072K), 0.1542504 secs] 17575K->14201K(1038336K), [Perm : 18514K->18514K(65536K)]
이 발생한다는게 아직도 이해가 가질 않네요. tenured 영역은 699072K 가량이 미리 생성되어 있는데
고작 82K(14119K->14201K)가 더 tenured 영역에 들어가기 위해 Tenured GC 가 발생한다??
제가 gc 로그를 잘못 읽고 있는건지..
gc 에 대한 개념이 없는건지... 복잡하네요.
다만 s1, s2 영역이 계속해서 0%인걸로 봐서는
답변주신대로 s1, s2영역의 크기가 너무 작어서 eden 에서 살아남은 객체들이 이동하지 못하는 것 같습니다.
(이부분은 정확히 모르겠네요. 일단 사이즈를 늘려서 모니터링 해보는 수 밖에 없을 듯 싶습니다.)
또한 Tenured GC 가 발생하는 경우가 Tenured 가 부족한 경우 이외에 또 어떤 경우가 있나요?
염치불구하고
부디 '많은벌레사냥꾼'님도 도와주시고 또 다른 분들의 도움도 부탁드립니다.
그래도 JVM 튜닝은 이제 왠만큼 한다고 생각했는데.. 역시 갈길이 멉니다..
==============================
From parankiho
MailTo : parankiho@naver.com
==============================
제목 : Re: 아마도 System.gc() 가 동작하는 것 같네요.
글쓴이: 너스(guest) 2007/05/14 11:15:11 조회수:312 줄수:49
1.
로그 상황을 보니, 코드의 어딘가에서 System.gc()를 1분 간격으로 호출하는 것으로 보입니다.
JVM 시작후 4초, 64초 경에 Full GC발생하는 것으로 보아 그런 것 같습니다.
제 짐작이 맞다면 124초, 184초 경에 발생한 로그가 있겠군요.
물론 발생 시간은 조금씩, 한 0.5초씩, 뒤로 밀리겠죠.
아래의 option은 System.gc()를 disable 시킵니다.
-XX:+DisableExplicitGC
이렇게 해 놓으시고 tuning하시면 되실 것 같습니다.
2.
님께서 보신 로그가 가장 상세한 로그 형태입니다.
각 메모리 영역별 상황을 보여주니까요.
-XX:+PrintTenuringDistribution
이 옵션은 survival space에서 존재하는 객체들의 이동 횟수를 보여주는데,
그다지 큰 도움은 되지 않습니다.
3.
기존 로그를 덮어쓰지 않으려면, WAS 구동 shell script에서 pid로 이름을 받아서 로그를 남기는 방법을
사용하시면 됩니다.
제가 기억을 잘 못하겠는데, $$ 를 사용하는 것 같은데, 죄송합니다만, 님께서 직접 찾아 보시는게...
아니면, WAS에서 제공하는 log를 남기는 방법을 활용하셔야 할 것 같습니다.
+ 추가 사항
1) PermSize와 MaxPermSize는 동일하게 설정하시는게 좋습니다.
2) 그리고, 아무리 튜닝을 잘하셔도 Tenured GC는 발생합니다.
이유는 아무리 enden 영역이 커도 old 영역으로 promotion되는 객체는 존재할 수 밖에 없기때문입니다.
그리고 그 pomotion되는 객체들이 아주 미량이나마 존재하는한 언젠가는 Tenured GC가 발생합니다.
(상세한 설명은 생략합니다.)
그렇게 때문에 JVM의 전체 메모리를 아주 크게 설정하는 게 가장 좋은 답은 아닙니다.
3) 1.4.2라면 jstat (또는 jvmstat) 를 사용하셔서 모니터링하는 것도 권고합니다.
java.sun.com에 가셔서 구하시면됩니다.
JDK 1.5에서는 default로 내장되어 있지만, 1.4.2 는 download 받으셔야 합니다.
도움이 되시기를...
제목 : Re: 추가 사항의 반론
글쓴이: 벌레 사냥꾼(guest) 2007/05/15 09:51:59 조회수:234 줄수:36
"pomotion되는 객체들이 아주 미량이나마 존재하는한 언젠가는 Tenured GC가 발생합니다"
라는 말씀이 제 생각과 다르네요.
물론 포인트는 다릅니다.
저도 eden에서 old영역으로 넘어가는 것을 크기를 늘려서 해결할 수 있다고 생각하지 않습니다.
제가 튜닝한 포인트는 이글 쓰레드 중에 있으니 따로 언급은 하지 않겠습니다.
결과적으로 old가 saturated된후 2시간 부하상황에서 1k의 증가도 없었습니다.
실제로는 며칠동안 운영한 경우와 비슷하다고 생각되고 실제로 현업들이 반응속도가 빨라졌다는 의견을 들었습니다.
실제 tps는 0.2%정도 손실됐습니다만, 평균 gc타임이 0.5미만이었고 gc가 발생하는 빈번도도 4에 한번 정도였습니다.
만일 survivor이동 횟수를 500으로 정할 경우 eden에서 old로 넘어가기까지 약 30분정도 걸립니다.
이 시간동안 유지되는 객체라면 영구히 존재하는 (WAS나 공통 객체같은) 객체일 가능성이 높죠.
물론, 영역의 크기나 다른 파라미터를 조정하지 않으면 다른 요인에 의해 Tenured GC가 발생합니다.
그러나, 다른 요인을 배제하면 단지 영역의 크기와 이동횟수 파라미터만으로 튜닝이 가능합니다.
추가적으로 일정한 시간마다 gc가 발생했다면, rmi 에서 하는 gc일 가능성이 있습니다.
JVM은 객체의 변화에 따라서만 gc가 구동합니다.
아무일도 하지 않는 경우에는 gc가 발생하지 않죠.
그런데, WAS의 경우 타이머를 사용해 특정시간에 gc를 발생시키는 방법이 있습니다.
역시 정확한 옵션은 기억나지 않지만 rmi객체의 gc를 주기적으로 해주는 옵션이 제우스에 있었던 것 같습니다.
jeus.properties나 jeus에 찾아보시면 있을 겁니다.
제목 : Re: 어플리케이션 및 운영 상황에 따라서 다릅니다.
글쓴이: 너스(guest) 2007/05/15 10:56:17 조회수:232 줄수:42
GC에 대하여 많이 알고 계시니, 요점만 씁니다.
제가 언급한 것은 튜닝이 불가능하다는 의미가 아니라,
그 어떤 방법을 써도, 'Old GC가 발생하는 것을 막을 수 없다.' 입니다.
어플리케이션의 특성에 따라서, eden에서 old로 promotion되지 않을 수도 있습니다.
(운좋게) 그런 어플리케이션이 있는 경우도 있습니다만, 일반화시키기는 어렵습니다.
즉, 모든 어플리케이션이 그렇게 동작할 수는 없습니다.
이유는,
1. survivor space의 크기를 넘는 객체들이 생성될 수도 있습니다.
2. 어떤 객체들은 상상외로 길게 long live할 수도 있습니다.
갑자기 부하가 조금 더 걸리는 순간은 이런 경우들이 더 자주 발생할 것입니다.
이런 이유들로 모든 객체가 eden에서 소멸되지 않을 가능성은 충분히 있습니다.
물론, tenuing threshold를 조절하는 것은 매우 좋은 turning 방법입니다만,
GC의 시간을 많이 잡아먹는 Old GC의 발생을 궁극적으로는 막을 수는 없습니다.
결론은,
그 어떤 방법을 써도, 'Old GC가 발생하는 것은 막을 수 없다.' 입니다.
그 발생 빈도를 획기적으로 줄이는 것은 님께서 말씀하신 방법대로 가능합니다.
관련된 의견의 기술적인 배경을 하나 더 말씀드립니다.
동시 사용자가 10명인 시스템과 100명인 시스템의 JVM Heap 메모리 크기의 configuration은 달라져야 합니다.
이유는, 동시 사용자가 많은 시스템은 객첵의 생성량도 많고, minor gc 시의 live한 객체의
수 및 양도 많을 것입니다.
물론 이 경우에 10배로 크게 메모리 구성을 할 필요는 없지만,
10명과 100명의 상황에서는 확실하게 100명의 경우가 메모리를 크게 구성해야 합니다.
(이 부분은 이견이 없으시겠죠?)
님께서 튜닝하신 시스템에서 만일 사용자가 좀 더 증가한다면,
또는 traffic이나 transaction 량이 좀 더 증가한다면,
(즉, user interactive한 시스템인 경우에 heavy한 select query를 처리하거나 하는 등)
그렇게 된다면, tenured 영역으로 이전되는 live한 객체가 발생할 가능성이 있겠죠?
결국은 언젠가는 Old GC가 발생하지 않을까요...
제목 : Re: 오랜만에 재미있는 쓰레드가 생겼네요.
글쓴이: 벌레 사냥꾼(guest) 2007/05/15 12:04:22 조회수:248 줄수:51
서로의 가정이 틀린 것 같습니다.
너스님은 모든 케이스에 대한 고려인 것 같네요. 반대로 저는 웹어플리케이션을 가정했습니다.
저는 기본 모델이 확률 모델입니다.
너스님이 말씀하신 부분
1. survivor space의 크기를 넘는 객체들이 생성될 수도 있습니다.
2. 어떤 객체들은 상상외로 길게 long live할 수도 있습니다.
에서 저는 이렇게 생각합니다.
1. survivor space의 크기를 넘는 객체들이 생성될 가능성은 작다.(survivor영역을 추정하는 방법은 위에서 설명)
2. 상상외로 길게 long live 하는 객체가 발생할 가능성은 작다.
예를 들어 횟수에 대한 쓰레스 홀드는 65536까지 설정가능하고 gc빈번도가 5초, survivor영역의 크기가 충분히 크다면 old영역에 들어가기 위해서는 3.7일이 걸립니다.
3.7일 이상 live하는 객체라면 당연히 old영역에 들어가는 것이 맞지 않을까 생각됩니다.
웹어플리케이션이라면 특히나 data tier는 db를 주로 사용할 테고, 각서비스간의 연계는 session을 이용하는 것이 보통일 것 같은데, 일반 온라인 서비스의 경우 3.7일간 지속되는 task chain이 발생할 수 있을까요?
그 정도라면 batch로 돌리는 것이 맞다고 생각했습니다.
추가적으로 동시 사용자 10명과 100명의 시스템 예는 JVM configuration이 바꿀 필요가 없을 수도 있습니다. 제대로 튜닝이 되어 있다면 보통은 필요가 없습니다.
이유는 현재 논의가 WAS를 가정하고 있기 때문입니다.
WAS에서 보통 queueing 모델을 기본적으로 적용하고 있고, 실제로도 thread queue를 적용하는데 100명이 동시에 접속하더라도 WAS의 max thread가 10인 경우는 10개의 쓰레드만 돌게 됩니다.
물론 시스템 확장시 튜닝을 새로 해야하지 않느냐는 질문이 있을 수 있는데, 튜닝은 application 단, 공통 유틸, 미들웨어, jvm, os와 같은 순으로 상위 layer에서 하위 레이어로 진행합니다.
상위 레이어가 동일하다면 하위단은 변경이 발생하지 않아야 합니다.
마지막에 말씀하신 부분에서 사용자 증가시 was의 max thread제한에 걸리게 되고 그 사용자는 대기 상태에 있게 되기 때문에, 객체 생성량이 증가하지는 않습니다.
실제로도 부하 테스트시 10명부터 시작해서 100까지 증가시키면 tps는 증가하다 saturate되고 이후는 유지됩니다.
또한 메모리 증가 추이도 비슷하게 부하를 아무리 증가 시켜도 saturate됩니다.
그리고, 같은 이유로 부하가 폭발적으로 걸리더라도 메모리는 10개 업무분만 쓰게 됩니다.
현재 개인적으로 java memory관련해서 문서를 만들고 있는데, 기본 모델을 확률 모델로 했습니다.
확률 모델이란게 worst case에 대해서는 고려하지 않다보니 생각이 짧았던 것 같습니다.
현제 WAS를 사용한 application튜닝 사례와 eclipse의 gc튜닝을 예로 포함시켜서 진행하고 있는데, 혹시 특이한 사례가 있다면 알려주시면 감사하겠습니다.
제목 : Re: 그렇다면, 힘들게 튜닝하는 과정이 필요 없을 것 같네요.
글쓴이: 너스(guest) 2007/05/15 13:36:47 조회수:234 줄수:63
이렇게 글로써 진행하는 의견 교환은 상당히 어렵네요.
현실적인 예로써 한번 애기를 해 봅니다.
우선, 님의 생각과 저의 생각이 가장 차이가 나는 부분은,
'Old GC의 발생을 0으로 할 수 있다.'에 대한 견해 차이라고 생각합니다.
저는 '웹 어플리케이션에서도 그런 경우는 거의 없다' 라는 의견이고,
님은 '대부분의 웹 어플리케이션은 그렇게 할 수 있다' 라는 의견이라고 생각합니다.
(맞나요? 이게 아니라면 더 이상의 토론은 의미가 없네요.)
만일 님의 의견이 맞다면,
JVM Heap Size를 최대한 키우는게 가장 좋은 best practice가 될 것으로 저는 생각합니다.
예를 들어, 어떤 웹 어플리케이션을 tuning했는데,
1GB의 Heap 크기에,
eden - 300MB, old - 700MB 정도로 구성하였을 때,
그리고, S0, S1의 크기가 각각 100MB 정도일 때,
Old GC가 발생하지 않는 app 및 운영 상황이라면,
이때, JVM heap 크기를 3-4배로 키워도 문제가 없을 것입니다.
minor gc의 시간은 조금 늘어날 것입니다.
하지만, 통상적으로 minor gc의 시간은 큰 문제가 되지 않습니다.
아마, 3GB의 heap size에서 minor gc의 시간은 평균 1초 이내가 아닐까 하네요.
그렇다면, 굳이 님께서 제시하신 tuning process를 거칠 필요가 없지 않을까 생각합니다.
왜냐면,
jvm heap min, max를 3.6GB 정도로 설정,
(이 크기는 32bit JVM에서 할당 가능한 가장 큰 크기입니다.)
young 영역을 한 1GB 정도,
survival ratio를 1 또는 2 정도로 설정,
(그러면, s0, s1은 각각 대략 200-300M 정도 되겠네요.)
max tenuring threshold를 65535 정도로 설정하면
거의 모든 web app에서는 old gc가 발생하지 않게 되지 않을까요?
왜냐면, web app의 behavior는 거의 유사하고 (님의 가정임)
(여기서, behavior는 memory foot print 및 객체의 생존 시간이 되겠죠)
현실적으로 가능한 가장 큰 survivor space 크기를 부여하고,
충분히 survivor space에서 객체가 머무르게 65535로 횟수 조절도 했으니까요.
정말로 이렇게 된다면,
많은 web app들이 그 동안 고민했던,
old gc 때의 5~10초 이상의 pause time 및 그로 인해 발생되는 문제들이 한방에 해결됩니다.
근데, 그렇지 않을 것 같은게 저의 생각입니다.
그에 대한 이유는 앞의 쓰레드에 설명을 했다고 생각하고요.
* 추가 의견
제가 한 얘기에서,
만일 minor gc 의 시간이 문제라서, 4GB에 가까운 메모리를 할당하는 것은 문제가 있다고 생각하시면,
tuning process를 역으로 해서,
즉, 일단, 최대한 큰 메모리를 부여하고,
s0, s1, old 영역의 메모리 점유율을 관찰한 다음,
(관찰 시간은 1일이면 충분하지 않을까 하네요)
그 점유량에 맞춰서 old, eden, s0, s1 의 크기를 결정하면 되지 않을까 합니다.
제목 : Re: 음, 생각해보니 최적화 자체가 현실 상황에서 필요한 것 같네요.
글쓴이: 벌레 사냥꾼(guest) 2007/05/16 10:25:53 조회수:232 줄수:98
말씀하신 것이 모두 맞습니다. 저도 이론적으로는 그런 결과에 도달했구요.
근데 말씀하신 현실에서는 그렇지 못했습니다.
막상 메모리를 늘려도 실제로는 tps가 더 증가하지도 않고 단지 minor gc 시간만 길어졌습니다.
즉, 튜닝의 효과를 보기 전에 이며 다른 쪽에서 병목이 발생한 것이죠.
3.6G가 풀로 사용할 정도면 이미 cpu나 네트워크같은 쪽에서 병목이 발생해 버리는 거죠..
실제 모니터링 한 결과 시스템 call횟수가 꽤 많았고 wait타임이 길었는 것으로 보아 네트워크 쪽에서 병목이 발생한 것 같습니다.
만일 네트워크가 받혀줬다면, 말씀하신대로 메모리를 가장 크게 잡으면 되었겠지요.
아, 제가 만진 시스템은 8개의 ap서버(1대는 배치 전용)가 있고, 각 서버마다 2개의 container가 있었습니다.
db도 3개로 분리되어 있었구요. 실제 튜닝은 모든 container에 부하를 건 상태에서 하나의 container에 대한 튜닝을 진행했습니다.
추측하기에는 context switching과 같은 각 쓰레드, 프로세서의 경쟁에 의해 시스템 콜이 많아지고 이 때문에 네트워크 대기가 많음에도 쓰레드를 증가 시킬 수 없었던 것 같습니다.
만일, 서버 자원이 빵빵하다면, 말씀하신대로 memory 튜닝은 거의 필요하지 않을 것 같습니다.
그리고, gc튜닝의 목적은 long pause를 없애는 것에 주안점이 맞춰져 있었습니다.
gc튜닝 사례에도 tps의 증가는 3%정도가 최고였던 것같습니다.(기억으로는 parallel을 사용했던 듯)
결과론적으로 최적화 무용론에 도달하게 되네요.(장비를 늘리면 된다?)
아시겠지만 장비를 늘리는 것이 현실에서는 쉽지 않은 문제이고 그렇기 때문에 주어진 환경에서 좀더 좋은 성능을 뽑아내야만 하겠죠
제도 보통 튜닝을 하게 되면 많은 불만이 있습니다.
도대체 장비는 왜 이딴 것 쓰는 거야? 부터 해서 WAS, 서버 숫자, contianer숫자, thread pool갯수, L4셋팅까지
바꿀려고 딴지도 몇번 걸어봤지만, 여러가지 이유(영업, 돈, 정치, 심지어는 다른 개발자의 자존심)로 바꿀 수 있었던 적은 거의 없었습니다.
결국 주어진 환경에서 주어진 일만 하게 되더라구요.
마지막에는 약간 넋두리같이 되어 버렸네요.
그리고, 윗글에서 약간 틀리신 부분이 minor gc가 1초 미만이라는 부분은 전혀 아닙니다.
WAS와 공통 유틸을 올리면 실제 100 메가를 넘는 정도 밖에 안되었습니다.
old영역은 512 메가를 할당했고 전체 2.5기가였으며, 그중 perm이 1기가 정도(사용량은 600메가 정도?) 였습니다.
perm 사이즈를 보시면 아시겠지만 작은 시스템은 절대 아닙니다.
1기가가 new영역이고 survivor ratio가 8이었습니다. gc타임은 평균 0.5초 정도였지만 max 1초 정도였습니다.
아슬아슬하게 1초를 안넘어서 통과했죠.
튜닝하기 전에 3.8g통채로 잡은 경우는 minor gc도 2초 3초였고 FULL gc도 7~8초까지 된 경우도 있었습니다.
무엇보다 그래프를 그리면 gc에 의해 시스템이 불안정해지는 것이 가장 큰 문제였습니다.
그리고 하나더!
32bit에서 4giga 역시 틀린 내용입니다.
sun jdk 1.4.x-32bit 기준으로 2giga limit가 걸려있습니다. 단, 64bit머신에서는 limit가 4giga(32-bit addresss limit)로 올라가는데, jvm과 기타등등(대부분이 gc가 사용하는 공간)에서 쓰는 주소 공간을 빼면 3.8giga 정도 입니다.
또한, os에 따라 limit가 바뀝니다.
기억에는 ms 가 가장 작았던 것(1.6giga) 같은데 만일 주어진 환경이 ms이고 sun인경우라면, 생각보다 충분한 메모리 공간을 확보할 수 없습니다.
즉, 요점은 생각보다 제약사항이 많다는 거죠.^^;
마지막으로 추가의견에 대해서는 완전히 동의합니다.
제가 위에 쓴 글이 old, eden, s영역의 크기를 쉽게 한번에 찾는 방법입니다.
관찰 시간은 부하상황에서 20분 정도면 충분하다고 생각하고요.
단, 부하를 줄 업무 선정에 따라 관찰은 여러번해야 하는 경우도 있습니다.
제 경우는
login만(9시경에 폭발적으로 발생하지 않을까 하는 생각에...)
주요 업무(가장 자주 사용할 업무 10개)
가장 무거운 업무만
이렇게 했고, 계산된 값에서 좀 여유 공간을 더 확보했습니다.(eden영역은 더 확보하면 안되고요. gc time도 증가하고, 계산값이 다 틀려버려지니까)
이정도면, 제가 얘기하고 싶은 내용은 충분히 전달한 듯 싶네요.
내용이 복잡하고 그다지 관심이 없는 분야라 쓰레드가 진행이 될까하는 걱정도 했었는데, 서로 의견 교환이 잘되어서 기쁘네요.
사실 실제 튜닝하러 나가면 제대로 말이 통하는 사람이 거의 없어서, 그냥 고객한테는 어려운 용어 써가면서 얼버무리고
혼자 끙끙대면서 진행하는 경우가 대부분인데, 이런 기회에 풀 수 있어서 기쁘네요.
제목 : Re: 아. 감사합니다...
글쓴이: 김기호(parankiho) 2007/05/17 13:44:25 조회수:221 줄수:29
요새 하도 일이 많아서 막상 글을 올리고도 확인을 못했네요.
여러가지 의견 내주셔서 감사합니다.
--------------
그런데, WAS의 경우 타이머를 사용해 특정시간에 gc를 발생시키는 방법이 있습니다.
역시 정확한 옵션은 기억나지 않지만 rmi객체의 gc를 주기적으로 해주는 옵션이 제우스에 있었던 것 같습니다.
jeus.properties나 jeus에 찾아보시면 있을 겁니다.
-------------
하지만 이부분은 아마 헷갈리신듯 합니다.
rmi gc 같은 경우 jeus 에서는 manager process 에서 발생하며 컨테이너에서는 발생하지 않습니다.
아마 다음 예와 같은 옵션일꺼라 생각됩니다.
-Dsun.rmi.dgc.client.gcInterval=21600000 -Dsun.rmi.dgc.server.gcInterval=21600000 -Djeus.properties.replicate=sun.rmi.dgc
full gc를 지연시킬수는 있어도 완전히 피할 수 없다고 생각합니다만.
max tenuring threshold 수치를 이용하는 방법은 기회가 되면 한번 시도해봐야겠군요.
어쨌거나 세상은 넓고 배울껀 끝이 없네요. ㅎㅎㅎ 감사합니다.
==============================
From parankiho
MailTo : parankiho@naver.com
==============================