[Cronet] Fix two races/leaks in JavaUrlRequest

[Cronet]  Fix two races/leaks in JavaUrlRequest

The underlying InputStream and HttpURLConnection were accessed on different
threads which during cancellation could result in races resulting in leaks
that StrictMode catches. Shift all accesses to these variables to one
thread like the Chromium threading principles recommends.

BUG=726193
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester

Review-Url: https://codereview.chromium.org/2903193002
Cr-Commit-Position: refs/heads/master@{#475945}
Committed: https://chromium.googlesource.com/chromium/src/+/8f8aa43973e496a65d9eecfa3e6f8b8dd68432e7

[pauljensen, 2017-05-25 01:25:26]

Description was changed from

==========
[Cronet] Test for race/leak in JavaUrlRequest
==========

to

==========
[Cronet] Test for race/leak in JavaUrlRequest
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester
==========

[pauljensen, 2017-05-25 02:17:09]

Description was changed from

==========
[Cronet] Test for race/leak in JavaUrlRequest
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester
==========

to

==========
[Cronet] Test and fixes for race/leaks in JavaUrlRequest

BUG=726193
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester
==========

[pauljensen, 2017-05-26 02:30:39]

Description was changed from

==========
[Cronet] Test and fixes for race/leaks in JavaUrlRequest

BUG=726193
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester
==========

to

==========
[Cronet]  Fix two races/leaks in JavaUrlRequest

The underlying InputStream and HttpURLConnection were accessed on different
threads which during cancellation could result in races resulting in leaks
that StrictMode catches. Shift all accesses to these variables to one
thread like the Chromium threading principles recommends.

BUG=726193
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester
==========

[pauljensen, 2017-05-26 02:30:39]

pauljensen@chromium.org changed reviewers:
+ clm@google.com

[pauljensen, 2017-05-26 02:44:55]

Charles, PTAL, thank you!

[Charles, 2017-05-26 13:58:48]

https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
File
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
(right):

https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:239:
* StrictMode enforcement it offers.
Should we add that same strictmode checking to CronetTestBase?

https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:252:
}
Shouldn't you block on all these operations completing before letting the test
finish?

[pauljensen, 2017-05-26 18:36:04]

https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
File
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
(right):

https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:239:
* StrictMode enforcement it offers.
On 2017/05/26 13:58:48, Charles wrote:
> Should we add that same strictmode checking to CronetTestBase?

Done.

https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:252:
}
On 2017/05/26 13:58:48, Charles wrote:
> Shouldn't you block on all these operations completing before letting the test
> finish?

If I block until each UrlRequest is done before starting the next then I never
catch the leak.  If I start them all and then wait for them all to finish, I
only catch the leak ~10% of the time.  In its current form I catch the leak ~70%
of the time.

I think the leak requires a lot of busy threads so that the cancel() happens
before the UrlRequest has made much progress (and set mCurrentUrlConnection and
mResponseChannel).  So this explains why the waiting for each one doesn't catch
the leak.

The other quirk of this is that from teardown() we call
JavaCronetEngine.shutdown() which calls ExecutorService.shutdown() which doesn't
wait for the thread to finish running tasks, and then we call GC looking for
leaks.  We could expose the ExecutorService and then have tests call
awaitTermination() but I think the simple test in its current form is probably
good enough.

[Charles, 2017-05-26 18:49:48]

