본문 바로가기
[Developer]/Android

Android Dumpstate 로그 추출 및 분석(2/2)

by 해피빈이 2021. 7. 13.

Photo by Ilya Pavlov on Unsplash

 

지난번에 이어 추가로 dumpstate 로그 추출 후 분석에 대한 부분을 다루려고 한다.

 

로그 읽기(이어서)

브로드 캐스트 로그

애플리케이션은 브로드캐스트를 생성하여 현재 애플리케이션 내의 이벤트를 전송하거나 다른 애플리케이션으로 보낸다. 버그 리포트에는 전송된 브로드캐스트와 전송되지 않은 브로드캐스트에 대한 정보는 물론 특정 브로드캐스트를 수신중인 모든 리시버의 dumpsys까지 포함된다.

 

이전 브로드 캐스트를 보는 방법은 다음과 같으며, 최근 로그가 가장 위로 보이게 된다.

summary 섹션은 foreground의 최근 브로드캐스트 300건과, background의 최근 브로드캐스트 300건에 대한것이 나온다. 아래는 그 예시이다.(Historical broadcasts summary로 검색이 가능하다.)

  Historical broadcasts summary [foreground]:
  #0: act=android.intent.action.TIME_TICK flg=0x50200010
    +1ms dispatch +1ms finish
    enq=2021-07-12 03:06:00.001 disp=2021-07-12 03:06:00.002 fin=2021-07-12 03:06:00.003
  #1: act=android.intent.action.CLOSE_SYSTEM_DIALOGS flg=0x50000010 (has extras)
    +1ms dispatch 0 finish
    enq=2021-07-12 03:05:23.300 disp=2021-07-12 03:05:23.301 fin=2021-07-12 03:05:23.301
    extras: Bundle[{reason=recentapps}]
  #2: act=android.intent.action.CLOSE_SYSTEM_DIALOGS flg=0x50000010 (has extras)
    0 dispatch +1ms finish
    enq=2021-07-12 03:05:20.459 disp=2021-07-12 03:05:20.459 fin=2021-07-12 03:05:20.460
    extras: Bundle[{reason=homekey}]
......
  Historical broadcasts summary [background]:
  #0: act=com.google.android.settings.intelligence.LOG_BRIDGE flg=0x10 pkg=com.google.android.settings.intelligence (has extras)
    +1ms dispatch +44ms finish
    enq=2021-07-12 03:06:20.476 disp=2021-07-12 03:06:20.477 fin=2021-07-12 03:06:20.521
    extras: Bundle[{STRIPPED=1}]
  #1: act=com.google.android.gms.gcm.ACTION_SCHEDULE flg=0x10 pkg=com.google.android.gms (has extras)
    +1ms dispatch +1ms finish
    enq=2021-07-12 03:05:26.693 disp=2021-07-12 03:05:26.694 fin=2021-07-12 03:05:26.695
    extras: Bundle[{STRIPPED=1}]
  #2: act=com.google.android.gms.gcm.ACTION_SCHEDULE flg=0x10 pkg=com.google.android.gms (has extras)
    0 dispatch +2ms finish
    enq=2021-07-12 03:05:26.692 disp=2021-07-12 03:05:26.692 fin=2021-07-12 03:05:26.694
    extras: Bundle[{STRIPPED=1}]

 

세부정보 섹션에는 foreground의 최근 브로드캐스트 50건과 background 최근 브로드캐스트 50건, 그리고 각 브로드캐스트의 리시버에 관한 모든 정보가 포함된다.

리시버는 BroadcastFilter 항목(런타임에 등록되며 이미 실행중인 프로세스에만 전송)과 ResolveInfo 항목(매니페스트를 통해 등록되며, ActivityManager가 실행중이 아니라면 ResolveInfo의 프로세스를 통해 실행됨)으로 각각 나뉘어 보이게 된다.

