버그 신고 읽기

버그는 모든 개발 유형에서 발생하기 마련이며 버그 신고는 문제를 식별하고 해결하는 데 있어 매우 중요합니다. 모든 Android 버전은 Android 디버그 브리지(adb)를 통한 버그 신고 캡처를 지원합니다. Android 버전 4.2 이상에서는 이메일, 드라이브 등을 통해 버그 신고를 접수하고 공유할 수 있는 개발자 옵션을 지원합니다.

Android 버그 신고에는 dumpsys, dumpstatelogcat 데이터가 텍스트(.txt) 형식으로 포함되어 특정 콘텐츠를 쉽게 검색할 수 있습니다. 다음 섹션에서는 버그 신고 구성요소와 일반적인 문제를 자세히 설명하며 버그와 연결된 로그를 찾는 데 필요한 유용한 팁과 grep 명령어를 제공합니다. 대부분의 섹션에는 grep 명령어와 출력 및 dumpsys 출력의 예도 포함됩니다.

Logcat

logcat 로그는 모든 logcat 정보의 문자열 기반 덤프입니다. system 부분은 프레임워크를 위해 예약되었으며 다른 모든 부분을 포함하는 main보다 더 긴 기록을 갖습니다. 각 행은 일반적으로 timestamp UID PID TID log-level로 시작하지만 Android의 이전 버전에서는 UID가 없을 수도 있습니다.

이벤트 로그 보기

이 로그에는 바이너리 형식 로그 메시지의 문자열 표현이 포함됩니다. 이 로그는 logcat 로그보다 노이즈는 적지만 읽기가 더 어렵습니다. 이벤트 로그를 볼 때는 이 섹션에서 구체적인 처리 ID(PID)를 검색하여 프로세스가 무슨 작업을 실행하고 있었는지 확인할 수 있습니다. 기본 형식은 timestamp PID TID log-level log-tag tag-values입니다.

로그 수준에는 다음이 포함됩니다.

  • V: 상세 출력
  • D: 디버그
  • I: 정보
  • W: 경고
  • E: 오류

 

기타 유용한 이벤트 로그 태그는 /services/core/java/com/android/server/EventLogTags.logtags를 참고하세요.

ANR 및 교착

버그 신고는 애플리케이션 응답 없음(ANR) 및 교착 이벤트의 원인을 식별할 수 있게 도와줍니다.

응답하지 않는 앱 식별

일반적으로 차단되었거나 사용량이 많은 기본 스레드로 인해 애플리케이션이 특정 시간 내에 응답하지 않는다면 시스템은 프로세스를 종료하고 스택을 /data/anr로 덤프합니다. ANR의 원인을 찾으려면 바이너리 이벤트 로그에서 grep 명령어를 사용하여 am_anr을 검색합니다.

ANR 발생 시 CPU를 사용하고 있던 주체에 관한 추가 정보가 포함된 logcat 로그에서 grep 명령어를 사용하여 ANR in을 검색할 수도 있습니다.

스택 트레이스 찾기

종종 ANR에 대응하는 스택 트레이스를 찾을 수 있습니다. VM 트레이스에서 타임스탬프와 PID가 조사 중인 ANR과 일치하는지 확인한 후 프로세스의 기본 스레드를 확인합니다. 이때 다음 사항을 유의하세요.

  • 기본 스레드는 ANR 발생 시 스레드에서 실행하고 있던 작업만 알려주며 이는 ANR의 실제 원인일 수도 있고 아닐 수도 있습니다. (버그 신고의 스택이 원인이 아닐 수 있습니다. 다른 부분이 ANR을 일으킬 만큼 긴 시간은 아니더라도 장시간 중단되었다가 다시 작동했을 수 있습니다.)
  • 2개 이상의 스택 트레이스 세트(VM TRACES JUST NOWVM TRACES AT LAST ANR)가 존재할 수 있습니다. 올바른 섹션을 보고 있는지 확인하세요.

교착 상태 찾기

교착은 ANR로 먼저 표시될 때가 많으며 이는 스레드가 멈추고 있기 때문입니다. 시스템 서버에서 교착 상태가 발생하면 워치독은 결국 서버를 종료하며 로그에 WATCHDOG KILLING SYSTEM PROCESS와 유사한 항목이 기재됩니다. 사용자 관점에서는 기기 재부팅이지만 기술적으로 이는 실제 재부팅이 아닌 런타임 재시작입니다.

  • 런타임 재시작에서는 시스템 서버가 종료되었다가 다시 시작됩니다. 사용자에게는 기기가 부팅 애니메이션으로 돌아오는 모습이 표시됩니다.
  • 재부팅은 커널이 비정상 종료되었을 때 일어납니다. 사용자에게는 기기가 Google 부팅 로고로 돌아오는 모습이 표시됩니다.

교착 상태를 찾으려면 스레드 B에서 가지고 있는 무언가를 기다리고 있는 스레드 A의 패턴이 VM 트레이스 섹션에 있는지 확인합니다. 순차적으로 스레드 B도 스레드 A가 가지고 있는 무언가를 기다리고 있습니다.

활동

활동은 사용자가 전화 걸기, 사진 찍기, 이메일 보내기 등의 작업을 하도록 상호작용하는 화면을 제공하는 애플리케이션 구성요소입니다. 버그 신고의 관점에서 활동은 사용자가 할 수 있는 단 하나의 집중된 작업이므로 비정상 종료 시 하고 있던 활동을 찾는 것이 매우 중요합니다. ActivityManager를 통한 활동은 프로세스를 실행하므로 활동 프로세스의 모든 중단 및 시작을 찾는 것도 문제해결에 도움을 줄 수 있습니다.

집중적 활동 보기

집중적 활동의 기록을 보려면 am_focused_activity를 검색합니다.

프로세스 시작 보기

프로세스 시작 기록을 보려면 Start proc을 검색합니다.

기기 스래싱 여부 파악

기기가 스래싱되는지 알아보려면 짧은 시간 동안 am_proc_diedam_proc_start 주변에서 활동이 비정상적으로 증가했는지 확인합니다.

메모리

Android 기기는 물리적 메모리가 제한적인 경우가 많습니다. 따라서 랜덤 액세스 메모리(RAM) 관리가 매우 중요합니다. 버그 신고에는 메모리 부족에 관한 여러 지표, 그리고 메모리 스냅샷을 제공하는 dumpstate가 포함되어 있습니다.

메모리 부족 식별

메모리가 부족하면 시스템이 메모리 확보를 위해 일부 프로세스를 종료하는 동시에 다른 프로세스를 계속해서 시작하는 과정에서 스래싱을 경험할 수 있습니다. 메모리가 부족하다는 증거를 확인하려면 바이너리 이벤트 로그에서 am_proc_diedam_proc_start 항목의 집중 정도를 확인합니다.

또한 메모리가 부족하면 작업 전환이 둔화되고 반환 시도가 저지될 수 있습니다(사용자가 반환하려고 시도했던 작업이 종료되었기 때문). 종료된 런처는 사용자가 홈 버튼을 터치하면 재시작되고, 로그에는 런처가 콘텐츠를 다시 로드하는 모습이 표시됩니다.

이전 지표 보기

바이너리 이벤트 로그의 am_low_memory 항목은 마지막으로 캐시된 프로세스가 종료되었다는 의미입니다. 이후에는 시스템이 서비스를 종료하기 시작합니다.

스래싱 지표 보기

시스템 스래싱(페이징, 직접 회수 등)의 다른 표시기로는 kswapd, kworkermmcqd 소비 주기가 있습니다. 수집되고 있는 버그 신고가 스래싱 지표에 영향을 미칠 수 있음을 기억하세요.

ANR 로그는 유사한 메모리 스냅샷을 제공할 수 있습니다.

메모리 스냅샷 가져오기

메모리 스냅샷은 실행 중인 자바 및 네이티브 프로세스를 나열하는 dumpstate입니다. 자세한 내용은 전체 메모리 할당 보기를 참고하세요. 스냅샷은 구체적인 시점의 상태만 제공합니다. 시스템은 스냅샷 전에 상태가 훨씬 좋거나 나빴을 수 있습니다.

브로드캐스트

애플리케이션은 브로드캐스트를 생성하여 현재 애플리케이션 내의 이벤트를 전송하거나 다른 애플리케이션으로 보냅니다. Broadcast receiver는 필터를 통해 특정 메시지를 구독하여 브로드캐스트를 수신하고 응답할 수 있도록 지원합니다. 버그 신고에는 전송된 브로드캐스트와 전송되지 않은 브로드캐스트에 관한 정보는 물론 특정 브로드캐스트를 수신 중인 모든 receiver의 dumpsys까지 포함됩니다.

이전 브로드캐스트 보기

이전 브로드캐스트는 이미 전송된 브로드캐스트로서 시간 역순으로 나열됩니다.

요약 섹션은 포그라운드의 마지막 브로드캐스트 300건과 백그라운드의 마지막 브로드캐스트 300건에 관한 개요입니다.

세부정보 섹션에는 포그라운드의 마지막 브로드캐스트 50건과 백그라운드의 마지막 브로드캐스트 50건, 그리고 각 브로드캐스트의 receiver에 관한 모든 정보가 포함됩니다. Receiver는 다음 두 가지로 나뉩니다.

  • BroadcastFilter 항목은 런타임에 등록되며 이미 실행 중인 프로세스에만 전송됩니다.
  • ResolveInfo 항목은 매니페스트 항목을 통해 등록됩니다. ActivityManager가 아직 실행 중이 아니라면 각 ResolveInfo의 프로세스를 시작합니다.

