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

Issue 618089 link

Starred by 4 users

Issue metadata

Status: Fixed
Owner:
not available
Closed: Nov 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Bug

Blocking:
issue 617655



Sign in to add a comment

CTS WebViewTest#testFindNext is flaky

Project Member Reported by boliu@chromium.org, Jun 7 2016

Issue description

https://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@@@@
 

Comment 1 by boliu@chromium.org, Jun 8 2016

Cc: jbudorick@chromium.org mikec...@chromium.org boliu@chromium.org hush@chromium.org
 Issue 618322  has been merged into this issue.

Comment 2 by hanxi@chromium.org, 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?

Comment 3 by boliu@chromium.org, Jun 10 2016

low priority, it's probably a bug in the test, and making changes to cts is... kinda hard

Comment 4 by sgu...@chromium.org, Jun 10 2016

Owner: yolandyan@chromium.org
Yoland, can you disable this test?

Comment 5 by sgu...@chromium.org, Jun 10 2016

Blocking: 617655

Comment 7 by sgu...@chromium.org, 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.
Project Member

Comment 8 by bugdroid1@chromium.org, 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

Comment 9 by hush@chromium.org, 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.
Project Member

Comment 10 by bugdroid1@chromium.org, 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

Status: Assigned (was: Untriaged)
Yoland, is there anything left to do here? If not, feel free to mark it as fixed.
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?
Currently looking into it
Project Member

Comment 14 by bugdroid1@chromium.org, Jun 29 2016

Status: Started (was: Assigned)
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
maybe it is related to the test that is running immediately before it, some test not leaving a clean state.
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? :)

Comment 18 by hush@chromium.org, Jun 30 2016

That'll be great!
Screenshot on failure is a commandline option you can pass to cts-tradefed, FWIW.
improving sgtm 
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
send me a CL for ownership
Project Member

Comment 22 by bugdroid1@chromium.org, 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

Project Member

Comment 23 by bugdroid1@chromium.org, 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

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).
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
Cc: sgu...@chromium.org
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
success.png
36.2 KB View Download
failed.png
35.7 KB View Download

Comment 28 by hush@chromium.org, 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.
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
Labels: -Pri-3 Pri-2
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

Comment 32 by hush@chromium.org, Sep 23 2016

Thanks Yoland for trying very hard to deflake this CTS test!
Project Member

Comment 36 by bugdroid1@chromium.org, 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

Cc: -hush@chromium.org
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/
Project Member

Comment 38 by bugdroid1@chromium.org, 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

Status: Fixed (was: Started)

Sign in to add a comment