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—— 应用使用数据网络的时间