GN(Android): Fix CleanupReferenceTest#testCreateMany failing.

GN(Android): Fix CleanupReferenceTest#testCreateMany failing.

For some reason, it consistently fails without this change, and
consistently passes with it.

BUG=510485
Committed: https://crrev.com/ea9f7be13f4451e66bddfa20b29adb78044a0035
Cr-Commit-Position: refs/heads/master@{#358366}

[agrieve, 2015-11-04 02:54:55]

agrieve@chromium.org changed reviewers:
+ pkotwicz@chromium.org, yfriedman@chromium.org

[agrieve, 2015-11-04 02:54:55]

☀

[Yaron, 2015-11-04 03:01:02]

yfriedman@chromium.org changed reviewers:
+ boliu@chromium.org

[Yaron, 2015-11-04 03:01:03]

+bo

[boliu, 2015-11-04 03:09:02]

On 2015/11/04 03:01:03, Yaron wrote:
> +bo

That... makes no sense to me. Can I try what you are doing and see why that
makes a difference?

The webview counterpart to this test calls gc in each of the polling loop
though, to reduce flake (but there, the object graph is a lot more complicated).
Does that help?

[boliu, 2015-11-04 03:18:56]

On 2015/11/04 03:09:02, boliu wrote:
> On 2015/11/04 03:01:03, Yaron wrote:
> > +bo
> 
> That... makes no sense to me. Can I try what you are doing and see why that
> makes a difference?
> 
> The webview counterpart to this test calls gc in each of the polling loop
> though, to reduce flake (but there, the object graph is a lot more
complicated).
> Does that help?

Also webview calls Runtime.getRuntime().gc(); isntead of System.gc(); Not sure
if that makes a difference too.

Webview tests here:
https://code.google.com/p/chromium/codesearch#chromium/src/android_webview/ja...

[agrieve, 2015-11-04 16:23:34]

On 2015/11/04 03:18:56, boliu wrote:
> On 2015/11/04 03:09:02, boliu wrote:
> > On 2015/11/04 03:01:03, Yaron wrote:
> > > +bo
> > 
> > That... makes no sense to me. Can I try what you are doing and see why that
> > makes a difference?
> > 
> > The webview counterpart to this test calls gc in each of the polling loop
> > though, to reduce flake (but there, the object graph is a lot more
> complicated).
> > Does that help?
> 
> Also webview calls Runtime.getRuntime().gc(); isntead of System.gc(); Not sure
> if that makes a difference too.
> 
> Webview tests here:
>
https://code.google.com/p/chromium/codesearch#chromium/src/android_webview/ja...

Tried it with Runtime.getRuntime().gc(), but same thing. Tried putting the GC
within isSatisfied(), but no change (value stays at 20).

Agree this is completely random and only found it by trying to log out the value
of sObjectCount :S

Happens in both static & component builds with either gcc or clang.

If you want to have a go at it, that would be great! Here's how I'm testing it:

gn gen --args='target_os="android"' out-gn/Debug
ninja -C out-gn/Debug -j1000 content_shell_test_apk
out-gn/Debug/bin/run_content_shell_test_apk --test-filter
'*CleanupReferenceTest#testCreateMany*'

[boliu, 2015-11-04 19:54:08]

It's really the whims of the jvm I think..

I checked hprof dump. The only reference to ReferredObject is CleanupReference
which itself is a WeakReference and should not prevent gc. Also checked that UI
is lively since the destroy callback is posted to UI thread.

Then I noticed that in fact, there are *zero* gc-events happening, since there
are no logs like this for the duration of the test:

11-04 11:25:55.181 14201 14219 I art     : Explicit concurrent mark sweep GC
freed 1126(60KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 16MB/27MB,
paused 1.148ms total 53.185ms
11-04 11:25:55.209 14201 14219 I art     : Explicit concurrent mark sweep GC
freed 5(160B) AllocSpace objects, 0(0B) LOS objects, 40% free, 16MB/27MB, paused
1.811ms total 23.181ms

And a manully triggered gc from ddms will unblock the test.

The minimum set of changes I found to get this passing, on a 5.1 nexus 5:
* Runtime.getRuntime().gc() instead of System.gc()
* Call gc in each iteration of poll loop
* Slow poll interval to 1s (default is 50ms)

And probably for good measure, increase the poll timeout and make this a medium
or large test.

Are these safer/saner changes than the current one? I dunno.

Pure speculation now:
I suspect slowing the poll loop is important for the jvm to think "oh it's idle
now, so it's safe to do a gc". Also I noticed content shell is not actually in
the foreground (gn or gyp), and I don't know if jvm will gc more aggressively
while in foreground.

I don't have any guesses why this is gn only :/

And one more unrelated point: Is this test thread safe? Creating
CleanupReference on non-UI thread (webview never does that). But then
CleanupReference *seems* to handle this correctly.

[agrieve, 2015-11-06 14:55:17]

On 2015/11/04 19:54:08, boliu wrote:
> It's really the whims of the jvm I think..
> 
> I checked hprof dump. The only reference to ReferredObject is CleanupReference
> which itself is a WeakReference and should not prevent gc. Also checked that
UI
> is lively since the destroy callback is posted to UI thread.
> 
> Then I noticed that in fact, there are *zero* gc-events happening, since there
> are no logs like this for the duration of the test:
> 
> 11-04 11:25:55.181 14201 14219 I art     : Explicit concurrent mark sweep GC
> freed 1126(60KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 16MB/27MB,
> paused 1.148ms total 53.185ms
> 11-04 11:25:55.209 14201 14219 I art     : Explicit concurrent mark sweep GC
> freed 5(160B) AllocSpace objects, 0(0B) LOS objects, 40% free, 16MB/27MB,
paused
> 1.811ms total 23.181ms
> 
> And a manully triggered gc from ddms will unblock the test.
> 
> The minimum set of changes I found to get this passing, on a 5.1 nexus 5:
> * Runtime.getRuntime().gc() instead of System.gc()
> * Call gc in each iteration of poll loop
> * Slow poll interval to 1s (default is 50ms)
> 
> And probably for good measure, increase the poll timeout and make this a
medium
> or large test.
> 
> Are these safer/saner changes than the current one? I dunno.
> 
> Pure speculation now:
> I suspect slowing the poll loop is important for the jvm to think "oh it's
idle
> now, so it's safe to do a gc". Also I noticed content shell is not actually in
> the foreground (gn or gyp), and I don't know if jvm will gc more aggressively
> while in foreground.
> 
> I don't have any guesses why this is gn only :/
> 
> And one more unrelated point: Is this test thread safe? Creating
> CleanupReference on non-UI thread (webview never does that). But then
> CleanupReference *seems* to handle this correctly.

Sounds like maybe the only "correct" fix would be to have the test message to
the test runner asking it to trigger a GC via ddms...

For now though, looks like changes that we make are mostly just random, so let's
either go ahead with this one-liner, or disable the test. WDYT?

[boliu, 2015-11-06 16:58:00]

On 2015/11/06 14:55:17, agrieve wrote:
> On 2015/11/04 19:54:08, boliu wrote:
> > It's really the whims of the jvm I think..
> > 
> > I checked hprof dump. The only reference to ReferredObject is
CleanupReference
> > which itself is a WeakReference and should not prevent gc. Also checked that
> UI
> > is lively since the destroy callback is posted to UI thread.
> > 
> > Then I noticed that in fact, there are *zero* gc-events happening, since
there
> > are no logs like this for the duration of the test:
> > 
> > 11-04 11:25:55.181 14201 14219 I art     : Explicit concurrent mark sweep GC
> > freed 1126(60KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 16MB/27MB,
> > paused 1.148ms total 53.185ms
> > 11-04 11:25:55.209 14201 14219 I art     : Explicit concurrent mark sweep GC
> > freed 5(160B) AllocSpace objects, 0(0B) LOS objects, 40% free, 16MB/27MB,
> paused
> > 1.811ms total 23.181ms
> > 
> > And a manully triggered gc from ddms will unblock the test.
> > 
> > The minimum set of changes I found to get this passing, on a 5.1 nexus 5:
> > * Runtime.getRuntime().gc() instead of System.gc()
> > * Call gc in each iteration of poll loop
> > * Slow poll interval to 1s (default is 50ms)
> > 
> > And probably for good measure, increase the poll timeout and make this a
> medium
> > or large test.
> > 
> > Are these safer/saner changes than the current one? I dunno.
> > 
> > Pure speculation now:
> > I suspect slowing the poll loop is important for the jvm to think "oh it's
> idle
> > now, so it's safe to do a gc". Also I noticed content shell is not actually
in
> > the foreground (gn or gyp), and I don't know if jvm will gc more
aggressively
> > while in foreground.
> > 
> > I don't have any guesses why this is gn only :/
> > 
> > And one more unrelated point: Is this test thread safe? Creating
> > CleanupReference on non-UI thread (webview never does that). But then
> > CleanupReference *seems* to handle this correctly.
> 
> Sounds like maybe the only "correct" fix would be to have the test message to
> the test runner asking it to trigger a GC via ddms...

Which apparently just calls Runtime.getRuntime().gc():
http://stackoverflow.com/questions/25396276/how-can-i-invoke-gc-using-adb-tools.
(I checked that the handleHPGC part still holds in M)

> 
> For now though, looks like changes that we make are mostly just random, so
let's
> either go ahead with this one-liner, or disable the test. WDYT?

I'm not owner here. But at minimum need a giant comment explaining all this?

[Yaron, 2015-11-06 17:17:37]

lgtm 

I suppose this is fine for now. In practice, I'd prefer it if we didn't use
CleanupReference in chrome and moved it to Android (crbug/507405). There's only
one usage and it's not necessary.

[agrieve, 2015-11-06 18:31:01]

On 2015/11/06 17:17:37, Yaron wrote:
> lgtm 
> 
> I suppose this is fine for now. In practice, I'd prefer it if we didn't use
> CleanupReference in chrome and moved it to Android (crbug/507405). There's
only
> one usage and it's not necessary.

Going to submit with the comment as-is, as I think it's pretty wtf as-is :P.

[agrieve, 2015-11-06 18:31:44]

The CQ bit was checked by agrieve@chromium.org

[commit-bot: I haz the power, 2015-11-06 18:33:36]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1423713013/1
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1423713013/1

[commit-bot: I haz the power, 2015-11-06 19:00:06]

Committed patchset #1 (id:1)

[commit-bot: I haz the power, 2015-11-06 19:01:10]

Patchset 1 (id:??) landed as
https://crrev.com/ea9f7be13f4451e66bddfa20b29adb78044a0035
Cr-Commit-Position: refs/heads/master@{#358366}