Closed Bug 1591722 Opened 5 years ago Closed 2 years ago

High memory-file-data/string memory usage over time on Deezer.com

Categories

(Core :: DOM: File, defect, P2)

Product:
Core
Component:
DOM: File
Version:
70 Branch
Type:
defect

Tracking

()

Status:
RESOLVED WORKSFORME
Project Flags:
Webcompat Priority P3

People

(Reporter: 5228, Unassigned)

References

(
URL
)

Details

(Keywords: reproducible, webcompat:site-wait, Whiteboard: [MemShrink])

Attachments

(5 files, 1 obsolete file)

Firefox 72 memory dump directly after a clean cold start
160.34 KB, application/gzip
Details
Firefox 72 memory dump after running Deezer for 7h
2.06 MB, application/gzip
Details
Firefox 72 memory dump after running Deezer for almost a day
8.60 MB, application/gzip
Details
patch
1.82 KB, patch
Details | Diff | Splinter Review
app-web.js.diff
1.01 KB, patch
Details | Diff | Splinter Review

User Agent: Mozilla/5.0 (Windows NT 10.0; rv:70.0) Gecko/20100101 Firefox/70.0

Steps to reproduce:

Listening to music on the Deezer.com streaming platform for a while (about 30-50 minutes). I'm using Firefox 70 x86, but this problem has been seen in previous versions as well.

Actual results:

Firefox crashes after a while (~ 30 min - 1 hour) of listening to music on Deezer.com's streaming service. Each time

Expected results:

Firefox playing music on Deezer 24/7

Hi
I tried to replicate the issue using Windows10 64bit with Firefox Nightly version 72.0a1.
Listened for more than 1 hour on deezer and had no problems at all.

Please download the latest Firefox Nightly release from here: https://nightly.mozilla.org/ and retest the problem.

If you still have the issue please create a new profile, you have the steps here:https://support.mozilla.org/en-US/kb/profile-manager-create-and-remove-firefox-profiles?redirectlocale=en-US&redirectslug=Managing-profiles#w_starting-the-profile-manager

Lastly test if the issue is reproducible in safe mode, here is a link that can help you:
https://support.mozilla.org/en-US/kb/troubleshoot-firefox-issues-using-safe-mode

Regards
Pablo

Component: Untriaged → Widget: Win32
Product: Firefox → Core

Can you paste the crash from about:crashes?

Flags: needinfo?(5228)