On 2017/05/26 18:36:04, pauljensen wrote:
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> File
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
> (right):
> 
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:239:
> * StrictMode enforcement it offers.
> On 2017/05/26 13:58:48, Charles wrote:
> > Should we add that same strictmode checking to CronetTestBase?
> 
> Done.
> 
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:252:
> }
> On 2017/05/26 13:58:48, Charles wrote:
> > Shouldn't you block on all these operations completing before letting the
test
> > finish?
> 
> If I block until each UrlRequest is done before starting the next then I never
> catch the leak.  If I start them all and then wait for them all to finish, I
> only catch the leak ~10% of the time.  In its current form I catch the leak
~70%
> of the time.
> 
> I think the leak requires a lot of busy threads so that the cancel() happens
> before the UrlRequest has made much progress (and set mCurrentUrlConnection
and
> mResponseChannel).  So this explains why the waiting for each one doesn't
catch
> the leak.
> 
> The other quirk of this is that from teardown() we call
> JavaCronetEngine.shutdown() which calls ExecutorService.shutdown() which
doesn't
> wait for the thread to finish running tasks, and then we call GC looking for
> leaks.  We could expose the ExecutorService and then have tests call
> awaitTermination() but I think the simple test in its current form is probably
> good enough.

This explanation should be a comment in the code.

[pauljensen, 2017-05-30 13:07:13]

On 2017/05/26 18:49:48, Charles wrote:
> On 2017/05/26 18:36:04, pauljensen wrote:
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > File
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
> > (right):
> > 
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:239:
> > * StrictMode enforcement it offers.
> > On 2017/05/26 13:58:48, Charles wrote:
> > > Should we add that same strictmode checking to CronetTestBase?
> > 
> > Done.
> > 
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:252:
> > }
> > On 2017/05/26 13:58:48, Charles wrote:
> > > Shouldn't you block on all these operations completing before letting the
> test
> > > finish?
> > 
> > If I block until each UrlRequest is done before starting the next then I
never
> > catch the leak.  If I start them all and then wait for them all to finish, I
> > only catch the leak ~10% of the time.  In its current form I catch the leak
> ~70%
> > of the time.
> > 
> > I think the leak requires a lot of busy threads so that the cancel() happens
> > before the UrlRequest has made much progress (and set mCurrentUrlConnection
> and
> > mResponseChannel).  So this explains why the waiting for each one doesn't
> catch
> > the leak.
> > 
> > The other quirk of this is that from teardown() we call
> > JavaCronetEngine.shutdown() which calls ExecutorService.shutdown() which
> doesn't
> > wait for the thread to finish running tasks, and then we call GC looking for
> > leaks.  We could expose the ExecutorService and then have tests call
> > awaitTermination() but I think the simple test in its current form is
probably
> > good enough.
> 
> This explanation should be a comment in the code.

Done.

[Charles, 2017-05-30 22:37:34]

On 2017/05/30 13:07:13, pauljensen wrote:
> On 2017/05/26 18:49:48, Charles wrote:
> > On 2017/05/26 18:36:04, pauljensen wrote:
> > >
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > > File
> > >
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
> > > (right):
> > > 
> > >
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > >
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:239:
> > > * StrictMode enforcement it offers.
> > > On 2017/05/26 13:58:48, Charles wrote:
> > > > Should we add that same strictmode checking to CronetTestBase?
> > > 
> > > Done.
> > > 
> > >
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > >
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:252:
> > > }
> > > On 2017/05/26 13:58:48, Charles wrote:
> > > > Shouldn't you block on all these operations completing before letting
the
> > test
> > > > finish?
> > > 
> > > If I block until each UrlRequest is done before starting the next then I
> never
> > > catch the leak.  If I start them all and then wait for them all to finish,
I
> > > only catch the leak ~10% of the time.  In its current form I catch the
leak
> > ~70%
> > > of the time.
> > > 
> > > I think the leak requires a lot of busy threads so that the cancel()
happens
> > > before the UrlRequest has made much progress (and set
mCurrentUrlConnection
> > and
> > > mResponseChannel).  So this explains why the waiting for each one doesn't
> > catch
> > > the leak.
> > > 
> > > The other quirk of this is that from teardown() we call
> > > JavaCronetEngine.shutdown() which calls ExecutorService.shutdown() which
> > doesn't
> > > wait for the thread to finish running tasks, and then we call GC looking
for
> > > leaks.  We could expose the ExecutorService and then have tests call
> > > awaitTermination() but I think the simple test in its current form is
> probably
> > > good enough.
> > 
> > This explanation should be a comment in the code.
> 
> Done.

Sounds like the leak is related to the RejectedExecutionException handling then.
Might be worth adding shutdown specifically into the test, rather than relying
on teardown to always do it for you.

[Charles, 2017-05-30 22:37:44]

lgtm

[pauljensen, 2017-05-31 13:25:57]

The CQ bit was checked by pauljensen@chromium.org

[pauljensen, 2017-05-31 13:25:57]

The patchset sent to the CQ was uploaded after l-g-t-m from clm@google.com
Link to the patchset: https://codereview.chromium.org/2903193002/#ps120001
(title: "whoops, put back JavaUrlRequest.java")

[commit-bot: I haz the power, 2017-05-31 13:26:08]

CQ is trying da patch.

Follow status at:
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-05-31 13:26:09]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-05-31 13:26:10]

No L-G-T-M from a valid reviewer yet.
CQ run can only be started once the patch has received an L-G-T-M from a full
committer.
Even if an L-G-T-M may have been provided, it was from a non-committer,_not_ a
full super star committer.
Committers are members of the group "project-chromium-committers".
Note that this has nothing to do with OWNERS files.

[pauljensen, 2017-05-31 15:09:12]

pauljensen@chromium.org changed reviewers:
+ mef@chromium.org

[pauljensen, 2017-05-31 15:09:12]

Misha, PTAL, thank you!

[pauljensen, 2017-05-31 15:11:00]

On 2017/05/30 22:37:34, Charles wrote:
> On 2017/05/30 13:07:13, pauljensen wrote:
> > On 2017/05/26 18:49:48, Charles wrote:
> > > On 2017/05/26 18:36:04, pauljensen wrote:
> > > >
> > >
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > > > File
> > > >
> > >
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java
> > > > (right):
> > > > 
> > > >
> > >
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > > >
> > >
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:239:
> > > > * StrictMode enforcement it offers.
> > > > On 2017/05/26 13:58:48, Charles wrote:
> > > > > Should we add that same strictmode checking to CronetTestBase?
> > > > 
> > > > Done.
> > > > 
> > > >
> > >
> >
>
https://codereview.chromium.org/2903193002/diff/40001/components/cronet/andro...
> > > >
> > >
> >
>
components/cronet/android/test/javatests/src/org/chromium/net/UploadDataProvidersTest.java:252:
> > > > }
> > > > On 2017/05/26 13:58:48, Charles wrote:
> > > > > Shouldn't you block on all these operations completing before letting
> the
> > > test
> > > > > finish?
> > > > 
> > > > If I block until each UrlRequest is done before starting the next then I
> > never
> > > > catch the leak.  If I start them all and then wait for them all to
finish,
> I
> > > > only catch the leak ~10% of the time.  In its current form I catch the
> leak
> > > ~70%
> > > > of the time.
> > > > 
> > > > I think the leak requires a lot of busy threads so that the cancel()
> happens
> > > > before the UrlRequest has made much progress (and set
> mCurrentUrlConnection
> > > and
> > > > mResponseChannel).  So this explains why the waiting for each one
doesn't
> > > catch
> > > > the leak.
> > > > 
> > > > The other quirk of this is that from teardown() we call
> > > > JavaCronetEngine.shutdown() which calls ExecutorService.shutdown() which
> > > doesn't
> > > > wait for the thread to finish running tasks, and then we call GC looking
> for
> > > > leaks.  We could expose the ExecutorService and then have tests call
> > > > awaitTermination() but I think the simple test in its current form is
> > probably
> > > > good enough.
> > > 
> > > This explanation should be a comment in the code.
> > 
> > Done.
> 
> Sounds like the leak is related to the RejectedExecutionException handling
then.
> Might be worth adding shutdown specifically into the test, rather than relying
> on teardown to always do it for you.

