630645 - Profile Thunderbird startup process on Mac [SSD did not improve startup time]

Status: RESOLVED WORKSFORME

(Thunderbird :: General, defect)

Description

[Nomis101]

Attachment: mozconfig

Briefed from [1] I've build a Thunderbird debug build and profiled it with Apples Shark. It was build with the attached mozconfig.

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b11pre) Gecko/20110201 Thunderbird/3.3a3pre


[1]: http://groups.google.com/group/mozilla.dev.apps.thunderbird/browse_thread/thread/35293778b6da6c88#

Comment 1

[Nomis101]

Attachment: Time Profile (All Thread States) of thunderbird-bin

Text file "Time Profile (All Thread States) of thunderbird-bin". With Shark 4.7.3.
I also have a mshark file from this, but it is 18,2 MB.

Comment 2

[Nomis101]

Attachment: Time Profile of thunderbird-bin

Text file "Time Profile of thunderbird-bin". I also have an mshark file from this, but this is 31,2 MB in size.

Comment 3

[Nomis101]

Attachment: Time Profiling with Instruments

Trace file from profiling with Instruments (Time Profiler). It is similar to "Time Profile of thunderbird-bin", but can be opened with Instruments.

Comment 4

[Nomis101]

Attachment: Dispatch profiling with Instruments

Instruments file for profiling with Dispatch template.

Comment 5

[Nomis101]

Attachment: File activity profiling with Instruments

Profiling file from Instruments with File Activity template.

Comment 6

[Nomis101]

Attachment: Shark: Time Profile (All Thread States) of thunderbird-bin, from nightly

Shark Time Profile (All Thread States) of thunderbird-bin, from a Thunderbird nightly. I've fetched the symbols for this nightly and than run shark. The archive contains the following text files:
Time Profile (All Thread States)
• Thread: All, View: Tree (Top-Down)
• Thread: NSApplication, View: Tree (Top Down)
• Thread: All, View: Heavy (Bottom-Up)
• Thread: NSApplication, View: Heavy (Bottom-Up)

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b12pre) Gecko/20110203 Thunderbird/3.3a3pre

Comment 7

[Nomis101]

Attachment: Shark: Time Profile of thunderbird-bin, from nightly

Shark Time Profile of thunderbird-bin, from a Thunderbird
nightly. I've fetched the symbols for this nightly and than run shark. The
archive contains the following text files:
Time Profile (All Thread States)
• Thread: All, View: Tree (Top-Down)
• Thread: NSApplication, View: Tree (Top Down)
• Thread: All, View: Heavy (Bottom-Up)
• Thread: NSApplication, View: Heavy (Bottom-Up)

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b12pre) Gecko/20110203
Thunderbird/3.3a3pre

Comment 8

[Nomis101]

Attachment: Shark: Time Profile of thunderbird-bin, online vs. offline

This are three Time Profiles of a own TB build. Mozconfig similar to the official one, but with --enable-profile. Test system was a MacBookPro7,1. The tree files are:
• Sample Intervall 1 ms, Thread All, View Tree, TB online mode
• Sample Intervall 1 ms, Thread All, View Tree, TB offline mode
• Sample Intervall 20 µs, Thread All, View Tree, TB offline mode

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b12pre) Gecko/20110212 Thunderbird/3.3a3pre

Comment 9

[Wayne Mery (:wsmwk)]

Nomis, we are two years since your profile and unfortunately no one has commented on your data.  Might you be able to create new profile data? Or use gecko profiler?  (Once it gets fixed - mconley may be able to tell us when it gets tuned up)

Comment 10

[Nomis101]

Oh yes, this is really an old bug. I don't remember exactly what I have done to obtain this datas and why I have done all this.^^ But if you think it would be interesting to have new datas, than I can create new ones. I have never worked with gecko profiler. Would it be better to use the gecko profiler?

Comment 11

[Mike Conley (:mconley) (:⚙️)]

