New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 765936 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner: ----
Closed: Sep 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 1
Type: Bug-Regression

Blocked on:
issue 766622
issue 767153



Sign in to add a comment

Multiple flaky failures in chrome_public_test_apk on linux_android_rel_ng

Project Member Reported by kbr@chromium.org, Sep 16 2017

Issue description

There are multiple apparently flaky test failures inside chrome_public_test_apk. Here are a couple I'm positive are unrelated to the CL being tried:

https://luci-milo.appspot.com/buildbot/tryserver.chromium.android/linux_android_rel_ng/386721
org.chromium.chrome.browser.partnercustomizations.PartnerHomepageIntegrationTest#testPreferenceCustomUriFixup

https://luci-milo.appspot.com/buildbot/tryserver.chromium.android/linux_android_rel_ng/386723
org.chromium.chrome.browser.crash.MinidumpUploadServiceTest#testTryUploadAllCrashDumps

https://luci-milo.appspot.com/buildbot/tryserver.chromium.android/linux_android_rel_ng/386702
org.chromium.chrome.browser.payments.PaymentRequestPaymentAppAndCardsTest#testEditPaymentMethodAndCancelEditorShouldKeepCardSelected

https://luci-milo.appspot.com/buildbot/tryserver.chromium.android/linux_android_rel_ng/386615
org.chromium.chrome.browser.payments.PaymentRequestFreeShippingTest#testPayWithRender

Maybe there's some underlying root cause for all of these but not sure. The affected teams should triage.

There are a lot more failures of this suite on linux_android_rel_ng, including jobs affected by the Logdog Issue 721889, but ignoring those, the failure rate for this test suite is too high and is causing lots of retries on the CQ.

 
Labels: Sheriff-Chromium
See also issue 765237.
I see the stack trace is similar, this is for org.chromium.chrome.browser.partnercustomizations.PartnerHomepageIntegrationTest#testCloseAllTabs:
android.os.StrictMode$StrictModeViolation: policy=2655 violation=2
	at android.os.StrictMode.executeDeathPenalty(StrictMode.java:1377)
	at android.os.StrictMode.access$1300(StrictMode.java:116)
	at android.os.StrictMode$AndroidBlockGuardPolicy.handleViolation(StrictMode.java:1370)
	at android.os.StrictMode$AndroidBlockGuardPolicy$1.run(StrictMode.java:1252)
	at android.os.Handler.handleCallback(Handler.java:733)
	at android.os.Handler.dispatchMessage(Handler.java:95)
	at android.os.Looper.loop(Looper.java:136)
	at android.app.ActivityThread.main(ActivityThread.java:5001)
	at java.lang.reflect.Method.invokeNative(Method.java)
	at java.lang.reflect.Method.invoke(Method.java:515)
	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:785)
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:601)
	at dalvik.system.NativeStart.main(NativeStart.java)
Search logcat for "StrictMode policy violation" for full stack.
Searching for native crashes in: /b/swarming/w/it376tyD/tmpqQnIeZ
Unknown Android release, consider passing --packed-lib.
Reading Android symbols from: /b/swarming/w/ir
Searching for Chrome symbols from within: /b/swarming/w/ir/out/Release/lib.unstripped:/b/swarming/w/ir/out/Release/lib:/b/swarming/w/ir/out/Release

It's not realistic to disable affected tests, so I'm putting this in the sheriff queue as a heads-up for future sheriffs.
Labels: sheriff-android
Owner: wnwen@chromium.org
Status: Assigned (was: Untriaged)
Hi wnwen@, I am the Chromium Sheriff of the day.  I noticed you have some experience dealing with Strict Mode errors from  Bug 574532 .  Can you help us to assign this bug to the right owner?  
Components: -Infra>Client>Chrome

Comment 5 by wnwen@chromium.org, Sep 18 2017

Going to the bot, then result_details, then logcat of the failing test, we see:

09-16 18:33:11.729 29498 29508 E StrictMode: A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
09-16 18:33:11.729 29498 29508 E StrictMode: java.lang.Throwable: Explicit termination method 'close' not called
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.CloseGuard.open(CloseGuard.java:184)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.DexFile.<init>(DexFile.java:113)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.DexFile.loadDex(DexFile.java:151)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.DexPathList.loadDexFile(DexPathList.java:266)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.DexPathList.makeDexElements(DexPathList.java:221)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.DexPathList.<init>(DexPathList.java:112)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.BaseDexClassLoader.<init>(BaseDexClassLoader.java:48)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at dalvik.system.DexClassLoader.<init>(DexClassLoader.java:57)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at org.chromium.webapk.lib.client.DexOptimizer.optimize(DexOptimizer.java:71)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at org.chromium.chrome.browser.webapps.WebApkVersionManager.updateWebApksIfNeeded(WebApkVersionManager.java:74)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at org.chromium.chrome.browser.init.ProcessInitializationHandler$16.doInBackground$10299ca(ProcessInitializationHandler.java:462)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at org.chromium.chrome.browser.init.ProcessInitializationHandler$16.doInBackground(ProcessInitializationHandler.java:427)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at android.os.AsyncTask$2.call(AsyncTask.java:288)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
09-16 18:33:11.729 29498 29508 E StrictMode: 	at java.lang.Thread.run(Thread.java:841)

Comment 6 by wnwen@chromium.org, Sep 18 2017

Cc: pkotw...@chromium.org estevenson@chromium.org
+pkotwicz,estevenson@

Comment 7 by wnwen@chromium.org, Sep 18 2017

Here is another stack trace from 
https://luci-milo.appspot.com/buildbot/tryserver.chromium.android/linux_android_rel_ng/386702

09-16 14:29:21.859 25286 25286 D StrictMode: StrictMode policy violation; ~duration=468 ms: android.os.StrictMode$StrictModeDiskReadViolation: policy=2911 violation=2
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.StrictMode$AndroidBlockGuardPolicy.onReadFromDisk(StrictMode.java:1135)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at libcore.io.BlockGuardOs.open(BlockGuardOs.java:106)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at libcore.io.IoBridge.open(IoBridge.java:393)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at java.io.FileOutputStream.<init>(FileOutputStream.java:88)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at java.io.FileOutputStream.<init>(FileOutputStream.java:73)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.DropBoxManagerService.add(DropBoxManagerService.java:211)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.DropBoxManager.addText(DropBoxManager.java:272)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService$17.run(ActivityManagerService.java:10018)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService.addErrorToDropBox(ActivityManagerService.java:10025)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService.handleApplicationWtf(ActivityManagerService.java:9832)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.internal.os.RuntimeInit.wtf(RuntimeInit.java:337)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.util.Log$1.onTerribleFailure(Log.java:104)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.util.Log.wtf(Log.java:293)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.util.Slog.wtf(Slog.java:82)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActiveServices.killServicesLocked(ActiveServices.java:2081)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService.cleanUpApplicationRecordLocked(ActivityManagerService.java:12427)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService.handleAppDiedLocked(ActivityManagerService.java:3606)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:3751)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:1026)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.BinderProxy.sendDeathNotice(BinderProxy.java:493)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at dalvik.system.NativeStart.run(NativeStart.java)
09-16 14:29:21.859 25286 25286 D StrictMode: # via Binder call with stack:
09-16 14:29:21.859 25286 25286 D StrictMode: android.os.StrictMode$LogStackTrace
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.StrictMode.readAndHandleBinderCallViolations(StrictMode.java:1705)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.Parcel.readExceptionCode(Parcel.java:1447)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.Parcel.readException(Parcel.java:1416)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.hardware.display.IDisplayManager$Stub$Proxy.getDisplayInfo(IDisplayManager.java:222)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.hardware.display.DisplayManagerGlobal.getDisplayInfo(DisplayManagerGlobal.java:117)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.view.Choreographer.getRefreshRate(Choreographer.java:181)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.view.Choreographer.<init>(Choreographer.java:172)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.view.Choreographer.<init>(Choreographer.java:72)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.view.Choreographer$1.initialValue(Choreographer.java:98)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.view.Choreographer$1.initialValue(Choreographer.java:91)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at java.lang.ThreadLocal$Values.getAfterMiss(ThreadLocal.java:430)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at java.lang.ThreadLocal.get(ThreadLocal.java:65)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.view.Choreographer.getInstance(Choreographer.java:194)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.ui.VSyncMonitor.<init>(VSyncMonitor.java:69)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.ui.base.WindowAndroid.<init>(WindowAndroid.java:214)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.ui.base.WindowAndroid.<init>(WindowAndroid.java:199)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.ui.base.WindowAndroid.<init>(WindowAndroid.java:199)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.ui.base.ActivityWindowAndroid.<init>(ActivityWindowAndroid.java:69)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.ui.base.ActivityWindowAndroid.<init>(ActivityWindowAndroid.java:60)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.chrome.browser.ChromeWindow.<init>(ChromeWindow.java:24)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.chrome.browser.ChromeActivity.createWindowAndroid(ChromeActivity.java:306)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.chrome.browser.init.AsyncInitializationActivity.onCreateInternal(AsyncInitializationActivity.java:278)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at org.chromium.chrome.browser.init.AsyncInitializationActivity.onCreate(AsyncInitializationActivity.java:243)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.Activity.performCreate(Activity.java:5231)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.support.test.runner.MonitoringInstrumentation.callActivityOnCreate(MonitoringInstrumentation.java:532)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2148)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2233)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.ActivityThread.access$800(ActivityThread.java:135)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1196)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.Handler.dispatchMessage(Handler.java:102)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.os.Looper.loop(Looper.java:136)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at android.app.ActivityThread.main(ActivityThread.java:5001)
09-16 14:29:21.859 25286 25286 D StrictMode: 	at java.lang.reflect.Method