(In reply to Timothy Nikkel (:tnikkel) from comment #2)

Can you paste the crash from about:crashes?

I have already stopped listening to music on Deezer in Firefox. But to create a new report, I turned on the music and simultaneously worked in Firefox. After about 1.5 hours, the browser crashed (at which time it was minimized and did not open for about 10 minutes). Report link https://crash-stats.mozilla.org/report/index/c5716c88-4a14-45f5-9299-223790191101

Flags: needinfo?(5228)

(In reply to Timothy Nikkel (:tnikkel) from comment #2)

Can you paste the crash from about:crashes?

And one more (now) : https://crash-stats.mozilla.org/report/index/1cefef5b-1fb9-41aa-9b13-b45b00191101

Crash Signature: 1cefef5b-1fb9-41aa-9b13-b45b00191101

I tried to reproduce on macOS. I saw memory increase, but perhaps not as badly as you are seeing.

Interesting things in the memory report. 181mb (36%) under gfx/heap-textures in the parent process. 144mb (28%) of heap unclassified in the parent process. 95mb (38%) in the content process under dom, memory-file-data/string. This was after clicking minimize memory. Seems like we need over 100mb of gfx/heap-textures at the start just to draw the website, so most of the increase is in heap-unclassified and memory-file-data/string.

Almost all of the unreported is

Unreported {
873 blocks in heap block record 1 of 7,159
113,391,680 bytes (113,391,680 requested / 0 slop)
Individual block sizes: 131,072 x 865; 2,048 x 7; 64
36.02% of the heap (36.02% cumulative)
70.65% of unreported (70.65% cumulative)
Allocated at {
#01: replace_malloc(unsigned long) (DMD.cpp:1071, in libmozglue.dylib)
#02: nsTSubstring<char>::StartBulkWriteImpl(unsigned int, unsigned int, bool, unsigned int, unsigned int, unsigned int) (nsSubstring.cpp:223, in XUL)
#03: nsTSubstring<char>::SetLength(unsigned int, std::nothrow_t const&) (nsTSubstring.cpp:949, in XUL)
#04: nsTSubstring<char>::SetLength(unsigned int) (nsTSubstring.cpp:939, in XUL)
#05: IPC::ParamTraits<nsTSubstring<char> >::Read(IPC::Message const*, PickleIterator*, nsTSubstring<char>) (nsTSubstring.h:352, in XUL)
#06: bool mozilla::ipc::ReadIPDLParam<mozilla::ipc::StringInputStreamParams>(IPC::Message const, PickleIterator*, mozilla::ipc::IProtocol*, mozilla::ipc::StringInputStreamParams*) (InputStreamParams.cpp:122, in XUL)
#07: mozilla::ipc::IPDLParamTraits<mozilla::ipc::InputStreamParams>::Read(IPC::Message const*, PickleIterator*, mozilla::ipc::IProtocol*, mozilla::ipc::InputStreamParams*) (InputStreamParams.cpp:2066, in XUL)
#08: mozilla::ipc::IPDLParamTraits<mozilla::ipc::IPCStream>::Read(IPC::Message const*, PickleIterator*, mozilla::ipc::IProtocol*, mozilla::ipc::IPCStream*) (IPCStream.cpp:59, in XUL)
}
}

Component: Widget: Win32 → IPC

The stack in comment #6 indicates that we're receiving nsCStrings over IPC, but that doesn't help us understand where they're leaked. StringInputStreamParams and memory-file-data/string might indicate DOM Blob objects?

Whiteboard: [MemShrink]

You could use DMD heap scan mode to find out the allocation stack of whatever is holding onto these strings. You just run it with --mode=scan. There's some instructions on the special scripts you have to run in order to analyze the result.
https://developer.mozilla.org/en-US/docs/Mozilla/Performance/DMD/Heap_Scan_Mode

Summary: Deezer.com destroy Firefox → High memory-file-data/string memory usage over time on Deezer.com
Status: UNCONFIRMED → NEW
Ever confirmed: true
Component: IPC → DOM: File
See Also: → 1592169
Priority: -- → P2

I think I can reproduce this bug. I'm on openSUSE Tumbleweed with distros Firefox 72.0.2. My Firefox doesn't crash when using Deezer, but the memory consumption steadily grows. I guess it's because I have 16GiB of RAM, but I already got Firefox to something over 10GiB of RAM...

The memory leak is in the webcontent process of Deezer and the firefox process itself.

I will attach two memory dumps: one after a cold start of firefox and the other after listening music for 7h in Deezer.

If needed I can try to reproduce it with a current Nightly. If you need more logs or dumps, just ask. I will try my best :)

Earlier, I thought that the memory leak problem was somehow related to the version of the x86 processor for Windows. But now I'm using a 64-bit version of Firefox 74.0.1 with Ubuntu 18.04. I have 16 GB of RAM installed. After listening to music on Deezer.com for a long time, the Firefox process can use up to 10GB or more. At the same time no more than 5 tabs are opened, and when closing the tab with Deezer the memory is released.

Flags: needinfo?(5228)
Keywords: steps-wanted

As for steps all you need to do is register for a deezer account (free, no cc required), and then stream some music, after an hour the memory use should be noticable.

Keywords: steps-wanted → reproducible

It's much worse if you buy a Hi-Fi account there (FLAC streaming). System goes out of RAM in half an hour. No matter how much RAM you have.

Addendum: Google Chrome also has this problem but it does this at a slower pace.

Closing because no crashes reported for 12 weeks.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → WORKSFORME

This isn't a crash.

Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---

The problem is still relevant.
There is another (perhaps not related to this bug) bug with a memory leak in Firefox which is much easier and faster to repeat on your PC - I described it here bugzilla.mozilla.org/show_bug.cgi?id=1674550

Flags: needinfo?(5228)
URL: https://bugzilla.mozilla.org/show_bug...
See Also: → 1674550

(Removing text from the crash signature field so that comment #17 doesn't happen again. For future reference, “crash signature” in this context refers to those strings that look like [@ FunctionName ].)

Crash Signature: 1cefef5b-1fb9-41aa-9b13-b45b00191101

The problem is still relevant. Checked in v. 86.0b1

I have the same issue with Firefox 86.0, after ~30 minutes on deezer.com playing songs, I see this memory use:

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                          
  3150 xxx       20   0 6290088   1.3g 332928 S   4.0   8.8  42:12.44 firefox-bin                                                      
 43381 xxx       20   0 4424524   1.0g 107664 S  11.3   7.0   2:31.54 Web Content

After a few hours, the memory increases dramatically.
Closing the deezer.com tab releases immediately the memory used by both process shown above.

I have been affected by this issue for many many months (between 2 and 3 years).
Hopefully a complete bug report will help in pinpointing the root cause!

The issue (ever increasing memory use) occurs 100% systematically on

  1. Firefox Desktop (Linux x86-64)
  2. Firefox Mobile (Android arm64)

so I think it's safe to say that the issue is not platform-dependent?
And it's 100% reproducible.

Basically, the tab running Deezer keeps gobbling more and more memory until

  1. either the OOM daemon kills the tab, freeing the memory (typical on Android)
  2. or the system starts swapping and becomes sluggish and unresponsive (typical on Linux with swap)

 
Reproduction steps:

  1. I installed a fresh copy of firefox-94.0b9 in Ubuntu 18.04
  2. I created a fresh profile (deezer-test)
  3. I started firefox-94 in safe mode (firefox --safe-mode -P deezer-test)
  4. I have a single tab open
  5. I log in to www.deezer.com
  6. I enable playlist shuffle
  7. I play my main playlist

I started the test at 13:43
About 8 hours later, my desktop started feeling sluggish (I have 8 GB of RAM).
Running top confirmed that the system was running low on RAM, and had started using swap:

KiB Mem :  8069264 total,   246936 free,  7327548 used,   494780 buff/cache
KiB Swap:  2097148 total,  2059752 free,    37396 used.   317540 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND        
10973 me        20   0 10,474g 4,080g 106004 R  31,1 53,0  89:34.22 Web Content    
10781 me        20   0 11,085g 2,605g 127448 S  22,5 33,9  30:39.29 GeckoMain      
10886 me        20   0 2601200 105456  70112 S   0,3  1,3   0:05.18 Privileged Cont
10844 me        20   0 2553716  77776  53872 S   0,0  1,0   0:17.70 WebExtensions  
11040 me        20   0 2521844  59976  44648 S   0,0  0,7   0:00.38 Web Content

 
The corresponding ps faux view:

  PID %CPU %MEM    VSZ     RSS   TTY   STAT START   TIME COMMAND
10781  5.8 34.8 11629360 2810192 pts/1 Sl   13:43  30:06  |   \_ /$HOME/firefox-94.0b9/firefox-bin --safe-mode -P deezer-test
10784  0.0  0.0        0       0 pts/1 Z    13:43   0:00  |   |   \_ [GeckoMain] <defunct>
10844  0.0  1.0  2553716   81304 pts/1 Sl   13:43   0:17  |   |   \_ /$HOME/firefox-94.0b9/firefox-bin -contentproc -childID 1 -isForBrowser -prefsLen 1 -prefMapSize 230897 -safeMode -parentBuildID 20211028161635 -appdir /$HOME/firefox-94.0b9/browser 10781 true tab
10886  0.0  1.3  2601200  109760 pts/1 Sl   13:43   0:05  |   |   \_ /$HOME/firefox-94.0b9/firefox-bin -contentproc -childID 2 -isForBrowser -prefsLen 406 -prefMapSize 230897 -safeMode -parentBuildID 20211028161635 -appdir /$HOME/firefox-94.0b9/browser 10781 true tab
10973 17.2 53.6 10974956 4328352 pts/1 Sl   13:44  88:52  |   |   \_ /$HOME/firefox-94.0b9/firefox-bin -contentproc -childID 4 -isForBrowser -prefsLen 8243 -prefMapSize 230897 -safeMode -parentBuildID 20211028161635 -appdir /$HOME/firefox-94.0b9/browser 10781 true tab
11040  0.0  0.7  2521844   62712 pts/1 Sl   13:44   0:00  |   |   \_ /$HOME/firefox-94.0b9/firefox-bin -contentproc -childID 5 -isForBrowser -prefsLen 10633 -prefMapSize 230897 -safeMode -parentBuildID 20211028161635 -appdir /$HOME/firefox-94.0b9/browser 10781 true tab
11056  2.5  0.3   339820   32036 pts/1 Sl   13:44  12:55  |   |   \_ /$HOME/firefox-94.0b9/firefox-bin -contentproc -parentBuildID 20211028161635 -prefsLen 10700 -prefMapSize 230897 -appdir /$HOME/firefox-94.0b9/browser 10781 true rdd

 
At this point, I opened about:memory to check which component was gobbling all my RAM.

Main Process (pid 10781)
Explicit Allocations

4,319.48 MB (100.0%) -- explicit
|--3,895.43 MB (90.18%) -- dom
|  |--3,894.71 MB (90.17%) -- memory-file-data/stream [7788]
...

web (pid 10973)
Explicit Allocations

4,191.83 MB (100.0%) -- explicit
|--3,894.09 MB (92.90%) -- dom
|  |--3,894.00 MB (92.89%) -- memory-file-data/string [7788]

 
FWIW, the JSON memory report contains gobs of

  {
   "process": "Main Process (pid 10781)",
   "path": "explicit/dom/memory-file-data/stream",
   "kind": 1,
   "units": 0,
   "amount": 524384,
   "description": "Memory used to back a File/Blob based on an input stream."
  },

and

  {
   "process": "web (pid 10973)",
   "path": "explicit/dom/memory-file-data/string",
   "kind": 1,
   "units": 0,
   "amount": 524288,
   "description": "Memory used to back a File/Blob based on a string."
  },

 
Obviously, there is something wrong with memory-file-data/stream and memory-file-data/string.
They keep growing bigger and bigger, until all system memory is exhausted.

Is there an about:config knob to say
"Don't use more than X MB for memory-file-data storage" ?

What can we do to fix this misbehavior?

As noted in bug 1619604 (High blob memory usage and lags)
I do have a high(?) file-blob-urls count

web (pid 10973)
...
Other Measurements
7,788 (100.0%) -- file-blob-urls

I CCed a few key people from bug 1619604, perhaps they can comment on the memory-gobbling issue.

Flags: needinfo?(felash)

Still following the trail of crumbs:
https://www.reddit.com/r/firefox/comments/meu7tf/memory_leak_while_on_deezer_just_by_clicking_in/

Reporter then opened bug 1701458 (which seems related to this one)

I think bug 1706356 is also relevant.

I had overlooked one important fact (in my bug report) that appears to tie everything together:

3,894.71 MB (90.17%) -- memory-file-data/stream [7788]
3,894.00 MB (92.89%) -- memory-file-data/string [7788]
7,788 (100.0%) -- file-blob-urls

The "memory-file-data/stream", "memory-file-data/string", and "file-blob-urls" counts are identical (7788).

Thus, there appears to be:
Exactly 1 memory-file-data/stream and 1 memory-file-data/string allocated for each file-blob-url.

As a low-level developer, I am not familiar with web technologies and browser APIs.
Are "file-blob-urls" and "memory-file-data" objects explicitly allocated and managed by the API consumer, i.e. a website?
Or are they part of the automatic memory management (and subsequent garbage collection) as in Java?

In other words, are we dealing with a website bug, where memory is continuously allocated, and never freed?
Or is the browser memory manager not automatically releasing stale(?) objects?

In C, the equivalent of the first situation would be a program continuously calling malloc() and never free().
It is not the OS's role to constrain a program's memory use (until memory is exhausted, or some administrative policy dictates otherwise).

As I mentioned before, Blink also has this memory leak problem, so it's more on the Deezer's side of things. Firefox just goes out of memory faster.

Deezer cannot solve this problem. In response to my appeals, I received the following letter from deezer.com:

Our users who had same issue they solved it with these steps:
Deezer is working with :
Protection Firefox : On
Protection DuckDuckGo : On
User-Agent Switcher : default user agent"
Without this workaround, you will still experiencing the problem

But I'm not sure that solves the problem.
In any case, there should be no memory leak and this should be fixed.

The issue was reported for FF 69 (in September 2019) on the Deezer forums (in French)
https://fr.deezercommunity.com/autres-appareils-35/fuite-memoire-firefox-69-0-opera-63-0-ubuntu-18-04-lts-23850

That thread points to an earlier report (in March 2018) for FF 59 (in English)
https://en.deezercommunity.com/other-devices-49/memory-leak-in-browser-and-deezer-desktop-app-9548

(Both threads include a link back to here.)

The message by bytesnz seems interesting to me:
https://en.deezercommunity.com/other-devices-49/memory-leak-in-browser-and-deezer-desktop-app-9548?postid=181788

To summarize both threads: Deezer has been aware of the situation for years,
but fixing the memory issue in the web client appears to be either low-priority or too hard to solve.

(In reply to Mason from comment #26)

In C, the equivalent of the first situation would be a program continuously calling malloc() and never free().

The malloc equivalent here is createObjectURL. File/Blob objects are GCed, but blob: URLs are manually managed (they're basically pointers, except strings instead of integers). It certainly looks like this is the JS/DOM version of a classical memory leak.

But there's something interesting here that I don't think has been commented on yet:

3,894.71 MB (90.17%) -- memory-file-data/stream [7788]
3,894.00 MB (92.89%) -- memory-file-data/string [7788]
7,788 (100.0%) -- file-blob-urls

The /stream and /string values are almost the same, they're siblings in the reporting tree so that should mean separate sets of allocations, and there's one of each per blob URL. Are we storing two copies of each leaked string?

IIRC the Deezer website has an issue especially with Firefox due to how they play their music and the fact Firefox doesn't support DRM with MP3, so they have to do a hack with blob urls, and I believe they don't properly manage to revoke them. I haven't tested lately though, but I believe this should be reported (again) to them.

Flags: needinfo?(felash)

(In reply to Julien Wajsberg [:julienw] from comment #31)

I haven't tested lately though, but I believe this should be reported (again) to [Deezer].

As for testing recently, please see comment #23
Streaming from deezer.com on 2021-10-31 with FF 94 exhausts all memory

As for reporting to Deezer, please see comment #29
Dozens of users have reported the problem, so far Deezer has been unwilling or unable to fix the website.
"Community managers" (I hate that term) keep mentioning an Electron app that will fix the problem...

(In reply to Jed Davis from comment #30)

The malloc equivalent here is createObjectURL. File/Blob objects are GCed, but blob: URLs are manually managed (they're basically pointers, except strings instead of integers). It certainly looks like this is the JS/DOM version of a classical memory leak.

I had promised myself I'd never touch Javascript... but this bug is pushing my buttons.

The solution seems "simple" enough (for some value of "simple")

  1. Find where the code calls createObjectURL()
  2. Figure out where the code should be calling revokeObjectURL()
  3. Inject the call to revokeObjectURL (with something like Greasemonkey?)

I loaded deezer.com in a Web Developper Tools session.
Even when looping a single track, the code downloads the entire track every time.
Thus, a trivial fix would be to revoke() the previous URL every time we create() a new one.

If someone who knows JS is lurking, feel free to jump in, and give me a hand.

https://e-cdns-files.dzcdn.net/cache/js/app-web.ed407a627743a80bca1f.js -- via https://beautifier.io/

createObjectURL() is called from 2 functions:

        nXFM: function(x, C, e) {
            "use strict";
            e("4mDm"), e("07d7"), e("PKPk"), e("3bBZ");
            var t, a = e("tKx9"),
                r = e.n(a),
                c = decodeURIComponent("snip 400 KB obfuscated string"),
                n = {
                    get singleton() {
                        var x = self.URL.createObjectURL(new Blob([c]));
                        return t || (t = new r.a(x))
                    }
                };
            C.a = n
        },

and a more complex one involving... service workers maybe?
(Though mozdoc states "createObjectURL is not available in Service Workers")

            var u = function() {
                function x(C) {
                    var e = this,
                        t = arguments.length > 1 && void 0 !== arguments[1] ? arguments[1] : {};
                    c(this, x);
                    var a, r = o(this),
                        n = i.bind(this),
                        _ = d.bind(this);
                    r.catch = [], r.callbacks = {}, r.ready = new Promise((function(x) {
                        return r.callbacks[-1] = x
                    })), t.fetch ? ((a = new XMLHttpRequest).onload = function() {
                        e.worker = new Worker((self.URL || self.webkitURL).createObjectURL(a.response)), e.worker.onerror = n, e.worker.onmessage = _
                    }, a.onerror = n, a.ontimeout = n, a.responseType = "blob", a.open("GET", C, !0), a.send()) : (this.worker = C instanceof self.Worker ? C : new Worker(C), this.worker.onerror = n, this.worker.onmessage = _)
                }
                return t(x, [{
                    key: "catch",
                    value: function(x) {
                        var C = this;
                        if ("function" != typeof x) throw new TypeError("Invalid argument.");
                        var e = o(this);
                        return e.catch.push(x), e.error && e.catch.forEach((function(x) {
                            return x.call(C, e.error)
                        })), this
                    }
                }, {
                    key: "post",
                    value: function(x, C) {
                        var e = this,
                            t = o(this),
                            a = t.callbacks;
                        return t.ready.then((function() {
                            return new Promise((function(t, c) {
                                var f;
                                a[++_] = function(x, C) {
                                    return x ? c(x) : t(C)
                                };
                                var o = (r(f = {}, n.toString(), _), r(f, "message", x), f);
                                e.worker.postMessage(C ? o : JSON.stringify(o), C)
                            }))
                        }))
                    }
                }, {
                    key: "terminate",
                    value: function() {
                        this.worker.terminate()
                    }
                }]), x
            }();

Hi Mason! Are we thinking of a site intervention here? I assume the component is wrong then, as the defect is not in the DOM: File implementation, IIUC.

Flags: needinfo?(shill)
See Also: 1592169 →

(In reply to Jens Stutte [:jstutte] from comment #35)

Hi Mason! Are we thinking of a site intervention here?
I assume the component is wrong then, as the defect is not in the DOM: File implementation, IIUC.

Hello Jens,

So far, my understanding is that the memory bug is in the javascript code served by deezer.com
(basically, they never call revokeObjectURL() for "stale" createObjectURL() instances)

If by "site intervention", you mean "making Deezer aware that there is a bug in deezer.com",
then I'm afraid to say that it's already been done, see comment #29

In my spare time, I'm trying to write a Greasemonkey script to patch the Deezer javascript at run-time,
but it's quite time-consuming to debug auto-generated minified javascript, moreso because I don't speak JS.

I wouldn't say Firefox is completely in the clear, though. Several users have claimed that Chrome handles
the situation slightly better than Firefox. I have not tested this claim. I'm thinking maybe Chrome manually
swaps to disk least-recently-used memory allocations. That would help a little bit, especially on systems
with only 2 or 4 GB of RAM.

Do you know if FF is able to do that? Or if it's ever been considered?
Or if FF implements other strategies to deal with memory hogs?

Flags: needinfo?(shill) → needinfo?(jstutte)

Hi Karl, is this on the webcompat radar? Should it be?

Flags: needinfo?(jstutte) → needinfo?(kdubost)

Time to time there are issues related to deezer, but seems to have closed them automatically or manually as invalid. Probably because they all require long testing. I went through all the reports from 2019 to now, and I could find this that could be relevant.
https://github.com/webcompat/web-bugs/issues?q=is%3Aissue+deezer+in%3Atitle+is%3Aclosed

#91488 Page loads blank white screen.
#58180 Page loads blank white screen.
#58099 black screen.
#57442 memory full after a few hours of streaming then browser crash
#56064 deezer crashes after a while if you play any music on premium (FLAC) quality
#46195 white page
#46168 browser is too old to work.
#45717 error on login
#44053 Infinity load
#39512 The site do not load, still white.
#30967 Increasing memory usage each time a new song starts with HTML 5 Playe

Flags: needinfo?(kdubost)
Webcompat Priority: --- → P3

Julien just reminded me we had a partner ml for deezer, I just sent them a message.

Following their answer, padenot and I had a closer look at this issue.

  1. we can still reproduce: simply seeking in a track shows a lot of blob objects being retained in the main process.
  2. we added a few breakpoints in the deezer code, and it looks like they're indeed doing the right thing (createObjectURL and revokeObjectURL are called when switching tracks).
  3. But still we see a lot of small blob objects, all with the same size (0.28MB) in the main process.

Tomorrow padenot will look at GC/CC logs see if we can have another clue from that.

Hello :julienw

I'm debugging firefox-95.0b10 (Developer Edition) in gdb:

  1. gdb firefox
  2. source ../symbols.py (download debug symbols for every dynamic library)
  3. run --safe-mode -P deezer-test
  4. break CreateObjectURL (set breakpoints on 8 CreateObjectURL methods)
  5. break RevokeObjectURL (set breakpoints on 3 RevokeObjectURL methods)

However, it seems I never hit any of the 11 breakpoints. I'm confused...

Does anyone know what I'm doing wrong?

I'm not an expert in native code and gdb, but my guess would be that you're not breaking in the right process. If you're in nightly you can find the pid for a tab with its tooltip. I'm not sure how to switch to the right process or break in all processes, maybe some other folks here would know? Or your favorite search engine will know for sure :-)

Doh! Of course... Firefox has been multi-process for a while. Back to lab! :)

As seen in comment #23, after running deezer.com for ~8 hours, about:memory reports:

  • "Main Process" has allocated 3,894.71 MB across 7788 memory-file-data/stream
    NB1: the OS reports only 2810192 kB RSS for this process, I can't explain the discrepancy at this point.
    NB2: memory-report.json reports 2859999232 "resident" bytes for "Main Process", which is consistent with 2810192 kB.
    NB3: each alloc is 524384 bytes (2^19 + 96) and 7788 * 524384 = 4083902592 which is precisely 3894,71 MB (for M=1024)

I attached gdb to a just-started "Main Process" and set a breakpoint in
mozilla::dom::StreamBlobImpl::Create(...) at /builds/worker/checkouts/gecko/dom/file/StreamBlobImpl.cpp:26
(I also set breakpoints in: the other StreamBlobImpl::Create, StringBlobImpl::Create, their respective destructors)

I then played a single song, and jumped around the track about 60 times.

At this point
about:memory reports "332.06 MB (66.70%) ── memory-file-data/stream [664]"
gdb reports "StreamBlobImpl.cpp:26 breakpoint already hit 663 times"
The two numbers match (within the error margin).

Up to this point, I had never hit any destructor breakpoints.
I hit reload on the deezer.com tab, and I immediately hit the StreamBlobImpl destructor:
"destructor breakpoint already hit 1328 times"
NB: 1328 = 664*2 -- no idea at this point why it's doubled.
(I provide one release call stack below for completeness)

Conclusion: it is clear that the deezer.com code allocates StreamBlobs in Main Process,
and never releases them.
Reloading the tab triggers FF to clean up the old tab, and reclaim leaked allocs.

(gdb) bt
#0  mozilla::dom::StreamBlobImpl::~StreamBlobImpl (this=0x7f380aab7880) at /builds/worker/checkouts/gecko/dom/file/StreamBlobImpl.cpp:66
#1  0x00007f38343d0697 in mozilla::dom::BlobImpl::Release (this=0x7f380aab7880) at /builds/worker/checkouts/gecko/dom/file/BlobImpl.cpp:97
#2  mozilla::dom::StreamBlobImpl::Release (this=0x7f380aab7880) at /builds/worker/checkouts/gecko/dom/file/StreamBlobImpl.cpp:17
#3  0x00007f38343d973e in mozilla::RefPtrTraits<mozilla::dom::BlobImpl>::Release (aPtr=0x7f380aab7880) at /builds/worker/workspace/obj-build/dist/include/mozilla/RefPtr.h:50
#4  RefPtr<mozilla::dom::BlobImpl>::ConstRemovingRefPtrTraits<mozilla::dom::BlobImpl>::Release (aPtr=0x7f380aab7880) at /builds/worker/workspace/obj-build/dist/include/mozilla/RefPtr.h:381
#5  RefPtr<mozilla::dom::BlobImpl>::~RefPtr (this=0x7f380ac4e978) at /builds/worker/workspace/obj-build/dist/include/mozilla/RefPtr.h:81
#6  mozilla::dom::DataInfo::~DataInfo (this=0x7f380ac4e970) at /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:49
#7  mozilla::DefaultDelete<mozilla::dom::DataInfo>::operator() (aPtr=0x7f380ac4e970, this=<optimized out>) at /builds/worker/workspace/obj-build/dist/include/mozilla/UniquePtr.h:463
#8  mozilla::UniquePtr<mozilla::dom::DataInfo, mozilla::DefaultDelete<mozilla::dom::DataInfo> >::reset (this=<optimized out>, aPtr=<optimized out>) at /builds/worker/workspace/obj-build/dist/include/mozilla/UniquePtr.h:305
#9  0x00007f3830f6d64f in mozilla::UniquePtr<mozilla::dom::DataInfo, mozilla::DefaultDelete<mozilla::dom::DataInfo> >::~UniquePtr (this=0x7f380aab7880) at /builds/worker/workspace/obj-build/dist/include/mozilla/UniquePtr.h:253
#10 nsBaseHashtableET<nsCStringHashKey, mozilla::UniquePtr<mozilla::dom::DataInfo, mozilla::DefaultDelete<mozilla::dom::DataInfo> > >::~nsBaseHashtableET (this=0x7f38087b3180) at /builds/worker/workspace/obj-build/dist/include/nsBaseHashtable.h:251
#11 nsTHashtable<nsBaseHashtableET<nsCStringHashKey, mozilla::UniquePtr<mozilla::dom::DataInfo, mozilla::DefaultDelete<mozilla::dom::DataInfo> > > >::s_ClearEntry (aTable=<optimized out>, aEntry=0x7f38087b3180) at /builds/worker/workspace/obj-build/dist/include/nsTHashtable.h:720
#12 0x00007f3832f1842e in PLDHashTable::RawRemove (this=0x7f380ae40040, aSlot=...) at /builds/worker/checkouts/gecko/xpcom/ds/PLDHashTable.cpp:576
#13 PLDHashTable::RawRemove (this=0x7f380ae40040, aEntry=<optimized out>) at /builds/worker/checkouts/gecko/xpcom/ds/PLDHashTable.cpp:559
#14 PLDHashTable::RemoveEntry (this=0x7f380ae40040, aEntry=<optimized out>) at /builds/worker/checkouts/gecko/xpcom/ds/PLDHashTable.cpp:553
#15 0x00007f3830f6ce36 in nsTHashtable<nsBaseHashtableET<nsCStringHashKey, mozilla::UniquePtr<mozilla::dom::DataInfo, mozilla::DefaultDelete<mozilla::dom::DataInfo> > > >::RemoveEntry (this=0x7f380ae40040, aEntry=0x7f38382d51b0 <vtable for mozilla::dom::StreamBlobImpl+16>) at /builds/worker/workspace/obj-build/dist/include/nsTHashtable.h:369
#16 nsBaseHashtable<nsCStringHashKey, mozilla::UniquePtr<mozilla::dom::DataInfo, mozilla::DefaultDelete<mozilla::dom::DataInfo> >, mozilla::dom::DataInfo*, nsUniquePtrConverter<mozilla::dom::DataInfo> >::Remove (this=0x7f380ae40040, aKey=...) at /builds/worker/workspace/obj-build/dist/include/nsBaseHashtable.h:521
#17 mozilla::dom::ReleasingTimerHolder::RevokeURI (this=<optimized out>) at /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:490
#18 0x00007f3830f6cd2d in non-virtual thunk to mozilla::dom::ReleasingTimerHolder::Notify(nsITimer*) () at /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:439
#19 0x00007f383377d3dd in nsTimerImpl::Fire(int)::$_1::operator()(nsCOMPtr<nsITimerCallback> const&) const (this=<optimized out>, i=...) at /builds/worker/checkouts/gecko/xpcom/threads/nsTimerImpl.cpp:631
#20 _ZN7mozilla6detail21VariantImplementationIhLm1EJ8nsCOMPtrI16nsITimerCallbackES2_I11nsIObserverEN11nsTimerImpl12FuncCallbackENS7_15ClosureCallbackEEE6matchNIRNS_7VariantIJNS7_15UnknownCallbackES4_S6_S8_S9_EEEZNS7_4FireEiE3$_1JZNS7_4FireEiE3$_2ZNS7_4FireEiE3$_3ZNS7_4FireEiE3$_4EEEDcOT_OT0_DpOT1_ (aV=..., aMi=..., aMs=..., aMs=..., aMs=...) at /builds/worker/workspace/obj-build/dist/include/mozilla/Variant.h:309
#21 _ZN7mozilla6detail21VariantImplementationIhLm0EJN11nsTimerImpl15UnknownCallbackE8nsCOMPtrI16nsITimerCallbackES4_I11nsIObserverENS2_12FuncCallbackENS2_15ClosureCallbackEEE6matchNIRNS_7VariantIJS3_S6_S8_S9_SA_EEEZNS2_4FireEiE3$_0JZNS2_4FireEiE3$_1ZNS2_4FireEiE3$_2ZNS2_4FireEiE3$_3ZNS2_4FireEiE3$_4EEEDcOT_OT0_DpOT1_ (aV=..., aMi=..., aMs=..., aMs=..., aMs=..., aMs=...) at /builds/worker/workspace/obj-build/dist/include/mozilla/Variant.h:318
#22 _ZN7mozilla7VariantIJN11nsTimerImpl15UnknownCallbackE8nsCOMPtrI16nsITimerCallbackES3_I11nsIObserverENS1_12FuncCallbackENS1_15ClosureCallbackEEE6matchNIRSA_ZNS1_4FireEiE3$_0ZNS1_4FireEiE3$_1JZNS1_4FireEiE3$_2ZNS1_4FireEiE3$_3ZNS1_4FireEiE3$_4EEEDcOT_OT0_OT1_DpOT2_ (aVariant=..., aM0=..., aM1=..., aMs=..., aMs=..., aMs=...) at /builds/worker/workspace/obj-build/dist/include/mozilla/Variant.h:902
#23 _ZNR7mozilla7VariantIJN11nsTimerImpl15UnknownCallbackE8nsCOMPtrI16nsITimerCallbackES3_I11nsIObserverENS1_12FuncCallbackENS1_15ClosureCallbackEEE5matchIZNS1_4FireEiE3$_0ZNS1_4FireEiE3$_1JZNS1_4FireEiE3$_2ZNS1_4FireEiE3$_3ZNS1_4FireEiE3$_4EEEDcOT_OT0_DpOT1_ (this=0x7ffdde4cec50, aM0=..., aM1=..., aMs=..., aMs=..., aMs=...) at /builds/worker/workspace/obj-build/dist/include/mozilla/Variant.h:857
#24 nsTimerImpl::Fire (this=0x7f380aa1e6a0, aGeneration=1) at /builds/worker/checkouts/gecko/xpcom/threads/nsTimerImpl.cpp:629
#25 0x00007f3833768e7a in nsTimerEvent::Run (this=0x7f3813d494a0) at /builds/worker/checkouts/gecko/xpcom/threads/TimerThread.cpp:265
#26 0x00007f3832f2c248 in mozilla::RunnableTask::Run (this=0x7f37cd2bad00) at /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:468
#27 mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal (this=0x7f382e94bc30, aProofOfLock=...) at /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:771
#28 0x00007f3832f33958 in mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal (this=0x7f382e94bc30, aProofOfLock=...) at /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:607
#29 mozilla::TaskController::ProcessPendingMTTask (this=0x7f382e94bc30, aMayWait=true) at /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:391
#30 mozilla::TaskController::InitializeInternal()::$_1::operator()() const (this=<optimized out>) at /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:127
#31 mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() (this=<optimized out>) at /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.h:531
#32 0x00007f383376d6c0 in nsThread::ProcessNextEvent (this=0x7f3841ff9f30, aMayWait=<optimized out>, aResult=0x7ffdde4cf258) at /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1175
#33 0x00007f3832f6525a in NS_ProcessNextEvent (aThread=0x7f380aab7880, aMayWait=true) at /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:467
#34 mozilla::ipc::MessagePump::Run (this=0x7f382e926480, aDelegate=0x7f3841f370c0) at /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:107
#35 0x00007f38339dc52d in MessageLoop::RunInternal (this=0x0) at /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:331
#36 MessageLoop::RunHandler (this=0x0) at /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:324
#37 MessageLoop::Run (this=0x0) at /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:306
#38 0x00007f38348e9bb9 in nsBaseAppShell::Run (this=0x7f382e928a50) at /builds/worker/checkouts/gecko/widget/nsBaseAppShell.cpp:137
#39 0x00007f3831e38a71 in nsAppStartup::Run (this=0x7f38293d3100) at /builds/worker/checkouts/gecko/toolkit/components/startup/nsAppStartup.cpp:295
#40 0x00007f3834def54c in XREMain::XRE_mainRun (this=0x7ffdde4cf5e8) at /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5293
#41 XREMain::XRE_main (this=0x7ffdde4cf5e8, argc=<optimized out>, argv=<optimized out>, aConfig=...) at /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5478
#42 0x00007f3831e87343 in XRE_main (argc=0, argv=0x7f3842000020, aConfig=...) at /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5537
#43 0x000055c395b6c035 in _start ()

We've sent an email to Deezer's technical team that explains the issue. It's a simple fix on their end, hopefully deployed quickly.

Hi there, Deezer developer here.
Thanks to your work (especially Mason, :padenot and :julienw) I submitted a patch, it should be deployed tomorrow.
I'll let you know when it's available. Hopefully it'll fix this issue.

Hello :padenot & neovov,

I'm very excited to hear that this long-standing bug is about to bite the dust.
(My phone leaves only ~1 GB of RAM available to apps, thus FF is OOM-killed frequently.)

I'm curious: obviously, the JS served by deezer.com is minified and probably transcompiled.
Did you have access to their original source code, or did you debug the minified mess?

Could you share the technical details of the bug and of the corresponding fix?

I did learn to run FF in gdb along the way, so it was worth it :)

Hi Mason,

I guess Paul digged into the minified code to look for createObjectURL because the memory profiles clearly pointed that way.
He noticed a call for something called get singleton which were wrongly using createObjectURL on each call.

If you want more technical hindsight: It was when the player wanted to decrypt a chunk received from a fetch.
This decryption is done in a WebWorker, which is handled by the code having get singleton.

I simply fixed it by moving the call to createObjectURL so it is used once.
It was indeed a long lasting issue (the commit introducing this leak was merged on may 2017).

Awesome. Thanks!

I pointed out the get singleton call site in comment #34 but I wasn't expecting the problem to be precisely there :)

Attached patch patch — — Splinter Review

For reference, this was the diagnosing patch I used. It prints when a createObjectURL or revokeObjectURL is done, alongside with the type of object for the former, and then it dumps the javascript stack. I then noticed there were precisely three locations for createObjectURL, and only one of the three that was seemingly never revoked.

This dumps the URL of the js file in the stacks, so then I used the devtools to unminify and searched for the only call of createObjectURL in this file, added a breakpoint, and figured out what was slightly off by reading the code.

I'd like to add that we found this location very early when we were looking for createObjectUrl occurrences, but because we focused on media stuff, we ditched that one because it was containing Js code. Only after Paul instrumented the Firefox code that the obvious appeared finally.

Clap clap clap to everyone who participated into resolving this issue. Really cool.

It should be deployed 🎉.
I'd recommend to wait for some users feedback to know if we can close this issue or if there is still other leaks.

(In reply to neovov from comment #55)

I'd recommend to wait for some users feedback to know if we can close this issue or if there is still other leaks.

I will test the two known-leaking use-cases over the week-end:

  1. seeking within a track used to leak on every jump (can test quickly)
  2. listening through a playlist with no user interaction (requires a few hours)
Attached patch app-web.js.diff (obsolete) — — Splinter Review

As for seeking within a track, I jumped 50 times.

Before
I had 306 memory-file-data/stream objects in main process
(Didn't check memory-file-data/string in web process, but I expect 306 as well)

After
I have only 1 memory-file-data/stream (main) and 1 memory-file-data/string (web)
Also, only 1 file-blob-urls

Looking good.

Attached patch app-web.js.diff — — Splinter Review

Snipping the obfuscated string to make the diff more palatable.

Second test:
I started my playlist,
let each song play 3 seconds before skipping to the next song in the playlist,
40 times

Network tool counted 144 MB downloaded (36 tracks, maybe the first 4 were cached)
(I'll do a proper test over the week-end, but I was curious enough for a quickie)

Still only 1 memory-file-data/stream + 1 memory-file-data/string + 1 file-blob-urls

Attachment #9252615 - Attachment is obsolete: true

I tested myself, and I can reproduce the last two comments. Marking as RESOLVED, thanks all!

Status: REOPENED → RESOLVED
Closed: 4 years ago → 2 years ago
Resolution: --- → WORKSFORME

Everything works fine. So many years of glitches and hangs, and finally it's solved ..
Now I can renew my premium subscription to Deezer xD
Thank you all!

Hello Paul,

Did you mark the bug as "WORKSFORME" (rather than "FIXED") because
nothing was checked into the moz source tree to fix it?

Either way, FIXED would have made more sense to me.

Regards.

(In reply to Mason from comment #61)

Did you mark the bug as "WORKSFORME" (rather than "FIXED") because
nothing was checked into the moz source tree to fix it?

Yes.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: