114904 - Redundant and confusing data in a Mac nspr log for msgcompose:5

Status: VERIFIED WORKSFORME

(MailNews Core :: Composition, defect)

Description

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

Build ID:  2001-12-07, Mac OS 9.0

Summary:  Redundant and confusing data in a Mac nspr log for msgcompose:

Steps to Reproduce:

1. Create a file to enable logging such as:
ENV:NSPR_LOG_MODULES=msgcompose:5
ENV:NSPR_LOG_FILE=messagecomposeperflog

2. Enable the logging for mailnews:

user_pref("mailnews.logComposePerformance", true);

3. Drag the file in step #1 to Mozilla/Netscape and click Compose 3 times, but 
waiting and closing each window after it has finished loading.

Expected Results:

Logfiles for each successive operation.

Actual Results:

The 3rd metric for some reason is a mess, and I can't tell what the data should 
be.

0[5ac3d0c]: --------------------
0[5ac3d0c]: [    0][    0] - Start opening the window, message size = 0
0[5ac3d0c]: [ 2849][ 2849] - Start initializing the compose window (ComposeLoad)
0[5ac3d0c]: [ 2979][  130] - Done with the initialization (ComposeLoad). Waiting 
on editor to load about:blank
0[5ac3d0c]: [ 3386][  407] - Editor is done loading about::blank. Now let mime do 
its job
0[5ac3d0c]: [ 3808][  422] - Finished inserting data into the editor. The window 
is finally ready!
0[5ac3d0c]: --------------------
0[5ac3d0c]: [    0][    0] - Start opening the window, message size = 0
0[5ac3d0c]: [ 1377][ 1377] - Start initializing the compose window (ComposeLoad)
0[5ac3d0c]: [ 1468][   91] - Done with the initialization (ComposeLoad). Waiting 
on editor to load about:blank
0[5ac3d0c]: [ 1838][  370] - Editor is done loading about::blank. Now let mime do 
its job
0[5ac3d0c]: [ 2229][  391] - Finished inserting data into the editor. The window 
is finally ready!
0[5ac3d0c]: --------------------
0[5ac3d0c]: [    0][    0] - Start opening the window, message size = 0
0[5ac3d0c]: [ 1401][ 1401] - Start initializing the compose window (ComposeLoad)
0[5ac3d0c]: [ 1492][   91] - Done with the initialization (ComposeLoad). Waiting 
on editor to load about:blank
0[5ac3d0c]: [ 1865][  373] - Editor is done loading about::blank. Now let mime do 
its job
0[5ac3d0c]: [ 2253][  388] - Finished inserting data into the editor. The window 
is finally ready!
c]: [ 1397][ 1397] - Start initializing the compose window (ComposeLoad)
0[5ac3d0c]: [ 1512][  115] - Done with the initialization (ComposeLoad). Waiting 
on editor to load about:blank
0[5ac3d0c]: [ 1880][  368] - Editor is done loading about::blank. Now let mime do 
its job
0[5ac3d0c]: [ 1956][   76] - done with mime. Lets update some UI element
0[5ac3d0c]: [ 3203][ 1247] - addressing widget, windows title and focus are now 
set, time to insert the body
0[5ac3d0c]: [ 3338][  135] - Finished inserting data into the editor. The window 
is finally ready!

Comment 1

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

BTW, this same logging was fine on Windows 98.

Comment 2

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

Marking this worksforme; running the 02-01 build on Mac OS 9.2.2, this now 
worksforme.  Must've been some random NSPR glitch or something on mac.

0[5a4bfdc]: 
[process]: [totalTime][deltaTime]
--------------------
0[5a4bfdc]: [0.01][0.01] - Start opening the window, message size = 2941
0[5a4bfdc]: [3.76][3.76] - Start initializing the compose window (ComposeLoad)
0[5a4bfdc]: [3.97][0.21] - Done with the initialization (ComposeLoad). Waiting on 
editor to load about:blank
0[5a4bfdc]: [4.40][0.43] - Editor is done loading about:blank. This is New 
Compose window time.  Time for MIME.
0[5a4bfdc]: [4.66][0.27] - Done with MIME. Now we're updating the UI elements
0[5a4bfdc]: [5.80][1.14] - Addressing widget, window title and focus are now set, 
time to insert the body
0[5a4bfdc]: [5.95][0.16] - Finished inserting data into the editor. The window is 
finally ready!
0[5a4bfdc]: 
[process]: [totalTime][deltaTime]
--------------------
0[5a4bfdc]: [0.01][0.01] - Start opening the window, message size = 2941
0[5a4bfdc]: [1.09][1.09] - Start initializing the compose window (ComposeLoad)
0[5a4bfdc]: [1.19][0.11] - Done with the initialization (ComposeLoad). Waiting on 
editor to load about:blank
0[5a4bfdc]: [1.50][0.32] - Editor is done loading about:blank. This is New 
Compose window time.  Time for MIME.
0[5a4bfdc]: [1.70][0.21] - Done with MIME. Now we're updating the UI elements
0[5a4bfdc]: [2.69][0.99] - Addressing widget, window title and focus are now set, 
time to insert the body
0[5a4bfdc]: [2.81][0.13] - Finished inserting data into the editor. The window is 
finally ready!
0[5a4bfdc]: 
[process]: [totalTime][deltaTime]
--------------------
0[5a4bfdc]: [0.01][0.01] - Start opening the window, message size = 2941
0[5a4bfdc]: [1.08][1.08] - Start initializing the compose window (ComposeLoad)
0[5a4bfdc]: [1.19][0.11] - Done with the initialization (ComposeLoad). Waiting on 
editor to load about:blank
0[5a4bfdc]: [1.53][0.35] - Editor is done loading about:blank. This is New 
Compose window time.  Time for MIME.
0[5a4bfdc]: [1.76][0.24] - Done with MIME. Now we're updating the UI elements
0[5a4bfdc]: [2.80][1.04] - Addressing widget, window title and focus are now set, 
time to insert the body
0[5a4bfdc]: [2.95][0.15] - Finished inserting data into the editor. The window is 
finally ready!

Comment 3

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

verified