1068268 - B2G M9 shutdown leaks involving APZC

Status: RESOLVED FIXED

(Core :: Panning and Zooming, defect)

Description

[Andrew McCreight [:mccr8]]

For some reason, we leak more in M9 than in other tests.  This is a regression in the last month or something, because we silently stopped reporting shutdown leaks.  The additional leaks are something like 6 AsyncPanZoomController, 2 CompositorParent, 6 CondVar, 2 CrossProcessMutex, 1 GeckoContentController, 2 GestureEventListener, 6 Mutex, 1 PCompositorParent, 3 ReentrantMonitor, 1 RefCountedMonitor, 2 RefCountedTask, 4 SharedMemory, 1 WeakReference<MessageListener>, 4 ZoomConstraints, 1 ipc::MessageChannel, 14 nsTArray_base.  About 11kb in total, which isn't huge, but this gets in the way of letting us catch failures to create leak logs and other things.

Comment 1

[Kartikaya Gupta (email:[e-mail])]

I'm doing a local emulator build to see if I can reproduce this locally.

Comment 2

[Kartikaya Gupta (email:[e-mail])]

First attempt at running the M-9 locally failed. I'll have to dig through a bunch of harness code to figure out what's going on.

Comment 3

[Andrew McCreight [:mccr8]]

You'll need the patches in bug 962871 for it to produce a leak log at all.

Comment 4

[Kartikaya Gupta (email:[e-mail])]

After another attempt I was able to successfully run the M9 chunk on b2g-emulator. I think the port it was trying to use was just busy before. I'll apply the patches from bug 962871 and see if I can repro the leak. In the run I just did there was "no output line for total leaks!"

Comment 5

[Kartikaya Gupta (email:[e-mail])]

Ok, so I updated gecko to git sha eff47d926 which is just after the first landing of part 3 in bug 962871 and it's still not producing a leak log. The only leak-related stuff output is this:

TEST-INFO | leakcheck | threshold set at 5116 bytes

WARNING | leakcheck | missing output line for total leaks!

Any ideas?

Comment 6

[Andrew McCreight [:mccr8]]

Hmm.  Well, my current theory is that the bug just made us stop timing out somehow, so if your machine is running things more slowly then you'll hit the timeout anyways.  You could try running smaller chunks and see if that gets you a leak log.  So, instead of running chunk 9 of 16, run 18 and 19 of 32, or whatever.

Comment 7

[Kartikaya Gupta (email:[e-mail])]

I went all the way down to 120 chunks and still nothing.

Comment 8

[Andrew McCreight [:mccr8]]

It still had "WARNING | leakcheck | missing output line for total leaks!"?  Odd.

Comment 9

[Andrew McCreight [:mccr8]]

Do you have any ideas, Kyle?

Comment 10

[Kartikaya Gupta (email:[e-mail])]

