66516 - Further adventures in page loading times (beyond style resolution)

Status: VERIFIED FIXED

(SeaMonkey :: General, defect)

Description

[John Morrison]

The page loading times for Mac and Linux, increased over and above
known problems with style resolution and another XP bug that affected
page load times for one page in a known way (see below for details).

Overall, Mac page load times are now averaging ~7800msec, up from
~6300msec on Monday and Tuesday, and ~5500msec last week. 
Linux is up to ~6800msec, up from ~5300msec on Tuesday, and ~4500 last
week.

There isn't yet a verification build that includes the backout of 
the style resolution problem code, but twalker will be running that
build in the morning. Unless this is a transient build problem with
the builds I tested, I expect that tomorrow's tests for Mac and Linux
will still show an increase over times for last week.

[Tracy: can you update this bug with a copy/paste of the first row of
the table from the Mac test tomorrow, the line "All Pages"].

I don't know who to assign this to, so I pick me for now. CC: some folks
in general in the interim, if they want to have a look at recent checkins 
that may have affected Mac and Linux (but apparently not win32).

Details from post to porkjockeys/performance: 
-----

An updated time series: 

1) The times for 01/24/2001 are for builds before the style checkin
   was backed out (with the exception of windows which has times for
   both the am and the pm build (post backout)). In general, the time
   on windows _has_returned_ to the level of previous tests.

2) However, today's builds on all platforms were affected by 
          http://bugzilla.mozilla.org/show_bug.cgi?id=63750
   a.k.a. http://bugzilla.mozilla.org/show_bug.cgi?id=52798
   where slashdot.org gets into a state where layout oscillates
   with multiple fetches of the same image from the server, and 
   finally completes page load in >20s. I cancel a page load if
   it takes >30s, but in this case, that 20s number is included 
   in the overall average (increasing the average load time by 
   >400msec). Not sure how to deal with it otherwise.

3) Over and above the effect of the style checkin, and the effect of
   the slashdot page, Mac times and Linux times are showing an
   additional increase from Monday and Tuesday. 

   I re-ran this today's Mac build two more times with similar
   numbers, and re-ran yesterday's Mac build and I can reproduce the
   increase. [e.g., machine and profile are the same but today's build
   is slower than yesterday's]. I also ran the Linux test again, back
   to back, same machine, same profile (but emptied cache), dormant
   server and quiet network, and there's a clear difference (unless of
   course, I'm wrong, which is of course, conclusion #2).

Comment 1

[John Morrison]

Attachment: results of page load tests up to 01/24

Comment 2

[John Morrison]

Attachment: results of page load tests up to 01/25; times still elevated.

Comment 3

[John Morrison]

Times are lower after the backout of code for 

 1) http://bugzilla.mozilla.org/show_bug.cgi?id=66263

but are still up from last week, due to:

 2) http://bugzilla.mozilla.org/show_bug.cgi?id=63750, but that is 
    not of major concern (affects one page in a quirky way).

 3) http://bugzilla.mozilla.org/show_bug.cgi?id=66516, which only 
    (apparently) affects mac and linux, but don't know much else 
    about the reason for the slowdown.

Comment 4

[Chris McAfee]

perf keyword

Comment 5

[Darin Fisher]

Looks like minus the style checkin, there is still about a 400-500ms increase that
is unaccounted for.  I am in the process of comparing load times with and without
my necko changes made on 1/23 around 2pm PST.

Comment 6

[Darin Fisher]

It looks like about 1200-1300ms still unaccounted for under linux and mac.

Comment 7

[chris hofmann]

adding top perf

Comment 8

[Darin Fisher]

I've identified a 500ms slowdown (on linux) in my changes from 1/23.  I'm not sure
yet whether or not it is my changes that can account for the other 700-800ms.

Comment 9

[Darin Fisher]

