电量统计日志分析

Batterystats日志分析

概述

   由于项目组的原因，慢慢的接触了一些Android系统的“快省稳”知识，最近陆续学习了一些关于功耗的知识，而Batterystats日志是搞功耗的日常工作之一，搞功耗人员，每天都要从用户反馈和日常测试中分析大量的日志，从日志中不仅可以发现很多的功耗问题，还可以提取到很多有用的信息和功耗优化得方向，从中积累了一些分析经验，现把这些经验总结出来。

注：Batterystats日志中统计的信息有Statistics since last charge和Statistics since last unplugged两部分，有用的信息是Statistics since last charge部分，重点查看此部分即可。

基本信息

   为了将大量的日志信息形成报表，并用来跟踪问题及对比耗电情况，需要从日志中提取基本的耗电信息，并计算出耗电指标，列出以下重要指标。

Total run time: 总运行时间（包含充电）
Time on battery: 电池状态下运行时间 
Screen on:亮屏时间 
Time on battery screen off（realtime）:灭屏时间 
Time on battery screen off（uptime）:灭屏未待机时间 
Amount discharged while screen on:亮屏耗电值 
Amount discharged while screen off:灭屏耗电值

注：Batterystats日志信息中数据的统计包含了亮屏和灭屏的情况！

   根据以上信息，我们可以计算出相关耗电指标：

待机成功率 =（灭屏时间-灭屏未待机时间）/ 灭屏时间 
亮屏平均耗电 = 亮屏时间/亮屏耗电值 
灭屏平均耗电 = 灭屏时间/灭屏耗电值

耗电问题

   获取基本的信息后，就能基本确认出这份日志是否存在耗电问题，但是还是不清楚具体的耗电情况，需要对以下点具体分析。

查看耗电排行

   从日志中提出出以下信息，可以看出当前日志的耗电排行情况，耗电高的应用可能是耗电问题的来源。

Estimated power use (mAh):
    Capacity: 3000, Computed drain: 500, actual drain: 600-1000
    Screen: 100
    Unaccounted: 200
    Uid u0a73: 50
    Cell standby: 40
    Idle: 30
    Uid u0a48: 100
    Uid 0: 30
    Uid 1000: 20
    Uid u0a22: 10
    Uid u0a2: 15.4
    Uid u0a104: 12.3
    ...

查看内核持锁情况

   搜索以下信息，可以得到当前日志的内核持锁情况，持锁时间较长的锁，可能是耗电问题的来源。

All kernel wake locks:
  Kernel Wake lock EINT wakelock: 2d 13h 13m 59s 137ms (7 times) realtime
  Kernel Wake lock ttyC0       : 12h 10m 39s 396ms (44100 times) realtime
  Kernel Wake lock MT662x      : 3h 2m 11s 129ms (147074 times) realtime
  Kernel Wake lock pmicAuxadc irq wakelock: 1h 18m 47s 509ms (244242 times) realtime
  Kernel Wake lock ccci_ipc_3  : 1h 13m 57s 623ms (4257 times) realtime
  Kernel Wake lock PowerManagerService.WakeLocks: 1h 10m 9s 474ms (17939 times) realtime
  ...

查看系统持锁情况

   从以下信息中可以看出当前日志的系统持锁情况，持锁时间较长的锁，可能是耗电问题的来源。

All partial wake locks:
  Wake lock u0a7 DownloadManager: 40m 34s 884ms (11 times) realtime
  Wake lock 1000 ConnectivityService: 18m 38s 526ms (25 times) realtime
  Wake lock 1000 NextAlarmTracker: 4m 53s 374ms (51 times) realtime
  Wake lock 1000 ProximitySensorManager: 2m 6s 817ms (3 times) realtime
  ...

查看应用耗电行为

   如果从上面的信息中，看到了某个应用耗电比较严重，可以根据日志中应用进程的UID找到具体的应用耗电行为，如下。

u0a48:
    Mobile network: 27.44KB received, 29.84KB sent (packets 279 received, 430 sent)
    Mobile radio active: 1h 23m 52s 154ms (19.2%) 59x @ 7098 mspp
    Wi-Fi network: 35.04KB received, 53.29KB sent (packets 422 received, 770 sent)
    Wake lock *alarm*: 1s 267ms partial (57 times) realtime
    Foreground activities: 4s 126ms realtime (1 times)
    Foreground for: 2d 12h 24m 34s 925ms 
    Proc com.example.cloud:service_v1:
      CPU: 11s 200ms usr + 5s 110ms krn ; 0ms fg
      2 starts
    Proc com.example.cloud:
      CPU: 6s 620ms usr + 5s 190ms krn ; 1s 850ms fg
      2 starts
    Apk com.example.cloud:
      250 wakeup alarms
      Service com.example.statsapp.UsageStatsManagerService:
      ...

   从上面的信息，可以看到一个应用的使用锁，CPU，WiFi，数据等的情况，这些功能的使用可能是造成应用耗电的原因，应用异常的使用行为也可以从中看出，而这些异常的行为也可能是耗电问题的来源，我需要追踪这些耗电行为，限制应用的耗电行为，从而解决耗电问题。