아래는 그 예시이다.(Historical broadcasts로 검색하면 볼 수 있다. 당연히 summary는 검색어에서 빠져야 하며, 각 해당 내용을 보면 summary보다 훨씬 길다는 것을 알 수 있다.)

 Historical broadcasts [foreground]:
  Historical Broadcast foreground #0:
    BroadcastRecord{7b1bd87 u-1 android.intent.action.TIME_TICK} to user -1
    Intent { act=android.intent.action.TIME_TICK flg=0x50200010 }
    caller=android 1543:system/1000 pid=1543 uid=1000
    enqueueClockTime=2021-07-12 03:06:00.001 dispatchClockTime=2021-07-12 03:06:00.002
    dispatchTime=-34s687ms (+1ms since enq) finishTime=-34s685ms (+2ms since disp)
    Deliver 0 #0: BroadcastFilter{5ccf222 10046/u0 ReceiverList{f2a63ed 2007 com.android.systemui/10046/u0 remote:e30a204}}
    Deliver 0 #1: BroadcastFilter{a3e696e 10046/u0 ReceiverList{65d38e9 2007 com.android.systemui/10046/u0 remote:ddfd70}}
    Deliver 0 #2: BroadcastFilter{45ea62b 10046/u0 ReceiverList{76bae7a 2007 com.android.systemui/10046/u0 remote:5477aa5}}
    Deliver 0 #3: BroadcastFilter{a5b5342 10046/u-1 ReceiverList{e9f158d 2007 com.android.systemui/10046/u-1 remote:2e89624}}
    Deliver 0 #4: BroadcastFilter{87e9e58 10046/u0 ReceiverList{f5ee73b 2007 com.android.systemui/10046/u0 remote:ecf09ca}}
  Historical Broadcast foreground #1:
    BroadcastRecord{bd704b4 u-1 android.intent.action.CLOSE_SYSTEM_DIALOGS} to user -1
    Intent { act=android.intent.action.CLOSE_SYSTEM_DIALOGS flg=0x50000010 (has extras) }
      extras: Bundle[{reason=recentapps}]
    caller=null null pid=-1 uid=1000
......
  Historical broadcasts [background]:
  Historical Broadcast background #0:
    BroadcastRecord{a7bc37b u0 com.google.android.settings.intelligence.LOG_BRIDGE} to user 0
    Intent { act=com.google.android.settings.intelligence.LOG_BRIDGE flg=0x10 pkg=com.google.android.settings.intelligence (has extras) }
      extras: Bundle[{STRIPPED=1}]
    caller=com.android.settings 12240:com.android.settings/1000 pid=12240 uid=1000
    enqueueClockTime=2021-07-12 03:06:20.476 dispatchClockTime=2021-07-12 03:06:20.477
    dispatchTime=-14s236ms (+1ms since enq) finishTime=-14s192ms (+44ms since disp)
    resultTo=null resultCode=0 resultData=null
    nextReceiver=1 receiver=null
    Deliver +44ms #0: (manifest)
      priority=0 preferredOrder=0 match=0x108000 specificIndex=-1 isDefault=false
      ActivityInfo:
        name=com.google.android.settings.intelligence.modules.settingslogbridge.impl.SettingsLogBridgeBroadcastReceiver
        packageName=com.google.android.settings.intelligence
        enabled=true exported=true directBootAware=false
        permission=android.permission.WRITE_SETTINGS_HOMEPAGE_DATA
        resizeMode=RESIZE_MODE_RESIZEABLE
  Historical Broadcast background #1:
    BroadcastRecord{863e598 u0 com.google.android.gms.gcm.ACTION_SCHEDULE} to user 0
    Intent { act=com.google.android.gms.gcm.ACTION_SCHEDULE flg=0x10 pkg=com.google.android.gms (has extras) }
      extras: Bundle[{STRIPPED=1}]

 

