测试命令: run gts-suite -s ID -o -m GtsGmscoreHostTestCases -t com.google.android.gts.devicepolicy.managedprovisioning.DeviceOwnerProvisioningHostsideTest#testRequiredAppsInManagedProfileForManagedDevice
报错堆栈:
07-27 06:59:30.611 32075 32125 I SilentProvisioningTest: managedProfileProvisionedReceiver.awaitForBroadcast(): failed
07-27 06:59:30.612 2091 2129 D ContactsDatabaseHelper: insertMimeType: vnd.android.cursor.item/website
07-27 06:59:30.613 1535 1587 W zygote64: kill(-1628, 9) failed: No such process
07-27 06:59:30.614 1535 2857 D CompatibilityInfo: mCompatibilityFlags - 10
07-27 06:59:30.614 1535 2857 D CompatibilityInfo: applicationDensity - 480
07-27 06:59:30.614 1535 2857 D CompatibilityInfo: applicationScale - 1.0
07-27 06:59:30.617 32075 32122 I TestRunner: failed: testProvision(com.google.android.gts.managedprovisioning.ManagedProfileProvisioningTest)
07-27 06:59:30.617 32075 32122 I TestRunner: ----- begin exception -----
07-27 06:59:30.618 32075 32122 I TestRunner: java.lang.AssertionError
07-27 06:59:30.618 32075 32122 I TestRunner: at org.junit.Assert.fail(Assert.java:86)
07-27 06:59:30.618 32075 32122 I TestRunner: at org.junit.Assert.assertTrue(Assert.java:41)
07-27 06:59:30.618 32075 32122 I TestRunner: at org.junit.Assert.assertTrue(Assert.java:52)
07-27 06:59:30.618 32075 32122 I TestRunner: at com.google.android.gts.managedprovisioning.ManagedProfileProvisioningTest.testProvision(ManagedProfileProvisioningTest.java:54)
从log看是case中在规定时间内没有接受到想要的广播导致的超时，那么凭借以往的经验，觉得这个case应该是偶现的
经过复测发现果然有三种情况
- case pass
- 延长广播receiver的等待时间可以pass
- 延长广播的等待时间也不能pass
主要需要分析的是第三种情况，因为这才最可能是测试偶现fail的root cause
问题分析
当延长广播的等待时间也不能pass，那么说明有很大可能广播根本就没有发出去或者在传播过程中出现了问题，再查看log:
发现了关键性的log:
BroadcastQueue: Failure [foreground] sending broadcast result of Intent { act=android.app.action.PROFILE_PROVISIONING_COMPLETE flg=0x10000030 (has extras) }
重新整理case
SilentProvisioningTestManager里面注册了两个广播
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 |
private boolean waitManagedProfileProvisioning() throws InterruptedException { BlockingBroadcastReceiver localBlockingBroadcastReceiver1 = new BlockingBroadcastReceiver(this.mContext, "android.app.action.MANAGED_PROFILE_PROVISIONED"); BlockingBroadcastReceiver localBlockingBroadcastReceiver2 = new BlockingBroadcastReceiver(this.mContext, "android.intent.action.MANAGED_PROFILE_ADDED"); try { localBlockingBroadcastReceiver1.register(); localBlockingBroadcastReceiver2.register(); boolean bool = pollProvisioningResult(); if (!bool) { return false; } this.mReceivedProfileProvisionedIntent = localBlockingBroadcastReceiver1.awaitForBroadcast(); if (this.mReceivedProfileProvisionedIntent == null) { Log.i("SilentProvisioningTest", "managedProfileProvisionedReceiver.awaitForBroadcast(): failed"); return false; } if (localBlockingBroadcastReceiver2.awaitForBroadcast() == null) { Log.i("SilentProvisioningTest", "managedProfileAddedReceiver.awaitForBroadcast(): failed"); return false; } return true; } finally { localBlockingBroadcastReceiver1.unregisterQuietly(); localBlockingBroadcastReceiver2.unregisterQuietly(); } } |
</p
只要有一个receiver没有在10s内接受，那么case fail
smali加了一下log，正常能pass的版本应该是</p
|
1 2 3 4 5 6 7 8 9 10 |
01-21 07:09:26.830 30298 30298 D weijuncheng: -------------->a2 01-21 07:09:26.830 29764 29764 D weijuncheng: -------------->a1 01-21 07:09:26.830 29764 29764 D weijuncheng: android.intent.action.MANAGED_PROFILE_ADDED 01-21 07:09:26.830 29764 29764 D weijuncheng: -------------->a3 01-21 07:09:26.832 2452 5951 I ActivityManager: Killing 25473:com.google.android.apps.messaging/u0a66 (adj 906): empty #17 01-21 07:09:26.832 2452 2509 W zygote64: kill(-25473, 9) failed: No such process 01-21 07:09:26.833 29547 29547 D ManagedProvisioning: ACTION_PROFILE_PROVISIONING_COMPLETE broadcast received by mdm 01-21 07:09:26.836 29764 29764 D weijuncheng: -------------->a1 01-21 07:09:26.836 29764 29764 D weijuncheng: android.app.action.MANAGED_PROFILE_PROVISIONED 01-21 07:09:26.836 29764 29764 D weijuncheng: -------------->a3 |
两个广播都能收到，且会有如下log:
ACTION_PROFILE_PROVISIONING_COMPLETE broadcast received by mdm
这两个广播其实都和PROFILE_PROVISIONING_COMPLETE 这个广播有关，都是接收PROFILE_PROVISIONING_COMPLETE这个广播后才会发送
对比一下fail的log:
|
1 2 3 4 |
07-31 21:58:22.306 1310238 9274 9274 D weijuncheng: -------------->a2 07-31 21:58:22.307 10238 8155 8155 D weijuncheng: -------------->a1 07-31 21:58:22.307 10238 8155 8155 D weijuncheng: android.intent.action.MANAGED_PROFILE_ADDED 07-31 21:58:22.307 10238 8155 8155 D weijuncheng: -------------->a3 |
可见MANAGED_PROFILE_PROVISIONED这个广播没有等到，因为其根本没有顺利发送出来；其发送的地方DpcReceivedSuccessReceiver.java中的
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
64 @Override 65 public void onReceive(Context context, Intent intent){ 66 ProvisionLogger.logd("ACTION_PROFILE_PROVISIONING_COMPLETE broadcast received by mdm"); 67 68 final Intent primaryProfileSuccessIntent = new Intent(ACTION_MANAGED_PROFILE_PROVISIONED); 69 primaryProfileSuccessIntent.setPackage(mMdmPackageName); 70 primaryProfileSuccessIntent.addFlags(Intent.FLAG_INCLUDE_STOPPED_PACKAGES | 71 Intent.FLAG_RECEIVER_FOREGROUND); 72 primaryProfileSuccessIntent.putExtra(Intent.EXTRA_USER, mManagedUserHandle); 73 74 // Now cleanup the primary profile if necessary 75 if (mMigratedAccount != null) { 76 primaryProfileSuccessIntent.putExtra(EXTRA_PROVISIONING_ACCOUNT_TO_MIGRATE, 77 mMigratedAccount); 78 finishAccountMigration(context, primaryProfileSuccessIntent); 79 // Note that we currently do not check if account migration worked 80 } else { 81 context.sendBroadcast(primaryProfileSuccessIntent); 82 } 83 } |
可以看到上面onReceive中的第一行就有"ACTION_PROFILE_PROVISIONING_COMPLETE broadcast received by mdm，而现在没有这行log，说明没有接收到ACTION_PROFILE_PROVISIONING_COMPLETE这个广播，所以case等待的广播就不能发出去了，所以延长多少等待时间都会fail
再回到上面的报错，广播ACTION_PROFILE_PROVISIONING_COMPLETE发送后最后一个处理结果的receiver没有顺利接收
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
if (r.resultTo != null) { try { if (DEBUG_BROADCAST) Slog.i(TAG_BROADCAST, "Finishing broadcast [" + mQueueName + "] " + r.intent.getAction() + " app=" + r.callerApp); performReceiveLocked(r.callerApp, r.resultTo, new Intent(r.intent), r.resultCode, r.resultData, r.resultExtras, false, false, r.userId); // Set this to null so that the reference // (local and remote) isn't kept in the mBroadcastHistory. r.resultTo = null; } catch (RemoteException e) { r.resultTo = null; Slog.w(TAG, "Failure [" + mQueueName + "] sending broadcast result of " + r.intent, e); } } |
没有被接收的原因是
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
491 void performReceiveLocked(ProcessRecord app, IIntentReceiver receiver, 492 Intent intent, int resultCode, String data, Bundle extras, 493 boolean ordered, boolean sticky, int sendingUser) throws RemoteException { 494 // Send the intent to the receiver asynchronously using one-way binder calls. 495 if (app != null) { 496 if (app.thread != null) { ... 516 } else { 517 // Application has died. Receiver doesn't exist. 518 throw new RemoteException("app.thread must not be null"); 519 } 520 } else { 521 receiver.performReceive(intent, resultCode, data, extras, ordered, 522 sticky, sendingUser); 523 } 524 } |
app.thread must not be null 这个是接收进程的processRecord中的thread为null时会打出的log，此时肯定不能接收到广播，而这里为null的原因是因为receiver所在进程处于被杀的过程中导致的
|
1 2 3 4 5 6 7 8 |
private final boolean cleanUpApplicationRecordLocked(ProcessRecord app, ... 18540 app.resetPackageList(mProcessStats); 18541 app.unlinkDeathRecipient(); 18542 app.makeInactive(mProcessStats); 18543 app.waitingToKill = null; ... } |
在进程被杀的过程中可能会将相应的ProcessRecord中的thread置为null
再回到log中，果然如此：
|
1 2 3 4 5 6 7 8 9 |
07-31 21:58:22.306 1310238 9274 9274 D weijuncheng: -------------->a2 07-31 21:58:22.307 10238 8155 8155 D weijuncheng: -------------->a1 07-31 21:58:22.307 10238 8155 8155 D weijuncheng: android.intent.action.MANAGED_PROFILE_ADDED 07-31 21:58:22.307 10238 8155 8155 D weijuncheng: -------------->a3 07-31 21:58:21.926 1000 1548 2796 I am_kill : 0,7930,com.android.managedprovisioning,906,empty #17 07-31 21:58:22.036 1000 1548 4644 I am_proc_died: [0,7930,com.android.managedprovisioning,906,17] 07-31 21:58:26.554 1000 1548 2853 I am_kill : 13,9155,com.android.managedprovisioning,906,empty #17 07-31 21:58:26.578 1000 1548 2853 I am_proc_died: [13,9155,com.android.managedprovisioning,906,17] |
对比能通过的Android one版本
|
1 2 3 4 5 6 7 8 9 |
01-21 07:09:26.833 10023 29547 29547 D ManagedProvisioning: ACTION_PROFILE_PROVISIONING_COMPLETE broadcast received by mdm 01-21 07:09:26.836 10109 29764 29764 D weijuncheng: -------------->a1 01-21 07:09:26.836 10109 29764 29764 D weijuncheng: android.app.action.MANAGED_PROFILE_PROVISIONED 01-21 07:09:26.836 10109 29764 29764 D weijuncheng: -------------->a3 01-21 07:09:28.269 1000 2452 3340 I am_kill : 0,29547,com.android.managedprovisioning,906,empty #17 01-21 07:09:28.296 1000 2452 3340 I am_proc_died: [0,29547,com.android.managedprovisioning,906,17] 01-21 07:09:31.564 1000 2452 3340 I am_kill : 11,30283,com.android.managedprovisioning,906,empty #17 01-21 07:09:31.590 1000 2452 4036 I am_proc_died: [11,30283,com.android.managedprovisioning,906,17] |
通过对比能发现果然是因为com.android.managedprovisioning在receicever接收到之前被杀导致的问题，原因单纯就是因为优先级太低了
在运行过程中不停的运行：
adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning(Android p换成p，打印系统中进程信息)
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 |
69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 143- state: cur=IMPF set=IMPF lastPss=4.6MB lastSwapPss=326KB lastCachedPss=0.00 144- cached=false empty=true hasAboveClient=false 145: Proc # 2: vis +99 F/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (vis-activity) 146- oom: max=1001 procState: max=18 curRaw=199 setRaw=199 cur=199 set=199 147- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 190- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 191- cached=true empty=true hasAboveClient=false 192: Proc #17: cch+2 B/ /CEM trm: 0 18156:com.android.managedprovisioning/u0a25 (cch-empty) 193- oom: max=1001 procState: max=18 curRaw=902 setRaw=902 cur=902 set=902 194- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 74- cached=false empty=false hasAboveClient=false 75: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 76- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 77- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 0: fore T/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (top-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 69- state: cur=IMPF set=IMPF lastPss=17MB lastSwapPss=2.3MB lastCachedPss=0.00 70- cached=false empty=true hasAboveClient=false 71: Proc # 1: fore F/A/TOP trm: 0 18156:com.android.managedprovisioning/u0a25 (vis-activity) 72- oom: max=1001 procState: max=18 curRaw=0 setRaw=0 cur=0 set=0 73- state: cur=TOP set=TOP lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 217- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 218- cached=true empty=true hasAboveClient=false 219: Proc #22: cch+2 B/ /CEM trm: 0 18156:com.android.managedprovisioning/u0a25 (cch-empty) 220- oom: max=1001 procState: max=18 curRaw=902 setRaw=902 cur=902 set=902 221- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 252- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 253- cached=true empty=true hasAboveClient=false 254: Proc #18: cch+2 B/ /CEM trm: 0 19376:com.android.managedprovisioning/u14a25 (cch-empty) 255- oom: max=1001 procState: max=18 curRaw=902 setRaw=902 cur=902 set=902 256- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 weijuncheng@weijuncheng:~/qcts$ adb shell dumpsys activity o | grep -n2 com.android.managedprovisioning 244- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 245- cached=true empty=true hasAboveClient=false 246: Proc #27: cch+2 B/ /CEM trm: 0 19376:com.android.managedprovisioning/u14a25 (cch-empty) 247- oom: max=1001 procState: max=18 curRaw=902 setRaw=902 cur=902 set=902 248- state: cur=CEM set=CEM lastPss=0.00 lastSwapPss=0.00 lastCachedPss=0.00 |
从上面的过程可以看出，只要com.android.managedprovisioning到了后台，基本立即就变成了空进程；而通过观察进入后台的时机就是因为case会起一个Activity进行了遮挡，那么com.android.managedprovisioning就到了后台；那么首先想到的是将起这个Activity的时间延长一段时间，看看能不能通过
|
1 2 3 4 5 |
const-wide/16 v3, 0x2710 invoke-static {v3, v4}, Landroid/os/SystemClock;->sleep(J)V invoke-virtual {v0, v1}, Landroid/content/Context;->startActivity(Landroid/content/Intent;)V |
首先试了下，将startActivity之前做了一个sleep操作就可以必过了，那么从侧面说明了我们前面分析的没错；就是因为com.android.managedprovisioning变成了空进程导致的，系统杀空进程的原则是达到了空进程上限，然后开始统一杀空进程。对比了Android one的机器，空进程上限都是17，但是因为我们的系统中有miui的很多进程，导致被杀的快。理论上如果将Android one的机器缩小空进程上限，或者安装上很多app也是可能复现的，这里我们将Android one设置为不允许后台启动，相当于缩小了上限，果然在Android one上也复现了该问题
那么能想到的问题处理方案：
1.增大允许的空进程上限，但是这会造成的很大的影响，如内存什么的，为了一条case肯定是不能允许的
2.测试时将com.android.managedprovisioning保活在前台，可以利用我们MIUI的卡片机制，在测试过程中为相应进程加锁，加锁后也能通过，但是这相当于人为干预测试，其实是google不允许的
因此，最终决定和google反馈
问题总结
这个问题虽然google的case也有不合理的地方，但我觉得原生关于Broadcast的resultTo也有一点问题。发送有序广播的进程，可以设置个resultTo当作发送完的"回调"，但是这个进程在发送期间是没有优先级额外的提升的，所以容易在这期间被杀；而我们看到，正常接收广播时，它们在接收期间进程ADJ会提升到FOREGROUND，所以不太容易被杀，如下:
|
1 2 3 4 5 6 7 8 |
276 private final void processCurBroadcastLocked(BroadcastRecord r, 277 ProcessRecord app) throws RemoteException { ... 296 app.forceProcessStateUpTo(ActivityManager.PROCESS_STATE_RECEIVER); 297 mService.updateLruProcessLocked(app, false, null); 298 mService.updateOomAdjLocked(); ... 326 } |
|
1 2 3 4 5 6 7 8 9 |
515 /** @hide Process is in the background running a receiver. Note that from the 516 * perspective of oom_adj receivers run at a higher foreground level, but for our 517 * prioritization here that is not necessary and putting them below services means 518 * many fewer changes in some process states as they receive broadcasts. */ 519 public static final int PROCESS_STATE_RECEIVER = 12; 388 case ActivityManager.PROCESS_STATE_RECEIVER: 389 procState = "RCVR"; 390 break; |
所以，com.android.managedprovisioning 这个进程在发送广播后，在接收resultTo回调之前，因为进程的ADJ变为900+、procState变为PROCESS_STATE_CACHED_EMPTY，并且系统中所有空进程个数超过了上限（17），导致了进程被杀死，com.android.managedprovisioning的resultTo.performReceive没有被调用，最终导致了测试失败。理论上这个问题在原生的系统上，如果安装、运行的APP越多，case fail的概率就越大;
因此这个case是因为google case设计+我们的机器app安装太多+广播处理resultTo的原生逻辑共同的导致的问题
google做了修复，优化了managedprofile的流程，保证provision完全结束后再stop ProvisioningService，防止进程提前被杀，保证流程的完整性
https://android-review.googlesource.com/c/platform/packages/apps/ManagedProvisioning/+/737556
可惜patch 1的修复是有问题的，反而会导致问题必现，见后续分析
后续分析
加上google上面的patch之后问题反而变成必现的了，关键log如下：
09-11 17:32:05.666 6875 6894 I TestRunner: started: testProvision(com.google.android.gts.managedprovisioning.ManagedProfileProvisioningTest)
09-11 17:32:06.531 22290 22290 I ManagedProvisioning: Processing mininalist extras intent.
09-11 17:32:06.535 22290 22290 D ManagedProvisioning: Device is provisioned, FRP not required.
09-11 17:32:06.538 22290 22290 D ManagedProvisioning: Cancelling provisioning reminder.
09-11 17:32:06.570 22290 22290 E ManagedProvisioning: Trying to start provisioning, but it's already running
09-11 17:32:06.579 22290 22290 I ManagedProvisioning: ProvisioningActivity pre-finalization completed
09-11 17:32:16.652 6875 6896 I SilentProvisioningTest: managedProfileProvisionedReceiver.awaitForBroadcast(): failed
09-11 17:32:16.653 6875 6894 I TestRunner: failed: testProvision(com.google.android.gts.managedprovisioning.ManagedProfileProvisioningTest)
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
104 /** 105 * Initiate a new provisioning process, unless one is already ongoing. 106 * 107 * @param params {@link ProvisioningParams} associated with the new provisioning process. 108 */ 109 public void maybeStartProvisioning(final ProvisioningParams params){ 110 synchronized (this) { 111 if (mController == null) { 112 mTimeLogger.start(); 113 startNewProvisioningLocked(params); 114 mProvisioningAnalyticsTracker.logProvisioningStarted(mContext, params); 115 } else { 116 ProvisionLogger.loge("Trying to start provisioning, but it's already running"); 117 } 118 } 119 } |
这样我们在测完一条case之后，执行到这里，将其置为空进程的操作已经被移到finalizationCompleted里面了，导致进程不会被杀，那么执行第二条case时其实根本没有真正执行，就fail了，也就是说google的change可能导致该进程再正常执行完后不能被杀，原因如下：
|
1 2 3 4 5 6 7 8 9 10 11 |
@Override public void finalizationCompleted(){ synchronized (this) { for (ProvisioningManagerCallback callback : mCallbacks) { mUiHandler.post(callback::finalizationCompleted); } mLastCallback = CALLBACK_FINALIZED; clearControllerLocked(); } ProvisionLogger.logi("ProvisioningManager finalization completed"); } |
google将使进程变为空进程的逻辑移到了上面的新增函数中，然而如何才能调用到这里呢？
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 |
@Override public void onReceive(Context context, Intent intent){ ProvisionLogger.logd("ACTION_PROFILE_PROVISIONING_COMPLETE broadcast received by mdm"); final Intent primaryProfileSuccessIntent = new Intent(ACTION_MANAGED_PROFILE_PROVISIONED); primaryProfileSuccessIntent.setPackage(mMdmPackageName); primaryProfileSuccessIntent.addFlags(Intent.FLAG_INCLUDE_STOPPED_PACKAGES | Intent.FLAG_RECEIVER_FOREGROUND); primaryProfileSuccessIntent.putExtra(Intent.EXTRA_USER, mManagedUserHandle); // Now cleanup the primary profile if necessary if (mMigratedAccount != null) { primaryProfileSuccessIntent.putExtra(EXTRA_PROVISIONING_ACCOUNT_TO_MIGRATE, mMigratedAccount); finishAccountMigration(context, primaryProfileSuccessIntent); // Note that we currently do not check if account migration worked } else { context.sendBroadcast(primaryProfileSuccessIntent); ProvisioningManager.getInstance(context).finalizationCompleted(); } } |
也就是说DpcReceivedSuccessReceiver接受到数据时才会调用ProvisioningManager中的 finalizationCompleted，进行收尾工作；而这个广播的发送是在
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 |
116 void provisioningFinalized(){ 117 if (mHelper.isStateUnmanagedOrFinalized()) { 118 ProvisionLogger.logw("provisioningInitiallyDone called, but state is finalized or " 119 + "unmanaged"); 120 return; 121 } 122 123 final ProvisioningParams params = loadProvisioningParamsAndClearFile(); 124 if (params == null) { 125 ProvisionLogger.logw("FinalizationController invoked, but no stored params"); 126 return; 127 } 128 129 if (params.provisioningAction.equals(ACTION_PROVISION_MANAGED_PROFILE)) { 130 notifyDpcManagedProfile(params); 131 } else { 132 // For managed user and device owner, we send the provisioning complete intent and maybe 133 // launch the DPC. 134 int userId = UserHandle.myUserId(); 135 Intent provisioningCompleteIntent = createProvisioningCompleteIntent(params, userId); 136 if (provisioningCompleteIntent == null) { 137 return; 138 } 139 mContext.sendBroadcast(provisioningCompleteIntent); 140 141 maybeLaunchDpc(params, userId); 142 } 143 144 mHelper.markUserProvisioningStateFinalized(params); 145 } 23/** 24 * This class is used to make sure that we start the MDM after we shut the setup wizard down. 25 * The shut down of the setup wizard is initiated in the 26 * {@link com.android.managedprovisioning.provisioning.ProvisioningActivity} by calling 27 * {@link DevicePolicyManager#setUserProvisioningState(int, int)}. This will cause the 28 * Setup wizard to shut down and send a ACTION_PROVISIONING_FINALIZATION intent. This intent is 29 * caught by this receiver instead which will send the 30 * ACTION_PROFILE_PROVISIONING_COMPLETE broadcast to the MDM, which can then present it's own 31 * activities. 32 */ 33public class FinalizationActivity extends Activity{ 34 35 @Override 36 public void onCreate(Bundle savedInstanceState){ 37 super.onCreate(savedInstanceState); 38 39 new FinalizationController(this).provisioningFinalized(); 40 finish(); 41 } 42} |
也就是说执行ManagedProfileSettingsTask时才会真正执行到finalizationCompleted，将进程杀死；然后这条case其实会执行两次Initializing provisioning process，且第一次没有执行ManagedProfileSettingsTask，因此进程不会被杀，第二次没有执行；换句话说，这个修改只是根据原来我们上报的错误修的，没有考虑过所有的执行路径，可能存在进程执行完任务无法自动被杀的情况，需要google再次修复
我的想法是在preFinalizationCompleted中将FinalizationActivity起起来，保证进程执行完task之后能被杀掉，下面是我的change
https://android-review.googlesource.com/c/platform/packages/apps/ManagedProvisioning/+/75480
最后google提供了新patch，https://partnerissuetracker.corp.google.com/u/1/issues/112177789
总体思路是通过Service进行保活，进dev观察一段时间