184550 - Performance regression, caused by the fix for Bug 131889, during forwarding inline.

Status: VERIFIED FIXED

(MailNews Core :: Composition, defect)

Description

[[e-mail] (gone - use [e-mail] instead)]

Build ID: 2002-12-09, Windows XP/2000.

Summary: Performance regression between 7/22/02 and 9/01/22 forwarding inline.

Steps to Reproduce:

1.  I have a 30KB text file (it's a C++ file) that when I forward as inline 
from a Local Folder, takes twice as slow as the Netscape 7.0 RTM/Mozilla 0.9.x 
milestone build. (I have logs to prove this, but it's evident visually, as 
well).

Actual Results:

BRANCH:
0[324328]: [0.82][0.17] - Finished inserting data into the editor. The window 
is finally ready!

TRUNK:
0[2642a8]: [1.90][1.43] - Finished inserting data into the editor. The window 
is finally ready!

To enable automatic logging for mail compose:

See http://www.mozilla.org/mailnews/performance/msgcompose_loggin.html

Comment 1

[[e-mail] (gone - use [e-mail] instead)]

Sorry for not being able to pare this down to a closer range of checkins/builds.

Neither ftp://ftp.mozilla.org/pub/mozilla/nightly nor ftp://sweetlou have builds
earlier than 9/01/02 and later than 7/22/02.

Comment 2

[Charles Manske]

The build that will tell me if it's the "remove editorShell" work is 11/10/02.
Please test that one.

Comment 3

[[e-mail] (gone - use [e-mail] instead)]

Meant to tell you that it's not that build (IE, still occurs with that build,
which means the perf regression occurred before then).

Comment 4

[Joe Francis]

I took a look at my checkins during that period and don't see anything
suggestive.  The big deletion rewrite landed in that timeframe, but it shouldn't
affect document load times.

Comment 5

[Joe Francis]

On the link to the perf page you provide, I see other interim numbers listed
before "Finished inserting data into the editor".  What do those interim numbers
look like?  Do we know what stage has become slower?

Comment 6

[Joe Francis]

My bad, the second number is the time differential for that step, right?  So we
are seeing data insertion go from 0.17 -> 1.43, an 8 fold increase.

Jean-Francois, I'm assuming nothing changed on the mail side here?  If it asn't
you should assign to me.

Comment 7

[Jean-Francois Ducarroz]

the only possible check in which may affect the perf number during that periode
in nsMsgCompose.cpp is:

08/27: rev 1.353. Bug 131889 - Need to insert separatly the HTML headers

I'll backup that change to see...

Comment 8

[Jean-Francois Ducarroz]

I backup the change for bug Bug 131889 and the time to insert the message body
went from 3.12s to 0.79s!

looks like htmlEditor->ReplaceHeadContentsWithHTML(headContent); is very time
consuming! I need more testing to really know where the time is lost...

Comment 9

[[e-mail] (gone - use [e-mail] instead)]

Attachment: Forwarding inline performance log results

Comment 10

[Jean-Francois Ducarroz]

The time is spend in htmlEditor->InsertHTML(aBuf); but the time this operatin
takes is depending on the fact we have removed the head tag from the buffer or
not! Just removing the line aBuf.Cut(start, end - start); will send the perf
number to normal.

I need to check the data in the buffer to be sure I cut properly the head tag...

Comment 11

[Jean-Francois Ducarroz]

here is an extended log with the code untouch:

[process]: [totalTime][deltaTime]
--------------------
0[2b5158]: [0.01][0.01] - Start opening the window
0[2b5158]: [0.97][0.97] - Start initializing the compose window (ComposeLoad)
0[2b5158]: [1.09][0.12] - Done with the initialization (ComposeLoad). Waiting on
editor to load about:blank
0[2b5158]: [1.59][0.51] - Start Removing the header tag from the buffer
0[2b5158]: [1.59][0.01] - done Removing the header tag from the buffer
0[2b5158]: [1.59][0.01] - Start Replacing the HeadContents With HTML
0[2b5158]: [1.60][0.01] - Done Replacing the HeadContents With HTML
0[2b5158]: [4.22][2.63] - Finished inserting data into the editor. The window is
finally ready!


