Android CTS SettingsProvider

于 2018-03-14 18:07:24 发布
阅读量510 收藏
点赞数
分类专栏： CTS
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.csdn.net/seiyaaa/article/details/79552816
版权

settings put/get 断言失败

用例过程

目前遇到Android O上关于settings put/get失败的用例很多，看了很多个用例，耗时很久

run cts –abi arm64-v8a -m CtsTextTestCases -t
android.text.format.cts.DateFormatTest#test_is24HourFormat
–bugreport-on-failure

这里写图片描述

分析

日志附件

日志查询关键字：

time_12_24|test_is24HourFormat|
MemoryIntArray|System.getStringForUser|is24HourFormat|insertSystemSetting|getSystemSetting|SettingsProvider

正常机型的日志如下：

Line 1817: 01-01 00:01:39.059  1637  1637 E GenerationRegistry: Created backing store android.util.MemoryIntArray@56
Line 5734: 01-01 00:01:42.165  1637  1637 I GenerationRegistry: backingStore = android.util.MemoryIntArray@56
Line 13208: 01-01 00:01:44.793  1637  1637 I GenerationRegistry: backingStore = android.util.MemoryIntArray@56

用例失败的机型出现两个MemoryIntArray，日志如下，

Line 15921: 01-01 08:04:38.108  2609  3035 E GenerationRegistry: Created backing store android.util.MemoryIntArray@fc
Line 15922: 01-01 08:04:38.108  2609  3035 I GenerationRegistry: backingStore = android.util.MemoryIntArray@fc
Line 28200: 01-01 08:08:41.169  2609  2946 I GenerationRegistry: backingStore = android.util.MemoryIntArray@50
Line 28253: 01-01 08:08:41.293  2609  3200 I GenerationRegistry: backingStore = android.util.MemoryIntArray@fc

一个MemoryIntArray对应一个GenerationRegistry，对应一个SettingsRegistry
通过和其他同样Android O机型的日志对比发现，MemoryIntArray在失败用例的机型上每次都有两个实例
MemoryIntArray->GenerationRegistry->SettingsRegistry
这三者是一一对应的关系，而SettingsRegistry是在SettingsProvider的onCreat()创建的，那么是SettingsProvider创建了两次？

那SettingsProvider在哪被创建的？在onCreate中添加日志打印
这里写图片描述

一开始使用的是android.util.Log打印，日志打不出来，可能有丢失，就以为只创建了一次
（1）改用Slog打印
（2）不每次重启机器，改用stop、start这样方式启动system_server
（3）logcat的ring buffer设置大点
终于走上正路，窥得真貌。第一次创建时候在09:22:24，这是系统在刚启动时通过startOtherService()调用的installSystemProviders，这个是正常的。
第一行日志的ActivityManager_MU告诉我们SettingsProvider是单例的，但是在09:22:41为啥又创建了一遍么？
这里写图片描述

