Android系统问题及日志分析

最新推荐文章于 2024-03-14 21:37:24 发布

大渔歌_

最新推荐文章于 2024-03-14 21:37:24 发布

阅读量4.2k

点赞数 2

分类专栏： Android 知识碎片文章标签： android系统问题

原文链接：https://blog.csdn.net/u010871962/article/details/109857386

版权

Android 知识碎片专栏收录该内容

51 篇文章 2 订阅

订阅专栏

这篇文章全是干货，我们一起聊聊安卓系统稳定性问题、部分性能问题。本篇列举了作者在某厂工作中遇到实际问题，大部分只有日志概率性问题，通过日志分析问题。

自己对这半年工作做个笔记，也希望对大家有用。方便你我他，希望大家多多支持原创。

2.有多个anr及crash弹窗提示太过频繁

3.[Framework-Google-GMS] com.google.android.gms.persistent Crash

4.[Framework-Google-GMS] com.google.android.googlequicksearchbox:search Crash

5.[Framework-Google-GMS] com.google.android.calendar Anr

6.点击相册显示“相册屡次停止运行”

7.[Framework Performance Stablility] com.android.vending Anr

8.[Google Services Framework]切换40多种语言后，测试机切换语言出现卡顿，一台出现“Google Services Framework keeps stopping”，重启无法恢复

9.电容笔放置屏幕上，开启youtube播放视频，同时开启录屏。待机至第二天屏幕黑屏，打开界面为主界面，录屏只录制40分钟

10.测试机从暗环境切换到亮环境，亮度数值变化与进度条变化不一致（进度条有点慢）

一、应用类问题相关日志

Crash 提示“应用停止运行”

搜索Android崩溃的日志。
按Fatal > Crash > AndroidRuntime > Shutting down VM > Exception > Error 的顺序逐个搜索。

Crash：
关键log:
androidlog:
Shutting down VM|am_crash|FATAL EXCEPTION|FAILED BINDER TRANSACTION|system_app_crash|JavaBinder
主要看：system_app_crash文件堆栈调用

ANR 提示“应用无响应“

ANR即（application not responding），即应用无响应，程序会弹出一个dialog提示用户程序无响应，而这对于用户体验无疑是很不好的
至于程序为何会“无响应”，主要有以下几个原因
1：InputDispatching (5 seconds) --主要类型
按键或触摸等输入事件在特定时间内无响应
2：BroadcastTimeout(10 seconds)
BroadcastReceiver在特定时间内无法处理完成
3：ServiceTimeout(20 seconds) --小概率类型
Service在特定的时间内无法处理完成
4：ContentProviderTimeout(10 seconds) --小概率类型
内容提供者,在publish过超时10s;
关键日志:" ANR in "、"Reason: " 、“Dumping to ”、“anr_in”
如：Dumping to /data/anr/
Reason: Input dispatching timed out

ANR
关键log:
androidlog:
am_anr|anr in|Dumping to|Collecting stacks for pid
trace:
查看Dumping to后生成对应trace文件
需要看：anr之前xxms当前进程log

dropbox —— 系统服务dropbox以文件形式记录了系统各种异常信息，例如app crash、native crash、anr、kernel panic、event记录、wtf输出等等。可以使用如下命令手动导出：
adb shell dumpsys dropbox

界面卡顿：

//跳帧时间
Choreographer: Frame time delta
//跳帧
Choreographer: Skipped 56 frames! The application may be doing too much work on its main thread.

启动activity日志：

//启一个Activity
start u0
//查看相关进程id
Already Exists in BG. So sending its PID
//显示一个Activity
ActivityTaskManager: Displayed

窗口焦点切换：
input_focus:Focus request|Focus leaving|Focus entering

Key事件动作：

KeyButtonView: Back button event: ACTION_DOWN //按下
KeyButtonView: Back button event: ACTION_UP //弹上
WindowManager: KeyEvent:4 //Back键，
InputDispatcher: Asynchronous input event injection succeeded. //表示点击动作成功

Recent:（只是A12有log）
D OverviewProxyRecentsImpl: toggleRecentApps
D OverviewProxyRecentsImpl: toggleRecentApps: device is unlocked
D OverviewProxyRecentsImpl: toggleRecentApps: notify launcher through proxy
Home:
I sysui_multi_action: [757,931,758,4,759,3,932,0,933,0] //home键down
I sysui_multi_action: [757,931,758,4,759,3,932,0,933,1] //home键up
Back:
sysui_multi_action: [757,931,758,4,759,4,932,0,933,0] //back键down
sysui_multi_action: [757,931,758,4,759,4,932,0,933,1] //back键up
I KeyButtonView: Back button event: ACTION_DOWN
I KeyButtonView: Back button event: ACTION_UP

