verbose:gc 정보 사용(AIX 및 Linux에만 해당됨)

-Xgc:verboseGCCycleTime=N 옵션과 함께 -verbose:gc 옵션을 사용하여 Metronome Garbage Collector 활동에 대한 정보를 콘솔에 기록할 수 있습니다. 표준 JVM의 -verbose:gc 출력에 있는 모든 XML 특성이 작성되거나 Metronome Garbage Collector의 출력에 적용되는 것은 아닙니다.

-verbose:gc 옵션을 사용하여 힙의 최소, 최대 및 평균 여유 공간을 보십시오. 이 방식으로 활동 레벨과 힙 사용을 검사하고 필요하면 값을 조정할 수 있습니다. -verbose:gc 옵션은 Metronome 통계를 콘솔에 작성합니다.

-Xgc:verboseGCCycleTime=N 옵션은 정보 검색 빈도를 제어합니다. 요약이 덤프되는 시간(밀리초)을 판별합니다. N의 기본값은 1000밀리초입니다. 주기 시간이 해당 시간에 정확하게 요약이 덤프됨을 의미하지는 않지만 이 시간 기준을 충족하는 마지막 가비지 콜렉션 이벤트가 전달됩니다. 이 통계의 수집 및 표시로 메트로놈 가비지 콜렉터 일시정지 시간이 증가되고 N이 작아질수록 일시정지 시간이 길어질 수 있습니다.

퀀텀은 애플리케이션의 인터럽트 또는 일시정지 시간을 유발하는 메트로놈 가비지 콜렉터 활동의 단일 기간입니다.

verbose:gc 출력 예제

다음을 입력하십시오.

java -Xgcpolicy:metronome -verbose:gc -Xgc:verboseGCCycleTime=N myApplication

가비지 콜렉션이 트리거되면 trigger start 이벤트가 발생하고 이후에 임의의 수의 heartbeat 이벤트가 발생한 후에 트리거가 충족되면 trigger end 이벤트가 발생합니다. 이 예는 트리거된 가비지 콜렉션 주기를 verbose:gc 출력으로 표시합니다.

<trigger-start id="25" timestamp="2011-07-12T09:32:04.503" /> 

<cycle-start id="26" type="global" contextid="26" timestamp="2011-07-12T09:32:04.503" intervalms="984.285" /> 

<gc-op id="27" type="heartbeat" contextid="26" timestamp="2011-07-12T09:32:05.209">   
  <quanta quantumCount="321" quantumType="mark" minTimeMs="0.367" meanTimeMs="0.524" maxTimeMs="1.878" 
    maxTimestampMs="598704.070" />   
  <exclusiveaccess-info minTimeMs="0.006" meanTimeMs="0.062" maxTimeMs="0.147" />   
  <free-mem type="heap" minBytes="99143592" meanBytes="114374153" maxBytes="134182032" />   
  <thread-priority maxPriority="11" minPriority="11" />
</gc-op> 

<gc-op id="28" type="heartbeat" contextid="26" timestamp="2011-07-12T09:32:05.458">   
  <quanta quantumCount="115" quantumType="sweep" minTimeMs="0.430" meanTimeMs="0.471" maxTimeMs="0.511" 
    maxTimestampMs="599475.654" />   
  <exclusiveaccess-info minTimeMs="0.007" meanTimeMs="0.067" maxTimeMs="0.173" />   
  <classunload-info classloadersunloaded=9 classesunloaded=156  />     
  <references type="weak" cleared="660" />   
  <free-mem type="heap" minBytes="24281568" meanBytes="55456028" maxBytes="87231320" />   
  <thread-priority maxPriority="11" minPriority="11" />
</gc-op> 

<gc-op id="29" type="syncgc" timems="136.945" contextid="26" timestamp="2011-07-12T09:32:06.046">   
  <syncgc-info reason="out of memory" exclusiveaccessTimeMs="0.006" threadPriority="11" />   
  <free-mem-delta type="heap" bytesBefore="21290752" bytesAfter="171963656" />
</gc-op> 

<cycle-end id="30" type="global" contextid="26" timestamp="2011-07-12T09:32:06.046" /> 

<trigger-end id="31" timestamp="2011-07-12T09:32:06.046" />

다음과 같은 이벤트 유형이 발생할 수 있습니다.

<trigger-start ...>: 사용된 메모리의 양이 트리거 임계값보다 높아질 경우 가비지 콜렉션 주기의 시작입니다. 기본 임계값은 힙의 50%입니다. intervalms 속성은 이전 trigger end 이벤트(id-1)와 이trigger start 이벤트 사이의 간격입니다.
<trigger-end ...>: 가비지 콜렉션 주기가 사용된 메모리의 양을 트리거 임계값 아래로 낮추었습니다. 가비지 콜렉션 주기가 종료되었지만 사용된 메모리가 트리거 임계값 아래로 낮아지지 않으면 새 가비지 콜렉션 주기가 동일한 컨텍스트 ID로 시작됩니다. 각 trigger start 이벤트에 대해 문맥 ID가 일치하는 trigger end 이벤트가 있습니다. intervalms 속성은 이전 trigger start 이벤트와 현재 trigger end 이벤트 사이의 간격입니다. 이 기간 동안 사용된 메모리가 트리거 임계값 아래로 낮아질 때까지 하나 이상의 가비지 콜렉션 주기가 완료됩니다.
<gc-op id="28" type="heartbeat"...>: 관련 기간 동안 모든 가비지 콜렉션 퀀텀에 대한 정보(메모리 및 시간)를 수집하는 정기적 이벤트입니다. heartbeat 이벤트는 trigger start 및 trigger end 이벤트의 일치하는 쌍(즉, 활성 가비지 콜렉션 주기가 처리 중임) 사이에서만 발생할 수 있습니다. intervalms 속성은 이전 heartbeat 이벤트(id -1)와 이 heartbeat 이벤트 사이의 간격입니다.
<gc-op id="29" type="syncgc"...>: 동기(비결정적) 가비지 콜렉션 이벤트입니다. 동기 가비지 콜렉션 을 참조하십시오.

이 예제에서 XML 태그는 다음과 같은 의미를 가집니다.

<quanta ...>: 일시정지 기간(밀리초)을 포함한 하트비트 간격 동안 퀀텀 일시정지 시간에 대한 요약입니다.
<free-mem type="heap" ...>: 하트비트 간격 동안 여유 힙 공간의 양에 대한 요약으로, 각 가비지 콜렉션 퀀텀 종료 시에 샘플링됩니다.
<classunload-info classloadersunloaded=9 classesunloaded=156 />: 하트비트 간격 동안 로드 해제된 클래스 로더 및 클래스의 수입니다.
<references type="weak" cleared="660 />: 하트비트 간격 동안 지워진 Java™ 참조 오브젝트의 수 및 유형입니다.

참고:

두 하트비트 사이의 간격에 한 개의 가비지 콜렉션 퀀텀만 발생한 경우 사용 가능한 메모리는 이 하나의 퀀텀의 종료 시에만 샘플링됩니다. 따라서 하트비트 요약에 제공된 최소값, 최대값 및 중간값이 모두 동일합니다.
힙이 가비지 콜렉션 활동이 필요할 만큼 충분히 차지 않은 경우에는 두 하트비트 사이의 간격이 지정된 주기 시간보다 훨씬 길 수 있습니다. 예를 들어, 프로그램에서 몇 초마다 한 번만 가비지 콜렉션 활동이 필요한 경우 몇 초마다 한 번만 하트비트가 표시될 가능성이 높습니다.
가비지 콜렉션 활동이 일어날 만큼 충분히 차지 않은 힙에서는 가비지 콜렉션이 작동하지 않기 때문에 가비지 콜렉션 간격이 지정된 주기 시간보다 더 길어질 수 있습니다. 예를 들어, 프로그램에서 몇 초마다 한 번만 가비지 콜렉션 활동이 필요한 경우 몇 초마다 한 번만 하트비트가 표시될 가능성이 높습니다.
동기 가비지 콜렉션이나 우선순위 변경 같은 이벤트가 발생하면 이벤트 세부사항과 하트비트 같은 보류 중인 이벤트가 출력으로 즉시 생성됩니다.
지정된 기간 동안 최대 가비지 콜렉션 퀀텀이 너무 크면 -Xgc:targetUtilization 옵션을 사용하여 대상 활용도를 줄일 수 있습니다. 이 조치로 가비지 콜렉터에 더 많은 작업 시간을 제공할 수 있습니다. 또는 힙 크기를 -Xmx 옵션으로 늘릴 수 있습니다. 이와 유사하게, 애플리케이션이 현재 보고되는 것보다 긴 지연을 허용할 경우 대상 이용률을 높이거나 힙 크기를 줄일 수 있습니다.
출력은 -Xverbosegclog:<file> 옵션을 사용하여 콘솔 대신 로그 파일로 경로 재지정될 수 있습니다. 예를 들어, -Xverbosegclog:out은(는) -verbose:gc 출력을 밖으로 파일에 기록합니다.
thread-priority 에 나열된 우선순위는 Java 스레드 우선순위가 아닌 기본 운영 체제 스레드 우선순위입니다.

동기 가비지 콜렉션

동기(비결정적) 가비지 콜렉션이 발생하면 항목도 -verbose:gc 로그에 기록됩니다. 이 이벤트는 다음 세 가지 가능한 원인을 가집니다.