01-01 09:22:24.235 11247 11247 V ActivityManager_MU: isSingleton(system, ApplicationInfo{f87dbf9 com.android.providers.settings}, com.android.providers.settings.SettingsProvider, 0x40100000) = true
01-01 09:22:24.235 11247 11247 V ActivityManager_MU: generateApplicationProvidersLocked, cpi.uid = 1000
01-01 09:22:24.236 11247 11247 V ActivityManager_MU: isSingleton(system, ApplicationInfo{d74b73e android}, com.android.server.am.DumpHeapProvider, 0x40000000) = true
01-01 09:22:24.236 11247 11247 V ActivityManager_MU: generateApplicationProvidersLocked, cpi.uid = 1000
01-01 09:22:24.236 11247 11247 I ActivityThread: Pub settings: com.android.providers.settings.SettingsProvider
01-01 09:22:24.236 11247 11247 D ActivityThread: Loading provider settings: com.android.providers.settings.SettingsProvider
01-01 09:22:24.253 11247 11247 V ActivityThread: Instantiating local provider com.android.providers.settings.SettingsProvider
01-01 09:22:24.257 11247 11247 E SettingsProvider: onCreate
01-01 09:22:24.257 11247 11247 E SettingsProvider: java.lang.Exception
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.providers.settings.SettingsProvider.onCreate(SettingsProvider.java:321)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at android.content.ContentProvider.attachInfo(ContentProvider.java:1919)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at android.content.ContentProvider.attachInfo(ContentProvider.java:1894)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at android.app.ActivityThread.installProvider(ActivityThread.java:6286)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at android.app.ActivityThread.installContentProviders(ActivityThread.java:5852)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at android.app.ActivityThread.installSystemProviders(ActivityThread.java:6461)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.server.am.ActivityManagerService.installSystemProviders(ActivityManagerService.java:12127)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.server.SystemServer.startOtherServices(SystemServer.java:804)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.server.SystemServer.run(SystemServer.java:399)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.server.SystemServer.main(SystemServer.java:263)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at java.lang.reflect.Method.invoke(Native Method)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
01-01 09:22:24.257 11247 11247 E SettingsProvider:  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:828)
01-01 09:22:24.266 11247 11247 I SettingsProvider: key=805306368
----------------------------------------------------------------------------------------
01-01 09:22:41.799 11247 11247 W SettingsProvider: onCreate
01-01 09:22:41.799 11247 11247 W SettingsProvider: java.lang.Exception
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at com.android.providers.settings.SettingsProvider.onCreate(SettingsProvider.java:333)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.content.ContentProvider.attachInfo(ContentProvider.java:1919)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.content.ContentProvider.attachInfo(ContentProvider.java:1894)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.app.ActivityThread.installProvider(ActivityThread.java:6286)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.app.ActivityThread.installContentProviders(ActivityThread.java:5852)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.app.ActivityThread.handleInstallProvider(ActivityThread.java:3124)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1814)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.os.Handler.dispatchMessage(Handler.java:105)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at android.os.Looper.loop(Looper.java:164)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at com.android.server.SystemServer.run(SystemServer.java:424)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at com.android.server.SystemServer.main(SystemServer.java:263)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at java.lang.reflect.Method.invoke(Native Method)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:240)
01-01 09:22:41.799 11247 11247 W SettingsProvider:  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:828)
01-01 09:22:41.801  2169  2169 E ServiceManager: add_service('settings',a3) uid=1000 - ALREADY REGISTERED, OVERRIDE
01-01 09:22:41.801  2169  2169 I ServiceManager: service 'settings' died

继续根据09:22:41时的堆栈进行分析，为啥会通过Message再次创建一遍SettingsProvider呢？

01-01 09:22:41.799 11247 11247 W SettingsProvider: at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1814)

继续对比正常机型的日志，正常机型在finishUserUnlocking后也发送了SYSTEM_USER_UNLOCK_MSG消息，也走消息处理到installEncryptionUnawareProviders()执行Installing ContentProviderInfo
finishUserUnlocking
这里写图片描述

    Line 24020: 12-31 19:00:47.405  3828  3828 V ActivityThread: Instantiating local provider com.android.providers.settings.SettingsProvider
    Line 24021: 12-31 19:00:47.406  3828  3828 E SettingsProvider: onCreate
    Line 27266: 12-31 19:00:51.148  3828  3844 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 27371: 12-31 19:00:51.170  3828  3851 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 27384: 12-31 19:00:51.173  3828  3851 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 27396: 12-31 19:00:51.174  3828  3851 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 27422: 12-31 19:00:51.176  3828  3851 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 27455: 12-31 19:00:51.196  3828  3851 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 27542: 12-31 19:00:51.399  3828  3851 I WindowManager: checkBootAnimationComplete: Animation complete!
    Line 27553: 12-31 19:00:51.400  3828  3851 I WindowManager: checkBootAnimationComplete: Animation complete!
    Line 27569: 12-31 19:00:51.430  3828  3851 D ActivityManager: Finishing user boot 0
    Line 28013: 12-31 19:00:51.811  3828  3851 W ActivityManager: finishUserUnlocking
    Line 28015: 12-31 19:00:51.811  3828  3851 W ActivityManager:   at com.android.server.am.UserController.finishUserUnlocking(UserController.java:332)
……
    Line 28508: 12-31 19:00:52.537  3828  3844 W ActivityManager: Installing ContentProviderInfo{name=com.google.android.inputmethod.latin.inputcontent className=com.google.android.apps.inputmethod.libs.search.gif.InputContentProvider}
    Line 28517: 12-31 19:00:52.537  3828  3844 V ActivityManager: Installing ContentProviderInfo{name=com.google.android.inputmethod.latin.inputcontent className=com.google.android.apps.inputmethod.libs.search.gif.InputContentProvider}

