64858 - 2666 seconds to load large page.

Status: NEW

(Core :: Layout: Images, Video, and HTML Frames, defect, P4)

Description

[Jamie Manley]

Running Redhat 7.0 w/errata here + kernel 2.4.0.  This was a problem with
2.2.x/mozilla 0.6 as well.  Machine is a 750Mhz PIII with 512 MB ram available,
NS 4.x loaded the page in seconds (cable modems rule :).

Comment 1

[R.K.Aa.]

Please always include build ID in bug-reports.

Comment 2

[Jamie Manley]

All versions since I first discovered the site a few months ago :)

Currently running 2001010517

Comment 3

[R.K.Aa.]

i tested the site  w/2001-010908 and it froze several times during load, till i
finally killed moz from commandline. Also some weird blinking in between freezes.

The html file in question is around 1.4MB and contains 2 unique small gifs.
One called buyit.gif is repeated 1418 times.
The other, called Photo.gif, is repeated 868 times.

I thought there was an open imagelib bug about this but couldnt find it.
Changing component.

Comment 4

[R.K.Aa.]

confirming for now.

Comment 5

[pnunn]

All pnunn bugs reassigned to Pav, who is taking over
the imglib.

Comment 6

[Chris Waterson]

Taking. Will profile and get back to you.

Comment 7

[Hixie (not reading bugmail)]

It's not imagelib related. I removed the images and the problem still exists:
   http://www.damowmow.com/mozilla/bugs/slow/002.html
Waterson says it might be a dup of bug 56854.

Comment 8

[John Morrison]

And hey, as an added bonus, because of this line: 

  <META content="text/html; charset=windows-1252" http-equiv=Content-Type>

we load the 2MB document twice!  (see bug 78018).

Comment 9

[John Morrison]

Sorry, that line is in a copy of the file that waterson gave to me. The 
original url states 'us-ascii' (although that also triggers the double fetch).

Comment 10

[Chris Waterson]

Okay, this is pretty funny. The main body of the page loads reasonably quickly
on a fast machine (and is probably network bound). But with hixie's version of
the page, you can actually _watch_ the |alt| text for the <image> tags being
popped in, one by one. For an exciting effect, scroll to the bottom of the page
and watch it slowly jiggle downwards; if you're lucky, you can scroll back up,
and find (and follow!) the point where the |alt| text is popping in at a rate of
about two or three <img> tags per second!

Anyway, I'm not too worried about this bug, as the browser appears to be
completely usable during the page load time (it's not ``hung'', IOW). I'm gonna
push this out to future, and we can investigate making the replaced elements
work faster later...

Comment 11

[Hixie (not reading bugmail)]

On the same machine, we take a LOT longer than IE to get to the end of the page.
Thus I would suggest this is not bound by the network itself (although I'm not
saying it's not bound by Necko, that's another story altogether...).

Waterson: Did you ever profile this page? It would be interesting to know where
most of the time is spent.

Comment 12

[David Baron :dbaron:]

I profiled the first few minutes of the load of Ian's testcase.  It shows some
of our O(N^2) algorithms nicely.

About 3/4 of the time is spent within nsBlockReflowState::RecoverStateFrom.

About 14% is within other parts of reflow:
  About 4% is within nsFrame::Invalidate.
  Includes the following (excluding descendants, of 48300 counts total):
    386  nsBlockFrame::ReflowDirtyLines(nsBlockReflowState &)
    331  nsBlockFrame::BuildFloaterList(void)
    323  nsLineBox::GetCombinedArea(nsRect *)
    261  nsBlockFrame::RecoverStateFrom(nsBlockReflowState &, nsLineBox *, ...
    232  nsLineBox::IndexOf(nsIFrame *) const


About 3% is within PresShell::GetPrimaryFrameFor (from within
PresShell::ContentAppended)

About 1% is within nsImageFrame::LoadImage.

About 1% is within style resolution (within nsStyleSetImpl::WalkRuleProcessors).

Slightly under 1% is in the gettimeofday call in nsCacheEntry::Fetched.

Comment 13

[Chris Waterson]

No, I didn't profile. As is, I'm not sure I'm going to get all that much useful
information from profiling because _so_ much time appears to be spent _after_
the main body of the page has loaded substituting the |alt| text for <img> tags.
Could I implore upon you to create a new version with the <img> tags stripped
from the test case? I could certainly profile that...

Comment 14

[Chris Waterson]

> About 3/4 of the time is spent within nsBlockReflowState::RecoverStateFrom.

This is certainly covered under bug 56854 or one of its dependents (maybe bug
78911 is most appropriate). The interesting thing about this test (as far as I'm
concerned, anyway) is humorous way in which we ploddingly replace the |alt| text
(although I suspect that most of this time is also spent in |RecoverStateFrom|).

Comment 15

[Hixie (not reading bugmail)]

Waterson: no need to implore! :-)
   http://www.damowmow.com/mozilla/bugs/slow/002-no-img.html

Comment 16

[Boris Zbarsky [:bzbarsky]]

At this point, the top caller in the flat profile is
nsSpaceManager::GetFrameInfoFor()

Comment 17

[Markus Hübner]

Is this bug somewhere depending on bug 78911 or bug 90725?

Comment 18

[Boris Zbarsky [:bzbarsky]]

Attachment: Zipped up testcase with <img> tags (all broken)

Comment 19

[Boris Zbarsky [:bzbarsky]]

Attachment: Same, but without <img> tags

Comment 20

[Boris Zbarsky [:bzbarsky]]

On those testcases, I see the following times:

Trunk:
  images: 32379
  no images: 29045
Reflow branch:
  images: 25194
  no images: 15233
Reflow branch with proposed changes for bug 349113
  images: 20635
  no images: 13539
Opera 8.5:
  images: 12936
  no images: 10696

Should retest and reprofile once reflow branch lands.

Comment 21

[Boris Zbarsky [:bzbarsky]]

Reflow branch with the patches for bug 349113 and bug 349200 gives me about 15s times on the "img tags" testcase.