The leaks are not particularly related to the shutdown behavior, they're caused
by two races which I listed in the bug crbug.com/726193

[mef, 2017-05-31 15:38:25]

lgtm

[pauljensen, 2017-05-31 15:39:03]

The CQ bit was checked by pauljensen@chromium.org

[commit-bot: I haz the power, 2017-05-31 15:39:36]

CQ is trying da patch.

Follow status at:
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-05-31 16:49:41]

CQ is committing da patch.

Bot data: {"patchset_id": 120001, "attempt_start_ts": 1496245143823360,
"parent_rev": "21edbfa38a6aac6c2f3dd7b024414725ad2afdbb", "commit_rev":
"8f8aa43973e496a65d9eecfa3e6f8b8dd68432e7"}

[commit-bot: I haz the power, 2017-05-31 16:49:51]

Description was changed from

==========
[Cronet]  Fix two races/leaks in JavaUrlRequest

The underlying InputStream and HttpURLConnection were accessed on different
threads which during cancellation could result in races resulting in leaks
that StrictMode catches. Shift all accesses to these variables to one
thread like the Chromium threading principles recommends.

BUG=726193
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester
==========

to

==========
[Cronet]  Fix two races/leaks in JavaUrlRequest

The underlying InputStream and HttpURLConnection were accessed on different
threads which during cancellation could result in races resulting in leaks
that StrictMode catches. Shift all accesses to these variables to one
thread like the Chromium threading principles recommends.

BUG=726193
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.android:android_cronet_tester

Review-Url: https://codereview.chromium.org/2903193002
Cr-Commit-Position: refs/heads/master@{#475945}
Committed:
https://chromium.googlesource.com/chromium/src/+/8f8aa43973e496a65d9eecfa3e6f...
==========

[commit-bot: I haz the power, 2017-05-31 16:49:54]

Committed patchset #7 (id:120001) as
https://chromium.googlesource.com/chromium/src/+/8f8aa43973e496a65d9eecfa3e6f...

[Peter Wen, 2017-05-31 19:08:49]

On 2017/05/31 16:49:54, commit-bot: I haz the power wrote:
> Committed patchset #7 (id:120001) as
>
https://chromium.googlesource.com/chromium/src/+/8f8aa43973e496a65d9eecfa3e6f...

Hmm... I get a NPE on StrictMode.setVmPolicy(mOldVmPolicy):
https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Ftryserver.chromium.andro...

[Peter Wen, 2017-05-31 19:09:14]

On 2017/05/31 19:08:49, Peter Wen wrote:
> On 2017/05/31 16:49:54, commit-bot: I haz the power wrote:
> > Committed patchset #7 (id:120001) as
> >
>
https://chromium.googlesource.com/chromium/src/+/8f8aa43973e496a65d9eecfa3e6f...
> 
> Hmm... I get a NPE on StrictMode.setVmPolicy(mOldVmPolicy):
>
https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Ftryserver.chromium.andro...

Detailed logs:

C   40.208s Main  [FAIL]
org.chromium.net.CronetTestBaseTest#testRunOnlyNativeMustRun:
C   40.208s Main  java.lang.NullPointerException: Attempt to read from field
'int android.os.StrictMode$VmPolicy.mask' on a null object reference
C   40.208s Main        at
android.os.StrictMode.setVmPolicy(StrictMode.java:1622)
C   40.209s Main        at
org.chromium.net.CronetTestBase.tearDown(CronetTestBase.java:100)
C   40.209s Main        at
org.chromium.net.CronetTestBaseTest.tearDown(CronetTestBaseTest.java:39)
C   40.209s Main        at
android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
C   40.209s Main        at
android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
C   40.209s Main        at
android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:555)
C   40.209s Main        at
android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1879)

[pauljensen, 2017-05-31 19:13:23]

I've been trying to land a fix for that for hours but the CQ is broken:
https://codereview.chromium.org/2920503002/