(In reply to Andrew McCreight [:mccr8] from comment #8)
> It still had "WARNING | leakcheck | missing output line for total leaks!"? 
> Odd.

Yeah. I added some more logging in harness, it seems to call processSingleLeakFile on a file in /tmp but I can't find that file afterwards. I'm not really sure what the race condition you're referring to, but I'm assuming that file is still being written to when the harness runs? And then it gets deleted before I get around to looking for it?

Comment 11

[Kartikaya Gupta (email:[e-mail])]

Even if I change [1] to pass an argument of delete=False so the file doesn't get deleted, it remains empty throughout. Do you know where the leakcheck output comes from? Can I just have it print to logcat instead of a file?

[1] http://mxr.mozilla.org/mozilla-central/source/testing/mochitest/runtestsb2g.py?rev=1db4be77a409#201

Comment 12

[Andrew McCreight [:mccr8]]

If the log is always empty, maybe the process is dying before the log gets written to?  If you still want to try to get it to log somewhere else, the code lives in nsTraceRefcnt::DumpStatistics().

Comment 13

[Kartikaya Gupta (email:[e-mail])]

Is there anything I need in a mozconfig or userconfig to enable this? I tried making it log to logcat but I'm not seeing anything at all.

Comment 14

[Andrew McCreight [:mccr8]]

Yeah, that suggests we're just not getting to the place that does the logging.

I've never run B2G emulator mochitests myself, but it should just set up all of the environment variables for leak checking, assuming you have a debug build.

Comment 15

[Andrew McCreight [:mccr8]]

Oh another thing, are you using emulator or emulator-jb?  The former is what is leaking on TBPL.  I have no idea what the difference is, and I'm not sure why I thought you were using the latter, but maybe that's something else to try.

Comment 16

[Kartikaya Gupta (email:[e-mail])]

I had to modify the gonk-misc/default-gecko-config to add --enable-logrefcnt. Not sure how that happens on buildbot but it doesn't happen by default in emulator builds. Now I'm getting leakcheck output, will try to isolate the right leaks.

Comment 17

[Kartikaya Gupta (email:[e-mail])]

For the record, I'm running ./mach mochitest-remote --this-chunk 9 --total-chunks 15 because those are the chunk numbers it indicates in the inbound logs I saw. However the set of tests that actually gets run for me is much larger than the tests that get run on buildbot.

For example at [1] the first test that gets run is tests/dom/devicestorage/test/test_fs_remove.html and the last one is tests/dom/indexedDB/test/test_invalid_version.html. In my run, the first test is tests/dom/events/test/test_bug593959.html and the last is tests/dom/imptests/html/html/dom/documents/dta/test_nameditem-06.html. I also see a much larger leak (542519 bytes) compared to that inbound run (16244 bytes). I do still see 6 APZC objects getting leaked though, so maybe that's good enough and I can try to figure out why they're getting leaked.

[1] https://tbpl.mozilla.org/php/getParsedLog.php?id=48219877&tree=Mozilla-Inbound&full=1

Comment 18

[Kartikaya Gupta (email:[e-mail])]

In the end I think trying to reproduce this problem locally was a waste of time. By reasoning through the log above and some code inspection I think I found the problem.

Comment 19

[Kartikaya Gupta (email:[e-mail])]

Try push to verify: https://tbpl.mozilla.org/?tree=Try&rev=4cd97c972fd9

Comment 20

[Kartikaya Gupta (email:[e-mail])]

My trychooser syntax was wrong (or rather, try didn't respect my syntax) but it doesn't matter because my theory was wrong. My local emulator run still shows the leak even with my patch. I narrowed down the leak to the dom/events/test/test_moz_mouse_pixel_scroll_event.html test.

Comment 21

[Kartikaya Gupta (email:[e-mail])]

Second attempt; this one actually fixes the problem for me locally. https://tbpl.mozilla.org/?tree=Try&rev=5f94797d2e73

Comment 22

[Kartikaya Gupta (email:[e-mail])]

Attachment: Part 1 - The fix

The problem occurs when we have two layers that have the same APZC (call it "A"), but those two layers have subtrees with different APZCs. When we recurse into the second subtree, we set the parent pointer to A and "nextsibling" pointer to null, even though A already has children from the first subtree.

As a result, those children A already had get clobbered and leaked. It also results in an incorrect APZC tree. To fix this the critical line is to set |next| to apzc->GetFirstChild() which makes sure the two subtrees of A get bound into a single tree. The rest is just cleanup and tests.

Comment 23

[Kartikaya Gupta (email:[e-mail])]

Attachment: Part 2 - Remove redundant ctor-counting

This is redundant for refcounted things. Also it results in the leakchecker reporting twice as many objects created/leaked.

Comment 24

[Kartikaya Gupta (email:[e-mail])]

Attachment: Part 3 - Remove unnecessary forward-declare

Random thing I noticed while poking around.

Comment 25

[Kartikaya Gupta (email:[e-mail])]

This bug was exposed from the layer tree changes in bug 967844 and will need uplifting to 34 as well.

Comment 26

[Nathan Froyd [:froydnj]]

Comment on attachment 8492348 [details] [diff] [review]
Part 2 - Remove redundant ctor-counting

Review of attachment 8492348 [details] [diff] [review]:
-----------------------------------------------------------------

::: gfx/layers/apz/src/AsyncPanZoomController.cpp
@@ -885,5 @@
>       mAPZCId(sAsyncPanZoomControllerCount++),
>       mSharedLock(nullptr),
>       mAsyncTransformAppliedToContent(false)
>  {
> -  MOZ_COUNT_CTOR(AsyncPanZoomController);

You should use MOZ_COUNT_CTOR_INHERITED, if I'm understanding your bug description correctly.

@@ -893,5 @@
>    }
>  }
>  
>  AsyncPanZoomController::~AsyncPanZoomController() {
> -  MOZ_COUNT_DTOR(AsyncPanZoomController);

...and resp. MOZ_COUNT_DTOR_INHERITED.

Comment 27

[Kartikaya Gupta (email:[e-mail])]

(Clarified on IRC with :froydnj that removing these macros is correct based on the comment at http://mxr.mozilla.org/mozilla-central/source/xpcom/glue/nsISupportsImpl.h?rev=b276ce875275#168 and the fact that there is no class hierarchy around AsyncPanZoomController that would necessitate using the _INHERITED versions.)

Comment 28

[Botond Ballo [:botond]]

Comment on attachment 8492347 [details] [diff] [review]
Part 1 - The fix

Review of attachment 8492347 [details] [diff] [review]:
-----------------------------------------------------------------

::: gfx/layers/apz/src/APZCTreeManager.cpp
@@ +439,5 @@
> +  // have our siblings as their siblings, and our parent as their parent.
> +  AsyncPanZoomController* next = aNextSibling;
> +  if (apzc) {
> +    // Otherwise, use this APZC as the parent going downwards, and start off
> +    // with it's first child as the next sibling

s/it's/its

Comment 29

[Kartikaya Gupta (email:[e-mail])]

Build-only try run to make sure the gtest passes everywhere: https://tbpl.mozilla.org/?tree=Try&rev=e34b89a551aa

Comment 30

[Kartikaya Gupta (email:[e-mail])]

And landed on inbound:

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/d6796f17d65f
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/b50ffee0de56
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/6cb9a72b4f7b

Comment 31

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/d6796f17d65f
https://hg.mozilla.org/mozilla-central/rev/b50ffee0de56
https://hg.mozilla.org/mozilla-central/rev/6cb9a72b4f7b

Comment 32

[Kartikaya Gupta (email:[e-mail])]

Comment on attachment 8492347 [details] [diff] [review]
Part 1 - The fix

Approval Request Comment
[Feature/regressing bug #]: bug 967844
[User impact if declined]: in some situations the apz code will leak objects. These cases will also have incorrect scrolling behavior because the apz code does not build the right data structure to track scrollable frames.
[Describe test coverage new/current, TBPL]: added gtest, also tested locally
[Risks and why]: low risk, change is relatively straightforward
[String/UUID change made/needed]: none

Comment 33

[Lawrence Mandel [:lmandel] (use needinfo)]

Comment on attachment 8492347 [details] [diff] [review]
Part 1 - The fix

Aurora+

Comment 34

[Lawrence Mandel [:lmandel] (use needinfo)]

Is this bug B2G specific? Are desktop or mobile affected?

Comment 35

[Kartikaya Gupta (email:[e-mail])]

This only affects platforms with APZ enabled, so B2G and Metro at this point.

Comment 36

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/d9441066656c
https://hg.mozilla.org/releases/mozilla-aurora/rev/654ca02c2785
https://hg.mozilla.org/releases/mozilla-aurora/rev/dfa9c38fecb6