1591214 - Firefox hangs after waking from sleep

Status: RESOLVED WORKSFORME

(Core :: General, defect, P3)

Description

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Sample of Firefox Nightly.txt

This bug is for crash report bp-53c94505-18ec-4e01-9b84-425eb0191024.

Top 10 frames of crashing thread:

0 libmozglue.dylib Allocator<MozJemallocBase>::malloc_usable_size memory/build/mozjemalloc.cpp:4116
1 libsystem_malloc.dylib malloc_size 
2 liboainject.dylib liboainject.dylib@0x17d3 
3 liboainject.dylib liboainject.dylib@0x2e76 
4 libsystem_malloc.dylib malloc_zone_malloc 
5 CoreFoundation __CFStringCreateImmutableFunnel3 
6 CoreGraphics CGRectInset 
7 CoreGraphics color_space_state_retain 
8 XUL mozilla::gfx::DrawTargetSkia::DrawGlyphs gfx/2d/DrawTargetSkia.cpp:1275
9 XUL GlyphBufferAzure::FlushGlyphs gfx/thebes/gfxFont.cpp:1652

After my MacBook fall into sleep for a while, Firefox was totally unresponsive when waking it up again. The opened tab was IRCCloud. When checking the Activity monitor Firefox was constantly allocating memory. It started by around 3GB and went up to 18GB. Finally it crashed due to an OOM situation.

During that time I recorded a sample via the Activity Monitor. See the attachment. Maybe it is helpful to further diagnose the problem.

As it looks like by checking the stack of the crashing thread it seems to be a graphics related problem. Note that I don't have webrender enabled.

Comment 1

[Markus Stange [:mstange]]

Yeah, the crash happened in Graphics, because that's where we actually ran out of memory. But the sample you attached is showing a GC. Is it possible that IRCCloud JavaScript allocated all that memory? Was it displaying a channel with tons of messages?

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I cannot exactly say in which channel I was last. But my suspicion is #selenium on Freenode. So it has at least a lot of messages, but it's not comparable to #developers on our server.

What I forget to note is that the memory consumption dropped twice in-between. So maybe this recording is exactly from such a time when the GC run, and parts of the memory usage was reset.

Due to the unresponsiveness I was not able to check anything inside of Firefox (profiler, about:performance, etc).

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: 2nd sample of Firefox Nightly without crash

I had a similar behavior today with Firefox Nightly when I woke up my machine from sleep. Firefox was immediately behaving slowly, and then again no reaction for user input or very delayed. I tried to create a gecko profile and maybe was successful, but the addon wasn't able to upload it to profiler.firefox.com. Not sure if that file is still present somewhere on my local disk? Maybe Julien can help here so that I could still submit it.

Note that this time the memory allocation stopped at 7GB, and that I tried to create a sample without having the GC being active. As what I can see here is that it seems that code for the network cache is taking up a lot of CPU. Note that also the activity monitor shows that all the CPU load is for the main process. So I it cannot be IRCCloud which would run in a content process, right?

Comment 4

[Julien Wajsberg [:julienw]]

We don't ever store the profile on local disk if you don't manually "save" it from the profiler UI.
We do have a project to store it locally in indexeddb, but it's not done yet, and anyway it will be only after it's been imported in the UI, so not sure it would have worked in your situation.
Sorry :(

Comment 5

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Hm, ok. :( Markus could you have a look at the newly attached sample? Is there anything helpful in there right now?

Comment 6

[Markus Stange [:mstange]]

This looks similar to bug 1551990.

It looks like we're hanging because we're calling nsHttpChannel::OnProxyAvailable on a very large number of channels. Honza, mind taking a look?

(I'm renaming this bug because the crash looks very unrelated to the hang, and this bug is about the hang.)

Comment 7

[Honza Bambas (:mayhemer)]

(In reply to Markus Stange [:mstange] from comment #6)

This looks similar to bug 1551990.

It looks like we're hanging because we're calling nsHttpChannel::OnProxyAvailable on a very large number of channels.

Where do you see this?

looking at 2nd sample of Firefox Nightly without crash it looks like we are delayed on moving callbacks stored in nsTArray in the HTTP cache code. It suggests we are opening a lot of requests to the same URL by the content process while the parent process is asleep. The original bug with powernap is still not fixed, apparently.

I can file a separate bug for optimizing somehow the callback array in HTTP cache, if easy. If not, I would give it a P3 (aka never work on it) as this is such an edge case. Usually there is just one callback in the array.

I think the whole platform is in a bad shape when something like this happens.

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Moving the bug to general until it's clear which component is really belongs to, or if different situations are covered by this meta bug.

Comment 9

[BugBot [:suhaib / :marco/ :calixte]]

Bugbug thinks this bug should belong to this component, but please revert this change in case of error.

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Sample of Firefox Nightly.txt

I've had the same situation again today when waking up my MBP from hibernation mode. The overall memory of the machine was all used and only 200MB of free memory remaining. Firefox was not responding even not after a couple of minutes. Attached you can find a sample of the Activity monitor.

After freeing up more memory by closing other applications I put the machine into sleep again, just to check what happens after the next wake-up. And by surprise the hang didn't appear anymore. So maybe this is related to low memory when waking up the machine?

Comment 11

[Andrew McCreight [:mccr8]]

That's kind of a strange sample. It looks like the topmost thing is the method Dump (from mozJSComponentLoader). I think that means some chrome JS is calling the dump() method.

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Note that this is still my DMD build. If it is related to dumping to the console maybe the automatic forced quit of the terminal application by MacOS due to the overall less memory available is responsible for that? Or shouldn't it matter if the console is gone?

Comment 13

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 9123616 [details]
Sample of Firefox Nightly.txt

This seems to be indeed different and not tied to the sleep mode. I filed bug 1612786 for that.

Comment 14

[Gabriele Svelto [:gsvelto]]

Came here from a Twitter thread where a user was having a problem similar to comment 10. My guess is that if the computer comes up from sleep and Firefox thinks it's been on for 24 hours straight it will send an idle-dailyevent (see the nsIdleService). Some of the activities triggered by idle-daily involve expiring old entries from the databases (such as places). In the machine I'm using now - which is not my main machine - places.sqlite is 125MiB so my guess is that it can be quite large. I don't know how purging works but if we're loading the entire database in memory in a non-compact form that might be the cause. This is just a guess, it could also be any of the other idle-daily listeners.

Comment 15

[BugBot [:suhaib / :marco/ :calixte]]

Closing because no crashes reported for 12 weeks.