1515893 - Memory is used up and system is freezed by a web page with interval and loops

Status: NEW

(Core :: DOM: Core & HTML, defect, P3)

Description

[Guo Yunhe]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:63.0) Gecko/20100101 Firefox/63.0

Steps to reproduce:

1. You need to have a Firefox on Linux.
2. Open Firefox.
3. Visit https://codepen.io/guoyunhe/pen/vvxymo
4. Wait a minute.


Actual results:

Memory usage rapidly increased to several GB and CPU usage is also very high. Finally desktop will freeze. (Tested with Core i5-6500 CPU)


Expected results:

Like in Chromium, it will warning the user before CPU and memory usage is getting crazy. Users can stop the page from loading to prevent system crash.

Comment 1

[Matthias Versen [:Matti]]

I can't see a memory leak here because the memory is freed if you close the page.

Comment 2

[Guo Yunhe]

(In reply to Matthias Versen [:Matti] from comment #1)
> I can't see a memory leak here because the memory is freed if you close the
> page.

I corrected the subject: leaks --> is used up.

I tested in another computer with Intel Core i7-4710MQ CPU and 8GB RAM, openSUSE Tumbleweed 64bit.

In Firefox 64:

1. Open the page.
2. Sometimes here is a warning (web page is slowing down your browser), click "Wait"/"Continue".
3. In about a minute, RAM is used up and swap, which causes desktop freeze.


Tested in Chromium 71:

1. Open the page.
2. Sometimes here is a warning (web page is slowing down your browser), click "Wait"/"Continue".
3. In about 10 minutes, RAM usage is 1.5GB but still growing.

Comment 3

[Rares Doghi, Desktop QA]

Hi, I managed to reproduce this issue in all versions of Firefox from 64.0 to Beta 65.0b7 and Nightly 66, I will set the component to Memory allocator but I'm not sure its the correct component, please feel free to change the component if there is a more suitable component for it.

Comment 4

[Marco Castelluccio [:marco]]

erahm, maybe you can investigate this runaway memory usage?

Comment 5

[Eric Rahm [:erahm]]

Guo Yunhe, can you attach a memory report when this happens?

Comment 6

[Guo Yunhe]

Attachment: memory-report.json.gz (i7 8550U, 32GB RAM)

Hi Eric, here is the memory report. Sorry I cannot generate it with my old laptop with 8GB RAM because it freeze too fast and here is no chance to save report. I did this on my new laptop with 32GB RAM.

Comment 7

[Eric Rahm [:erahm]]

Attachment: bug-1515893-dmd.txt

The memory report indicated a ton of heap-unclassified, I was able to repro with a DMD build. This mostly text data and layout related memory. We should definitely be reporting this memory, I feel like we've seen this before.

Top offenders:

Unreported {
  843,624 blocks in heap block record 1 of 4,358
  2,421,509,992 bytes (1,801,031,184 requested / 620,478,808 slop)
  Individual block sizes: 4,096 x 443,006; 2,048 x 231,699; 1,024 x 110,813; 512 x 2,811; 496 x 2,833; 480 x 2,769; 464 x 2,736; 448 x 2,694; 432 x 2,605; 416 x 2,543; 400 x 2,535; 384 x 2,477; 368 x 2,432; 352 x 2,397; 336 x 2,258; 320 x 2,190; 304 x 2,202; 288 x 2,070; 272 x 2,004; 256 x 1,942; 240 x 1,857; 224 x 1,756; 208 x 1,700; 192 x 1,622; 176 x 1,475; 160 x 1,386; 144 x 1,264; 128 x 1,142; 112 x 1,024; 96 x 915; 80 x 820; 64 x 667; 48 x 491; 32 x 350; 16 x 86; 8 x 53
  68.39% of the heap (68.39% cumulative)
  72.24% of unreported (72.24% cumulative)
  Allocated at {
    #01: replace_malloc(unsigned long) (/var/dev/erahm/mozilla-unified/memory/replace/dmd/DMD.cpp:1123)
    #02: nsTextFragment::SetTo(char16_t const*, int, bool, bool) (/var/dev/erahm/mozilla-unified/dom/base/nsTextFragment.cpp:299)
    #03: mozilla::dom::CharacterData::SetTextInternal(unsigned int, unsigned int, char16_t const*, unsigned int, bool, CharacterDataChangeInfo::Details*) (/var/dev/erahm/mozilla-unified/dom/base/CharacterData.cpp:264)
    #04: mozilla::dom::CharacterData::SetText(char16_t const*, unsigned int, bool) (/var/dev/erahm/mozilla-unified/dom/base/CharacterData.cpp:554)
    #05: nsGenericHTMLElement::SetInnerText(nsTSubstring<char16_t> const&) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang-7-debug/dist/include/mozilla/RefPtr.h:267)
    #06: mozilla::dom::HTMLElement_Binding::set_innerText(JSContext*, JS::Handle<JSObject*>, nsGenericHTMLElement*, JSJitSetterCallArgs) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang-7-debug/dom/bindings/HTMLElementBinding.cpp:358)
    #07: ??? (???:???)
  }
}

Unreported {
  82,251 blocks in heap block record 2 of 4,358
  458,835,200 bytes (458,835,200 requested / 0 slop)
  Individual block sizes: 8,192 x 41,612; 4,096 x 21,760; 2,048 x 10,854; 1,024 x 5,195; 512 x 2,139; 256 x 691
  12.96% of the heap (81.34% cumulative)
  13.69% of unreported (85.92% cumulative)
  Allocated at {
    #01: replace_malloc(unsigned long) (/var/dev/erahm/mozilla-unified/memory/replace/dmd/DMD.cpp:1123)
    #02: nsStringBuffer::Alloc(unsigned long) (/var/dev/erahm/mozilla-unified/xpcom/string/nsSubstring.cpp:222)
    #03: nsTSubstring<char16_t>::StartBulkWriteImpl(unsigned int, unsigned int, bool, unsigned int, unsigned int, unsigned int) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang-7-debug/dist/include/mozilla/AlreadyAddRefed.h:145)
    #04: Gecko_StartBulkWriteString (/var/dev/erahm/mozilla-unified/xpcom/string/nsSubstring.cpp:446)
    #05: nsstring::nsAString::start_bulk_write_impl (/var/dev/erahm/mozilla-unified/xpcom/rust/nsstring/src/lib.rs:649)
    #06: nsstring::nsAString::bulk_write (/var/dev/erahm/mozilla-unified/xpcom/rust/nsstring/src/lib.rs:637)
    #07: nsstring::conversions::<impl nsstring::nsAString>::fallible_append_latin1_impl (/var/dev/erahm/mozilla-unified/xpcom/rust/nsstring/src/conversions.rs:145)
    #08: nsstring_fallible_append_latin1_impl (/var/dev/erahm/mozilla-unified/xpcom/rust/nsstring/src/conversions.rs:698)
  }
}

Unreported {
  1 block in heap block record 3 of 4,358
  160,002,048 bytes (160,000,104 requested / 1,944 slop)
  4.52% of the heap (85.86% cumulative)
  4.77% of unreported (90.70% cumulative)
  Allocated at {
    #01: replace_malloc(unsigned long) (/var/dev/erahm/mozilla-unified/memory/replace/dmd/DMD.cpp:1123)
    #02: gfxTextRun::AllocateStorageForTextRun(unsigned long, unsigned int) (/var/dev/erahm/mozilla-unified/gfx/thebes/gfxTextRun.cpp:123)
    #03: gfxTextRun::Create(gfxTextRunFactory::Parameters const*, unsigned int, gfxFontGroup*, mozilla::gfx::ShapedTextFlags, nsTextFrameUtils::Flags) (/var/dev/erahm/mozilla-unified/gfx/thebes/gfxTextRun.cpp:141)
    #04: gfxFontGroup::MakeTextRun(unsigned char const*, unsigned int, gfxTextRunFactory::Parameters const*, mozilla::gfx::ShapedTextFlags, nsTextFrameUtils::Flags, gfxMissingFontRecorder*) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang-7-debug/dist/include/mozilla/AlreadyAddRefed.h:145)
    #05: BuildTextRunsScanner::BuildTextRunForFrames(void*) (crtstuff.c:?)
    #06: BuildTextRunsScanner::FlushFrames(bool, bool) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang-7-debug/dist/include/mozilla/AlreadyAddRefed.h:145)
    #07: nsTextFrame::EnsureTextRun(nsTextFrame::TextRunType, mozilla::gfx::DrawTarget*, nsIFrame*, nsLineList_iterator const*, unsigned int*) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang-7-debug/dist/include/nsTArray.h:344)
    #08: nsTextFrame::ReflowText(nsLineLayout&, int, mozilla::gfx::DrawTarget*, mozilla::ReflowOutput&, nsReflowStatus&) (/var/dev/erahm/mozilla-unified/layout/generic/nsTextFrame.cpp:9119)
    #09: nsLineLayout::ReflowFrame(nsIFrame*, nsReflowStatus&, mozilla::ReflowOutput*, bool&) (crtstuff.c:?)
    #10: nsInlineFrame::ReflowInlineFrame(nsPresContext*, mozilla::ReflowInput const&, nsInlineFrame::InlineReflowInput&, nsIFrame*, nsReflowStatus&) (/var/dev/erahm/mozilla-unified/layout/generic/nsIFrame.h:317)
    #11: nsInlineFrame::ReflowFrames(nsPresContext*, mozilla::ReflowInput const&, nsInlineFrame::InlineReflowInput&, mozilla::ReflowOutput&, nsReflowStatus&) (/var/dev/erahm/mozilla-unified/layout/generic/nsIFrame.h:315)
    #12: nsInlineFrame::Reflow(nsPresContext*, mozilla::ReflowOutput&, mozilla::ReflowInput const&, nsReflowStatus&) (/var/dev/erahm/mozilla-unified/layout/generic/nsInlineFrame.cpp:361)
    #13: nsLineLayout::ReflowFrame(nsIFrame*, nsReflowStatus&, mozilla::ReflowOutput*, bool&) (/var/dev/erahm/mozilla-unified/layout/generic/nsLineLayout.cpp:880)
    #14: nsBlockFrame::ReflowInlineFrame(mozilla::BlockReflowInput&, nsLineLayout&, nsLineList_iterator, nsIFrame*, LineReflowStatus*) (/var/dev/erahm/mozilla-unified/layout/generic/nsIFrame.h:271)
    #15: nsBlockFrame::DoReflowInlineFrames(mozilla::BlockReflowInput&, nsLineLayout&, nsLineList_iterator, nsFlowAreaRect&, int&, nsFloatManager::SavedState*, bool*, LineReflowStatus*, bool) (/var/dev/erahm/mozilla-unified/layout/generic/nsBlockFrame.cpp:3884)
    #16: nsBlockFrame::ReflowInlineFrames(mozilla::BlockReflowInput&, nsLineList_iterator, bool*) (/var/dev/erahm/mozilla-unified/layout/generic/nsBlockFrame.cpp:3769)
    #17: nsBlockFrame::ReflowLine(mozilla::BlockReflowInput&, nsLineList_iterator, bool*) (/var/dev/erahm/mozilla-unified/layout/generic/nsBlockFrame.cpp:2791)
    #18: nsBlockFrame::ReflowDirtyLines(mozilla::BlockReflowInput&) (/var/dev/erahm/mozilla-unified/layout/generic/nsBlockFrame.cpp:2333)
    #19: nsBlockFrame::Reflow(nsPresContext*, mozilla::ReflowOutput&, mozilla::ReflowInput const&, nsReflowStatus&) (/var/dev/erahm/mozilla-unified/layout/generic/nsIFrame.h:259)
    #20: nsBlockReflowContext::ReflowBlock(mozilla::LogicalRect const&, bool, nsCollapsingMargin&, int, bool, nsLineBox*, mozilla::ReflowInput&, nsReflowStatus&, mozilla::BlockReflowInput&) (/var/dev/erahm/mozilla-unified/layout/generic/nsBlockReflowContext.cpp:298)
  }
}

Comment 8

[Andrew McCreight [:mccr8]]

We have memory reporters for nsTextFragment, but it looks like we don't report it if the string data is shared.

Comment 9

[Eric Rahm [:erahm]]

The relevant code snippet:

var container = document.getElementById("container");
var text = "ram ";
setInterval(() => {
  for (var i = 0; i < 1000; i++) {
    var ram = document.createElement("span");
    for (var j = 0; j < 1000; j++) {
      ram.innerText += text;
    }
    container.append(ram);
  }
}, 1);

Comment 10

[Andrew McCreight [:mccr8]]

It is interesting that the memory isn't growing as rapidly in Chrome. Maybe Firefox is more eagerly flattening the strings involved, and Chrome somehow is able to keep them as ropes or whatever the Chrome equivalent of that is?

Comment 11

[Eric Rahm [:erahm]]

It looks like there's a perf difference with chrome, bz do you think there's anything particularly bad we're doing here?

Comment 12

[Andrew McCreight [:mccr8]]

My only theory here is that maybe Chrome is able to do some clever optimization that prevents them from having to flatten the string.

Comment 13

[Boris Zbarsky [:bzbarsky]]

If we assume this interval actually gets clamped to 4ms in the usual way, it's running 250 times a second.

It's allocating 1000 <span> elements per run, at about 100-200 bytes each (depending on 32-bit vs 64-bit, etc), so figure 25-50MB a second just for that if all the work in the function can be done in 4ms (which maybe it can't). That should be 15-30GB after 10 minutes, but comment 2 says Chrome is at 1.5GB. That would mean their <span>s are 10 bytes each (which they are not, by simple code inspection) or the timer is not running at 250Hz.

