Issue metadata
Sign in to add a comment
|
Multiple flaky failures in chrome_public_test_apk on linux_android_rel_ng |
||||||||||||||||||||||
Issue descriptionThere 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.
,
Sep 18 2017
,
Sep 18 2017
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?
,
Sep 18 2017
,
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)
,
Sep 18 2017
+pkotwicz,estevenson@
,
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
,
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?
,
Sep 18 2017
+ccameron@ from bc1ae6d669603f0b75213e7557c15cef80416989 to help with new display StrictMode violations.
,
Sep 18 2017
,
Sep 18 2017
+boliu for help!
,
Sep 18 2017
,
Sep 18 2017
,
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?
,
Sep 19 2017
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
,
Sep 19 2017
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.
,
Sep 19 2017
,
Sep 19 2017
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
,
Sep 20 2017
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.
,
Sep 20 2017
,
Sep 20 2017
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.
,
Sep 20 2017
,
Sep 20 2017
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.
,
Sep 20 2017
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 |
|||||||||||||||||||||||
Comment 1 by maxmorin@chromium.org
, Sep 18 2017