//正常log:down->up时长只有200多毫秒
D InputReader: dispatchTouches action DOWN now(ns): 174899239412
D InputReader: notifyMotion call dispatcher
I sysui_multi_action: [757,931,758,4,759,3,932,0,933,0] //home键down
V InputDispatcher: Asynchronous input event injection succeeded.

KeyEvent 常用按键KeyCode值：
Home键：3
Back键：4
Recent键：无
音量上/+键：24
音量下/-键：25
电源键：26

intercept_power: [ACTION_DOWN,0,1]---power键按下
intercept_power: [ACTION_UP,0,1]---power键抬起

切换导航样式log：
Settings进程会打印
sysui_multi_action: [757,830,758,4,833,0,854,system_nav_3buttons,1089,0]
sysui_multi_action: [757,830,758,4,833,0,854,system_nav_gestural,1089,0]

二、系统问题相关日志

切换用户
starting user |show called
 
usb拔掉广播
ACTION_POWER_DISCONNECTED

深色主题
persist.sys.theme,2 深色
persist.sys.theme,1 正常

旋转屏幕：
mRotation=ROTATION_0/mRotation=ROTATION_90/mRotation=ROTATION_180/mRotation=ROTATION_270

1.内存类关键词

（bugreport里会打印）：diskstats:|ps -A |- CPU INFO|Free RAM:内存泄露关键
日志：
blocking GC Alloc|WaitForGcToComplete|Clamp target GC heap from|Throwing OutOfMemoryError|Failed to allocate
重要日志：
Throwing OutOfMemoryError "Failed to allocate a 112 byte allocation with 0 free bytes and 0B until OOM, target footprint 134217728, growth limit 134217728"
查系统给应用分配内存：
J606L:/ # getprop|grep heapgrowthlimit
[dalvik.vm.heapgrowthlimit]: [128m]
J606L:/ # getprop|grep heapstart
[dalvik.vm.heapstartsize]: [8m]
J606L:/ # getprop|grep heapsize
[dalvik.vm.heapsize]: [512m]
参考案例分析：

1.1.Framework-Google-GMS crash FinalizerWatchdogDaemon

1.2.有多个anr及crash弹窗提示太过频繁

2. watchDog关键词：

WATCHDOG IS GOING TO KILL SYSTEM PROCESS |W Watchdog:

3. 死机重启前操作：

dmesglog/------ KERNEL LOG (dmesg) ------

4.Google应用

4.1.下载:
Finsky
status=DOWNLOADING
Finsky:download_service: [189] jug.a(3): Broadcasting <30:RUNNING:97%[97%]>.
4.2.安装：
Begin install of
status=INSTALLING
Successful install of

系统问题案例分析及相关日志

1.Framework-Google-GMS （com.google.android.gms Crash）

问题分析：
应用内部存在内存泄漏，多处不必要的对象创建，未来得及释放。造成GC压力过大，Finalize对象累积太多，导致FinalizerDaemon线程来不及处理。FinalizerWatchdogDaemon线程会让VM退出，应用程序程序crash。
应用内部逻辑问题，建议保持更新，申请wont do。
应用最小内存：8M
J606L:/ # getprop|grep heapstart
[dalvik.vm.heapstartsize]: [8m]
应用最大内存：128M
J606L:/ # getprop|grep heapgrowthlimit
[dalvik.vm.heapgrowthlimit]: [128m]
关键日志：
allocation with 0 free bytes and 0B until OOM, target footprint 134217728, growth limit 134217728
相关日志：
应用中存在多次内存泄露
Line 61834: 10-26 10:19:26.157 3167 3199 I ogle.android.g: Clamp target GC heap from 135MB to 128MB
内存泄露
Line 11833: 10-26 10:20:52.926 3167 3199 I ogle.android.g: Clamp target GC heap from 135MB to 128MB
Line 11841: 10-26 10:20:52.958 3167 6401 I ogle.android.g: WaitForGcToComplete blocked Alloc on HeapTrim for 24.371ms
Line 11843: 10-26 10:20:52.959 3167 6401 I ogle.android.g: Starting a blocking GC Alloc
Line 11874: 10-26 10:20:53.215 3167 4541 I ogle.android.g: Waiting for a blocking GC Alloc