日志中的其他信息

   除了以上介绍的一些信息来发现问题外，batterystats日志中还存在其他有用的信息，通过分析这些信息能帮助我们了解耗电行为及问题确认，并能发现潜在的一些问题和功耗优化点。

Power键操作

   Battery History中出现以下信息是说明用户有Power键的操作：

+36m43s558ms (3) 023 +wake_lock=1000:”PhoneWindowManager.mPowerKeyWakeLock” +screen brightness=dim

出现闹钟

   在灭屏情况下Battery History出现以下信息时，说明有闹钟点亮屏幕：

+8h57m57s358ms (3) 089 +screen brightness=bright 
+8h57m57s902ms (2) 089 +top=u0a33:”com.android.alarmclock” 
… 
+9h00m57s454ms (2) 089 -top=u0a33:”com.android.alarmclock” 
+9h00m57s454ms (3) 089 -screen brightness=dark

出现通话

   出现通话时，Battery History中出现以下信息：

+1m37s522ms (2) 100 +phone_in_call 
… 
+11m47s456ms (2) 100 -phone_in_call

   同时，在partial wake locks中会出现以下锁：

Wake lock 1000 ProximitySensorManager: 9m 16s 400ms (2 times) realtime!

出现充电

   有充电操作时，Battery History中出现以下信息：

+2h44m23s474ms (3) 037 status=charging plug=usb volt=3733 +plugged 
… 
+2h44m31s075ms (3) 037 status=not-charging plug=none volt=3774 -plugged

使用GPS

   有应用使用GPS时，在对应的应用耗电统计日志中会出现以下信息：

Sensor GPS: 1m 41s 376ms realtime (49 times)

   同时，在Battery History中也会出现以下信息：

+3h02m08s866ms (2) 097 +wake_lock=1000:”GpsLocationProvider” +gps +wifi_scan 
… 
+3h02m11s479ms (2) 097 +wake_lock=1000:”GpsLocationProvider” -gps

使用Sensor

   有应用使用Sensor时，在对应的应用耗电统计日志中会出现以下信息：

Sensor 4: 11h 42m 26s 292ms realtime (0 times) 
Sensor 15: 11h 42m 26s 292ms realtime (0 times) 
其中4，15代表sensor的编号，通过dumpsys sensorservice可查询到

WiFi的使用

   WiFi使用的信息可以在Statistics since last charge中查询：

Wi-Fi total received: 1.79GB, sent: 61.18MB (packets received 1428744, sent 866948)—— wifi总得数据流量 
Wifi on: 12h 23m 1s 730ms (20.5%), Wifi running: 12h 22m 42s 300ms (20.5%)—— wifi打开和运行的时间 
Wifi states: (no activity) 
Wifi supplicant states:—— wifi supplicant状态 
disconn 20h 56m 58s 879ms (34.7%) 54x—— 断开连接 
scanning 13h 13m 38s 990ms (21.9%) 52x—— 扫描 
associating 2m 39s 770ms (0.1%) 51x—— 配对 
associated 2m 5s 255ms (0.1%) 61x—— 配对成功 
4-way-handshake 28ms (0.0%) 1x —— 4次握手 
group-handshake 127ms (0.0%) 1x —— 组密钥握手 
completed 12h 6m 27s 576ms (20.0%) 61x—— 连接成功 
Wifi signal levels:—— wifi信号等级（值越小信号越差） 
level(1) 5h 23m 48s 425ms (8.9%) 15x 
level(2) 12h 38m 42s 455ms (20.9%) 53x 
level(3) 7h 5m 52s 764ms (11.7%) 203x 
level(4) 11h 13m 30s 530ms (18.6%) 165x

   通过观察以上信息我们可以判断WiFi连接状态：

未打开WiFi时的信息: 
Wi-Fi total received: 0B, sent: 0B (packets received 0, sent 0) 
Wifi on: 0ms (0.0%), Wifi running: 0ms (0.0%) 
Wifi states: (no activity) 
Wifi supplicant states: (no activity) 
Wifi signal levels: (no activity)

打开WiFi，未连接时的信息： 
Wi-Fi total received: 0B, sent: 0B (packets received 0, sent 0) 
Wifi on: 1h 2m 16s 246ms (100.0%), Wifi running: 1h 2m 16s 246ms (100.0%) 
Wifi states: (no activity) 
Wifi supplicant states: 
scanning 1h 2m 16s 246ms (100.0%) 0x 
Wifi signal levels: 
level(4) 1h 2m 16s 246ms (100.0%) 0x

