본문으로 건너뛰기
黯羽轻扬매일 조금씩

Android GC Log 해석

무료2016-03-11#Android#GC_CONCURRENT#GC_FOR_MALLOC#GC_HPROF_DUMP_HEAP#GC_EXPLICIT#GC_EXTERNAL_ALLOC#Concurrent#Alloc#Explicit#NativeAlloc#CollectorTransition#HomogeneousSpaceCompact#DisableMovingGc#HeapTrim

공식 문서를 번역하여 GC Log를 해석하고, OOM으로부터 멀어지기

들어가며

영어 원문 링크입니다. 번역에 미흡한 점이 있다면 지적해 주시기 바랍니다. 다음은 번역문입니다.

안드로이드는 모바일 기기를 위해 설계되었으므로 개발자는 앱이 점유하는 RAM(Random-Access Memory)을 항상 유심히 살펴봐야 합니다. Dalvik과 ART가 정기적으로 가비지 컬렉션(GC)을 수행하지만, 그렇다고 해서 개발자가 앱의 메모리 사용 현황(언제 어디서 얼마만큼의 메모리가 할당/해제되는지)을 무시해도 된다는 뜻은 아닙니다. 안정적인 사용자 경험을 보장하고 시스템이 여러 앱 사이를 신속하게 전환할 수 있도록 하려면, 사용자가 상호작용하지 않을 때 앱이 불필요한 메모리를 소비하지 않는 것이 매우 중요합니다.

P.S. Dalvik(안드로이드 전용 JVM), ART(Android Runtime). 안드로이드 4.4에서 ART가 도입되었으며 그 전에는 Dalvik이었습니다.

개발 기간 중 메모리 관리를 위한 모든 모범 사례를 따랐더라도(마땅히 그래야 합니다), 객체 누수나 기타 메모리 버그가 발생할 수 있습니다. 앱의 메모리 점유를 최소화할 수 있는 유일하고 확실한 방법은 도구를 사용하여 앱의 메모리 사용 현황을 분석하는 것입니다. 본 가이드는 그 구체적인 방법을 설명합니다.

Log 정보 해석

앱의 메모리 사용 현황을 확인하는 가장 간단한 방법은 런타임 로그 정보를 보는 것입니다. GC가 실행된 후 logcat에 관련 정보가 출력됩니다. logcat 출력은 Device Monitor에서 확인하거나 Android Studio와 같은 IDE에서 직접 확인할 수 있습니다.

Dalvik Log 정보

Dalvik(ART 아님) 모드에서는 매 GC 발생 시 logcat에 다음과 같은 정보가 출력됩니다.

D/dalvikvm: <GC_Reason> <Amount_freed>, <Heap_stats>, <External_memory_stats>, <Pause_time>

예시:

D/dalvikvm( 9050): GC_CONCURRENT freed 2049K, 65% free 3571K/9991K, external 4703K/5261K, paused 2ms+2ms

GC Reason

무엇이 GC를 트리거했는지, 그리고 어떤 유형의 가비지 컬렉션인지 나타냅니다. 가능한 값은 다음과 같습니다.

  • GC_CONCURRENT

힙(heap)이 거의 가득 찼을 때 발생하는 동시(concurrent) GC입니다.

  • GC_FOR_MALLOC

힙이 이미 가득 찬 상태에서 앱이 메모리 할당을 시도할 때 발생합니다. 시스템은 앱을 멈추고 메모리를 회수해야 하므로 메모리 할당이 실패할 수 있습니다.

  • GC_HPROF_DUMP_HEAP

힙 분석을 위한 HPROF 파일 생성을 요청했을 때 발생하는 GC입니다.

P.S. hprof 파일은 힙 사용 현황을 설명하며 Chrome의 heapsnapshot 파일과 유사합니다.

  • GC_EXPLICIT