Comparing today's trunk with today's necko vs. pre-1/23's necko, I see a ~900ms
slowdown.  I have been able to account for ~500ms of this, and I am working on
a patch for this.  But, I am still in the process of tracking down the cause of
the other ~400ms.

But, my changes aside, there still seems to be about a 300-400ms slowdown
elsewhere in the code.

-> assigning to myself, setting target as 0.9 (hopefully to land much sooner
though).

Comment 10

[Chris Waterson]

See attinasi's post to n.p.m.seamonkey

  news://news.mozilla.org/[e-mail]

which indicates there may be some other slowdowns in layout...

Comment 11

[Darin Fisher]

There are two contributors to the slowdown.

1) My patch made it so that writing data to the socket requires posting a
message back to the client of the socket transport.  This contributes about
1/2 of the slowdown.

2) The other 1/2 results from the fact that I am only trying to read from the
socket if PR_Poll sets PR_POLL_READ.  Previously, we tried to read every chance
we got.

I am close to having patches for these.

Comment 12

[Darin Fisher]

I am waiting for dougt's branch to land before finalizing my fix.

Comment 13

[chris hofmann]

dougt's branch has landed, right?

Comment 14

[Doug Turner (:dougt)]

The branch has landed, yes.

Comment 15

[Darin Fisher]

Added keyword nsbeta1.

Comment 16

[Darin Fisher]

Attachment: Fixes performance regression in necko.

Comment 17

[Darin Fisher]

My patch does three things:

1) It allows a nsIStreamProvider's OnDataWritable to be run on the socket
transport thread.  This happens automatically if a client uses
NS_AsyncWriteFromStream().

2) It eliminates any need to copy the data to a temporary buffer before writing
it to the socket.  Previously (and even before my 1/23 landing) it was necessary
to read the source into a temporary buffer and then flush that data to the
socket when possible.  This buffer copy can be avoided by calling ReadSegments
on the source nsIInputStream.

3) Removes the call to PR_Available on the socket, in favor of a fixed value
of 8192 (as was previously the case before my 1/23 landing).  This effectively
means, read as much as you can (not exceeding 8k).  This has no direct effect
on clients of the socket transport.

Comment 18

[Darin Fisher]

nominating for mozilla 0.8.1

Comment 19

[Brendan Eich [:brendan]]

Still looking at the patch, wondered about the unconditional QI of listener:

+            if (!(aFlags & nsITransport::DONT_PROXY_STREAM_PROVIDER)) {
+                rv = NS_NewStreamListenerProxy(getter_AddRefs(listener),
+                                               aListener, nsnull,
+                                               mBufferSegmentSize,
+                                               mBufferMaxSize);
+                observer = do_QueryInterface(listener);
+            }

Won't do_QueryInterface crash on a null pointer?

/be

Comment 20

[Darin Fisher]

brendan: good catch... thanks!

Comment 21

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

do_QueryInterface handles null pointers safely.  See nsCOMPtr.cpp line 30
(nsQueryInterface::operator() returns NS_ERROR_NULL_POINTER if |!mRawPtr|) and
nsCOMPtr.h line 970 (nsCOMPtr<T>::assign_from_helper assigns 0 if helper fails).

Comment 22

[Brendan Eich [:brendan]]

dbaron: thanks, good to know (I should have checked).  It simplifies the code in
callers, as in darin's patch.

/be

Comment 23

[Scott MacGregor]

cool. i like these changes. esp. the part about controlling whether a proxy is made.

sr=mscott

Comment 24

[Darin Fisher]

dougt gave me some suggestions for improving the comments in nsNetUtil.h...
i've added those to my tree and will be checking in soon.

Comment 25

[Darin Fisher]

Fix checked in.

Comment 26

[Tracy Walker [:tracy]]

jrgm, was this intended as an ongoing tracker bug, if so please reopen.  I'm 
going to mark it verified.

Comment 27

[John Morrison]

No, it wasn't a tracking bug. (Hey, ancient history!)