and now, the same one but without removing the head tag from the buffer (I still
do the header replacement):
--------------------
0[2b5158]: [0.01][0.01] - Start opening the window
0[2b5158]: [0.97][0.97] - Start initializing the compose window (ComposeLoad)
0[2b5158]: [1.08][0.11] - Done with the initialization (ComposeLoad). Waiting on
editor to load about:blank
0[2b5158]: [1.59][0.52] - Start Removing the header tag from the buffer
0[2b5158]: [1.59][0.01] - done Removing the header tag from the buffer
0[2b5158]: [1.59][0.01] - Start Replacing the HeadContents With HTML
0[2b5158]: [1.60][0.02] - Done Replacing the HeadContents With HTML
0[2b5158]: [1.88][0.28] - Finished inserting data into the editor. The window is
finally ready!

Comment 12

[Jean-Francois Ducarroz]

changing summary now that I have found what caused the regression

Comment 13

[Jean-Francois Ducarroz]

I discovered that I can fully remove the code added by the fix for bug 131889
without  regressing that bug. Something must have changed since in editor which
prevent having several head tag in a document. That also fix the performance
regression.

I was able to reproduce bug 131889 using a Netscape 7.0 RTM build (to be sure I
was doing the correct test).

Comment 14

[Jean-Francois Ducarroz]

Attachment: Proposed fix, v1

Remove code that cause the performance regression. It was for bug 131889 but
it's not needed anymore.

Comment 15

[Jean-Francois Ducarroz]

Comment on attachment 108914 [details] [diff] [review]
Proposed fix, v1

Cavin, please review...

Comment 16

[Cavin Song]

Comment on attachment 108914 [details] [diff] [review]
Proposed fix, v1

r=cavin.

Comment 17

[David :Bienvenu]

Comment on attachment 108914 [details] [diff] [review]
Proposed fix, v1

sr=bienvenu

Comment 18

[Jean-Francois Ducarroz]

Fix checked in the trunk

Comment 19

[(not reading, please use [e-mail] instead)]

worth taking for 1.3 alpha?

Comment 20

[[e-mail] (gone - use [e-mail] instead)]

Emphatically, yes ;-)  It's visible on a 1.7GHz with 512MB of RAM.

Comment 21

[Jean-Francois Ducarroz]

WHy not, it cannot hurt. But in the other hand, we can live with it too for an
alpha version...

Comment 22

[[e-mail] (gone - use [e-mail] instead)]

Using builds:

Mac OS X 10.2.2 - 2002-12-12-10
Windows 2000/XP - 2002-12-12-08
RedHat 8.0 Linux - 2002-12-12-08

Under HTML compose mode, when I forward a 30KB plain text C++ file inline, we're
back to what we were in Netscape 7.0 days.

Windows:

0[2642a8]: [0.77][0.29] - Finished inserting data into the editor. The window is
finally ready!

(subsequent runs are: 0[2642a8]: [0.21][0.21] - Finished inserting data into the
editor. The window is finally ready!)

Mac:

With the fix:
2002-12-12-10 build: [4.66, 2.03, 2.11] (in seconds, successive runs within the
same session)

Without the fix:
2002-12-09-03 build: [8.30, 4.61, 4.69] (in seconds, successive runs within the
same session)

Linux:

With the fix:
2002-12-12-08 build: [4.66, 2.03, 2.11] (in seconds, successive runs within the
same session)

Without the fix:
2002-12-09-22 build: [8.30, 4.61, 4.69] (in seconds, successive runs within the
same session)

By all accounts, 

VERIFIED FIXED

Comment 23

[[e-mail] (gone - use [e-mail] instead)]

Cut and paste error for Linux should read:

Linux:

With the fix:
2002-12-12-08 build: [1.44, 1.20, 1.26] (in seconds, successive runs within the
same session)

Without the fix:
2002-12-09-22 build: [2.78, 2.42, 2.39] (in seconds, successive runs within the
same session)

Note that Linux, by default, doesn't have the mail.compose.max_recycled_windows
pref set to 1 (which would enable it).