명시적 GC입니다. 예를 들어 gc()를 호출하는 경우입니다 (이러한 방식은 피해야 하며, GC가 필요할 때 자동으로 실행되도록 맡겨야 합니다).

  • GC_EXTERNAL_ALLOC

외부 메모리 할당(예: 네이티브 메모리에 저장된 픽셀 데이터나 NIO 바이트 버퍼)으로 인해 발생하는 GC입니다. API 10 및 그 이하 버전에서만 나타납니다 (최신 버전은 모든 것이 Dalvik 힙 내에서 할당됩니다).

Amount freed

이번 GC를 통해 회수된 메모리 크기입니다.

Heap stats

힙 내 가용 메모리의 백분율과 [사용 중인 메모리 크기]/[전체 힙 크기]입니다.

External memory stats

외부 메모리 통계 데이터입니다.

API 10 및 그 이하 버전에서 외부에서 할당된 메모리와 [할당된 메모리 크기]/[GC 임계치]를 나타냅니다.

P.S. GC 임계치에 도달하면 GC가 수행됩니다.

Pause time

힙이 클수록 더 많은 중단(pause) 횟수가 필요합니다. 동시 GC(GC Reason이 GC_CONCURRENT인 경우)의 중단 시간은 두 부분으로 나뉩니다. 첫 번째는 GC 시작 시, 두 번째는 GC 종료 시입니다.

이러한 로그 정보를 기록하고 힙 통계(예시에서는 3571K/9991K)에 주목하십시오. 만약 이 수치가 계속 증가한다면 메모리 누수가 발생했을 가능성이 있습니다.

ART Log 정보

Dalvik과 달리 ART는 명시적으로 요청되지 않은(암시적) GC를 로그로 남기지 않습니다. GC가 '매우 느리다'고 판단될 때만 정보를 출력합니다. 정확히는 GC 중단 시간이 5ms를 초과하거나 GC 총 소요 시간이 100ms를 초과하는 경우입니다. 앱이 인지할 수 있는 중단 상태가 아니라면 GC는 느린 것으로 간주되지 않으며, 명시적 GC만 로그에 기록됩니다.

ART의 GC 로그에는 다음 정보가 포함됩니다.

I/art: <GC_Reason> <GC_Name> <Objects_freed>(<Size_freed>) AllocSpace Objects, <Large_objects_freed>(<Large_object_size_freed>) <Heap_stats> LOS objects, <Pause_time(s)>

예시:

I/art : Explicit concurrent mark sweep GC freed 104710(7MB) AllocSpace objects, 21(416KB) LOS objects, 33% free, 25MB/38MB, paused 1.230ms total 67.216ms

GC Reason

무엇이 GC를 트리거했는지, 어떤 유형의 가비지 컬렉션인지 나타냅니다. 가능한 값은 다음과 같습니다.

  • Concurrent

동시 GC입니다. 앱 스레드를 중단시키지 않으며 백그라운드 스레드에서 실행되어 메모리 할당을 방해하지 않습니다.

  • Alloc

힙이 가득 찬 상태에서 앱이 할당을 요청하여 GC가 초기화된 경우입니다. 이때 GC는 할당을 요청한 현재 스레드에서 실행됩니다.

  • Explicit

앱에 의해 명시적으로 요청된 GC입니다. 예를 들어 System.gc() 또는 runtime.gc()를 호출한 경우입니다. Dalvik과 마찬가지로 ART에서도 GC를 믿고 명시적 GC 요청을 최대한 피할 것을 권장합니다. 명시적 GC는 현재 스레드를 차단하고 불필요한 CPU 사이클을 소모하므로 권장되지 않습니다. 또한 GC로 인해 다른 스레드가 선점(preempt)될 경우 잔상(jank)이 발생할 수 있습니다.

P.S. 잔상(jank)이란 n번째 프레임이 그려진 후 n+1번째 프레임이 그려져야 하는데, CPU 선점으로 인해 데이터가 준비되지 않아 n번째 프레임을 한 번 더 보여주고 다음 그리기 때 n+1번째 프레임을 보여주는 현상을 말합니다.

  • NativeAlloc