不必要的对象创建造成GC压力过大，Finalize对象累积太多，导致FinalizerDaemon线程来不及处理
10-26 10:21:17.903 3167 3203 E AndroidRuntime: FATAL EXCEPTION: FinalizerWatchdogDaemon
10-26 10:21:17.903 3167 3203 E AndroidRuntime: Process: com.google.android.gm, PID: 3167
10-26 10:21:17.903 3167 3203 E AndroidRuntime: java.util.concurrent.TimeoutException: com.android.internal.os.BinderInternal$GcWatcher.finalize() timed out after 10 seconds
10-26 10:21:17.903 3167 3203 E AndroidRuntime: at com.android.internal.os.BinderInternal$GcWatcher.finalize(BinderInternal.java:63)
10-26 10:21:17.903 3167 3203 E AndroidRuntime: at java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:289)
10-26 10:21:17.903 3167 3203 E AndroidRuntime: at java.lang.Daemons$FinalizerDaemon.runInternal(Daemons.java:276)
10-26 10:21:17.903 3167 3203 E AndroidRuntime: at java.lang.Daemons$Daemon.run(Daemons.java:137)
10-26 10:21:17.903 3167 3203 E AndroidRuntime: at java.lang.Thread.run(Thread.java:919)
应用中存在内存溢出，即将OOM
Line 3073: 10-26 10:24:38.657 3167 3202 W ogle.android.g: Throwing OutOfMemoryError "Failed to allocate a 40 byte allocation with 0 free bytes and 0B until OOM, target footprint 134217728, growth limit 134217728" (VmSize 5614796 kB)
Line 3211: 10-26 10:24:57.678 3167 3202 W ogle.android.g: Throwing OutOfMemoryError "Failed to allocate a 112 byte allocation with 0 free bytes and 0B until OOM, target footprint 134217728, growth limit 134217728" (VmSize 5614796 kB, recursive case)

2.有多个anr及crash弹窗提示太过频繁

crash弹框：Contacts Storage keeps stopping和android.process.acore keeps stopping
关键日志：FATAL EXCEPTION|No space left on device|Device free memory is insufficient
   Line 365148: 10-09 09:13:07.621 1000 978 978 I CNSS : Device free memory is insufficient //设备可用内存不足
   Line 365151: 10-09 09:13:07.627 1000 978 978 I CNSS : Device free memory is insufficient
   10-09 09:13:07.784 1000 1340 31659 E DropBoxManagerService: Can't write: system_app_crash
   10-09 09:13:07.784 1000 1340 31659 E DropBoxManagerService: java.io.FileNotFoundException: /data/system/dropbox/drop19792.tmp: open failed: ENOSPC (No space left on device)
结合视频及log分析，该设备应用Contacts多次发生crash，crash弹窗提示属于安卓机制正常现象。
经排查：1.diskstats的信息核算和设备EMMC的容量一致，LenovoTB-J606L设备 ROM:64G。
问题log中:
DUMP OF SERVICE diskstats:
Latency: 0ms [512B Data Write] Recent Disk Write Speed (kB/s) = 19974
Data-Free: 316692K / 44952396K total = 0% free 总：42.8G
Cache-Free: 316692K / 44952396K total = 0% free 总：42.8G
System-Free: 0K / 1254320K total = 0% free 1.3G
2.和其他的issue中得到信息在总容量一致
DUMP OF SERVICE diskstats:
Latency: 6ms [512B Data Write]
Recent Disk Write Speed (kB/s) = 10165
Data-Free: 38999292K / 44952396K total = 86% free 总：42.8G
Cache-Free: 38999292K / 44952396K total = 86% free 总：42.8G
System-Free: 3633076K / 3932528K total = 92% free 3.75G
3.开启了dump的蓝牙Log的功能，Ramdump停止录制，可以看到存储被用完。
10-09 09:37:11.354 1000 2314 2314 D LenovoLogger: stopLogger
10-09 09:37:11.369 1000 1340 1485 D BluetoothManagerService: MESSAGE_REGISTER_ADAPTER
10-09 09:37:11.370 1000 2314 2314 D LenovoLogger: Disable bluetooth btsnoop log
10-09 09:37:11.374 1000 2314 2314 W lenovologgerpannel avail size in MB:: /data0
4.检查防止Data分区被写满的修改生效，用apk—normal可以填充剩 212m，apk—system可以填充满。

测试结论：经查看，这32G基本为LTR测试中的log，可能由于国庆假期测试时间过长，log存储太多。
经过分析及排查和测试一起确认，该设备由于长时间测试，LTR测试log大量占用设备空间，导致空间不足引起应用Contacts多次发生crash，crash弹窗提示属于安卓机制正常现象。
因此申请wont do。

3.[Framework-Google-GMS] com.google.android.gms.persistent Crash