활성 브로드캐스트를 보기 위해서는 Active ordered broadcasts로 검색하면 되며, 아직 전송되지 않은 브로드캐스트를 의미한다. 대기열의 숫자가 높으면, 시스템이 원하는 속도로 브로드캐스트를 전송할 수 없음을 의미한다. 아래는 그 예시이다.

 Active ordered broadcasts [background]:
 Active Ordered Broadcast background #133: // size of queue
 ...

 

브로드캐스트 리스너는 다음과 같다. 현재 설치된 앱들이 각각 어떤 리시버로 대기하고 있는지 상태를 파악할 수 있다. 이것을 검색하기 위해서는 'ACTIVITY MANAGER BROADCAST STATE'라고 검색하면 된다. 아래는 그 예이다.

-------------------------------------------------------------------------------
ACTIVITY MANAGER BROADCAST STATE (dumpsys activity broadcasts)
  Registered Receivers:
  * ReceiverList{6c1f781 2007 com.android.systemui/10046/u0 remote:f6ab768}
    app=2007:com.android.systemui/u0a46 pid=2007 uid=10046 user=0
    Filter #0: BroadcastFilter{8c5e026}
      Action: "android.intent.action.MANAGED_PROFILE_AVAILABLE"
  * ReceiverList{68cbc8 1986 com.android.bluetooth/1002/u0 remote:c68a46b}
    app=1986:com.android.bluetooth/1002 pid=1986 uid=1002 user=0
    Filter #0: BroadcastFilter{f65e461}
      Action: "android.intent.action.USER_SWITCHED"
      Action: "android.intent.action.USER_UNLOCKED"
  * ReceiverList{8fe97dc 1543 system/1000/u0 local:44c844f}
    app=1543:system/1000 pid=1543 uid=1000 user=0
    Filter #0: BroadcastFilter{6d3e0e5}
      Action: "android.media.VOLUME_CHANGED_ACTION"
      Action: "android.media.STREAM_DEVICES_CHANGED_ACTION"
  * ReceiverList{73e0375 2650 com.google.android.gms.persistent/10023/u0 remote:aa86aac}
    app=2650:com.google.android.gms.persistent/u0a23 pid=2650 uid=10023 user=0
    Filter #0: BroadcastFilter{bf34f0a}
      Action: "com.google.android.gms.fido.CABLE_AUTHENTICATOR"

 

모니터 경합 로깅

모니터 경합 로깅은 모니터 경합을 의미하는 것이 맞지만, 대부분의 경우에는 시스템 과부하로 인해 모든 것이 둔화되었음을 나타내는 경우가 훨씬 많다. 시스템로그 혹은 이벤트로그에서는 ART에 의해 로깅된 긴 모니터 이벤트를 볼 수도 있다. 다음은 그 예이다.

// 시스템 로그에서
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]

 

백그라운드 컴파일 로그

컴파일은 기기를 로드할 수 있지만, 비용이 높다. 아래는 dex2oat로 로드되는 것을 보여주고 있다.

09-14 06:27:05.670  2508  2587 E ActivityManager: CPU usage from 0ms to 5857ms later:
09-14 06:27:05.670  2508  2587 E ActivityManager:   84% 5708/dex2oat: 81% user + 2.3% kernel / faults: 3731 minor 1 major
09-14 06:27:05.670  2508  2587 E ActivityManager:   73% 2508/system_server: 21% user + 51% kernel / faults: 10019 minor 28 major
09-14 06:27:05.670  2508  2587 E ActivityManager:   1% 3935/com.android.phone: 0.3% user + 0.6% kernel / faults: 2684 minor 2 major

 

컴파일은 Google Play Store 업데이트가 다운로드 되고 있을 때, 백그라운드에서 발생할 수 있다. 이 경우 Google Play Store 앱인 finsky와 installd의 메시지는 dex2oat 메시지 앞에 표시된다. 아래와 같다.

10-07 08:42:33.725 11051 11051 D Finsky  : [1] InstallerTask.advanceState: Prepare to patch com.garmin.android.apps.virb (com.garmin.android.apps.virb) from content://downloads/my_downloads/3602 format 2
10-07 08:42:33.752   495   495 I installd: free_cache(48637657) avail 15111192576
…
10-07 08:42:39.998  2497  2567 I PackageManager.DexOptimizer: Running dexopt (dex2oat) on: /data/app/vmdl436577137.tmp/base.apk pkg=com.garmin.android.apps.virb isa=arm vmSafeMode=false debuggable=false oatDir = /data/app/vmdl436577137.tmp/oat bootComplete=true
…

 

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

09-14 07:29:20.433 15736 15736 I dex2oat : /system/bin/dex2oat -j4 --dex-file=/data/user/0/com.facebook.katana/app_secondary_program_dex/program-72cef82b591768306676e10161c886b58b34315a308602be.dex.jar --oat-file=/data/user/0/com.facebook.katana/app_secondary_program_dex_opt/program-72cef82b591768306676e10161c886b58b34315a308602be.dex.dex
...
09-14 07:29:25.102 15736 15736 I dex2oat : dex2oat took 4.669s (threads: 4) arena alloc=7MB java alloc=3MB native alloc=29MB free=4MB

 

서사에 관한 로그(Narrative)

문제의 서사를 위해서는 확실한 이벤트 타임라인이 필요하다. 버그 리포트에 있는 정보를 활용하여 여러 로그의 타임라인을 동기화하고 버그 리포트의 정확한 타임스탬프를 파악할 수 있다.

 

버그리포트는 시스템로그, 이벤트로그, 커널로그, 브로드캐스트와 관련된 여러 특수한 타임라인, 배터리 통계 등을 비롯한 여러 병렬 타임라인을 반영한다. 시스템 및 이벤트로그 타임스탬프는 대부분의 타임스탬프처럼 사용자와 같은 시간대로 보여준다. 가령 사용자가 홈 버튼을 누르면 시스템 로그 및 이벤트 로그는 다음처럼 나오게 된다.

// 시스템 로그
07-12 02:50:57.409  1000  1543  1598 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10000100 cmp=com.google.android.apps.nexuslauncher/.NexusLauncherActivity (has extras)} from uid 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 exit 및 suspend entry 메시지를 검색하면 된다. 그리고 커널로그에는 정지 도중의 시간이 포함되어 있지 않을 수 있다. 또한 커널 로그는 UTC 시간대를 사용하며 사용자 시간대에 맞게 조정되어야 한다.

<6>[117639.270527] c7   3231 PM: suspend exit 2021-07-11 17:38:13.300455702 UTC
<6>[117639.270548] c3     73 Stop suspend monitor
<6>[117639.400223] c0   3231 PM: suspend entry 2021-07-11 17:38:13.430138580 UTC

버그 리포트를 한 시간을 확인하는 방법은 다음과 같다. 시스템로그에서 'dumpstate: begin'을 확인한다. 그리고 커널로그의 타임 스탬프에서는 'Starting service 'bugreport'' 메시지의 커널로그 타임스탬프를 확인한다. 참고로 버그신고 버튼을 눌러 진행한 것이 아닌 지금처럼 덤프로그 추출시에는 아래와 같은 로그가 나오지 않았을 수 있으니 참고하면 된다.

// 버그 접수시간 파악하기
10-03 17:19:54.322 19398 19398 I dumpstate: begin

// 커널로그의 타임스탬프 확인하기
<5>[207064.285315] init: Starting service 'bugreport'...

 

전원

이벤트 로그에는 화면 전원의 상태가 표시된다. 0은 화면 꺼짐, 2는 키가드 적용을 의미한다. screen_toggled라고 검색하면 찾을 수 있다.

grep screen_toggled bugreport-2015-10-18-16-52-22.txt
10-18 15:05:04.383   992   992 I screen_toggled: 1
10-18 15:05:07.010   992   992 I screen_toggled: 0
10-18 15:23:15.063   992   992 I screen_toggled: 1
10-18 15:23:25.684   992   992 I screen_toggled: 0
10-18 15:36:31.623   992   992 I screen_toggled: 1
10-18 15:36:37.660  3283  3283 I screen_toggled: 2

버그리포트에는 wake lock에 관한 통계도 포함된다. 집계된 wake lock 지속시간 통계는 wake lock이 실제로 기기 켜짐 상태에 기여한 시간만 추척하며 화면이 켜진 시간은 포함하지 않는다. 또한 여러 wake lock이 동시에 사용되는 경우 wake lock 지속시간이 이러한 wake lock에 걸쳐 분산된다. 전원상태 시각화에 도움을 주는 도구도 별도로 오픈소스로 제공되고 있다. Battery Historian이라 불리는 이 도구를 이용하여, 분석하는 것도 좋은 방법이다.

(https://github.com/google/battery-historian)

 

패키지

'Packages:'라고 검색하면 찾을 수 있는 이 패키지 로그에는 애플리케이션 버전 및 기타 유용한 정보가 포함되어 있으므로 분석에 용이하게 사용할 수 있다. 예시는 다음과 같다.

Packages:
  Package [com.android.internal.display.cutout.emulation.noCutout] (9a02cca):
    userId=10001
    pkg=Package{514ce3b com.android.internal.display.cutout.emulation.noCutout}
    codePath=/product/overlay/DisplayCutoutNoCutout
    resourcePath=/product/overlay/DisplayCutoutNoCutout
    legacyNativeLibraryDir=/product/overlay/DisplayCutoutNoCutout/lib
    primaryCpuAbi=null
    secondaryCpuAbi=null
    versionCode=1 minSdk=30 targetSdk=30
    versionName=1.0
    splits=[base]
    apkSigningVersion=3
    applicationInfo=ApplicationInfo{514ce3b com.android.internal.display.cutout.emulation.noCutout}
    flags=[ SYSTEM ALLOW_CLEAR_USER_DATA ALLOW_BACKUP ]
    privateFlags=[ PRIVATE_FLAG_ACTIVITIES_RESIZE_MODE_RESIZEABLE_VIA_SDK_VERSION ALLOW_AUDIO_PLAYBACK_CAPTURE PRODUCT PRIVATE_FLAG_ALLOW_NATIVE_HEAP_POINTER_TAGGING ]
    forceQueryable=false
    queriesPackages=[]
    dataDir=/data/user/0/com.android.internal.display.cutout.emulation.noCutout
    supportsScreens=[small, medium, large, xlarge, resizeable, anyDensity]
    timeStamp=2009-01-01 09:00:00
    firstInstallTime=2009-01-01 17:00:00
    lastUpdateTime=2009-01-01 09:00:00
    signatures=PackageSignatures{d53f958 version:3, signatures:[74691cb0], past signatures:[]}
    installPermissionsFixed=false
    pkgFlags=[ SYSTEM ALLOW_CLEAR_USER_DATA ALLOW_BACKUP ]
    overlayTarget=android
    overlayCategory=com.android.internal.display_cutout_emulation
    User 0: ceDataInode=2394 installed=true hidden=false suspended=false distractionFlags=0 stopped=false notLaunched=false enabled=0 instant=false virtual=false
    User 10: ceDataInode=0 installed=true hidden=false suspended=false distractionFlags=0 stopped=false notLaunched=false enabled=0 instant=false virtual=false
    User 11: ceDataInode=0 installed=true hidden=false suspended=false distractionFlags=0 stopped=false notLaunched=false enabled=0 instant=false virtual=false
  Package [com.google.android.networkstack.tethering] (331ce22):
    userId=1073
    sharedUser=SharedUserSetting{4ca2ab1 android.uid.networkstack/1073}
    pkg=Package{8fc4b96 com.google.android.networkstack.tethering}
    codePath=/apex/com.android.tethering/priv-app/TetheringGoogle
    resourcePath=/apex/com.android.tethering/priv-app/TetheringGoogle
    legacyNativeLibraryDir=/apex/com.android.tethering/priv-app/TetheringGoogle/lib
    primaryCpuAbi=arm64-v8a
    secondaryCpuAbi=null
    versionCode=30 minSdk=30 targetSdk=29
    versionName=11-7312643
    splits=[base]
    apkSigningVersion=3
    ......

 

프로세스

버그리포트에는 시작 및 중지시간, 런타임 길이, 연결된 서비스 및 oom_adj 스코어 등 방대한 양의 프로세스 데이터가 포함된다. 안드로이드에서 프로세스를 관리하는 방법에 관한 자세한 내용을 참고하면 도움이 된다.

(https://developer.android.com/guide/components/processes-and-threads.html?hl=ko)

프로세스 런타임을 파악하기 위해서는 procstats 섹션을 참고하면 된다. 'DUMP OF SERVICE procstats'로 검색 가능하다. 사람이 읽을 수 있는 빠른 요약을 보려면 'AGGREGATED OVER'를 검색하는 것이 도움이 되며, 이 경우 마지막 세 시간 혹은 24시간의 데이터를 확인할 수 있다. 그리고 'Summary:'를 검색하여 프로세스 목록, 이러한 프로세스가 다양한 우선순위에서 실행된 기간 및 최소-평균-최대 PSS/최소-평균-최대 USS 형식으로 표시된 프로세스의 RAM 사용량을 확인할 수 있다. 예시로는 다음과 같다.

-------------------------------------------------------------------------------
DUMP OF SERVICE processinfo:
-------------------------------------------------------------------------------
DUMP OF SERVICE procstats:
COMMITTED STATS FROM 2015-10-19-23-54-56 (checked in):
...
COMMITTED STATS FROM 2015-10-20-03-00-00 (checked in):
...
CURRENT STATS:
...
AGGREGATED OVER LAST 24 HOURS:
System memory usage:
...
Per-Package Stats:
...
Summary:
...
  * com.google.android.gms.persistent / u0a13 / v8186448:
           TOTAL: 100% (21MB-27MB-40MB/20MB-24MB-38MB over 597)
             Top: 51% (22MB-26MB-38MB/21MB-24MB-36MB over 383)
          Imp Fg: 49% (21MB-27MB-40MB/20MB-25MB-38MB over 214)
…
          Start time: 2015-10-19 09:14:37
  Total elapsed time: +1d0h22m7s390ms (partial) libart.so

AGGREGATED OVER LAST 3 HOURS:
System memory usage:
...
Per-Package Stats:
...
Summary:
  * com.google.android.gms.persistent / u0a13 / v8186448:
           TOTAL: 100% (23MB-27MB-32MB/21MB-25MB-29MB over 111)
             Top: 61% (23MB-26MB-31MB/21MB-24MB-28MB over 67)
          Imp Fg: 39% (23MB-28MB-32MB/21MB-26MB-29MB over 44)
...
          Start time: 2015-10-20 06:49:24
  Total elapsed time: +2h46m59s736ms (partial) libart.so

 

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

-------------------------------------------------------------------------------
ACTIVITY MANAGER RUNNING PROCESSES (dumpsys activity processes)
...
Process LRU list (sorted by oom_adj, 34 total, non-act at 14, non-svc at 14):
    PERS #33: sys   F/ /P  trm: 0 902:system/1000 (fixed)
    PERS #32: pers  F/ /P  trm: 0 2925:com.android.systemui/u0a27 (fixed)
    PERS #31: pers  F/ /P  trm: 0 3477:com.quicinc.cne.CNEService/1000 (fixed)
    PERS #30: pers  F/ /P  trm: 0 3484:com.android.nfc/1027 (fixed)
    PERS #29: pers  F/ /P  trm: 0 3502:com.qualcomm.qti.rcsbootstraputil/1001 (fixed)
    PERS #28: pers  F/ /P  trm: 0 3534:com.qualcomm.qti.rcsimsbootstraputil/1001 (fixed)
    PERS #27: pers  F/ /P  trm: 0 3553:com.android.phone/1001 (fixed)
    Proc #25: psvc  F/ /IF trm: 0 4951:com.android.bluetooth/1002 (service)
        com.android.bluetooth/.hfp.HeadsetService<=Proc{902:system/1000}
    Proc # 0: fore  F/A/T  trm: 0 3586:com.google.android.googlequicksearchbox/u0a29 (top-activity)
  Proc #26: vis   F/ /SB trm: 0 3374:com.google.android.googlequicksearchbox:interactor/u0a29 (service)
        com.google.android.googlequicksearchbox/com.google.android.voiceinteraction.GsaVoiceInteractionService<=Proc{902:system/1000}
    Proc # 5: vis   F/ /T  trm: 0 3745:com.google.android.gms.persistent/u0a12 (service)
        com.google.android.gms/com.google.android.location.network.NetworkLocationService<=Proc{902:system/1000}
    Proc # 3: vis   F/ /SB trm: 0 3279:com.google.android.gms/u0a12 (service)
        com.google.android.gms/.icing.service.IndexService<=Proc{947:com.google.android.googlequicksearchbox:search/u0a29}
    Proc # 2: vis   F/ /T  trm: 0 947:com.google.android.googlequicksearchbox:search/u0a29 (service)
        com.google.android.googlequicksearchbox/com.google.android.sidekick.main.remoteservice.GoogleNowRemoteService<=Proc{3586:com.google.android.googlequicksearchbox/u0a29}
    Proc # 1: vis   F/ /T  trm: 0 2981:com.google.process.gapps/u0a12 (service)
        com.google.android.gms/.tapandpay.hce.service.TpHceService<=Proc{3484:com.android.nfc/1027}
    Proc #11: prcp  B/ /IB trm: 0 3392:com.google.android.inputmethod.latin/u0a64 (service)
        com.google.android.inputmethod.latin/com.android.inputmethod.latin.LatinIME<=Proc{902:system/1000}
    Proc #24: svc   B/ /S  trm: 0 27071:com.google.android.music:main/u0a67 (started-services)

 

스캔 로그

다음은 과도한 BLE(저전력 블루투스)를 스캔하는 애플리케이션을 찾기 위한 방법이다.

  1. 다음과 같이 BluetoothLeScanner에 관한 로그 메시지를 찾는다.
    07-12 02:55:31.823 10023  2650  2675 D BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=6 mScannerId=0
  2. 로그 메시지에서 PID를 찾는다. 이 예에서는 '2650'이 PID이며, '2675'가 TID가 된다.
  3. PID에 연결된 애플리케이션을 찾는다. 'PID #숫자'형식으로 쉽게 찾을 수 있다.
        PID #2650: ProcessRecord{264b057 2650:com.badapp/u0a23}
    이 예에서 패키지 이름은 com.badapp이 된다.
  4. Google Play에서 패키지 이름을 찾아 해당하는 애플리케이션을 식별한다. 위와 같은 경우에는 'https://play.google.com/store/apps/details?id=com.badapp'과 같이 될 것이다.

 

결론

지난번에 이어서 공식문서를 기반으로 로그 분석에 대한 부분을 실행해보고 찾아보면서 유용하게 사용할 수 있는 부분을 직접 다시 정리해보았다. 공식문서에도 충분히 나오지만, 각 로그를 일일히 열어서 보기가 귀찮다면 이 포스팅이 작은 도움이 될 것이다. 중급 이상의 안드로이드 개발자라면 조금 까다로운 로그를 볼 경우가 생길텐데 이 경우 이러한 로그 분석이 광명을 찾게 해 줄 것이라고 믿는다.

 

 

출처

- 버그 신고캡처 및 읽기: https://developer.android.com/studio/debug/bug-report?hl=ko

- 버그신고 읽기: https://source.android.com/setup/contribute/read-bug-reports?hl=ko#anrs-deadlocks

 

반응형

댓글