활성 브로드캐스트 보기

활성 브로드캐스트는 아직 전송되지 않은 브로드캐스트입니다. 대기열의 숫자가 높으면 시스템이 속도에 맞춰 브로드캐스트를 전송할 수 없음을 의미합니다.

브로드캐스트 리스너 보기

브로드캐스트를 수신 중인 수신기의 목록을 보려면 dumpsys activity broadcasts에서 Receiver Resolver Table을 확인하세요. 다음 예는 USER_PRESENT를 수신하는 모든 수신기를 표시합니다.

모니터 경합

모니터 경합 로깅은 간혹 실제 모니터 경합을 나타낼 수도 있지만 대부분의 경우 시스템 과부하로 인해 모든 것이 둔화되었음을 나타냅니다. 시스템 또는 이벤트 로그에서는 ART에 의해 로깅된 긴 모니터 이벤트를 볼 수도 있습니다.

시스템 로그에서는 다음과 같이 표시됩니다.

10-01 18:12:44.343 29761 29914 W art     : Long monitor contention event with owner method=void android.database.sqlite.SQLiteClosable.acquireReference() from SQLiteClosable.java:52 waiters=0 for 3.914s

이벤트 로그에서는 다음과 같이 표시됩니다.

10-01 18:12:44.364 29761 29914 I dvm_lock_sample: [com.google.android.youtube,0,pool-3-thread-9,3914,ScheduledTaskMaster.java,138,SQLiteClosable.java,52,100]

백그라운드 컴파일

컴파일로 기기를 로드할 수 있지만 비용이 높습니다.

컴파일은 Google Play 스토어 업데이트가 다운로드되고 있을 때 백그라운드에서 발생할 수 있습니다. 이 경우 Google Play 스토어 앱(finsky)과 installd의 메시지는 dex2oat 메시지 이전에 표시됩니다.

컴파일은 애플리케이션이 아직 컴파일되지 않은 dex 파일을 로드하고 있을 때 백그라운드에서 발생할 수 있습니다. 이 경우 finsky 또는 installd 로깅이 보이지 않습니다.

설명

문제 설명(시작 경위, 상황, 시스템 대응 방식)을 수립하려면 확실한 이벤트 타임라인이 필요합니다. 버그 신고의 정보를 사용하여 여러 로그의 타임라인을 동기화하고 버그 신고의 정확한 타임스탬프를 파악할 수 있습니다.

타임라인 동기화

버그 신고는 시스템 로그, 이벤트 로그, 커널 로그, 브로드캐스트와 관련된 여러 특수 타임라인, 배터리 통계 등을 비롯한 여러 병렬 타임라인을 반영합니다. 안타깝게도 타임라인은 다른 시간 베이스를 사용하여 보고될 때가 많습니다.

시스템 및 이벤트 로그 타임스탬프는 다른 대부분의 타임스탬프처럼 사용자와 같은 시간대에 위치합니다. 예를 들어 사용자가 홈 버튼을 탭하면 시스템 로그는 다음을 보고합니다.

10-03 17:19:52.939  1963  2071 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL (has extras)} from uid 1000 on display 0

같은 작업에 관해 이벤트 로그는 다음을 보고합니다.

10-03 17:19:54.279  1963  2071 I am_focused_activity: [0,com.google.android.googlequicksearchbox/com.google.android.launcher.GEL]

커널(dmesg) 로그는 다른 시간 베이스를 사용하여 부트로더가 완료된 이후의 로그 항목을 초 단위로 태그합니다. 이 기간을 다른 기간에 등록하려면 다음과 같이 suspend exitsuspend entry 메시지를 검색합니다.

<6>[201640.779997] PM: suspend exit 2015-10-03 19:11:06.646094058 UTC
…
<6>[201644.854315] PM: suspend entry 2015-10-03 19:11:10.720416452 UTC

커널 로그에는 정지 도중의 시간이 포함되어 있지 않을 수 있습니다. 따라서 정지 항목 및 종료 메시지 간의 로그를 따로 등록해야 합니다. 또한 커널 로그는 UTC 시간대를 사용하며 사용자 시간대에 맞게 조정되어야 합니다.

버그 신고 시간 식별

버그 신고가 언제 접수되었는지 알아보려면 먼저 다음과 같이 시스템 로그(Logcat)에서 dumpstate: begin을 확인합니다.

10-03 17:19:54.322 19398 19398 I dumpstate: begin

