JavaCronetEngine is flaky in CronetUrlRequestTest#testThrowOrCancelInOnCanceled |
||||
Issue descriptionThis test is flaky when running with JavaCronetEngine. "CronetTestBase.java:143" indicates that this test failed when running with JavaCronetEngine. https://build.chromium.org/p/chromium.android/builders/Android%20Cronet%20Lollipop%20Builder/builds/3962/steps/cronet_test_instrumentation_apk/logs/stdio C 161.534s Main [FAIL] org.chromium.net.CronetUrlRequestTest#testThrowOrCancelInOnCanceled: C 161.534s Main java.lang.Throwable: CronetTestBase#runTest failed. C 161.534s Main at org.chromium.net.CronetTestBase.runTest(CronetTestBase.java:146) C 161.535s Main at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191) C 161.535s Main at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176) C 161.535s Main at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:555) C 161.535s Main at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1853) C 161.535s Main Caused by: junit.framework.AssertionFailedError: expected:<ON_CANCELED> but was:<ON_FAILED> C 161.535s Main at org.chromium.net.CronetUrlRequestTest.testThrowOrCancelInOnCanceled(CronetUrlRequestTest.java:1787) C 161.535s Main at org.chromium.net.CronetTestBase.runTest(CronetTestBase.java:143) C 161.535s Main ... 9 more
,
Nov 14 2016
logcat can be obtained from https://build.chromium.org/p/chromium.android/builders/Android%20Cronet%20Lollipop%20Builder/builds/3962/ Under "gsutil upload " step. I am attaching it here.
,
Nov 15 2016
Can we change the assert to include the exception that caused the request to enter the error state?
,
Nov 15 2016
I will add some more logging.
,
Nov 17 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/7acfe39937220b608b8dc8314c14f0e6604c8021 commit 7acfe39937220b608b8dc8314c14f0e6604c8021 Author: kapishnikov <kapishnikov@chromium.org> Date: Thu Nov 17 16:03:02 2016 Instrument CronetUrlRequestTest#testThrowOrCancelInOnCanceled flaky test Also, add toString method to UrlRequestException. BUG= 664872 Review-Url: https://codereview.chromium.org/2506653003 Cr-Commit-Position: refs/heads/master@{#432884} [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/api/src/org/chromium/net/UrlRequestException.java [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/test/javatests/src/org/chromium/net/BidirectionalStreamTest.java [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/test/javatests/src/org/chromium/net/CronetTestBase.java [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/test/javatests/src/org/chromium/net/CronetUrlRequestContextTest.java [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/test/javatests/src/org/chromium/net/CronetUrlRequestTest.java [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/test/javatests/src/org/chromium/net/TestUrlRequestCallback.java [modify] https://crrev.com/7acfe39937220b608b8dc8314c14f0e6604c8021/components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
,
Dec 14 2016
Example recent failure: https://uberchromegw.corp.google.com/i/chromium.android/builders/Android%20Cronet%20Marshmallow%2064bit%20Perf/builds/3958 I 240.523s run_tests_on_device(00bebe3061e6bdcf) detected failure in org.chromium.net.CronetUrlRequestTest#testThrowOrCancelInOnCanceled. raw output: I 240.523s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS: numtests=1 I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS: stream= I 240.524s run_tests_on_device(00bebe3061e6bdcf) org.chromium.net.CronetUrlRequestTest: I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS: id=InstrumentationTestRunner I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS: test=testThrowOrCancelInOnCanceled I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS: class=org.chromium.net.CronetUrlRequestTest I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS: current=1 I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_STATUS_CODE: 1 I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_RESULT: shortMsg=java.lang.NullPointerException I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_RESULT: longMsg=java.lang.NullPointerException: Attempt to write to field 'com.android.okhttp.okio.Segment com.android.okhttp.okio.Segment.next' on a null object reference I 240.524s run_tests_on_device(00bebe3061e6bdcf) INSTRUMENTATION_CODE: 0
,
Dec 15 2016
Thanks twellington@ for finding a flaky run. I am marking this Untriaged so it is in Cronet triager's queue.
,
Dec 29 2016
This flake was caused by a different reason. Here is the relevant stack trace: 6bdcf: --------- beginning of crash 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: FATAL EXCEPTION: JavaCronetEngine 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: Process: org.chromium.net, PID: 15805 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: java.lang.NullPointerException: Attempt to write to field 'com.android.okhttp.okio.Segment com.android.okhttp.okio.Segment.next' on a null object reference 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.okio.Segment.pop(Segment.java:82) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.okio.Buffer.skip(Buffer.java:780) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.okio.Buffer.clear(Buffer.java:762) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.internal.Util.skipAll(Util.java:177) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.internal.Util.discard(Util.java:158) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.internal.http.HttpConnection$FixedLengthSource.close(HttpConnection.java:435) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.okio.RealBufferedSource.close(RealBufferedSource.java:374) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at com.android.okhttp.okio.RealBufferedSource$1.close(RealBufferedSource.java:362) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at org.chromium.net.impl.InputStreamChannel.close(InputStreamChannel.java:72) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at org.chromium.net.impl.JavaUrlRequest$13.run(JavaUrlRequest.java:924) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at org.chromium.net.impl.JavaUrlRequest$1$1.run(JavaUrlRequest.java:160) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at org.chromium.net.impl.JavaCronetEngine$1$1.run(JavaCronetEngine.java:55) 6bdcf: 12-14 17:03:48.644 15805 15830 E AndroidRuntime: at java.lang.Thread.run(Thread.java:818) 6bdcf: 12-14 17:03:48.647 920 10283 W ActivityManager: Error in app org.chromium.net running instrumentation ComponentInfo{org.chromium.net.tests/android.test.InstrumentationTestRunner}: 6bdcf: 12-14 17:03:48.647 920 10283 W ActivityManager: java.lang.NullPointerException 6bdcf: 12-14 17:03:48.647 920 10283 W ActivityManager: java.lang.NullPointerException: Attempt to write to field 'com.android.okhttp.okio.Segment com.android.okhttp.okio.Segment.next' on a null object reference 6bdcf: 12-14 17:03:48.648 15797 15797 D AndroidRuntime: Shutting down VM It looks like a concurrency issue. Relevant okhttp source: https://android.googlesource.com/platform/external/okhttp/+/6d3859960e52daf10b48b4d0ce45b011fa27f3a7/okio/okio/src/main/java/okio/Segment.java
,
Jan 3 2017
Charles, do you have any ideas on this? Are we careful to only access the OkHttp (system HttlURLConnection impl) stuff from just the executor's thread?
,
Jan 5 2017
I spent some time trying to fix this. Here are my ideas: 1. Break the CANCELLED state in JavaUrlRequest into CANCELLING and CANCELLED. cancel() immediately transitions to CANCELLING, and if we're waiting on the user code (e.g. we're in AWAITING_READ or AWAITING_FOLLOW_REDIRECT) we can immediately transition to CANCELLED (via mState.compareAndSet(State.CANCELLING, State.CANCELLED)), otherwise if transitionState() fails because the state is currently CANCELLING, it can transition to CANCELLED and complete the cancelation (i.e. by calling onCancelled). This got pretty tricky however because of the number of state transitions... 2. Charles had the idea of using a serializing executor. If I'm not mistaken, currently the executor used by JavaUrlRequest is backed by a limitless pool of threads, which means theoretically if two tasks are posted to the executor, they may execute simultaneously. We sequence the tasks with compareAndSets of mState. That's why I thought adding the CANCELLING state was a good idea. Anyhow, we could wrap the executor we're given in one that serializes tasks. 3. What about the really simply solution of just putting synchronized blocks around the three places that access the HttpURLConnection? This has the effect of serializing them.
,
Jan 5 2017
Option 3 is certainly the easiest, but it's not just interactions with HttpUrlConnection we need to synchronize, we also need to guard interactions with the inputstream/outputstream we open from it. One advantage of using a SerializingExecutor vs the lock is that we get better thread utilization - holding a lock while calling read() could block other threads (admittedly, the ones in our unbounded pool) for a long time. SerializingExecutor doesn't have this problem because it'll queue rather than block, and as a bonus we get control over how the queue works - so we can do things like post our call to close() (triggered by cancellation) to the start of the queue, potentially avoiding work done by other operations.
,
Jan 10 2017
,
Jan 12 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/16325c0ba632bc13701728830fe14a873ef8ab53 commit 16325c0ba632bc13701728830fe14a873ef8ab53 Author: pauljensen <pauljensen@chromium.org> Date: Thu Jan 12 18:52:56 2017 [Cronet] In JavaUrlRequest avoid thread-unsafe access to HttpURLConnection Executor passed into JavaUrlRequest is backed by a thread-pool so it can concurrently run tasks which can lead to crashes in underlying HttpURLConnection. Prevent this by serializing taskes passed to underlying Executor. BUG= 664872 CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester Review-Url: https://codereview.chromium.org/2613393002 Cr-Commit-Position: refs/heads/master@{#443307} [modify] https://crrev.com/16325c0ba632bc13701728830fe14a873ef8ab53/components/cronet/android/BUILD.gn [modify] https://crrev.com/16325c0ba632bc13701728830fe14a873ef8ab53/components/cronet/android/java/src/org/chromium/net/impl/JavaUrlRequest.java
,
May 22 2017
|
||||
►
Sign in to add a comment |
||||
Comment 1 by clm@google.com
, Nov 14 2016