1442516 - Large amounts of garbage builds up in the focused tab (example: washingtonpost.com)

Status: RESOLVED INCOMPLETE

(Core :: JavaScript: GC, enhancement, P3)

Description

[Randell Jesup [:jesup] (needinfo me)]

Browse to https://www.washingtonpost.com/politics/courts_law/supreme-court-declines-trump-request-to-take-up-daca-controversy-now/2018/02/26/4fb2e528-132f-11e8-9570-29c9830535e5_story.html?utm_term=.046c5db0bcb0 and open a second tab with about:memory.  Focus the washington post tab, scroll down to make a few ads visible (typically one on the right and one in the text; for this test I avoid playing video).

Let it sit a small (or long) while.  Switch to the about:memory tab and Measure.  Note that the zone for washingtonpost will have a large amount of strings (often 100's of MB) and you'll see things like:

│  ├──330.36 MB (37.48%) -- top(https://www.washingtonpost.com/politics/courts_law/supreme-court-declines-trump-request-to-take-up-daca-controversy-now/2018/02/26/4fb2e528-132f-11e8-9570-29c9830535e5_story.html?utm_term=.046c5db0bcb0, id=7)
│  │  ├──193.26 MB (21.93%) -- js-zone(0x7fffb902f000)
│  │  │  ├───88.81 MB (10.08%) -- strings
│  │  │  │   ├──35.05 MB (03.98%) ++ (116 tiny)
│  │  │  │   ├──20.57 MB (02.33%) -- string(length=2700, copies=35, "rplpwabt4=1; de=; rpld0=1:03|2:-|; s_pers=%20s_vmonthnum%3D1522555200110%2526vn%253D1%7C1522555200110%3B%20s_nr%3D1519938000052-Repeat%7C1522530000052%3B%20s_lv%3D1519938000060%7C1614546000060" (truncated))
│  │  │  │   │  ├──20.51 MB (02.33%) ── malloc-heap/two-byte [75]
│  │  │  │   │  └───0.06 MB (00.01%) ── gc-heap/two-byte [75]
│  │  │  │   ├──19.39 MB (02.20%) -- string(length=2701, copies=33, " rplpwabt4=1; de=; rpld0=1:03|2:-|; s_pers=%20s_vmonthnum%3D1522555200110%2526vn%253D1%7C1522555200110%3B%20s_nr%3D1519938000052-Repeat%7C1522530000052%3B%20s_lv%3D1519938000060%7C1614546000060" (truncated))
│  │  │  │   │  ├──19.34 MB (02.19%) ── malloc-heap/two-byte [75]
│  │  │  │   │  └───0.06 MB (00.01%) ── gc-heap/two-byte [75]
│  │  │  │   └──13.81 MB (01.57%) -- string(<non-notable strings>)
│  │  │  │      ├──12.21 MB (01.39%) -- malloc-heap
│  │  │  │      │  ├──11.86 MB (01.35%) ── latin1
│  │  │  │      │  └───0.36 MB (00.04%) ── two-byte
│  │  │  │      └───1.59 MB (00.18%) ++ gc-heap
│  │  │  ├───76.11 MB (08.64%) ── unused-gc-things
│  │  │  └───28.33 MB (03.21%) ++ (15 tiny)
│  │  └──137.11 MB (15.56%) -- active



My understanding from njn is that the [75] is another form of "copies", where the string differs, but only after the subset of characters that included in the report (I truncated the string further for this bug report).  In any case, that's part of why this string is shown as using 20MB

Leave the memory report visible for "a while" (a few minutes say).  Hit measure again.  Note that the strings in the zone are much smaller:

│  ├──258.18 MB (33.88%) -- top(https://www.washingtonpost.com/politics/courts_law/supreme-court-declines-trump-request-to-take-up-daca-controversy-now/2018/02/26/4fb2e528-132f-11e8-9570-29c9830535e5_story.html?utm_term=.046c5db0bcb0, id=7)
│  │  ├──129.47 MB (16.99%) -- js-zone(0x7fffb902f000)
│  │  │  ├───82.90 MB (10.88%) ── unused-gc-things
│  │  │  ├───25.14 MB (03.30%) ++ (15 tiny)
│  │  │  └───21.44 MB (02.81%) -- strings
│  │  │      ├──12.84 MB (01.69%) -- string(<non-notable strings>)
│  │  │      │  ├──12.19 MB (01.60%) -- malloc-heap
│  │  │      │  │  ├──11.81 MB (01.55%) ── latin1
│  │  │      │  │  └───0.38 MB (00.05%) ── two-byte
│  │  │      │  └───0.65 MB (00.08%) ++ gc-heap
│  │  │      └───8.59 MB (01.13%) ++ (35 tiny)
│  │  └──128.71 MB (16.89%) -- active

In this case, 88MB -> 21MB

My presumption is that this string keeps getting replaced with a Very Similar or identical string, producing garbage, but the system doesn't notice that this is garbage and recycle it until we remove focus from the tab.  (Reducing memory use after loss of focus is a Good Thing, but in this case it just highlights that we're failing to ever recover this when it has focus, and that can lead higher system memory pressure and fragmentation of string arenas.)


A separate issue is the unused-gc-things, which I'll file another bug on.

Comment 1

[Randell Jesup [:jesup] (needinfo me)]

Another random example from washingtonpost.com (left maybe 10 hours?):

│  ├──3,331.74 MB (88.79%) -- top(https://www.washingtonpost.com/business/economy/the-northwest-washington-lifestyle-trap-500000-in-income-and-still-cant-save/2018/03/02/b2f23a4c-1c0a-11e8-9de1-147dd2df3829_story.html?undefined=&utm_term=.8a9d1406c5be&wpisrc=nl_most&wpmm=1, id=8589934642)
│  │  ├──2,284.70 MB (60.89%) -- js-zone(0x1e5fd320000)
│  │  │  ├──1,864.70 MB (49.70%) ── unused-gc-things
│  │  │  ├────317.77 MB (08.47%) -- strings
│  │  │  │    ├──251.40 MB (06.70%) -- string(<non-notable strings>)
│  │  │  │    │  ├──243.23 MB (06.48%) -- malloc-heap
│  │  │  │    │  │  ├──242.86 MB (06.47%) ── latin1
│  │  │  │    │  │  └────0.37 MB (00.01%) ── two-byte
│  │  │  │    │  └────8.17 MB (00.22%) ++ gc-heap
│  │  │  │    └───66.37 MB (01.77%) -- (152 tiny)
│  │  │  │        ├──14.54 MB (00.39%) ++ string(length=94, copies=127056, "wc:-8.-8.1936.1176,ac:562.432.300.250,am:i,cc:562.432.300.250,piv:100,obst:0,th:0,reas:,cmps:1")
│  │  │  │        ├──14.37 MB (00.38%) ++ string(length=94, copies=125599, "wc:-8.-8.1920.1035,ac:554.299.300.250,am:i,cc:554.299.300.250,piv:100,obst:0,th:0,reas:,cmps:1")
│  │  │  │        ├───4.34 MB (00.12%) ++ string(length=30, copies=30097, "https://www.washingtonpost.com")
│  │  │  │        ├───3.84 MB (00.10%) ++ string(length=2968, copies=35, "de=; rpld0=1:03|2:-|; __gads=ID=b404c92240f75782:T=1502860816:S=ALNI_MahOVLKuF6rDYjo3iA4e4pPfn_-yw; s_vi=[CS]v1|2CC9EB0985037DFD-6000118940000726[CE]; devicetype=0; osfam=0;" (truncated))
│  │  │  │        ├───3.62 MB (00.10%) ++ string(length=2969, copies=33, " de=; rpld0=1:03|2:-|; __gads=ID=b404c92240f75782:T=1502860816:S=ALNI_MahOVLKuF6rDYjo3iA4e4pPfn_-yw; s_vi=[CS]v1|2CC9EB0985037DFD-6000118940000726[CE]; devicetype=0; osfam=0;" (truncated))
│  │  │  │        ├───2.91 MB (00.08%) ── string(length=95, copies=127056, ",wc:-8.-8.1936.1176,ac:562.432.300.250,am:i,cc:562.432.300.250,piv:100,obst:0,th:0,reas:,cmps:1")/gc-heap/latin1
│  │  │  │        ├───2.87 MB (00.08%) ── string(length=95, copies=125599, ",wc:-8.-8.1920.1035,ac:554.299.300.250,am:i,cc:554.299.300.250,piv:100,obst:0,th:0,reas:,cmps:1")/gc-heap/latin1
│  │  │  │        ├───1.91 MB (00.05%) ++ string(length=99, copies=14702, "wc:-8.-8.1920.1035,ac:1404.-3689.160.600,am:i,cc:1404.-3689.160.600,piv:0,obst:0,th:0,reas:l,cmps:1")

Comment 2

[Jason Orendorff [:jorendorff]]

Steve, could you take a look, please?

Comment 3

[Steve Fink [:sfink] [:s:]]

Unlikely to still be the same problem now, though we do still see excessive string duplication. I believe that exploration is happening elsewhere. I guess (the long-stalled) bug 1367471 would be an appropriate place to redirect to.