对比异常机型的日志发现执行Installing ContentProviderInfo，但是processlist列表中有.
{name=settings className=com.android.providers.settings.SettingsProvider}，从而导致创建了两遍

    Line 790: 01-01 09:50:22.977 18037 18037 V ActivityThread: Instantiating local provider com.android.providers.settings.SettingsProvider
    Line 791: 01-01 09:50:22.979 18037 18037 E SettingsProvider: onCreate
    Line 64921: 01-01 09:50:33.207 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 64987: 01-01 09:50:33.220 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 65003: 01-01 09:50:33.222 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 65020: 01-01 09:50:33.224 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 65353: 01-01 09:50:33.361 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 65705: 01-01 09:50:33.427 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 65782: 01-01 09:50:33.628 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 66147: 01-01 09:50:33.829 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 66302: 01-01 09:50:33.939 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 66384: 01-01 09:50:34.043 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 66659: 01-01 09:50:34.218 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 66939: 01-01 09:50:34.420 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67074: 01-01 09:50:34.622 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67447: 01-01 09:50:34.822 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67605: 01-01 09:50:34.880 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67686: 01-01 09:50:34.928 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67701: 01-01 09:50:34.932 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67713: 01-01 09:50:34.934 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67778: 01-01 09:50:34.971 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67825: 01-01 09:50:34.985 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67904: 01-01 09:50:35.061 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 67939: 01-01 09:50:35.077 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 68005: 01-01 09:50:35.185 18037 18073 I WindowManager: checkBootAnimationComplete: Waiting for anim complete
    Line 68223: 01-01 09:50:35.386 18037 18073 I WindowManager: checkBootAnimationComplete: Animation complete!
    Line 68234: 01-01 09:50:35.387 18037 18073 I WindowManager: checkBootAnimationComplete: Animation complete!
    Line 68427: 01-01 09:50:35.411 18037 18073 D ActivityManager: Finishing user boot 0
    Line 68471: 01-01 09:50:35.648 18037 18073 W ActivityManager: finishUserUnlocking
    Line 68473: 01-01 09:50:35.648 18037 18073 W ActivityManager:   at com.android.server.am.UserController.finishUserUnlocking(UserController.java:333)
……
    Line 69450: 01-01 09:50:35.905 18037 18065 V ActivityManager: cts skip Installing ContentProviderInfo{name=com.jamdeo.data.thumbnailengine.channels;com.jamdeo.data.thumbnailengine.events className=com.jamdeo.data.ThumbnailEngine}
    Line 69461: 01-01 09:50:35.906 18037 18065 V ActivityManager: cts skip Installing ContentProviderInfo{name=com.jamdeo.data.epgdata className=com.*.livetv.service.data.epg.EpgData}
    Line 69472: 01-01 09:50:35.906 18037 18065 V ActivityManager: cts skip Installing ContentProviderInfo{name=com.android.calendar className=com.android.providers.calendar.CalendarProvider2}
    Line 69488: 01-01 09:50:35.907 18037 18065 V ActivityManager: cts skip Installing ContentProviderInfo{name=com.*.keylab.speech.CoreProvider.up02 className=com.*.keylab.speech.core.CoreProvider}
    Line 69528: 01-01 09:50:35.908 18037 18065 V ActivityManager: cts skip Installing ContentProviderInfo{name=com.android.server.heapdump className=com.android.server.am.DumpHeapProvider}
    Line 69555: 01-01 09:50:35.910 18037 18065 V ActivityManager: cts skip Installing ContentProviderInfo{name=settings className=com.android.providers.settings.SettingsProvider}

……
    Line 70328: 01-01 09:50:36.032 18037 18037 V ActivityThread: Instantiating local provider com.android.providers.settings.SettingsProvider
    Line 70337: 01-01 09:50:36.034 18037 18037 E SettingsProvider: onCreate
    Line 70924: 01-01 09:50:36.163 18037 18037 W SettingsProvider: onCreate

为啥Process列表中多个了一个{name=settings className=com.android.providers.settings.SettingsProvider}
初步怀疑我们机型启动时间太长，get时候get到SettingsProvider
后面有精力再查吧，查到这就用了很久

注意事项

（1）跟随文件的日志打印方式，文件用Slog同样自己要用Slog

（2）使用stop、start重启system_server

（3）放大logcat ring buffer

seiyaaa
关注
  • 0
    点赞
  • 踩
  • 0
    收藏
    觉得还不错? 一键收藏
  • 打赏
    打赏
  • 2
    评论
专栏目录
评论 2
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

seiyaaa

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付：¥1
获取中
扫码支付

您的余额不足，请更换扫码支付或充值

打赏作者

实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值