从log看，出现此现象之前，用户一直在调整小窗口。小窗口存在异常log，导致systemserver 的 android.anim 线程发生了ne，引起system died 。
已走Productivity mode-Full。
关键日志：
//update size
11-24 00:41:40.250 4125 19815 E TelecomFramework: MultiWindowService: updateTaskResizerBounds: Rect(819, 91 - 1865, 297)
//systemserver 的 android.anim 线程发生了ne
11-24 00:41:40.319 1355 1558 F libc : Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x968 in tid 1558 (android.anim), pid 1355 (system_server)
11-24 00:41:40.517 3096 3096 F DEBUG : pid: 1355, tid: 1558, name: android.anim >>> system_server <<<
11-24 00:41:40.517 3096 3096 F DEBUG : uid: 1000
11-24 00:41:40.517 3096 3096 F DEBUG : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x968
11-24 00:41:40.517 3096 3096 F DEBUG : Cause: null pointer dereference
//系统死亡
11-24 00:41:44.453 527 527 I ServiceManager: service 'account' died
11-24 00:41:44.456 527 527 I ServiceManager: service 'content' died
.....
11-24 00:41:44.456 527 527 I ServiceManager: service 'settings' died
11-24 00:41:44.464 527 527 I ServiceManager: service 'network_score' died
11-24 00:41:44.464 527 527 I ServiceManager: service 'package' died
// system died;引起上层重启
11-24 00:41:44.490 2869 2869 D AndroidRuntime: Shutting down VM
11-24 00:41:44.499 2869 2869 E AndroidRuntime: FATAL EXCEPTION: main
11-24 00:41:44.499 2869 2869 E AndroidRuntime: Process: com.google.android.gms.persistent, PID: 2869
11-24 00:41:44.499 2869 2869 E AndroidRuntime: DeadSystemException: The system died; earlier logs will point to the root cause
11-24 00:41:44.520 2869 2869 E GCore-Chimera-Crash: Hit an exception while processing the UncaughtExceptionHandler:
11-24 00:41:44.520 2869 2869 E GCore-Chimera-Crash: DeadSystemException: The system died; earlier logs will point to the root cause

4.[Framework-Google-GMS] com.google.android.googlequicksearchbox:search Crash

问题分析：
GMS应用内部存在未释放引用，出现内存泄露，频繁GC可看出内存空间超过512M无法释放可用空间,导致应用内存溢出。建议保持更新，建议wont do.
11-29 04:32:01.825 1399 1420 I system_server: NativeAlloc concurrent copying GC freed 174831(9150KB) AllocSpace objects, 63(3512KB) LOS objects, 42% free, 31MB/55MB, paused 140us total 209.732ms
//应用最早出现内存泄露
11-29 06:02:39.667 5681 5681 I earchbox:searc: Waiting for a blocking GC Alloc
11-29 06:02:39.686 5681 5681 I earchbox:searc: WaitForGcToComplete blocked Alloc on ProfileSaver for 18.173ms
11-29 06:02:39.686 5681 5681 I earchbox:searc: Starting a blocking GC Alloc
11-29 06:06:41.688 5681 5681 I earchbox:searc: Waiting for a blocking GC Alloc

11-29 06:06:42.363 5681 5926 I earchbox:searc: Clamp target GC heap from 523MB to 512MB
11-29 06:06:42.363 5681 5926 I earchbox:searc: Alloc concurrent copying GC freed 22771(1031KB) AllocSpace objects, 131(11MB) LOS objects, 2% free, 499MB/512MB, paused 82us total 687.552ms
11-29 06:15:13.797 5681 5681 I earchbox:searc: Alloc concurrent copying GC freed 27(648B) AllocSpace objects, 0(0B) LOS objects, 0% free, 511MB/512MB, paused 75us total 809.071ms
1-29 06:15:14.287 5681 5738 I earchbox:searc: Waiting for a blocking GC Alloc
11-29 06:15:14.287 5681 5782 I earchbox:searc: Waiting for a blocking GC Alloc
11-29 06:15:14.442 5681 5735 I earchbox:searc: Waiting for a blocking GC Alloc
11-29 06:15:14.461 5681 5681 I earchbox:searc: Clamp target GC heap from 535MB to 512MB
11-29 06:15:14.461 5681 5681 I earchbox:searc: Alloc concurrent copying GC freed 752(57KB) AllocSpace objects, 2(192KB) LOS objects, 0% free, 511MB/512MB, paused 77us total 603.968ms
11-29 06:15:14.461 5681 5681 E AndroidRuntime: FATAL EXCEPTION: main
11-29 06:15:14.461 5681 5681 E AndroidRuntime: Process: com.google.android.googlequicksearchbox:search, PID: 5681
11-29 06:15:14.461 5681 5681 E AndroidRuntime: com.facebook.litho.ap: ElementsRootFlat
11-29 06:15:14.461 5681 5681 E AndroidRuntime: Caused by: com.facebook.litho.ap: ComponentType
11-29 06:15:14.461 5681 5681 E AndroidRuntime: Caused by: java.lang.OutOfMemoryError: Failed to allocate a 97360 byte allocation with 72352 free bytes and 70KB until OOM, target footprint 536870912, growth limit 536870912

5.[Framework-Google-GMS] com.google.android.calendar Anr

结合mainlog和trace信息看，是Google Calendar 内部发生互锁导致导致广播超时发生 anr。
从堆栈看，均为 Calendar 内部调用，无法修改。申请 wont fix。

