77540 - Content sink mMaxTextRun defaults cause unreasonable slowdown

Status: RESOLVED DUPLICATE of bug 57451

(Core :: Layout, defect)

Description

[Mike Shaver (:shaver emeritus)]

Tomi reports that setting the pref
  user_pref("content.maxtextrun", 8191);
results in substantial speedup when loading large pages ("8mb file loads in
44sec in default, with 8191 it takes 5sec").

The default is 8192, which leads me to speculate wildly: are we possibly sending
8192+trailing-NUL==8193 characters to something with a default buffer sized to
8192, resulting in it being reallocated and copied?

I tried to poke around in the nsHTMLContentSink code, but got sufficiently
confused by the recursion in FlushText that I decided to just file this for now.

Seems like an easy win, and I can't imagine that small pages will suffer unduly
for having one fewer character flushed into a text node every time.  (Do we then
aggregate text nodes later?  Seems like we would, and so I wonder if there's not
an even better fix that will let us avoid that sort of aggregation cost later as
well.  But now I'm just talking.)

Comment 1

[Tomi Leppikangas]

Here is my results with 87000 line <pre> html page (~8MB) loaded
from local disk (file:///tmp/test.html):

16384 69.021
9000  42.615
8200  42.406
8193  42.159
8193  42.013
8192  42.033
8192  42.036
8191  8.731
8191  8.725
8000  8.707
8000  8.726
7000  8.666
7000  8.694
4096  8.678
4096  8.673
4095  8.657
4000  8.675
1024  9.031

First number maxtextrun and second page load time from statusbar.

Comment 2

[Mike Shaver (:shaver emeritus)]

I'm going to take this bug, and try to get it in 0.9.

Here's my offering:

Index: nsHTMLContentSink.cpp
===================================================================
RCS file: /cvsroot/mozilla/content/html/document/src/nsHTMLContentSink.cpp,v
retrieving revision 3.437
diff -u -r3.437 nsHTMLContentSink.cpp
--- nsHTMLContentSink.cpp	2001/04/24 23:59:45	3.437
+++ nsHTMLContentSink.cpp	2001/04/25 15:49:41
@@ -2393,7 +2393,9 @@
     prefs->GetIntPref("content.notify.interval", &mNotificationInterval);
   }
 
-  mMaxTextRun = 8192;
+  // Changed from 8192 to greatly improve page loading performance on large
+  // pages.  See bugzilla bug 77540.
+  mMaxTextRun = 8191;
   if (prefs) {
     prefs->GetIntPref("content.maxtextrun", &mMaxTextRun);
   }

Asa has said that he'll approve if I get r and sr.  Harish, can you help me out?

Comment 3

[Tomi Leppikangas]

Here is numbers over network with http without mem and disc-caches:
(http://www.student.oulu.fi/stats/Jan.wwwstats.html (~5MB))

8192  15.466
8192  15.817
8192  15.81
8191  9.83
8191  10.24
8191  9.874

Comment 4

[harishd]

Patch looks good. r=harishd.

Comment 5

[Christopher Blizzard (:blizzard)]

sr=blizzard

Comment 6

[Asa Dotzler [:asa]]

a= [e-mail] for checkin to 0.9

Comment 7

[chris hofmann]

put on the 0.9.1 trunk and we can pull to the branch later.
trying to get branched today.  - thanks

Comment 8

[Chris Waterson]

Nice find! On Win32, I can confirm a 3x speedup on the test case you've 
provided. Haven't tried others.

So, I'm trying to figure out *why* this happens, and am stepping through the, 
um, creative use of recursion in SinkContext::FlushText(). It looks like with 
the buffer set at 8192, we end up oscillating back and forth between firing the 

  if ((mLastTextNodeSize + mTextLength) > mSink->mMaxTextRun) {
    ...
  }

code and the ``else'' case of this same statement. With the buffer set to 8,191, 
we only ever trip the ``if'' condition, and never fall into the ``else'' case. 
When we oscillate, we initialize the text value with ~4000 characters, and then 
we append another ~3000. When we don't oscillate we just set the text node's 
text and are done with it.

Worse, when we append text, it turns out that we fall in to 
nsGenericDOMDataNode::AppendData() (because nsTextNode doesn't have an 
implementation of this method). The text node tries to store text as single-byte 
(see below), but nsGenericDOMDataNode just blats it all as double byte. So, when 
we oscillate, we end up using twice as much memory! Bottom line: nsTextNode 
needs to implement of AppendData() directly.

For kicks, I ended digging in to nsTextNode::SetText() anyway, which led me to 
nsTextFragment::SetTo(). This routine looks like it could use a bit of love. 
Specifically,

- we scan the entire string once to determine if we need to use a
  double-byte buffer. (Which sorta means that we're going to end up
  in a worst-case situation, since most web pages are probably 7-bit
  ASCII.)

  - Since we've probably scanned the string two or three times
    by this point, the caller could probably pass this information
    in.

  - Or, if we can't do that, then maybe we could optimisitcally
    allocate a single-byte buffer and start copying, and then
    fault and restart if it ends up being double-byte.

  - Or, pessimistically allocate a double-byte buffer and realloc()
    it to a smaller size if we get lucky and end up with a single-byte
    string?

- Why do we need our own implementation of memcpy() in SetTo()? Why
  not use the one provided with the standard library, as it's likely to
  be hand-optimized.

Comment 9

[Chris Waterson]

Filed bug 77585 on nsTextNode::AppendData(), bug 77586 on 
nsTextFragment::SetTo() issues. They're both assigned to jst, who 
unfortunately probably won't have time to deal with these issues.

Comment 10

[Chris Waterson]

FWIW, I bet the off-by-one has something to do with the fact that 
SinkContext::AddText() allocates a buffer that's 4096 characters big.

Comment 11

[Johnny Stenback (:jst)]

Wow!

Comment 12

[Tomi Leppikangas]

I did some partial profiling in content, here is what changes most:
8192     8191   diff     func
--------+------+--------+-----------------------------------------------------
38192858 555259 37637599 nsTextNode::AddRef(void)
38104619 465317 37639302 nsTextNode::Release(void)
37738160 90765  37647395 nsGenericDOMDataNode::GetBindingParent(nsIContent **)
37738160 90765  37647395 nsTextNode::GetBindingParent(nsIContent **)

Numbers are callcounts. That is 37 *million* calls more. Document only
is same 87000 line, 8MB.

Comment 13

[Mike Shaver (:shaver emeritus)]

Checked in on the branch.  When my tip build completes, I'll check it in there,
as well, though I think I will leave this bug open to track the recent findings.
 There's more going on here than just an unlucky constant, obviously.

Comment 14

[James Green]

Was this bug intended to speed up pages such as
http://cvsbook.red-bean.com/cvsbook.html which, loaded from a local file store,
take 10 seconds and more (with the patch as it is on the tip)? It doesn't appear
to have made any noticable difference on that file.

Comment 15

[Andrew Thompson]

Related to bug 57451?

That is about and has more examples of long, simple, pages which take forever to
load.

Comment 16

[Mike Shaver (:shaver emeritus)]

Looks like it's checked in on the tip.  Did I do that?  I can't recall, but
whatever...FIXED.

Comment 17

[Tomi Leppikangas]

Workaround is checked in, problem still exists -> reopening till
reason for slowdown found.

Comment 18

[Mike Shaver (:shaver emeritus)]

OK, that's fair.  I'm going to move the research expedition off of 0.9.1, though. =)

Comment 19

[Tomi Leppikangas]

I looked this a bit and had really hard time trying to follow logic
in SinkContext::AddText and SinkContext::FlushText. I tryed to
make it cleaner and come up with following patch. I did some timing
with and get thease resulst:
87000 line <pre> document:
Run  without patch      with patch
---+------------------+----------
1    17.6 sec           16.4 sec
2    17.9 sec           16.4 sec
3    17.5 sec           16.3 sec

Comment 20

[Tomi Leppikangas]

Attachment: patch for nsHTMLContentSink.cpp

Comment 21

[Mike Shaver (:shaver emeritus)]

Asa just told me that we shipped 0.9.2!  Who knew?

Comment 22

[chris hofmann]

->0.9.5 since we have run out of time

Comment 23

[Mike Shaver (:shaver emeritus)]

I don't really know when I will get this done, so I'm removing the lying
milestone marker.

Comment 24

[Mike Shaver (:shaver emeritus)]

Duping the rest on 57541 to clean up.

*** This bug has been marked as a duplicate of 57541 ***

Comment 25

[Stefan Seifert]

There is a typo in resolving this bug: I'm sure it was intended to be duped of
bug 57451 (Extreme slowness when loading long pages of text from disk) instead
of 57541 (The themes pane in the preferences window doesn't display the "Apply
them" button correctly. BUILD ID: 2000101014)

Comment 26

[Keyser Sose]

Reopening for correct dup marking.

Comment 27

[Keyser Sose]

Marking as correct dupe

*** This bug has been marked as a duplicate of 57451 ***