ActivityManager wtf causes StrictMode violation |
|||||||||||
Issue descriptionSee https://luci-logdog.appspot.com/v/?s=chromium%2Fandroid%2Fswarming%2Flogcats%2F38bd28ba551b9d11%2F%2B%2Flogcat_org.chromium.chrome.browser.payments.PaymentRequestNoShippingTest.testCloseDialog_20170921T121314-UTC_062b281400faa220: 09-21 12:13:15.209 10456 10456 D StrictMode: StrictMode policy violation; ~duration=401 ms: android.os.StrictMode$StrictModeDiskReadViolation: policy=2911 violation=2 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.StrictMode$AndroidBlockGuardPolicy.onReadFromDisk(StrictMode.java:1135) 09-21 12:13:15.209 10456 10456 D StrictMode: at libcore.io.BlockGuardOs.open(BlockGuardOs.java:106) 09-21 12:13:15.209 10456 10456 D StrictMode: at libcore.io.IoBridge.open(IoBridge.java:393) 09-21 12:13:15.209 10456 10456 D StrictMode: at java.io.FileOutputStream.<init>(FileOutputStream.java:88) 09-21 12:13:15.209 10456 10456 D StrictMode: at java.io.FileOutputStream.<init>(FileOutputStream.java:73) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.DropBoxManagerService.add(DropBoxManagerService.java:211) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.DropBoxManager.addText(DropBoxManager.java:272) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService$17.run(ActivityManagerService.java:10018) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService.addErrorToDropBox(ActivityManagerService.java:10025) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService.handleApplicationWtf(ActivityManagerService.java:9832) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.internal.os.RuntimeInit.wtf(RuntimeInit.java:337) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.util.Log$1.onTerribleFailure(Log.java:104) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.util.Log.wtf(Log.java:293) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.util.Slog.wtf(Slog.java:82) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActiveServices.killServicesLocked(ActiveServices.java:2081) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService.cleanUpApplicationRecordLocked(ActivityManagerService.java:12427) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:3606) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:3751) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:1026) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.BinderProxy.sendDeathNotice(BinderProxy.java:493) 09-21 12:13:15.209 10456 10456 D StrictMode: at dalvik.system.NativeStart.run(NativeStart.java) 09-21 12:13:15.209 10456 10456 D StrictMode: # via Binder call with stack: 09-21 12:13:15.209 10456 10456 D StrictMode: android.os.StrictMode$LogStackTrace 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.StrictMode.readAndHandleBinderCallViolations(StrictMode.java:1705) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.Parcel.readExceptionCode(Parcel.java:1447) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.Parcel.readException(Parcel.java:1416) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ActivityManagerProxy.checkPermission(ActivityManagerProxy.java:3414) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ContextImpl.checkPermission(ContextImpl.java:1659) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ContextImpl.checkCallingOrSelfPermission(ContextImpl.java:1685) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.view.accessibility.AccessibilityManager.getInstance(AccessibilityManager.java:168) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ContextImpl$2.getService(ContextImpl.java:318) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ContextImpl.getSystemService(ContextImpl.java:1632) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.content.ContextWrapper.getSystemService(ContextWrapper.java:540) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.ui.base.WindowAndroid.<init>(WindowAndroid.java:215) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.ui.base.WindowAndroid.<init>(WindowAndroid.java:199) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.ui.base.WindowAndroid.<init>(WindowAndroid.java:199) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.ui.base.ActivityWindowAndroid.<init>(ActivityWindowAndroid.java:69) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.ui.base.ActivityWindowAndroid.<init>(ActivityWindowAndroid.java:60) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.chrome.browser.ChromeWindow.<init>(ChromeWindow.java:24) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.chrome.browser.ChromeActivity.createWindowAndroid(ChromeActivity.java:306) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.chrome.browser.init.AsyncInitializationActivity.onCreateInternal(AsyncInitializationActivity.java:278) 09-21 12:13:15.209 10456 10456 D StrictMode: at org.chromium.chrome.browser.init.AsyncInitializationActivity.onCreate(AsyncInitializationActivity.java:243) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.Activity.performCreate(Activity.java:5231) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.support.test.runner.MonitoringInstrumentation.callActivityOnCreate(MonitoringInstrumentation.java:532) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2148) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2233) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ActivityThread.access$800(ActivityThread.java:135) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1196) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.Handler.dispatchMessage(Handler.java:102) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.os.Looper.loop(Looper.java:136) 09-21 12:13:15.209 10456 10456 D StrictMode: at android.app.ActivityThread.main(ActivityThread.java:5001) 09-21 12:13:15.209 10456 10456 D StrictMode: at java.lang.reflect.Method.invokeNative(Method.java) 09-21 12:13:15.209 10456 10456 D StrictMode: at java.lang.reflect.Method.invoke(Method.java:515) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:785) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:601) 09-21 12:13:15.209 10456 10456 D StrictMode: at dalvik.system.NativeStart.main(NativeStart.java) Is there anything we can do about that?
,
Sep 21 2017
I think this is similar to issue 767153 , where the android logging service (dropbox) causes a StrictMode violation. Even if we whitelisted this, I think it may have the same failure. I'll try to reproduce it locally.
,
Sep 21 2017
Actually was able to repro that locally, with StrictMode off the test passed. Will look into a fix.
,
Sep 21 2017
Thanks! :)
,
Sep 21 2017
,
Sep 21 2017
This is the actual stack trace of the failure: Now I'm trying to figure out why ContentViewCore is null in ChromeTabbedActivity C 37.217s Main java.lang.RuntimeException: Exception occurred while waiting for runnable C 37.217s Main at org.chromium.base.ThreadUtils.runOnUiThreadBlocking(ThreadUtils.java:81) C 37.217s Main at org.chromium.chrome.browser.payments.PaymentRequestTestCommon.openPage(PaymentRequestTestCommon.java:143) C 37.217s Main at org.chromium.chrome.browser.payments.PaymentRequestTestCommon.openPageAndClickNodeAndWait(PaymentRequestTestCommon.java:161) C 37.217s Main at org.chromium.chrome.browser.payments.PaymentRequestTestCommon.triggerUIAndWait(PaymentRequestTestCommon.java:155) C 37.217s Main at org.chromium.chrome.browser.payments.PaymentRequestTestRule.triggerUIAndWait(PaymentRequestTestRule.java:136) C 37.217s Main at org.chromium.chrome.browser.payments.PaymentRequestNoShippingTest.testCloseDialog(PaymentRequestNoShippingTest.java:69) C 37.217s Main at java.lang.reflect.Method.invoke(Native Method) C 37.217s Main at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) C 37.217s Main at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) C 37.217s Main at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:52) C 37.218s Main at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) C 37.218s Main at org.chromium.base.test.ScreenshotOnFailureStatement.evaluate(ScreenshotOnFailureStatement.java:37) C 37.218s Main at org.chromium.chrome.browser.payments.PaymentRequestTestRule$1.evaluate(PaymentRequestTestRule.java:581) C 37.218s Main at org.chromium.chrome.test.ChromeActivityTestRule$1.evaluate(ChromeActivityTestRule.java:65) C 37.218s Main at android.support.test.internal.statement.UiThreadStatement.evaluate(UiThreadStatement.java:55) C 37.218s Main at android.support.test.rule.ActivityTestRule$ActivityStatement.evaluate(ActivityTestRule.java:270) C 37.218s Main at org.junit.rules.RunRules.evaluate(RunRules.java:20) C 37.218s Main at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) C 37.218s Main at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) C 37.218s Main at org.chromium.base.test.BaseJUnit4ClassRunner.runChild(BaseJUnit4ClassRunner.java:175) C 37.218s Main at org.chromium.base.test.BaseJUnit4ClassRunner.runChild(BaseJUnit4ClassRunner.java:40) C 37.218s Main at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) C 37.218s Main at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) C 37.218s Main at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) C 37.218s Main at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) C 37.219s Main at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) C 37.219s Main at org.junit.runners.ParentRunner.run(ParentRunner.java:363) C 37.219s Main at org.chromium.base.test.BaseJUnit4ClassRunner.run(BaseJUnit4ClassRunner.java:164) C 37.219s Main at org.junit.runners.Suite.runChild(Suite.java:128) C 37.219s Main at org.junit.runners.Suite.runChild(Suite.java:27) C 37.219s Main at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) C 37.219s Main at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) C 37.219s Main at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) C 37.219s Main at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) C 37.219s Main at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) C 37.219s Main at org.junit.runners.ParentRunner.run(ParentRunner.java:363) C 37.219s Main at org.junit.runner.JUnitCore.run(JUnitCore.java:137) C 37.219s Main at org.junit.runner.JUnitCore.run(JUnitCore.java:115) C 37.219s Main at android.support.test.internal.runner.TestExecutor.execute(TestExecutor.java:59) C 37.219s Main at android.support.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:262) C 37.219s Main at org.chromium.base.test.BaseChromiumAndroidJUnitRunner.onStart(BaseChromiumAndroidJUnitRunner.java:98) C 37.220s Main at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1879) C 37.220s Main Caused by: java.util.concurrent.ExecutionException: java.lang.NullPointerException: Attempt to invoke virtual method 'org.chromium.content_public.browser.WebContents org.chromium.content.browser.ContentViewCore.getWebContents()' on a nul l object reference C 37.220s Main at java.util.concurrent.FutureTask.report(FutureTask.java:94) C 37.220s Main at java.util.concurrent.FutureTask.get(FutureTask.java:164) C 37.220s Main at org.chromium.base.ThreadUtils.runOnUiThreadBlocking(ThreadUtils.java:79) C 37.220s Main ... 41 more C 37.220s Main Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'org.chromium.content_public.browser.WebContents org.chromium.content.browser.ContentViewCore.getWebContents()' on a null object reference C 37.220s Main at org.chromium.chrome.browser.payments.PaymentRequestTestCommon.lambda$openPage$0$PaymentRequestTestCommon(PaymentRequestTestCommon.java:145) C 37.220s Main at org.chromium.chrome.browser.payments.PaymentRequestTestCommon$$Lambda$0.run(Unknown Source) C 37.220s Main at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:423) C 37.220s Main at java.util.concurrent.FutureTask.run(FutureTask.java:237) C 37.220s Main at android.os.Handler.handleCallback(Handler.java:739) C 37.220s Main at android.os.Handler.dispatchMessage(Handler.java:95) C 37.220s Main at android.os.Looper.loop(Looper.java:148) C 37.220s Main at android.app.ActivityThread.main(ActivityThread.java:5417) C 37.221s Main at java.lang.reflect.Method.invoke(Native Method) C 37.221s Main at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726) C 37.221s Main at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
,
Sep 21 2017
Opps, turns out that the error in #6 is purely because my device's screen was off.
,
Sep 21 2017
I thought I was able to reproduce it, but it was actually just that my device's screen was off. Now as long as the device is on and unlocked, the test works with strictmode on. :/ Seems like these are flakes on the SDK side. In any case from the logs it looks like the test would have failed regardless of whether StrictMode was on, since the violation was in appDied handling. :( com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:3606) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:3751) 09-21 12:13:15.209 10456 10456 D StrictMode: at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:1026)
,
Sep 21 2017
,
Sep 21 2017
Can we disable strict mode around this? It's still affecting tests...
,
Sep 21 2017
Is there a way for me to see stack traces of other tests that are being affected?
,
Sep 21 2017
So far I can see that it's mostly happening in WindowAndroid, so I can disable that, but not sure what is the extent of these flakes.
,
Sep 21 2017
https://chromium-review.googlesource.com/c/chromium/src/+/677226 should cover these two bugs.
,
Sep 21 2017
Whitelisted. See tracking bug.
,
Sep 21 2017
Tracked at issue 767624
,
Sep 21 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/908f3f7144b2598348d33a668d494f85070bba41 commit 908f3f7144b2598348d33a668d494f85070bba41 Author: Peter Wen <wnwen@chromium.org> Date: Thu Sep 21 22:54:55 2017 Android: Patch flaky tests due to strict mode Android system is crashing due to StrictMode but we need to know the underlying cause in order to understand why it is flaking. Disabling StrictMode just for those code paths as the flakiness is unreliable and hard to reproduce. BUG= 767423 , 767153 , 767624 Change-Id: I0ddcabd876bab99841487742f039cea920ea433d Reviewed-on: https://chromium-review.googlesource.com/677226 Commit-Queue: Peter Wen <wnwen@chromium.org> Reviewed-by: ccameron chromium <ccameron@chromium.org> Reviewed-by: Eric Stevenson <estevenson@chromium.org> Cr-Commit-Position: refs/heads/master@{#503595} [modify] https://crrev.com/908f3f7144b2598348d33a668d494f85070bba41/ui/android/java/src/org/chromium/ui/base/WindowAndroid.java
,
Oct 3 2017
It looks like the crash is still happening: https://luci-logdog.appspot.com/v/?s=chromium%2Fandroid%2Fswarming%2Flogcats%2F38f7ce5b84888e11%2F%2B%2Flogcat_org.chromium.chrome.browser.payments.PaymentRequestPaymentAppAndBasicCardWithModifiersTest.testUpdateTotalAndInstrumentLabelWithCreditVisaModifiers_20171002T213008-UTC_069a837b003bb7f1 Does the StrictMode policy perhaps only apply to the current process, not if we get an exception via Binder?
,
Oct 4 2017
For tests we use "--strict-mode=testing" which only sets our thread policy: https://cs.chromium.org/chromium/src/chrome/android/java/src/org/chromium/chrome/browser/ChromeStrictMode.java?q=chromestrictmode&sq=package:chromium&l=183 Maybe this is something android is setting or is device-wide? :/
,
Oct 16 2017
,
Nov 16 2017
Unfortunately this is an issue in Android causing the flakes. |
|||||||||||
►
Sign in to add a comment |
|||||||||||
Comment 1 by jbudorick@chromium.org
, Sep 21 2017