CTS WebViewTest#testFindNext is flaky |
|||||||||
Issue descriptionhttps://uberchromegw.corp.google.com/i/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/12000 https://uberchromegw.corp.google.com/i/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/11990 https://uberchromegw.corp.google.com/i/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/11987 https://uberchromegw.corp.google.com/i/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/11983 @@@STEP_LOG_LINE@stdout@06-07 13:51:58 I/03848d89f0e93fd0: android.webkit.cts.WebViewTest#testFindNext FAIL @@@ @@@STEP_LOG_LINE@stdout@junit.framework.AssertionFailedError@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.Assert.fail(Assert.java:48)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.Assert.assertTrue(Assert.java:20)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.Assert.assertTrue(Assert.java:27)@@@ @@@STEP_LOG_LINE@stdout@at android.webkit.cts.WebViewTest.testFindNext(WebViewTest.java:1469)@@@ @@@STEP_LOG_LINE@stdout@at java.lang.reflect.Method.invoke(Native Method)@@@ @@@STEP_LOG_LINE@stdout@at java.lang.reflect.Method.invoke(Method.java:372)@@@ @@@STEP_LOG_LINE@stdout@at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)@@@ @@@STEP_LOG_LINE@stdout@at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)@@@ @@@STEP_LOG_LINE@stdout@at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestCase.runBare(TestCase.java:134)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestResult$1.protect(TestResult.java:115)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestResult.runProtected(TestResult.java:133)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.internal.runner.junit3.DelegatingTestResult.runProtected(DelegatingTestResult.java:90)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestResult.run(TestResult.java:118)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.internal.runner.junit3.AndroidTestResult.run(AndroidTestResult.java:52)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestCase.run(TestCase.java:124)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.internal.runner.junit3.NonLeakyTestSuite$NonLeakyTest.run(NonLeakyTestSuite.java:63)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestSuite.runTest(TestSuite.java:243)@@@ @@@STEP_LOG_LINE@stdout@at junit.framework.TestSuite.run(TestSuite.java:238)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.internal.runner.junit3.DelegatingTestSuite.run(DelegatingTestSuite.java:103)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.internal.runner.junit3.AndroidTestSuite.run(AndroidTestSuite.java:52)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.internal.runner.junit3.JUnit38ClassRunner.run(JUnit38ClassRunner.java:90)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.Suite.runChild(Suite.java:128)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.Suite.runChild(Suite.java:24)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runners.ParentRunner.run(ParentRunner.java:300)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runner.JUnitCore.run(JUnitCore.java:157)@@@ @@@STEP_LOG_LINE@stdout@at org.junit.runner.JUnitCore.run(JUnitCore.java:136)@@@ @@@STEP_LOG_LINE@stdout@at android.support.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:245)@@@ @@@STEP_LOG_LINE@stdout@at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1853)@@@ @@@STEP_LOG_LINE@stdout@@@@
,
Jun 10 2016
Is there any update? This test is still flaky on Android WebView CTS L-MR1 (dbg): https://uberchromegw.corp.google.com/i/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/12157 Should we disable it?
,
Jun 10 2016
low priority, it's probably a bug in the test, and making changes to cts is... kinda hard
,
Jun 10 2016
Yoland, can you disable this test?
,
Jun 10 2016
,
Jun 10 2016
,
Jun 10 2016
I added the bug to fix-it week's bug list for a real fix. However, even if we fix it here, there is no way it a new CTS will be released on time to be able to enable it. So my expectation for fix-it week is to fix the test and set this to fixed and then file a new bug for enabling it when new cts is released. sorry for the complicated mechanism, but this is necessary for accounting the fix-it week efficiency correctly.
,
Jun 10 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/3e1b9e6ab5c00e723cc020fe28f2f62f57a27bf0 commit 3e1b9e6ab5c00e723cc020fe28f2f62f57a27bf0 Author: yolandyan <yolandyan@chromium.org> Date: Fri Jun 10 21:38:51 2016 Disable testFindNext CTS test BUG= 618089 Review-Url: https://codereview.chromium.org/2061473002 Cr-Commit-Position: refs/heads/master@{#399275} [modify] https://crrev.com/3e1b9e6ab5c00e723cc020fe28f2f62f57a27bf0/android_webview/tools/cts_config/expected_failure_on_bot.json
,
Jun 13 2016
re #7: Starting from a while ago, we upload android-cts.zip to internal google cloud storage, and CTS test bot will download from there. So we can update the test in AOSP and then re-upload a new android-cts.zip with the fix any time we want. Anyway, we need to investigate deeper.
,
Jun 15 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/3e1b9e6ab5c00e723cc020fe28f2f62f57a27bf0 commit 3e1b9e6ab5c00e723cc020fe28f2f62f57a27bf0 Author: yolandyan <yolandyan@chromium.org> Date: Fri Jun 10 21:38:51 2016 Disable testFindNext CTS test BUG= 618089 Review-Url: https://codereview.chromium.org/2061473002 Cr-Commit-Position: refs/heads/master@{#399275} [modify] https://crrev.com/3e1b9e6ab5c00e723cc020fe28f2f62f57a27bf0/android_webview/tools/cts_config/expected_failure_on_bot.json
,
Jun 20 2016
Yoland, is there anything left to do here? If not, feel free to mark it as fixed.
,
Jun 21 2016
Right now the test is disabled. We need to fix the CTS test, but I don't know if this is sth Yoland wants to work on? Yoland, do you think you can fix the actual CTS test or should we try to find an owner?
,
Jun 23 2016
Currently looking into it
,
Jun 29 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/30b6b4a55040dcba92f8b7f08a5b9e585713b641 commit 30b6b4a55040dcba92f8b7f08a5b9e585713b641 Author: yolandyan <yolandyan@google.com> Date: Wed Jun 29 20:07:11 2016 Enable testFindNext BUG= 618089 Review-Url: https://codereview.chromium.org/2108973003 Cr-Commit-Position: refs/heads/master@{#402917} [modify] https://crrev.com/30b6b4a55040dcba92f8b7f08a5b9e585713b641/android_webview/tools/cts_config/expected_failure_on_bot.json
,
Jun 30 2016
I am going to take the CTS bot down for a bit. I couldn't repro the bug on my local device after running it for 100 runs. (On the bot, more than 50% of the runs fails on this test). Gonna try to ssh in and run the test
,
Jun 30 2016
maybe it is related to the test that is running immediately before it, some test not leaving a clean state.
,
Jun 30 2016
True, I will try to run the previous test along with this test at the same time. I also think we can problem improve on with CTS testing bot. (logging, rerun, logcat if failure, screenshot if failure, bug report if failure, etc). OKR time? :)
,
Jun 30 2016
That'll be great! Screenshot on failure is a commandline option you can pass to cts-tradefed, FWIW.
,
Jun 30 2016
improving sgtm
,
Jul 1 2016
Can not reproduce the result locally, but fails 100% of times on bot. I am going disable the test again and grab one of the two devices from lab to run tests locally. Can +mikecase and I be the OWNERS for android_webview/tools/cts_config/? https://codereview.chromium.org/2114813002
,
Jul 1 2016
send me a CL for ownership
,
Jul 1 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/d017bd94fbbd617eb5f3d261d7a4a38342225d85 commit d017bd94fbbd617eb5f3d261d7a4a38342225d85 Author: yolandyan <yolandyan@google.com> Date: Fri Jul 01 01:35:40 2016 testFindNext is still failing on bots but not locally. Disable it on bot while borrowing the lab device to do the debugging BUG= 618089 Review-Url: https://codereview.chromium.org/2114813002 Cr-Commit-Position: refs/heads/master@{#403384} [add] https://crrev.com/d017bd94fbbd617eb5f3d261d7a4a38342225d85/android_webview/tools/cts_config/OWNERS [modify] https://crrev.com/d017bd94fbbd617eb5f3d261d7a4a38342225d85/android_webview/tools/cts_config/expected_failure_on_bot.json
,
Jul 12 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b68ebdbec5700c25844b8be949141bcc655e8999 commit b68ebdbec5700c25844b8be949141bcc655e8999 Author: yolandyan <yolandyan@chromium.org> Date: Tue Jul 12 19:29:26 2016 Resume testFindNext CTS test BUG= 618089 Review-Url: https://codereview.chromium.org/2142553002 Cr-Commit-Position: refs/heads/master@{#404821} [modify] https://crrev.com/b68ebdbec5700c25844b8be949141bcc655e8999/android_webview/tools/cts_config/expected_failure_on_bot.json
,
Sep 9 2016
This is still flaky, do we even know which line is failing - as in which line in the test? (in master testFindNext starts on line 1502).
,
Sep 9 2016
Ya, it fails on line 1469 which in android-cts-5.1_r7 (what we are using)
The test code is as follow:
1445 public void testFindNext() throws Throwable {
1446 if (!NullWebViewUtils.isWebViewAvailable()) {
1447 return;
1448 }
1449 // Reset the scaling so that finding the next "all" text will require scrolling.
1450 mOnUiThread.setInitialScale(100);
1451
1452 DisplayMetrics metrics = mOnUiThread.getDisplayMetrics();
1453 int dimension = Math.max(metrics.widthPixels, metrics.heightPixels);
1454 // create a paragraph high enough to take up the entire screen
1455 String p = "<p style=\"height:" + dimension + "px;\">" +
1456 "Find all instances of a word on the page and highlight them.</p>";
1457
1458 mOnUiThread.loadDataAndWaitForCompletion("<html><body>" + p + p + "</body></html>", "text/html", null);
1459
1460 // highlight all the strings found
1461 mOnUiThread.findAll("all");
1462 getInstrumentation().waitForIdleSync();
1463
1464 int previousScrollY = mOnUiThread.getScrollY();
1465
1466 // Focus "all" in the second page and assert that the view scrolls.
1467 mOnUiThread.findNext(true);
1468 waitForScrollingComplete(previousScrollY);
1469 assertTrue(mOnUiThread.getScrollY() > previousScrollY);
1470 previousScrollY = mOnUiThread.getScrollY();
I have yet to be able to reproduce the bug locally
,
Sep 9 2016
,
Sep 17 2016
A update on this bug:
I tested two version of testFindNext (5.1_r1 and 5.1_r7, difference linked below) and was able to reproduce the bug in both version by running the suite for 10 runs (usually, testFindNext fails from 1-2 times every 10 runs)
What appear to the problem is that the test first `mOnUiThread.findAll("all")` after html is loaded but doesn't actually match any "all" word in the html, and when findNext get's called, it find the first match and doesn't scroll to the next match the screen (screenshot included)
In 5.1_r1, normally onFindResultReceived method in FindListener would get called multiple times before it moves on, e.g.
```
42:33.263 18774 18792 D #YOLAND : called findAll("all"), waiting for findAll to finish
42:33.270 18774 18774 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 1
42:33.275 18774 18774 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 1
42:33.276 18774 18774 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 2
42:33.280 18774 18774 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 2
42:33.280 18774 18774 D #YOLAND-WaitForFindResultsListener: isDoneCounting is true
42:33.280 18774 18792 D #YOLAND : waited for webview find listener
```
But when it fails, FindListener doesn't match anything and gets called with `isDoneCounting` being true.
```
36:09.983 16027 16046 D #YOLAND : called findAll, waiting for findAll to finish
36:09.992 16027 16027 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 0
36:09.992 16027 16027 D #YOLAND-WaitForFindResultsListener: isDoneCounting is true
36:09.993 16027 16046 D #YOLAND : waited for webview find listener
```
I suspect either the html isn't fully loaded when findAll gets called, or the waiting mechanism (waitForIdleSync) doesn't actually wait until findAll finishes 100% of time. I will do a bit more debugging into this part.
Some other behaviours that might be useful to consider and I haven't figure out why:
testFindNext fails only when it was run together with the rest of the suite (not individually), but do not actually have ordering issues (if I don't run the test before testFindNext, I still get the same failure).
PS:
5.1_r1 version of the test uses FindListener to wait for findAll to finish, while 5.1_r7 uses `getInstrumentation().waitForIdleSync()`. The logging above shows 5.1_r1 version of CTS test with FindListener.
android-cts-5.1_r1 uses :https://android.googlesource.com/platform/cts/+/android-cts-5.1_r1/tests/tests/webkit/src/android/webkit/cts/WebViewTest.java#1460
android-cts-5.1_r7: https://android.googlesource.com/platform/cts/+/android-cts-5.1_r7/tests/tests/webkit/src/android/webkit/cts/WebViewTest.java#1462
,
Sep 19 2016
I guess you can modify the cts test to keep calling findAll until the number of matches is what you expect (which is 2). This will make sure that the page is fully loaded and rendered by the time you call findNext.
,
Sep 20 2016
Posted this change: https://android-review.googlesource.com/#/c/276115 Tested locally in all the 30 runs, testFindNext did not fail Will update the cts zip in source bucket once the change has landed
,
Sep 20 2016
,
Sep 23 2016
Updated the CL with help from +hush, ran 100 times with no failure The problem is actually just html not fully loaded sometime before the entile findAll process finishes, and the FindResult will find 0 matches and still think it's over, the fix just set a retry flag in the FutureTask and call findAll again if the match number is 2. Now the log for this part looks like: 09-23 18:40:39.931 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 0, isDone is true 09-23 18:40:39.933 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 0, isDone is true 09-23 18:40:39.937 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 0, isDone is true 09-23 18:40:39.944 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 0, isDone is true 09-23 18:40:39.944 26588 26588 D #YOLAND-WaitForFindResultsListener: retry findAll 09-23 18:40:39.950 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 1, isDone is false 09-23 18:40:39.963 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 1, isDone is false 09-23 18:40:39.967 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 2, isDone is false 09-23 18:40:39.967 26588 26588 D #YOLAND-WaitForFindResultsListener: onFindResultReceived called, activeMatch is 0, numberOfMatches is 2, isDone is true
,
Sep 23 2016
Thanks Yoland for trying very hard to deflake this CTS test!
,
Oct 25 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b669081afa7b30ce3d3d62d351e5d849a7ecbdc7 commit b669081afa7b30ce3d3d62d351e5d849a7ecbdc7 Author: yolandyan <yolandyan@chromium.org> Date: Tue Oct 25 01:41:15 2016 Updated cts zip and resume failed tests BUG= 618089 Review-Url: https://codereview.chromium.org/2444073002 Cr-Commit-Position: refs/heads/master@{#427226} [modify] https://crrev.com/b669081afa7b30ce3d3d62d351e5d849a7ecbdc7/android_webview/tools/cts_config/expected_failure_on_bot.json [modify] https://crrev.com/b669081afa7b30ce3d3d62d351e5d849a7ecbdc7/android_webview/tools/cts_config/webview_cts_gcs_path.json
,
Oct 25 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b669081afa7b30ce3d3d62d351e5d849a7ecbdc7 commit b669081afa7b30ce3d3d62d351e5d849a7ecbdc7 Author: yolandyan <yolandyan@chromium.org> Date: Tue Oct 25 01:41:15 2016 Updated cts zip and resume failed tests BUG= 618089 Review-Url: https://codereview.chromium.org/2444073002 Cr-Commit-Position: refs/heads/master@{#427226} [modify] https://crrev.com/b669081afa7b30ce3d3d62d351e5d849a7ecbdc7/android_webview/tools/cts_config/expected_failure_on_bot.json [modify] https://crrev.com/b669081afa7b30ce3d3d62d351e5d849a7ecbdc7/android_webview/tools/cts_config/webview_cts_gcs_path.json
,
Oct 25 2016
testFindNext is still flaking after this change: https://build.chromium.org/p/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/17179 https://build.chromium.org/p/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/17185 https://build.chromium.org/p/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/17187 https://build.chromium.org/p/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/17190 https://build.chromium.org/p/chromium.android/builders/Android%20WebView%20CTS%20L-MR1%20%28dbg%29/builds/17192 (and several other tests are now failing reliably, see issue 659072 ) I'm going to suppress the tests rather than reverting the CTS update.
,
Oct 25 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b0d46dd0952923c0726d351ebb92989c1a5d2b27 commit b0d46dd0952923c0726d351ebb92989c1a5d2b27 Author: torne <torne@chromium.org> Date: Tue Oct 25 12:09:52 2016 Suppress failing CTS tests. testFindNext is still flaking despite the changes in https://codereview.chromium.org/2444073002 and two tests are now failing consistently. Suppress the failures while we investigate. BUG= 618089 , 659072 TBR=yolandyan@chromium.org Review-Url: https://codereview.chromium.org/2446123002 Cr-Commit-Position: refs/heads/master@{#427325} [modify] https://crrev.com/b0d46dd0952923c0726d351ebb92989c1a5d2b27/android_webview/tools/cts_config/expected_failure_on_bot.json
,
Oct 26 2016
my bad, the CL does fix the issue, but I did not back port the changes to lollipop-cts and marshmallow-cts branches Cherry-picks: https://android-review.googlesource.com/#/c/295109/ https://android-review.googlesource.com/#/c/295108/ https://android-review.googlesource.com/#/c/294594/ https://android-review.googlesource.com/#/c/294591/
,
Nov 23 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/72806afba8fe38d2125beadb98632c0ac2c53212 commit 72806afba8fe38d2125beadb98632c0ac2c53212 Author: yolandyan <yolandyan@chromium.org> Date: Wed Nov 23 01:14:03 2016 Enable testFindNext after cherrypicking CTS changes After this CL: https://android-review.googlesource.com/#/c/294594/ has been merged into lollipop-mr1-cts-dev, testFindNext is now fixed (this time, defintely likely) BUG= 618089 Review-Url: https://codereview.chromium.org/2504143003 Cr-Commit-Position: refs/heads/master@{#434062} [modify] https://crrev.com/72806afba8fe38d2125beadb98632c0ac2c53212/android_webview/tools/cts_config/expected_failure_on_bot.json [modify] https://crrev.com/72806afba8fe38d2125beadb98632c0ac2c53212/android_webview/tools/cts_config/webview_cts_gcs_path.json
,
Nov 28 2016
|
|||||||||
►
Sign in to add a comment |
|||||||||
Comment 1 by boliu@chromium.org
, Jun 8 2016