Content sink mMaxTextRun defaults cause unreasonable slowdown

RESOLVED DUPLICATE of bug 57451

Status

()

Core
Layout
RESOLVED DUPLICATE of bug 57451
16 years ago
3 years ago

People

(Reporter: shaver, Assigned: shaver)

Tracking

({helpwanted, perf})

Trunk
x86
Linux
helpwanted, perf
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

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

16 years ago
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.
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?
Assignee: harishd → shaver
Keywords: mozilla0.9, patch, perf, review
Whiteboard: want for 0.9 -- need r=/sr=/a=
Target Milestone: --- → mozilla0.9

Comment 3

16 years ago
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

16 years ago
Patch looks good. r=harishd.
sr=blizzard

Comment 6

16 years ago
a= asa@mozilla.org for checkin to 0.9

Comment 7

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

Comment 8

16 years ago
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

16 years ago
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

16 years ago
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.
Wow!

Comment 12

16 years ago
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.
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.
Status: NEW → ASSIGNED
Keywords: mozilla0.9, review
Whiteboard: want for 0.9 -- need r=/sr=/a=
Target Milestone: mozilla0.9 → mozilla0.9.1

Comment 14

16 years ago
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

16 years ago
Related to bug 57451?

That is about and has more examples of long, simple, pages which take forever to
load.
Looks like it's checked in on the tip.  Did I do that?  I can't recall, but
whatever...FIXED.
Status: ASSIGNED → RESOLVED
Last Resolved: 16 years ago
Resolution: --- → FIXED

Comment 17

16 years ago
Workaround is checked in, problem still exists -> reopening till
reason for slowdown found.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
OK, that's fair.  I'm going to move the research expedition off of 0.9.1, though. =)
Target Milestone: mozilla0.9.1 → mozilla0.9.2

Comment 19

16 years ago
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

16 years ago
Created attachment 37648 [details] [diff] [review]
patch for nsHTMLContentSink.cpp
Asa just told me that we shipped 0.9.2!  Who knew?
Target Milestone: mozilla0.9.2 → mozilla0.9.3

Updated

16 years ago
Target Milestone: mozilla0.9.3 → mozilla0.9.4

Comment 22

16 years ago
->0.9.5 since we have run out of time
Target Milestone: mozilla0.9.4 → mozilla0.9.5

Updated

16 years ago
Blocks: 71668
I don't really know when I will get this done, so I'm removing the lying
milestone marker.
Status: REOPENED → ASSIGNED
Keywords: helpwanted
Target Milestone: mozilla0.9.5 → ---

Updated

16 years ago
Keywords: mozilla0.9.9

Updated

16 years ago
Keywords: mozilla1.0+
Duping the rest on 57541 to clean up.

*** This bug has been marked as a duplicate of 57541 ***
Status: ASSIGNED → RESOLVED
Last Resolved: 16 years ago13 years ago
Resolution: --- → DUPLICATE

Comment 25

13 years ago
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

13 years ago
Reopening for correct dup marking.
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---

Comment 27

13 years ago
Marking as correct dupe

*** This bug has been marked as a duplicate of 57451 ***
Status: REOPENED → RESOLVED
Last Resolved: 13 years ago13 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.