(In reply to Wayne Mery (:wsmwk) from comment #9)
> Nomis, we are two years since your profile and unfortunately no one has
> commented on your data.  Might you be able to create new profile data? Or
> use gecko profiler?  (Once it gets fixed - mconley may be able to tell us
> when it gets tuned up)

The Gecko Profiler v1.10.17, available here: https://addons.mozilla.org/en-us/thunderbird/addon/gecko-profiler/

*Should* work properly with release Thunderbird.

Comment 12

[Nomis101]

(In reply to Mike Conley (:mconley) from comment #11)
> (In reply to Wayne Mery (:wsmwk) from comment #9)
> > Nomis, we are two years since your profile and unfortunately no one has
> > commented on your data.  Might you be able to create new profile data? Or
> > use gecko profiler?  (Once it gets fixed - mconley may be able to tell us
> > when it gets tuned up)
> 
> The Gecko Profiler v1.10.17, available here:
> https://addons.mozilla.org/en-us/thunderbird/addon/gecko-profiler/
> 
> *Should* work properly with release Thunderbird.

I've tried this today, but it didn't work for me with the Add-On from this link. So I've tried  it like it is described in your blog: http://mikeconley.ca/blog/2012/06/15/gecko-profiler-now-works-in-thunderbird-daily/
And with this Add-On it worked. But I can not profile the startup process with the Gecko profiler. I enable it, close Thunderbird, start Thunderbird and it is disabled again. So I only can profile things if TB is allready running. I will profile the startup process now with Instruments and attach the results here soon.

Comment 13

[Nomis101]

Attachment: New TB 22 profiles, gathered with Instruments 4.6

I've made this profiling with Thunderbird 22.0a1 (20130331031003) with Instruments 4.6 on OS X 10.8.3 12D78 with a MacBook Pro Mid-2010. I've made a "Time Profile" and a "System Trace". The Allocation profile I've also made is too big to upload on Bugzilla. I've also tried to make leak profiling, but this didn't work, TB always crashed while profiling for leaks and Instruments told me "Unknown error 11 occoured (LeakAgent)". My steps for getting this startup profiles are very simple, let Instruments start TB, wait until TB has checked for new mails and than close it. Sampling interval is 1 ms.

Comment 14

[Wayne Mery (:wsmwk)]

https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Reporting_a_Thunderbird_Performance_Problem_with_G has link to an xpi that should work

Comment 15

[Nomis101]

(In reply to Wayne Mery (:wsmwk) from comment #14)
> https://developer.mozilla.org/en-US/docs/Mozilla/Performance/
> Reporting_a_Thunderbird_Performance_Problem_with_G has link to an xpi that
> should work

Yes, this seems to work with TB 35. But, on every start it is disabled and has to be enabled first. Which is not the perfect thing if you want to profile a startup process...

Comment 16

[Wayne Mery (:wsmwk)]

I wonder if the MOZ_PROFILER_STARTUP environment variable will help. 
Implemented via https://bugzilla.mozilla.org/show_bug.cgi?id=799638

According to irving it should work per https://bugzilla.mozilla.org/show_bug.cgi?id=903451#c32

Other perhaps relevant settings (per https://blog.mozilla.org/jseward/ )
MOZ_PROFILER_INTERVAL=1 
MOZ_PROFILER_MODE=native 
MOZ_PROFILER_NEW=1
MOZ_PROFILER_VERBOSE=1 
MOZ_PROFILER_STARTUP=1

Comment 17

[Nomis101]

(In reply to Wayne Mery (:wsmwk) from comment #16)
> I wonder if the MOZ_PROFILER_STARTUP environment variable will help. 
> Implemented via https://bugzilla.mozilla.org/show_bug.cgi?id=799638
> 
> According to irving it should work per
> https://bugzilla.mozilla.org/show_bug.cgi?id=903451#c32
> 
> Other perhaps relevant settings (per https://blog.mozilla.org/jseward/ )
> MOZ_PROFILER_INTERVAL=1 
> MOZ_PROFILER_MODE=native 
> MOZ_PROFILER_NEW=1
> MOZ_PROFILER_VERBOSE=1 
> MOZ_PROFILER_STARTUP=1

Hm, https://blog.mozilla.org/jseward/ tells I will need a build with –enable-profiling for this. I will try this later.

Comment 18

[Wayne Mery (:wsmwk)]

(In reply to Nomis101 from comment #17)
> ...
> Hm, https://blog.mozilla.org/jseward/ tells I will need a build with
> –enable-profiling for this. I will try this later.

Nomis, any luck?
And, has startup time improved significantly in last few years, or since original bug report?

Not also, TB startup on Mac is impacted by Bug 701661 - Firefox maintain an open file descriptor for every single font.  [every font file is opened on launch]

Comment 19

[Nomis101]

(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #18)
> (In reply to Nomis101 from comment #17)
> > ...
> > Hm, https://blog.mozilla.org/jseward/ tells I will need a build with
> > –enable-profiling for this. I will try this later.
> 
> Nomis, any luck?
> And, has startup time improved significantly in last few years, or since
> original bug report?
I think it has a bit improved. But I can not test currently. Startup time significantly depends on signing. If the build is not properly signed, it takes a very long time for startup. Because I will need to build with –enable-profiling, it seems I need my own build. But because due an bug since macOS 10.12 (1285754) I'm currently not able to sign my own builds anymore properly.

Comment 20

[Wayne Mery (:wsmwk)]

Bug 517045 has some nuggets about font initialization. For example...
"... font enumeration** ... takes place at startup.  The reading of font cmaps takes place 8s after startup on mac/windows, that's a distinct and separate event."

** see also bug 404310 and bug 491283

Have you had Photoshop or any packages that may have installed lots of fonts?
Any idea how many fonts you have installed in OS X?

Comment 21

[Nomis101]

(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #20)
> Bug 517045 has some nuggets about font initialization. For example...
> "... font enumeration** ... takes place at startup.  The reading of font
> cmaps takes place 8s after startup on mac/windows, that's a distinct and
> separate event."
> 
> ** see also bug 404310 and bug 491283
> 
> Have you had Photoshop or any packages that may have installed lots of fonts?
> Any idea how many fonts you have installed in OS X?
Yes, OS X had some performance issues with lots of fonts on some applications (especially if there was a corrupted font) years ago. This was also happening with e.g. Microsoft Office. But font handling has improved in OS X, so I don't see issues like this anymore. I have 588 fonts installed, but Office, Photoshop and so on a starting very quickly. In general Thunderbird is also starting very fast recently, but as I said, I currently can not measure it.

Comment 22

[Wayne Mery (:wsmwk)]

(In reply to Nomis101 from comment #19)
> (In reply to Wayne Mery (:wsmwk, NI for questions) from comment #18)
> > (In reply to Nomis101 from comment #17)
> > > ...
> > > Hm, https://blog.mozilla.org/jseward/ tells I will need a build with
> > > –enable-profiling for this. I will try this later.
> > 
> > Nomis, any luck?
> > And, has startup time improved significantly in last few years, or since
> > original bug report?
> I think it has a bit improved. But I can not test currently. Startup time
> significantly depends on signing. If the build is not properly signed, it
> takes a very long time for startup. Because I will need to build with
> –enable-profiling, it seems I need my own build. But because due an bug
> since macOS 10.12 (1285754) I'm currently not able to sign my own builds
> anymore properly.

Would it be a bad assumption that if an unsigned build takes longer to start, that the fault is with OS X and we can't do anything about it?

Comment 23

[Wayne Mery (:wsmwk)]

Anyone else seeing slow startup on Mac?

Comment 24

[Eckard Berberich]

I haven't seen slow Thunderbird startups on my iMac running macOS 10.14.6 (Mojave).
Actually it takes between two and three seconds for Thunderbird to build the main window in my work profile, a little less in a test profile without add-ons.

Comment 25

[Antony]

With ref to my recent bug report 1601808, startup is not a problem, its the left folder pane that is sluggish and jerky when scrolling.

TB starts up fine

Comment 26

[Wayne Mery (:wsmwk)]

Nomis,

Do you consider Mac startup on SSD to be slow? Reading back through your comments, I don't mention of how many seconds.

If you have lots of folders, then you will want to test beta after bug 163964 lands.
Other potential items are the dependencies of bug 487832

Comment 27

[Nomis101]

Hi Wayne, I have forgotten about this bug. On a recent Mac startup on SSD is not slow at all. It nearly starts immediately.

Comment 28

[Wayne Mery (:wsmwk)]

super. Thanks for the update