关键log:
11-27 21:23:48.049 13202 13202 I Choreographer: Skipped 39 frames! The application may be doing too much work on its main thread.
11-27 21:23:48.805 13202 13214 W ndroid.calenda: Suspending all threads took: 5.063ms
// 真正发生anr，Dump到堆栈data/anr/anr_2020-11-27-21-32-15-752文件
11-27 21:32:15.752 1354 1483 I ActivityManager: Dumping to /data/anr/anr_2020-11-27-21-32-15-752
11-27 21:32:15.752 1354 1483 I ActivityManager: Collecting stacks for pid 13202
11-27 21:32:15.781 1354 1483 I system_server: libdebuggerd_client: started dumping process 13202
11-27 21:32:15.788 1083 1083 I /system/bin/tombstoned: registered intercept for pid 13202 and type kDebuggerdJavaBacktrace
11-27 21:32:15.796 13202 13213 I ndroid.calenda: Thread[3,tid=13213,WaitingInMainSignalCatcherLoop,Thread*=0x79d8ca5800,peer=0x132803f8,"Signal Catcher"]: reacting to signal 3
11-27 21:32:15.798 13202 13213 I ndroid.calenda:
11-27 21:32:16.219 1083 1083 I /system/bin/tombstoned: received crash request for pid 13202
11-27 21:32:16.219 1083 1083 I /system/bin/tombstoned: found intercept fd 512 for pid 13202 and type kDebuggerdJavaBacktrace
11-27 21:32:16.222 13202 13213 I ndroid.calenda: Wrote stack traces to tombstoned
11-27 21:32:16.222 1354 1483 I system_server: libdebuggerd_client: done dumping process 13202
// 程序无响应
11-27 21:32:29.013 1354 1483 I ActivityManager: Done dumping
11-27 21:32:29.071 1354 1483 E ActivityManager: ANR in com.google.android.calendar
11-27 21:32:29.071 1354 1483 E ActivityManager: PID: 13202
11-27 21:32:29.071 1354 1483 E ActivityManager: Reason: Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE flg=0x1000010 pkg=com.google.android.calendar cmp=com.google.android.calendar/com.google.android.libraries.notifications.entrypoints.gcm.GcmBroadcastReceiver (has extras) }

anr_2020-11-27-21-32-15-752：
----- pid 13202 at 2020-11-27 21:32:15 -----
Cmd line: com.google.android.calendar
// calendar 主线程 thread 1，在等待 34号线程
"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x719a7e78 self=0x79d8ca3c00
| sysTid=13202 nice=-10 cgrp=default sched=0/0 handle=0x79da20bed0
| state=S schedstat=( 16269419750 1686751945 9297 ) utm=1414 stm=212 core=5 HZ=100
| stack=0x7fdafe9000-0x7fdafeb000 stackSize=8192KB
| held mutexes=
at cal.owy.l(PG:-1)
- waiting to lock <0x0e021f24> (a cal.owy) held by thread 34
at cal.owx.b(PG:1)
at cal.pba.d(PG:5)
- locked <0x063c6a8d> (a cal.pba)

// calendar 34号线程，在等待主线程 thread 1
"BACKGROUND_0" prio=5 tid=34 Blocked
| group="BACKGROUND" sCount=1 dsCount=0 flags=1 obj=0x13282cd8 self=0x794795d800
| sysTid=13262 nice=1 cgrp=default sched=0/0 handle=0x78d7c89d50
| state=S schedstat=( 567132691 274993231 1363 ) utm=48 stm=8 core=0 HZ=100
| stack=0x78d7b87000-0x78d7b89000 stackSize=1039KB
| held mutexes=
at cal.pba.c(PG:-1)
- waiting to lock <0x063c6a8d> (a cal.pba) held by thread 1
at cal.owy.o(PG:1)
- locked <0x0e021f24> (a cal.owy)

6.点击相册显示“相册屡次停止运行”

测试在安装GMS过程中使用Photos应用导致，操作问题。建议wont do
关键日志信息：
正在下载GMS
10-15 22:40:19.424 14579 1454 I Finsky:download_service: [189] jug.a(3): Broadcasting <30:RUNNING:97%[97%]>.
10-15 22:40:19.441 14406 14406 I Finsky : [2] nrg.a(191): Installer: Notifying status update. package=com.google.android.gms, status=DOWNLOADING
10-15 22:40:19.452 14406 14617 I Finsky : [171] odk.b(67): IQ: Notifying installation update. package=com.google.android.gms, status=DOWNLOADING
开始安装GMS
10-15 22:40:28.795 14406 14501 I Finsky : [132] nuc.c(55): IT: Begin install of com.google.android.gms (isid: s91KhTJiQFuh0UDD1JH91g)
10-15 22:40:28.827 14406 14501 I Finsky : [132] nrg.a(191): Installer: Notifying status update. package=com.google.android.gms, status=INSTALLING
10-15 22:40:28.838 14406 14617 I Finsky : [171] odk.b(67): IQ: Notifying installation update. package=com.google.android.gms, status=INSTALLING
强制停止GMS服务
10-15 22:40:29.668 1415 1504 I ActivityManager: Force stopping com.google.android.gms appid=10119 user=-1: installPackageLI
10-15 22:40:29.669 1415 1504 I ActivityManager: Killing 26613:com.google.android.youtube/u0a153 (adj 995): stop com.google.android.gms
Photos Crash 两次
10-15 22:40:47.880 1415 3656 I am_crash: [16556,0,com.google.android.apps.photos,953794117,java.lang.SecurityException,Unable to start service Intent{ act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }: Unable to launch app com.google.android.gms/10119 for service Intent
{ act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms }: process is bad,ContextImpl.java,1613]
10-15 22:40:52.665 1415 5215 I am_crash: [2971,0,com.google.android.apps.photos,953794117,java.lang.SecurityException,Unable to start service Intent
{ act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }: Unable to launch app com.google.android.gms/10119 for service Intent
{ act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms }: process is bad,ContextImpl.java,1613]
GMS安装完成
10-15 22:40:57.738 14406 14406 I Finsky : [2] ntz.c(4): IT: Successful install of com.google.android.gms (isid: s91KhTJiQFuh0UDD1JH91g)

