112767 - Profile: -P adds 3% to startup time

Status: VERIFIED FIXED

(Core Graveyard :: Profile: BackEnd, defect, P1)

Description

[Chris McAfee]

Find a build with one profile, and (redundantly) specify
the profile with -P <profilename>, this bumped two of my
performance tinderbox startup times up by about 3%.
20.18 secs to 20.70 secs, something like that.

What's going on here?  Just profile service overhead?

Comment 1

[Conrad Carlen (not reading bugmail)]

When you use -P, the code path is slightly shorter than when you don't. Using -P
bypasses nsProfile::LoadDefaultProfileDir().

It may be this code which went in recently:
http://lxr.mozilla.org/mozilla/source/profile/src/nsProfile.cpp#842
I doubt it though because, on Windows & Unix, reading the registry uses
NS_NewUnicodeLocalFile which uses uconv services (a huge problem we're working
to solve in the nsIFile impl) so that code should already be loaded and the code
I mentioned should have very little overhead.

Roy - In case it is that, your code which converts to the platform charset
should just check the incoming string using IsASCII before resorting to uconv
services. If it already is ASCII, a simple cheap conversion could be done.
 

Comment 2

[Conrad Carlen (not reading bugmail)]

Sorry, that link was wrong. It was the similar looking code at
http://lxr.mozilla.org/mozilla/source/profile/src/nsProfile.cpp#777

Comment 3

[Matthias Versen [:Matti]]

*** Bug 112871 has been marked as a duplicate of this bug. ***

Comment 4

[Roy Yokoyama]

conrad: I can put the patch together to utilize the IsASCII().

However, as you noted in comment #1, it probably doesn't 
improve 3% of start-up.

Comment 5

[Roy Yokoyama]

Attachment: Check for ASCII before uconv service

Comment 6

[Roy Yokoyama]

I did the Start-up performance test result
and here it is:

# run | without patch      | with patch
------+--------------------+---------------
1     | 10.422             | 10.422
2     | 10.437             | 10.437
3     | 10.438             | 10.406
4     | 10.422             | 10.406
5     | 10.438             | 10.390
6     | 10.422             | 10.421
7     | 10.422             | 10.406
8     | 10.422             | 10.422
------+--------------------+---------------
ave   | 10.4278 sec        | 10.4137 sec

The result is 3.3% better with the patch.

Comment 7

[Roy Yokoyama]

Conrad: I'll check in the patch if you'd like. Let me know.

Comment 8

[Conrad Carlen (not reading bugmail)]

Comment on attachment 60883 [details] [diff] [review]
Check for ASCII before uconv service

r=ccarlen. Thanks Roy - I'll give it to you.

Comment 9

[Conrad Carlen (not reading bugmail)]

-> Roy

Comment 10

[Roy Yokoyama]

brendan: can you super review?

Comment 11

[Brendan Eich [:brendan]]

Comment on attachment 60883 [details] [diff] [review]
Check for ASCII before uconv service

Existing code, I realize, but it's silly to test (cmdResult) after you've
established that NS_SUCCEEDED(rv) from a string getter that computed cmdResult.

Otherwise, sr=[e-mail], although any more common code and I would
rather see a common subroutine for -P and -CreateProfile to use.

/be

Comment 12

[Roy Yokoyama]

brendan: I think we should leave the if (cmdResult) check
because we still receive NS_SUCCEEDED(rv) for an empty cmd string.

-- cc'ing conrad

Comment 13

[Brendan Eich [:brendan]]

Roy, my point is that you don't need *both* NS_SUCCEEDED(rv) and the
cmdResult-converted-to-null test.  You don't propagate rv, so just get rid of
the rv assignment and the NS_SUCCEEDED(rv) test.

/be

Comment 14

[Roy Yokoyama]

Attachment: Removing rv assignments and NS_SUCCEEDED(rv) tests.

Comment 15

[Brendan Eich [:brendan]]

Thanks, my sr= stands.

/be

Comment 16

[Frank Tang]

>ave   | 10.4278 sec        | 10.4137 sec
>The result is 3.3% better with the patch.
??? where is the 3.3% better with the patch?
If with the path is 3.3% better, than we should see 

10.4278 * (1.0 - 0.033) = 10.478 * 0.967 = 10.0836826

10.4137 is only about 0.13 % better than 
10.4278 ( (10.4278-10.4137)/10.4278 * 100% )

Comment 17

[Roy Yokoyama]

Sigh, I thought I used the same equation to determine the average.
(I *always* double check the result before I post on the web before
embrass myself in front of public eyes.)
I am pretty sure I got something 3.3xxxx% improvement before; 
but I guess I was little excited.

