Extremely slow image load - MessagePumpForNonMainThreads may delay events for minutes

RESOLVED WORKSFORME

Status

()

defect
--
major
RESOLVED WORKSFORME
5 years ago
23 days ago

People

(Reporter: mayhemer, Assigned: mayhemer)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

(Assignee)

Description

5 years ago
m-c@caefe18d7ffe + few local changes (unrelated), opt build, win7.

Loading a page with 5 images each having ~5 MB (jpgs).  Loading from the HTTP cache (content valid).


Problem: the 5 images load all extremely slowly.


Reason is that the MessagePumpForNonMainThreads from some reason doesn't process events immediately when they are dispatched to the target thread (here the ImageDecoder), in this case data-availability event from Cache I/O thread to ImageDecoder threads.

In the log search for "NotifyChunkListenerEvent::NotifyChunkListenerEvent" that is dispatched from IO thread to the Image thread.  "NotifyChunkListenerEvent::Run" then is logged when the even is actually run.

(Checked this is NOT an HTTP cache bug)


Filtered log snippet (68ed4a0, 195eaf20) of "timestamp,threadnames,cache2:5,nsThread:5" :

2014-07-03 21:14:59.992000 UTC - [Cache2 I/O] 5196[911360]: CacheFile::NotifyChunkListener() [this=195fc540, listener=13ba6f68, target=68ed4a0, rv=0x00000000, idx=10, chunk=a35c740]
2014-07-03 21:14:59.992000 UTC - [Cache2 I/O] 5196[911360]: NotifyChunkListenerEvent::NotifyChunkListenerEvent() [this=195eaf20]
2014-07-03 21:14:59.992000 UTC - [Cache2 I/O] 5196[911360]: THRD(68ed4a0) Dispatch [195eaf20 0]

delay of more then 1 minute...

2014-07-03 21:16:02.485000 UTC - [ImageDecoder #7] 4304[72af0c0]: THRD(68ed4a0) ProcessNextEvent [0 0]
2014-07-03 21:16:02.485000 UTC - [ImageDecoder #7] 4304[72af0c0]: THRD(68ed4a0) running [195eaf20]
2014-07-03 21:16:02.485000 UTC - [ImageDecoder #7] 4304[72af0c0]: NotifyChunkListenerEvent::Run() [this=195eaf20] 


The stack the event is run at is:

 	xul.dll!mozilla::net::NotifyChunkListenerEvent::Run() Line 91	C++
 	xul.dll!nsThread::ProcessNextEvent(false, 0x230ff75f) Line 768	C++
 	xul.dll!NS_ProcessNextEvent(0x018ed4a0, false) Line 284	C++
	xul.dll!mozilla::ipc::MessagePumpForNonMainThreads::Run(0x0a380140) Line 337	C++
 	xul.dll!MessageLoop::RunHandler() Line 223	C++
 	xul.dll!MessageLoop::Run() Line 197	C++
 	xul.dll!nsThread::ThreadFunc(0x068ed4a0) Line 357	C++
 	nss3.dll!_PR_NativeRunThread(0x0a37c3d0) Line 419	C
 	nss3.dll!pr_root(0x072af0c0) Line 90	C
(Assignee)

Comment 1

5 years ago
I'll expose the test case on my web and link here.
(Assignee)

Comment 2

5 years ago
Test case:
http://janbambas.cz/moz/bug1034309/

Make sure the images all go from cache (304 or even unvalidated cache load), load the page once and then F5 will do.
(Assignee)

Comment 3

5 years ago
Any idea?
Flags: needinfo?(bent.mozilla)
Nothing off the top of my head. We use this pump on all threads now so if there is a race it's somehow not a very common one or we would have seen this before now.
Flags: needinfo?(bent.mozilla)
(Assignee)

Comment 5

5 years ago
Looks I have to look at this...
Assignee: nobody → honzab.moz
(Assignee)

Updated

5 years ago
See Also: → 1042192
Comment hidden (obsolete)
Comment hidden (obsolete)
(Assignee)

Comment 8

3 years ago
Haven't seen this for a while.
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.