7.[Framework Performance Stablility] com.android.vending Anr

问题分析：
Google PlayStore应用内部存在死锁，导致主线程超时引起Anr。建议保持更新，建议wont do。
关键日志信息：
//存储anr的dump信息
12-04 14:06:12.541 1000 1374 1488 I ActivityManager: Dumping to /data/anr/anr_2020-12-04-14-06-12-540
//应用弹出无响应
12-04 14:06:23.518 1000 1374 1488 E ActivityManager: ANR in com.android.vending
12-04 14:06:23.518 1000 1374 1488 E ActivityManager: PID: 677
12-04 14:06:23.518 1000 1374 1488 E ActivityManager: Reason: executing service com.android.vending/com.google.android.finsky.scheduler.process.mainimpl.PhoneskyJobServiceMain

------ VM TRACES AT LAST ANR (/data/anr/anr_2020-12-04-14-06-12-540: 2020-12-04 14:06:23) ------
----- pid 677 at 2020-12-04 14:06:12 -----
Cmd line: com.android.vending
//等待<0x05ee37cf>锁，被线程83持有
"main" prio=5 tid=1 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x72877a78 self=0xea05ce00
| sysTid=677 nice=0 cgrp=default sched=0/0 handle=0xea560dc0
| state=S schedstat=( 14831821629 2738463385 17496 ) utm=1151 stm=331 core=0 HZ=100
| stack=0xff7bb000-0xff7bd000 stackSize=8192KB
| held mutexes=
at aciw.n(PG:1)
- waiting to lock <0x05ee37cf> (a com.google.android.finsky.installqueue.impl.InstallQueuePhoneskyJob) held by thread 83
at aciw.m(PG:-1)
at rdv.E(PG:1)
at rdv.r(PG:1)
at com.google.android.finsky.installqueue.impl.InstallQueuePhoneskyJob.t(PG:-1)
at aciw.q(PG:8)
at aciv.a(unavailable:7)
at acha.e(PG:7)
- locked <0x0ba1fdff> (a acha)

//等待<0x0ba1fdff>锁，被主线程持有
"InstallQueueUsingScheduler" prio=5 tid=83 Blocked
| group="main" sCount=1 dsCount=0 flags=1 obj=0x14544230 self=0xd4081800
| sysTid=6628 nice=10 cgrp=default sched=0/0 handle=0xa5d0b230
| state=S schedstat=( 367180002 388557770 934 ) utm=28 stm=8 core=1 HZ=100
| stack=0xa5c08000-0xa5c0a000 stackSize=1040KB
| held mutexes=
at acha.b(PG:-1)
- waiting to lock <0x0ba1fdff> (a acha) held by thread 1
at aciw.n(PG:5)
- locked <0x05ee37cf> (a com.google.android.finsky.installqueue.impl.InstallQueuePhoneskyJob)
at aciw.m(PG:-1)

8.[Google Services Framework]切换40多种语言后，测试机切换语言出现卡顿，一台出现“Google Services Framework keeps stopping”，重启无法恢复