코드에서 명시적인 System.gc() 호출입니다.
JVM의 메모리가 부족해지면 동기 가비지 콜렉션을 수행하여 OutOfMemoryError 상황을 방지합니다.
JVM이 가비지 콜렉션이 지속되는 동안 종료됩니다. JVM은 콜렉션을 취소할 수 없으므로 콜렉션을 동기적으로 완료한 다음 존재합니다.

System.gc() 항목의 예는 다음과 같습니다.

<gc-op id="9" type="syncgc" timems="12.92" contextid="8" timestamp=
"2011-07-12T09:41:40.808">
  <syncgc-info reason="system GC" totalBytesRequested="260" exclusiveaccessTimeMs="0.009" 
  threadPriority="11" />
  <free-mem-delta type="heap" bytesBefore="22085440" bytesAfter="136023450" />
  <classunload-info classloadersunloaded="54" classesunloaded="234" />
  <references type="soft" cleared="21" dynamicThreshold="29" maxThreshold="32" />
  <references type="weak" cleared="523" />
  <finalization enqueued="124" />
</gc-op>

JVM 종료의 결과로 인한 동기 가비지 콜렉션 항목의 예제는 다음과 같습니다.

<gc-op id="24" type="syncgc" timems="6.439" contextid="19" timestamp="2011-07-12T09:43:14.524">   
  <syncgc-info reason="VM shut down" exclusiveaccessTimeMs="0.009" threadPriority="11" />   
  <free-mem-delta type="heap" bytesBefore="56182430" bytesAfter="151356238" />   
  <classunload-info classloadersunloaded="14" classesunloaded="276" />   
  <references type="soft" cleared="154" dynamicThreshold="29" maxThreshold="32" /> 
  <references type="weak" cleared="53" />   
  <finalization enqueued="34" />
</gc-op>

이 예제에서 XML 태그 및 속성은 다음 의미를 가집니다.

< gc-op id="9 "type="syncgc" timems= "6.439" ...: 이 행은 이벤트 유형이 동기 가비지 콜렉션임을 나타냅니다. timems 속성은 동기 가비지 콜렉션의 지속 기간(밀리초)입니다.
<syncgc-info reason="..."/>: 동기 가비지 콜렉션의 원인입니다.
<free-mem-delta.../>: 동기 가비지 콜렉션 전후의 사용 가능한 Java힙 메모리 (바이트) 입니다.
<finalization .../>: 완료 대기 중인 오브젝트의 수입니다.
<classunload-info .../>: 하트비트 간격 동안 로드 해제된 클래스 로더 및 클래스의 수입니다.
<references type="weak" cleared="53" .../>: 하트비트 간격 동안 지워진 Java 참조 오브젝트의 수 및 유형입니다.

메모리 부족 상태 또는 VM 종료로 인한 동기 가비지 콜렉션은 가비지 콜렉터가 활성 상태인 경우에만 발생할 수 있습니다. 바로 이어질 필요는 없지만 이전에 trigger start 이벤트가 선행해야 합니다. 일부 하트비트 이벤트는 trigger start 이벤트와 synchgc 이벤트 사이에 발생합니다. System.gc()(으)로 인해 발생하는 동기 가비지 콜렉션은 언제든지 발생할 수 있습니다.

모든 GC 퀀텀 추적

개별 GC 퀀텀은 GlobalGCStart 및 GlobalGCEnd 추적점을 사용하여 추적할 수 있습니다. 이러한 추적점은 동기 가비지 콜렉션을 포함하여 모든 메트로놈 가비지 콜렉터 활동의 시작과 종료 시에 생성됩니다. 이러한 추적점의 출력은 다음과 유사합니다.

03:44:35.281 0x833cd00 j9mm.52 - GlobalGC start: globalcount=3

03:44:35.284 0x833cd00 j9mm.91 - GlobalGC end: workstackoverflow=0 overflowcount=0

메모리 부족 항목

힙에 여유 공간이 부족하면 OutOfMemoryError 예외가 발생하기 전에 -verbose:gc 로그에 항목이 기록됩니다. 이 출력의 예제는 다음과 같습니다.

<out-of-memory id="71" timestamp="2011-07-12T10:21:50.135" memorySpaceName="Metronome" 
  memorySpaceAddress="0806DFDC"/>

기본적으로 Java 덤프가 OutOfMemoryError 예외의 결과로 생성됩니다. 이 덤프에는 사용자 프로그램에서 사용되는 메모리에 대한 정보가 포함되어 있습니다.

NULL
1STSEGTOTAL    Total memory:           4066080 (0x003E0B20)
1STSEGINUSE    Total memory in use:    3919440 (0x003BCE50)
1STSEGFREE     Total memory free:       146640 (0x00023CD0)