Comment 8 by wnwen@chromium.org, Sep 18 2017

@John - did something change in our build system or bots recently to trigger these seemingly new StrictMode issues? GMS update? Bot OS update?

Comment 9 by wnwen@chromium.org, Sep 18 2017

Cc: ccameron@chromium.org
+ccameron@ from bc1ae6d669603f0b75213e7557c15cef80416989 to help with new display StrictMode violations.

Comment 10 by wnwen@chromium.org, Sep 18 2017

Blockedon: 750196
Cc: boliu@chromium.org
+boliu for help!
Labels: -Sheriff-Chromium

Comment 13 by tkent@chromium.org, Sep 18 2017

Cc: -tkent@chromium.org

Comment 14 by boliu@chromium.org, Sep 19 2017

#7 is taking .5 seconds talking to the display manager service. And it's not even chrome directly requesting that, it's Choreographer. Chrome isn't doing anything wrong here

I'm not sure if we are supposed to be running tests with strict mode turned on. Things like this are really useless.


Also... why focus on strict mode violation? The three other tests linked by kbr are all actual test timeouts?

Comment 15 by boliu@chromium.org, Sep 19 2017

Cc: yfried...@chromium.org
seems like default for tests is --strict-mode=testing
https://cs.chromium.org/chromium/src/build/android/test_runner.py?rcl=01b28422bcb168e52fc1039112f1329937c85321&l=460

which adds threadPolicy.penaltyDeath
https://cs.chromium.org/chromium/src/chrome/android/java/src/org/chromium/chrome/browser/ChromeStrictMode.java?rcl=01b28422bcb168e52fc1039112f1329937c85321&l=184

so dying on violation is expected. It's just super annoying when it's not actually fault of chrome code
Note that something on linux_android_rel_ng got *significantly* worse yesterday afternoon. TabsTest#testHideKeyboardWhenOpeningWindow appears to be the most acutely affected, and I'm disabling it in crbug.com/766735.
Blockedon: 766622
Ya, just to comment on #15 - strict mode failing builds isn't new and the webapks one from #5 isn't either so something else about our tests, product or environment has changed

Comment 19 by wnwen@chromium.org, Sep 20 2017

Blockedon: -750196
Status: Availal (was: Assigned)
We've determined in  issue 750196  that the error in #5 does not actually crash the test, it's just logging.

Yes, it's very annoying when we find StrictMode violations we cannot fix, which we need to bandage. At the same time running --strict-mode=testing prevents unintentional performance regressions from passing CQ and then being found and painfully debugged in the wild. Especially since it's relatively easy to bandage one we can't fix, while it's hard to tell just by calling a random API or method whether it will result in disk read/write or not.

Currently only 2 classes use Choreographer.getInstance, so if there's a lot more flakes then I can whitelist those: https://cs.chromium.org/search/?q=Choreographer.getInstance+-file:third_party&sq=package:chromium&type=cs

So far, as noted in #16, something else is happening here that is causing flakiness.

Comment 20 by wnwen@chromium.org, Sep 20 2017

Status: Available (was: Availal)
The "something else" I mentioned in #16 has been resolved. The issues discussed in this bug -- which, tbh, should be broken into bugs per test rather than a generic superbug -- are separate.

Comment 22 by wnwen@chromium.org, Sep 20 2017

Blockedon: 767153

Comment 23 by wnwen@chromium.org, Sep 20 2017

Cc: wnwen@chromium.org
Owner: ----
I'm whitelisting the error in #5 ( issue 750196 ) and investigating the policy violation in #7 ( issue 767153 ). Making the rest of this bug available.

Comment 24 by wnwen@chromium.org, Sep 20 2017

Status: Fixed (was: Available)
The rest of the issues in this bug can be attributed to issue 766622. No point keeping both open.

Sign in to add a comment