从Log分析，gms服务相关应用binder数据传输的数据太大导致system server挂了，引起死机、卡顿、Google GMS应用大量OutOfMemoryError，等一系列性能问题。
Line 68764: 12-29 03:21:46.057 10119 3535 3535 E gle.android.gm: Not starting debugger since process cannot load the jdwp agent.
Line 68827: 12-29 03:21:46.476 1000 1329 2411 E JavaBinder: !!! FAILED BINDER TRANSACTION !!! (parcel size = 523848)
12-29 03:21:46.476 1000 1329 2411 E JavaBinder: !!! FAILED BINDER TRANSACTION !!! (parcel size = 523848)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: Exception thrown during bind of ProcessRecord{824ad91 3535:com.google.android.gms/u0a119{color}}
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: android.os.TransactionTooLargeException: data parcel size 523848 bytes
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at android.os.BinderProxy.transactNative(Native Method)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at android.os.BinderProxy.transact(BinderProxy.java:511)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at android.app.IApplicationThread$Stub$Proxy.bindApplication(IApplicationThread.java:1479)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at com.android.server.am.ActivityManagerService.attachApplicationLocked(ActivityManagerService.java:5137)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at com.android.server.am.ActivityManagerService.attachApplication(ActivityManagerService.java:5262)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:2003)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2763)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at android.os.Binder.execTransactInternal(Binder.java:1021)
12-29 03:21:46.477 1000 1329 2411 E ActivityManager: at android.os.Binder.execTransact(Binder.java:994)
......
12-29 03:21:46.591 1000 3631 3631 F DEBUG : Timestamp: 2020-12-29 03:21:46-0500
12-29 03:21:46.591 1000 3631 3631 F DEBUG : pid: 1329, tid: 2411, name: Binder:1329_6 >>> system_server <<<
12-29 03:21:46.591 1000 3631 3631 F DEBUG : uid: 1000
12-29 03:21:46.591 1000 3631 3631 F DEBUG : signal 35 (<debuggerd signal>), code 0 (SI_USER), fault addr --------
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x0 0000000000000000 x1 00000000c0306201 x2 00000071960dcb28 x3 00000000000002d0
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x4 00000071960dcc10 x5 00000071dfdd7e44 x6 00000000000002d0 x7 0000000000000000
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x8 000000000000001d x9 00000071960dcad8 x10 00000071960dcaa0 x11 00000071960dcad8
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x12 00000071960dcb20 x13 00000071d6178400 x14 0000000070e33b78 x15 000000007083036c
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x16 00000072e8423e60 x17 00000072e4e2762c x18 000000718b35c000 x19 00000071960de020
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x20 00000071dfe44200 x21 00000071dfe44320 x22 0000000000000044 x23 0000000000000100
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x24 00000071960de020 x25 0000000000000000 x26 0000000012f5df68 x27 0000000000000000
12-29 03:21:46.591 1000 3631 3631 F DEBUG : x28 0000000000000000 x29 00000071960dcb10
12-29 03:21:46.591 1000 3631 3631 F DEBUG : sp 00000071960dca20 lr 00000072e4e276b4 pc 00000072e4e6d098

之前复现相关log:

最近1分钟，5分钟的CPU负载较高，1分钟的CPU负载 > 5分钟的CPU负载，说明服务器目前处在CPU负载高峰期

------ UPTIME (uptime) ------
01:21:23 up 6 min, 0 users, load average: 16.29, 8.25, 3.58
------ UPTIME (uptime) ------
01:31:59 up 17 min, 0 users, load average: 1047.38, 237.35, 81.10
------ UPTIME (uptime) ------
04:52:56 up 1 day, 3:38, 0 users, load average: 119.31, 31.11, 11.94
------ UPTIME (uptime) ------
05:02:58 up 1 day, 3:48, 0 users, load average: 20.44, 14.49, 11.06

从测试提供的现场内存、CPU截图来看，卡顿是因为系统内存不足 system server占比较高。

12-17 01:15:03.787 2772 2772 E ActivityThread: Failed to find provider info for com.google.android.gsf.gservices

12-17 01:17:04.842 2797 25450 E AndroidRuntime: FATAL EXCEPTION: [com.google.android.gms.chimera.PersistentIntentOperationService$ChimeraService-Executor] idle
12-17 01:17:04.842 2797 25450 E AndroidRuntime: Process: com.google.android.gms.persistent, PID: 2797
12-17 01:17:04.842 2797 25450 E AndroidRuntime: java.lang.OutOfMemoryError: pthread_create (1040KB stack) failed: Try again

GMS相关应用偶现问题，无代码无法修改，建议保持更新，建议wont do。

9.电容笔放置屏幕上，开启youtube播放视频，同时开启录屏。待机至第二天屏幕黑屏，打开界面为主界面，录屏只录制40分钟

