304683 - firefox struggles with large doxygen html file in nsLocalFile::GetLastModifiedTime (from imgLoader)

Status: NEW

(Core :: Graphics: ImageLib, defect)

Description

[Nikolay]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-GB; rv:1.7.10) Gecko/20050717 Firefox/1.0.6
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-GB; rv:1.7.10) Gecko/20050717 Firefox/1.0.6

With the latest version of doxygen (1.4.4) if you have a lot of source code the
resulting html that gets produced makes firefox struggle. IE seems to render the
tree view much quicker. I do not havea a url that reproduces the bug but I will
attach an example html file

Reproducible: Always

Steps to Reproduce:
1.Open attached HTML file and observer how slowly it renders in firefox


Actual Results:  
Firefox too about 10 minutes to render the page

Expected Results:  
Displayed it quicker

Comment 1

[Nikolay]

Attachment: offending html part 1

Comment 2

[Nikolay]

Attachment: offending html part 2

Comment 3

[Boris Zbarsky [:bzbarsky]]

Nikolay, could you possibly attach as a zip file so I can get to it on a
non-Windows system?  If bugzilla won't let you attach it, you can just email it
to [e-mail] (please mention this bug's number in the message subject).

Comment 4

[Boris Zbarsky [:bzbarsky]]

Attachment: Zip file of the HTML involved

Comment 5

[Boris Zbarsky [:bzbarsky]]

Attachment: Zip file of a profile of that pageload

Comment 6

[Boris Zbarsky [:bzbarsky]]

I'll file some bugs blocking this one on the few issues in that profile that I
can fix myself, but here's what things look like:  The page is 18 megabytes of
HTML, almost all of it links and images.  The same several images are used over
and over again.  The profile breaks down as:

Total hit count: 1498127
Of this 1307724 is under CNavDTD::HandleStartToken
  Of this 1175447 is under HTMLContentSink::AddLeaf
    Of this 180133 is under HTMLContentSink::AddAttributes
        and 968168 is under nsGenericElement::AppendChildTo

HTMLContentSink::AddAttributes breaks up as:

              90690 nsHTMLImageElement::SetAttr
              27965 CopyUTF16toUTF8
              22502 NS_NewAtom
              10327 nsHTMLAnchorElement::SetAttr
               5458 nsContentUtils::TrimCharsInSet

nsGenericElement::AppendChildTo breaks up as:

             575019 nsContentUtils::LoadImage
             152904 nsImageLoadingContent::StringToURI
             144782 nsContentUtils::CanLoadImage
              17249 nsCOMPtr_base::~nsCOMPtr_base()

And imgLoader::LoadImage (called from nsContentUtils::LoadImage) has 564152 hits
under it (30+% of the total!) and breaks down as:

             234846 imgCache::Get
             147614 imgRequest::NotifyProxyListener
              83980 imgRequestProxy::AddToLoadGroup
              22921 imgLoader::CreateNewProxyForRequest
              22382 nsEventQueueServiceImpl::ResolveEventQueue
              16878 nsCOMPtr_base::assign_from_gs_contractid_with_error
              14193 nsCOMPtr_base::~nsCOMPtr_base

imgCache::Get breaks down as:

              78728 nsStandardURL::GetFile
              72203 nsCacheSession::OpenCacheEntry
              41748 nsLocalFile::GetLastModifiedTime
               5928 nsStandardURL::GetAsciiSpec
               5892 nsCOMPtr_base::~nsCOMPtr_base
               3167 nsCacheEntryDescriptor::GetCacheElement
               3027 GetCacheSession
               2428 nsCOMPtr_base::assign_from_qi
               2291 gettimeofday

So it looks like anything we can do to make the imglib part of this be not quite
so slow would be a nice win...

Comment 7

[Stuart Parmenter]

Do you have the breakdown for 
             147614 imgRequest::NotifyProxyListener
as well?  Presumably the people that is calling are taking their time as well.

Comment 8

[Boris Zbarsky [:bzbarsky]]

That breaks down as:

              72217 imgRequestProxy::OnStopDecode
              59871 imgRequestProxy::OnStopRequest
               1894 imgRequestProxy::OnStartDecode

OnStopDecode is almost all taken up by nsImageLoadingContent::FireEvent (firing
the onload event).  About half of that is just getting the event queue to stick
the PLEvent into.  :(

OnStopRequest is almost all in nsLoadGroup::RemoveRequest which involves sending
progress notifications, etc, etc.

Comment 9

[Nikolay]

I have tried opening the same page on firefox 1.5 which has just come out and it seems to me that things have gotten worse. I had to kill firefox after 15 minutes of 100% CPU usage and no progress.

Comment 10

[nivtwig]

I can confirm that the bug is still there - it still loads very very slowly (several minutes at least) for Firefox 3.5 RC1 .

Comment 11

[Boris Zbarsky [:bzbarsky]]

It's really not worth retesting until the bugs blocking this are fixed...

Comment 12

[Mayank Bansal]

Nightly: https://share.firefox.dev/3AiKFW3 (14s wallclock)
Chrome: https://share.firefox.dev/4dN2Ku1 (3.5s)

Comment 13

[Emilio Cobos Álvarez [:emilio]]

It seems it's mostly nsLocalFile::GetLastModifiedTime in imgLoader. I wonder if bug 1812488 makes it better.

Comment 14

[Julien Wajsberg [:julienw]]

The Performance Impact Calculator has determined this bug's performance impact to be medium. If you'd like to request re-triage, you can reset the Performance Impact flag to "?" or needinfo the triage sheriff.

Platforms: [x] Windows [x] Linux
Impact on site: Causes noticeable jank
Page load impact: Severe
Websites affected: Rare
Resource impact: Some
[x] Able to reproduce locally

Comment 15

[Julien Wajsberg [:julienw]]

Loading from network is slow (but similar to chrome).
Loading from the local filesystem is way worse.
I'm puzzled by the fact we seem to spend so much time on reading png files.

Comment 16

[Julien Wajsberg [:julienw]]

New profile when loading from my filesystem: https://share.firefox.dev/4g5aj1b
New profile when loading from a local python simple server: https://share.firefox.dev/4e4RauV