打开WiFi，并连接时的信息： 
Wi-Fi total received: 0B, sent: 0B (packets received 0, sent 0) 
Wifi on: 1h 2m 16s 246ms (100.0%), Wifi running: 1h 2m 16s 246ms (100.0%) 
Wifi states: (no activity) 
Wifi supplicant states: 
scanning 1h 2m 16s 246ms (100.0%) 0x 
Wifi signal levels: 
level(4) 1h 2m 16s 246ms (100.0%) 0x

应用使用WiFi的信息

   应用使用WiFi的信息可以在对应的应用耗电统计日志中查询：

u0a109: 
Wi-Fi network: 84.54KB received, 117.80KB sent (packets 470 received, 663 sent)—— 应用使用wifi的流量 
Wifi Running: 0ms (0.0%)—— 应用使用wifi时间（未统计） 
Full Wifi Lock: 3h 39m 0s 107ms (33.3%)—— 应用持有wifi lock的时间（即不让wifi模块进入休眠的时间） 
Wifi Scan: 57m 10s 697ms (8.7%)—— 应用持有wifi scan时间

Modem的使用

   Modem数据网络在使用时，可以在Statistics since last charge中查询到以下信息(部分机型没有该信息)：

+4h18m48s144ms (1) 093 +mobile_radio 
… 
+4h18m53s474ms (1) 093 -mobile_radio

   Modem的使用的信息可以在Statistics since last charge中查询：

Mobile total received: 111.71MB, sent: 9.96MB (packets received 111391, sent 107681)—— Modem总得数据流量 
Phone signal levels:—— Modem信号等级 
none 7s 900ms (0.0%) 4x 
poor 464ms (0.0%) 1x 
moderate 27m 24s 343ms (0.8%) 84x 
good 2h 43m 53s 415ms (4.5%) 169x 
great 3h 51m 46s 147ms (6.4%) 122x 
very 2d 5h 21m 18s 662ms (88.2%) 39x 
Signal scanning time: 7s 900ms 
Radio types:—— Modem数据网络类型 
none 2d 5h 8m 7s 632ms (87.9%) 28x 
lte 7h 16m 21s 403ms (12.0%) 24x 
Mobile radio active time: 7h 16m 19s 539ms (12.0%) 23x—— Modem数据网络使用时间 
Mobile radio active unknown time: 9m 18s 517ms (0.3%) 59x 
Mobile radio active adjusted time: 0ms (0.0%)

   通过观察以上信息我们可以判断Modem连接状态：

飞行模式 
Phone signal levels: (no activity) 
Signal scanning time: 0ms 
Radio types: (no activity) 
Mobile radio active time: 0ms (0.0%) 0x

非飞行模式，不带SIM卡 
Phone signal levels: 
none 14h 45m 30s 764ms (100.0%) 0x 
Signal scanning time: 14h 45m 30s 764ms 
Radio types: (no activity) 
Mobile radio active time: 0ms (0.0%) 0x

非飞行模式，带SIM卡，不开启数据网络 
Mobile total received: 0B, sent: 0B (packets received 0, sent 0) 
Phone signal levels: 
none 1h 43m 21s 326ms (5.0%) 85x 
poor 11m 1s 594ms (0.5%) 1x 
moderate 1h 17m 50s 873ms (3.8%) 5x 
good 2h 35m 0s 176ms (7.5%) 21x 
great 1d 0h 59m 14s 343ms (72.7%) 65x 
very 3h 36m 4s 988ms (10.5%) 16x 
Signal scanning time: 17m 23s 759ms 
Radio types: 
none 1d 10h 22m 33s 300ms (100.0%) 0x 
Mobile radio active time: 0ms (0.0%) 0x

非飞行模式，带SIM卡，开启数据网络 
Mobile total received: 1.92MB, sent: 1.06MB (packets received 8064, sent 11425) 
Phone signal levels: 
great 5s 873ms (0.0%) 2x 
very 15h 1m 8s 875ms (100.0%) 2x 
Signal scanning time: 0ms 
Radio types: 
none 12s 320ms (0.0%) 0x 
lte 15h 1m 2s 428ms (100.0%) 1x 
Mobile radio active time: 2h 33m 48s 773ms (17.1%) 1206x

应用使用数据网络的信息

   应用使用数据网络的信息可以在对应的应用耗电统计日志中查询：

u0a99: 
Mobile network: 193.95KB received, 148.75KB sent (packets 1411 received, 1556 sent)—— 应用使用数据网络的流量 
Mobile radio active: 32m 40s 220ms (21.2%) 620x @ 661 mspp—— 应用使用数据网络的时间