Bitmap이나 RenderScript 객체와 같은 네이티브 할당으로 인한 네이티브 메모리 압박 때문에 발생하는 GC입니다.

  • CollectorTransition

힙 전이(heap transition)로 인해 발생하는 GC입니다. 런타임에서 GC 방식을 동적으로 전환할 때 발생하며, 가비지 컬렉터 전이 과정에는 모든 객체를 free-list backed space에서 bump pointer space로(혹은 그 반대로) 복사하는 과정이 포함됩니다. 현재 가비지 컬렉터 전이는 RAM이 적은 기기에서 앱이 실행 상태를 변경할 때(예: 인지 가능한 중단 상태에서 비인지 상태로 전환될 때 또는 그 반대)만 발생합니다.

  • HomogeneousSpaceCompact

Homogeneous space compaction은 free-list space들 간의 병합을 의미하며, 주로 앱이 비인지 중단 상태가 되었을 때 발생합니다. 주요 목적은 RAM 점유를 줄이고 힙 파편화(fragmentation)를 정리하는 것입니다.

  • DisableMovingGc

진정한 GC 사유는 아니지만, 파편화를 정리 중인 GC가 GetPrimitiveArrayCritical에 의해 차단된 상태를 의미합니다. 일반적으로 GetPrimitiveArrayCritical은 가비지 컬렉터의 전이를 제한하므로 사용하지 않는 것을 강력히 권장합니다.

  • HeapTrim

진정한 GC 사유는 아니지만, 힙 트리밍(heap trim)이 끝날 때까지 GC가 차단된 상태입니다.

GC Name

ART에는 몇 가지 서로 다른 GC가 있습니다.

  • Concurrent mark sweep (CMS)

전체 힙 가비지 컬렉터로, 이미지를 제외한 모든 공간을 회수하고 해제합니다.

  • Concurrent partial mark sweep

거의 전체 힙 가비지 컬렉터이며, 이미지와 zygote를 제외한 모든 공간을 회수합니다.

  • Concurrent sticky mark sweep

세대별 가비지 컬렉터로, 지난 GC 이후 할당된 객체만 회수합니다. 전체 또는 부분 마크 스위프보다 더 자주 실행되며, 속도가 빠르고 중단 시간이 짧습니다.

  • Marksweep + semispace

비동시적이며, 힙 복사 전이 및 homogeneous space compaction(힙 파편화 정리용) 시 사용되는 GC입니다.

Objects freed

이번 GC에서 비대형 객체 공간(non large object space)으로부터 회수된 객체 수입니다.

Size freed

이번 GC에서 비대형 객체 공간으로부터 회수된 바이트 수입니다.

Large objects freed

이번 GC에서 대형 객체 공간(large object space)으로부터 회수된 객체 수입니다.

Large object size freed

이번 GC에서 대형 객체 공간으로부터 회수된 바이트 수입니다.

Heap stats

가용 공간의 백분율과 [사용 중인 메모리 크기]/[전체 힙 크기]입니다.

Pause times

일반적으로 GC 실행 시 중단 횟수는 수정된 객체 참조 수에 비례합니다. 현재 ART CMS GC는 GC가 끝날 때 한 번만 중단됩니다. GC 전이 시에는 긴 중단이 발생하며, 이것이 GC 소요 시간의 주요 요인이 됩니다.

logcat에서 수많은 GC 정보를 보게 된다면 힙 통계(예시에서는 25MB/38MB)를 찾으십시오. 만약 수치가 결코 줄어들지 않고 지속적으로 증가한다면 메모리 누수가 있을 수 있습니다. 만약 GC 사유가 Alloc이라면 힙이 거의 가득 찼으며 OOM(Out Of Memory)이 임박했음을 의미합니다.

댓글

아직 댓글이 없습니다

댓글 작성