그다음 Starting service 'bugreport' 메시지의 커널 로그(dmesg) 타임스탬프를 확인합니다.

<5>[207064.285315] init: Starting service 'bugreport'...

역으로 작업하여 두 이벤트 간의 상관 관계를 지정하고, 이때 타임라인 동기화에 언급된 주의사항을 유념해야 합니다. 버그 신고가 시작된 후에는 많은 상황이 발생하지만 대부분의 활동은 크게 유용하지 않습니다. 이는 버그 신고 접수 시 시스템에 상당한 부하가 발생하기 때문입니다.

전원

이벤트 로그에는 화면 전원 상태가 표시됩니다. 0은 화면 꺼짐, 1은 화면 켜짐, 2는 키가드 적용을 의미합니다.

버그 신고에는 wake lock에 관한 통계도 포함됩니다. 애플리케이션 개발자는 이 메커니즘을 사용하여 애플리케이션이 기기의 켜짐 상태를 유지해야 함을 나타냅니다. (wake lock에 관한 자세한 내용은 PowerManager.WakeLockCPU를 켜진 상태로 유지를 참조하세요.)

집계된 wake lock 지속 시간 통계는 wake lock이 실제로 기기 켜짐 상태에 기여한 시간만 추적하며 화면이 켜진 시간은 포함하지 않습니다. 또한 여러 wake lock이 동시에 사용되는 경우 wake lock 지속 시간이 이러한 여러 wake lock에 걸쳐 분산됩니다.

전원 상태 시각화에 관한 도움이 더 필요한 경우 Battery Historian을 사용하세요. 이 Google 오픈소스 도구는 Android 버그 신고 파일을 사용하여 배터리 소모 요소를 분석합니다.

패키지

DUMP OF SERVICE package 섹션에는 애플리케이션 버전 및 기타 유용한 정보가 포함되어 있습니다.

프로세스

버그 신고에는 시작 및 중지 시간, 런타임 길이, 연결된 서비스 및 oom_adj 스코어 등 방대한 양의 프로세스 데이터가 포함됩니다. Android에서 프로세스를 관리하는 방법에 관한 자세한 내용은 프로세스와 스레드를 참고하세요.

프로세스 런타임 파악

procstats 섹션에는 프로세스 및 연결된 서비스가 실행된 기간에 관한 일체의 통계가 포함됩니다. 사람이 읽을 수 있는 빠른 요약을 보려면 AGGREGATED OVER를 검색하여 마지막 세 시간 또는 24시간의 데이터를 확인한 다음 Summary:를 검색하여 프로세스 목록, 이러한 프로세스가 다양한 우선순위에서 실행된 기간 및 최소-평균-최대 PSS/최소-평균-최대 USS 형식으로 표시된 프로세스의 RAM 사용량을 확인합니다.

프로세스가 실행 중인 이유

dumpsys activity processes 섹션에는 현재 실행 중인 모든 프로세스가 oom_adj 스코어 순으로 나열됩니다(Android는 프로세스에 oom_adj 값을 할당하여 프로세스 중요도를 표시하며 이 값은 ActivityManager에서 동적으로 업데이트할 수 있음). 출력은 메모리 스냅샷의 출력과 유사하지만 프로세스를 실행시킨 주체에 관한 추가 정보를 포함합니다. 아래 예에서 굵게 표시된 항목은 시스템 프로세스가 NetworkLocationService와 결합되어 있기 때문에 우선순위가 vis(공개)인 상태에서 gms.persistent 프로세스가 실행 중임을 나타냅니다.

검색

과도한 저전력 블루투스(BLE) 검색을 실행 중인 애플리케이션을 식별하려면 다음 단계를 따르세요.

  • 다음과 같이 BluetoothLeScanner에 관한 로그 메시지를 찾습니다.
    $ grep 'BluetoothLeScanner' ~/downloads/bugreport.txt
    07-28 15:55:19.090 24840 24851 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=5
    
  • 로그 메시지에서 PID를 찾습니다. 이 예에서는 '24840' 및 '24851'이 프로세스 ID(PID) 및 스레드 ID(TID)입니다.
  • PID에 연결된 애플리케이션을 찾습니다.
    PID #24840: ProcessRecord{4fe996a 24840:com.badapp/u0a105}
    

    이 예에서 패키지 이름은 com.badapp입니다.

  • Google Play에서 패키지 이름을 찾아 해당하는 애플리케이션을 식별합니다(https://play.google.com/store/apps/details?id=com.badapp).

참고: Android 7.0을 실행하는 기기에서는 시스템이 BLE 검색 데이터를 수집하고 이러한 활동을 시작 애플리케이션에 연결합니다. 자세한 내용은 저전력(LE) 및 블루투스 검색을 참조하세요.