ftang: So what do you want me to do with the patch? 
       Is it worth check it in?  I think it's worth it.

Comment 18

[Conrad Carlen (not reading bugmail)]

I think it's a good patch. Question is: are the performance measurements
repeatable to within 3%.

Comment 19

[Frank Tang]

>ftang: So what do you want me to do with the patch? 
>Is it worth check it in?  I think it's worth it.
The question is, does your patch really fix the target issue? If so, check it 
in, if not, don't do so. While the patch have no problem in general, it does 
make the code a little bit complex then before. We should check in if it DOES 
help performacnce. 

Comment 20

[Roy Yokoyama]

Conrad: do you have any other ideas for the cause of the slowness?
I would be more than happy to help you out. Just let me know.

Comment 21

[Roy Yokoyama]

Conrad: I'll assign this back to you.  I think I am done with my share.

Comment 22

[Conrad Carlen (not reading bugmail)]

What is the repeatability of this test which detected this? If it's not within
+-3%, this should be closed. In reading through the code, using -P should, if
anything, be faster (not significantly though).

Comment 23

[Conrad Carlen (not reading bugmail)]

Closing - see comment #22.

Comment 24

[K'Trina Medina]

Verified 

Comment 25

[Chris McAfee]

> What is the repeatability of this test which detected this? If it's not within
> +-3%, this should be closed. In reading through the code, using -P should, if
> anything, be faster (not significantly though).
This looks like a really weak justification to close this bug.
Am I missing something, or should we test this to determine
how repeatable the speedup is instead of "looking at it".

Reopening.  Either we should test this and get some real numbers
here, or come up with a better reason to close this.

Comment 26

[Conrad Carlen (not reading bugmail)]

  Once you determined that one code path was 3% slower than another, "looking at
it" is how to determine why. I found that some additional code was added to the
slower code path, and Roy made a patch for that, though it cut a very small
percentage off of the runtime.
  That the two paths of execution are within 3% of each other in cost does not
make it a bug. If the same code slowed down by 3% suddenly, that's a different
story. It was also closed because the question in comment 22 was not answered.
  As it is, I think Roy's patch should be checked in as it does cut *some*
amount of time.

Comment 27

[Chris Waterson]

So, dp is clawing and scratching for 1% wins. Now that we've shaken out our test
harness, maybe we could re-collect numbers? Cathleen, you've been doing some
startup testing: have you noticed any difference?

Comment 28

[Cathleen]

I tried on my win98 machine 200mHz 64MB, it's hard to tell ...

here are the timings, for warm startup

     w/ -P    w/o -P
    -------  ---------
     8450      7860    
     8680      8430
     7830      8760
     8380      7950

avg  8335      8250 

about 1.03% increase.

mcafee is going to tweak one of the tinderbox test to see if we can confirm the
increase, while tree is closed for 0.9.8

Comment 29

[Cathleen]

I also want to add, people are really chasing after those 0.5% perf wins, and
fixing them.  There aren't any big fish to fry at this stage, so if we do find
the increase is real, lets try to figure this out.  

- thanks!!

Comment 30

[Chris McAfee]

Attachment: Ts graph for test-only mode. graph before 10am is stock build, after 10am has -P default added, I can't see a change here

Comment 31

[Chris McAfee]

> That the two paths of execution are within 3% of each other in cost does not
> make it a bug. If the same code slowed down by 3% suddenly, that's a different
> story. It was also closed because the question in comment 22 was not answered.

For the record, I disagree with this statement.  A 3% finding is indeed a
performance problem, and we file bugs to work on these things.

Your question about repeatability re: comment #22 is valid, but
not-having-an-answer does not justify closing this.  If you can't do the
timings, ask for help next time.
--

I don't see any changes between -P and no -P, so I think we have
solved the problem for now.  Marking fixed.

Comment 32

[Daniel Veditz [:dveditz]]

Roy's patch was never checked in, and it does appear to be an improvement. Maybe
it stopped making a difference if something new has triggered the early use of
uconv, but that might get fixed and we'll want this ready for it.

Comment 33

[Conrad Carlen (not reading bugmail)]

I think Roy's patch should be checked in so back to him. It did some amount of
good and, now that nsLocalFile is not using uconv for unicode path conversion,
it may do even more good.

Comment 34

[Roy Yokoyama]

I think any amount of perf improvement is a winner.
I accept this bug and I will checkin my patch.

Comment 35

[Roy Yokoyama]

Fix checked in.
From comment #31; I am marking this bug as FIXED.
Please reopen if disgree

Comment 36

[K'Trina Medina]

Verified code fix