In addition to that, there's the text for the spans. Each span is getting 4000 bytes of text (assuming it gets deflated to 1-byte-per-char), which means 1GB/sec if the timers are running at full speed and assuming there is no sharing.

All of that assumes no time spent on layout, etc, which is of course not true either.

OK, so what is the actual, not theoretical, behavior of browsers on this testcase? They're certainly not managing to run that code in 4ms. It takes multiple seconds in both to do a single invocation of the interval callback, with all the time taken in the innerText bits. So the observed dates of growth are much lower than what the above estimates suggest.

Anyway, I poked at what Chrome is doing. Chrome does not in fact avoid flattening the string, I don't think: the thing passed to https://cs.chromium.org/chromium/src/third_party/blink/renderer/core/html/html_element.cc?l=712&rcl=4b516fbd73fdc20698882520028f306c0950faca is a String, which is a flat character buffer.

But what they do manage to do is to share the string with JS on the setter. And presumably on the getter. What's not clear to me is whether they manage to share it across the elements (which would explain the slower memory growth)...

Emilio, do you happen to know enough about Blink's strings and bindings to say what might be going on there?

Comment 14

[Emilio Cobos Álvarez [:emilio]]

Emilio, do you happen to know enough about Blink's strings and bindings to say what might be going on there?

I don't unfortunately. I'm pretty sure the innerText getter will return a new string every time (since the spans are rendered, you need to actually do all the whitespace processing and such the innerText spec requires), so I'm moderately sure they're not sharing these across elements.

They may end up somehow sharing this via V8, but that sounds also unlikely.

They do have a fast path for where the innerText string has no newlines or carriage returns:

https://cs.chromium.org/chromium/src/third_party/blink/renderer/core/html/html_element.cc?l=745&rcl=55ac49d5a5e68ba1f373d371f41a404d9202dce2

Which does avoid allocating another string. That might explain part of the performance difference? Our innerText setter does allocate on the heap unconditionally, so we end up with four copies of the string (whereas Blink ends up with one for the whole thing):

• The SpiderMonkey string.
• The argument to SetInnerText.
• The innerText setter str variable.
• The copy that ends up in CharacterData.

Does that seem like a plausible explanation?

Comment 15

[Boris Zbarsky [:bzbarsky]]

I'm pretty sure the innerText getter will return a new string every time

OK, but this testcase is doing innerText sets, not gets.

That might explain part of the performance difference?

I don't think that's nearly enough.

The argument to SetInnerText.

This goes away as soon as the stack unwinds.

The innerText setter str variable.

This also goes away as soon as the stack unwinds.

So there are only two long-lived copies... And even just the one that ends up in CharacterData is already bigger than Chrome's observed memory usage.