结合Log和视频分析：
06:05:46打开youtube，06:06:12开始录屏，43分12秒后录屏结束恰好为06:49:24左右， 06:49:25左右MPEG4Writer.cpp 提示:记录的文件大小超出限制(4294967295byte=4G)，视频大小也3.8G。
综上：录屏超过4G大小限制，引起 BufferQueue has been abandoned。
Line 7560: 10-16 06:05:46.327 1241 2031 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x4000000 cmp=com.google.android.youtube/com.google.android.apps.youtube.app.WatchWhileActivity bnds=[1000,841][1329,1056] (has extras)} from uid 10163
Line 12797: 10-16 06:06:08.058 1241 5873 I ActivityTaskManager: START u0 {flg=0x10008000 cmp=com.lenovo.screencapture/.activity.GetPermissionActivity (has extras)} from uid 10124
Line 12892: 10-16 06:06:08.182 1241 5856 I ActivityTaskManager: START u0 {act=android.content.pm.action.REQUEST_PERMISSIONS pkg=com.google.android.permissioncontroller cmp=com.google.android.permissioncontroller/com.android.packageinstaller.permission.ui.GrantPermissionsActivity (has extras)} from uid 10124
Line 13452: 10-16 06:06:09.892 1241 2959 I ActivityTaskManager: START u0 {act=android.content.pm.action.REQUEST_PERMISSIONS pkg=com.google.android.permissioncontroller cmp=com.google.android.permissioncontroller/com.android.packageinstaller.permission.ui.GrantPermissionsActivity (has extras)} from uid 10124
Line 13576: 10-16 06:06:10.995 1241 5868 I ActivityTaskManager: START u0 {cmp=com.android.systemui/.media.MediaProjectionPermissionActivity} from uid 10124
Line 13887: 10-16 06:06:12.258 799 825 I /vendor/bin/hw/vendor.qti.hardware.servicetracker@1.1-service: startService() is called for servicecom.lenovo.screencapture/.service.RecorderService
Line 13897: 10-16 06:06:12.270 17784 17784 D FZY : startRecorderService: SCREEN_RECORDING_START
Line 13898: 10-16 06:06:12.280 1241 1485 V ActivityManager: Attempted to start a foreground service (com.lenovo.screencapture/.service.RecorderService) with a broken notification (no icon: Notification(channel=channelId pri=0 contentView=null vibrate=null sound=null defaults=0x0 flags=0x40 color=0x00000000 vis=PRIVATE))
Line 13899: 10-16 06:06:12.280 17784 17784 D FZY : RecorderService onCreate:
Line 13915: 10-16 06:06:12.354 17784 17784 D FZY : RecorderService onStartCommand: SCREEN_RECORDING_START
Line 14083: 10-16 06:06:13.501 1035 5230 I MPEG4Writer: limits: 4294967295/0 bytes/us, bit rate: 12595112 bps and the estimated moov size 3192 bytes
.......
Line 47185: 10-16 06:47:09.571 1035 18011 W MPEG4Writer: Recorded file size is approaching limit 4294967295bytes
Line 49291: 10-16 06:49:25.854 1035 18011 W MPEG4Writer: No FileDescripter for next recording
Line 49292: 10-16 06:49:25.857 1035 18011 W MPEG4Writer: Recorded file size exceeds limit 4294967295bytes
10-16 06:49:25.904 1056 20272 W GraphicBufferSource: onFrameAvailable: EOS is sent, ignoring frame
Line 49300: 10-16 06:49:25.917 1035 18016 W MPEG4Writer: No FileDescripter for next recording
Line 49301: 10-16 06:49:25.917 1035 18016 W MPEG4Writer: Recorded file size exceeds limit 4294967295bytes
Line 49368: 10-16 06:49:26.493 1035 18016 I MPEG4Writer: Received total/0-length (20249/0) buffers and encoded 20247 frames. - Audio
Line 49369: 10-16 06:49:26.493 1035 18016 I MPEG4Writer: Audio track drift time: 0 us
Line 49376: 10-16 06:49:26.556 1056 3062 E BufferQueueProducer: [GraphicBufferSource] dequeueBuffer: **BufferQueue has been abandoned**
Line 49378: 10-16 06:49:26.557 866 866 W SurfaceFlinger: **Dequeuing buffer for display [MainActivity] failed, bailing out of client composition for this frame**
视频文件大小：3.8G,已走给录屏

10.测试机从暗环境切换到亮环境，亮度数值变化与进度条变化不一致（进度条有点慢）

分析：
从复现log看有这些从暗到亮的变化：
第一次经历大约2s
10-27 20:15:10.795 D/RampAnimator( 1089): mTargetValue 254 mCurrentValue 30 mAnimatedValue 29.908333
10-27 20:15:12.789 D/RampAnimator( 1089): mTargetValue 254 mCurrentValue 254 mAnimatedValue 254.0
第二次经历大约900ms
10-27 20:17:06.171 D/RampAnimator( 1089): mTargetValue 198 mCurrentValue 72 mAnimatedValue 71.90833
10-27 20:17:07.283 D/RampAnimator( 1089): mTargetValue 198 mCurrentValue 198 mAnimatedValue 197.85858
屏幕从暗到亮的时间允许范围以内，屏幕的自动背光功能本身没有问题。
背光自动更新的时候是每个step调整都会调用 DisplayPowerController中updateSecreenBrightnessSetting来更新setting背光值。
这个设置状态和上面log是一个函数内的调用，是同步的，属于LV自动背光方案，调整余地不大。
走systemUI同事确认下亮度条的更新方式，是否有优化的可能。
已走systemUI

转载:https://blog.csdn.net/u010871962/article/details/109857386