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

Issue 643771 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Last visit > 30 days ago
Closed: Sep 2016
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 1
Type: Bug



Sign in to add a comment

CronetUrlRequestTest#testUnexpectedReads flake

Project Member Reported by xunji...@chromium.org, Sep 2 2016

Issue description

The JavaCronetEngine impl fails this CronetUrlRequestTest#testUnexpectedReads in https://build.chromium.org/p/chromium.android/builders/Android%20Cronet%20Lollipop%20Builder/builds/1151/steps/cronet_test_instrumentation_apk/logs/stdio

4b057:  09-02 18:49:15.111 15413 15431 I TestRunner: failed: testUnexpectedReads(org.chromium.net.CronetUrlRequestTest)
4b057:  09-02 18:49:15.111 15413 15431 I TestRunner: ----- begin exception -----
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: java.lang.Throwable: CronetTestBase#runTest failed.
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at org.chromium.net.CronetTestBase.runTest(CronetTestBase.java:147)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.TestCase.runBare(TestCase.java:134)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.TestResult$1.protect(TestResult.java:115)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.TestResult.runProtected(TestResult.java:133)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.TestResult.run(TestResult.java:118)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.TestCase.run(TestCase.java:124)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:555)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1853)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: Caused by: junit.framework.ComparisonFailure: expected:<[this is a text file
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: ]> but was:<[]>
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.Assert.assertEquals(Assert.java:85)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.Assert.assertEquals(Assert.java:91)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at org.chromium.net.CronetUrlRequestTest.testUnexpectedReads(CronetUrlRequestTest.java:928)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at java.lang.reflect.Method.invoke(Native Method)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at java.lang.reflect.Method.invoke(Method.java:372)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at junit.framework.TestCase.runTest(TestCase.java:168)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	at org.chromium.net.CronetTestBase.runTest(CronetTestBase.java:144)
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: 	... 9 more
4b057:  09-02 18:49:15.112 15413 15431 I TestRunner: ----- end exception -----

Likely due to https://codereview.chromium.org/2283243002/. Though not sure if this is a bad test expectation that is surfaced by the CL. Investigating..

 

Comment 1 by mef@chromium.org, Sep 2 2016

I also wonder whether this could be specific to Java or Native CronetEngine.
See the call stack -- It is from JavaCronetEngine.

Comment 3 by clm@google.com, Sep 2 2016

I think this code:

// Verify reading right after start throws an assertion. Both must be
      // invoked on the Executor thread, to prevent receiving data
until after        // startNextRead has been invoked.is racy, because
of changed error handling in JavaUrlRequest. It's trying to assert
that a call to read() before onResponseStarted results in an illegal
state exception, but it's relying on how the underlying executor's
ordering works to create that condition. I did this to capture
RejectedExcecutionException. I think it's fair game to call read() as
soon as we've submitted tasks to your executor, but I could also
change the error handling to make this throw the way it used to.
I don't quite understand the flake. I can reproduce it once if I repeatedly run the test for 50 times (--repeat=50).

We did reach ResponseStep.ON_SUCCEEDED, it's just the mResponseAsString is not populated. If the executor thread is single threaded, why is mResponseAsString not populated?

I am sheriff on duty. If this is easy to fix on your end, please feel free to take the bug.

Comment 5 by clm@google.com, Sep 2 2016

The failure is that one of the reads that's supposed to fail is succeeding.
This is masked by the fact that the assertions currently in the test are
not actually causing the test to fail if they fail, since they're failing
on a thread pool and not being propagated back to the test.
Cc: -clm@google.com
Owner: clm@google.com
Ah, I see. Misha can correct me -- I think we want to keep the behavior where read() can only be invoked after onResponseStarted().  Could you update the implementation? thanks!
Status: Fixed (was: Assigned)

Sign in to add a comment