Re: Gnome first-time login profiling report.

[Narayana Pattipati <narayana pattipati wipro com>]

Sorry. I forgot to attach the timings report. Attaching it now.

Sorry for the inconvenience caused. 

Thanks and Regards,
Narayana.

Narayana Pattipati wrote:
> 
> Hi,
> 
> Please find attached the first-time login timings splitup for Linux.
> Earlier I had sent the timings report for Solaris.
> 
> Also you can have a look at the truss outputs for Linux as well as
> Solaris at the following links:
> 
>                 http://www.gnome.org/~michael/solaris-login-truss.txt
>                 http://www.gnome.org/~michael/linux-login-truss.txt
>

This document gives details of time split-up for each activity during the
first-time login on Linux.

Note: Tested on Pentium-III, processor speed 650 MHz, Red Hat linux 7.1,
      running debug build of gnome-2.0. Nautilus is disabled during the  
      performance  measurements.  

Note: I have measured the timings by putting debug statements, sometimes
      manually, and also using Truss(with timestamp option) output.
      

 |<----------------- Total Run of 17 seconds ---------------------------->|
    

        3               4           2         2          2         4
 |--------------|---------------|-------|----------|----------|-----------|
 1      (a)     2      (b)      3  (c)  4     (d)  5    (e)   6    (f)    7


Steps:
~~~~~~

1. password Entered
2. Starting of gnome-session main function
3. Starting of gnome-splash i.e gnome-splash appears.
4. End of gnome-session main function
5. Starting of updates on gnome-splash(i.e starting of window-manager,
   smproxy etc.)
6. Startng Panel
7. Panel appears and user can start using the desktop


Sections:
~~~~~~~~~

(a). Time spent from Password entry to the start of gnome-session main 
     function execution. This time can be considered as the time taken for 
     XSession initialization.( Total 3 seconds )

(b). Four seconds time is spent from starting of gnome-session main to 
     the start of the gnome-splash. This time is spent in executing the 
     following functions called from main of gnome-session:
     
     gtk_init, gnome_login_check, command_line_sync(1 sec),
     gnome_program_init(2 sec.), initialize_ice, gconf_client_get_default, 
     read_session, gsm_sound_login, gsm_gsd_start and start_splash(less than
     1 sec).

(c). Time taken from start_splash to end of gnome-session main. This time is 
     spent executing the following function(s):
     
     start_session(more than 1 second)
	
(d). Two seconds time is spent in gnome-settings-daemon. Out of this more
     than 1.5 seconds is spent in executing function gnome_settings_daemon_new(). 
     (Enable Sound Server Startup option under sound preferences is 
      disabled.)

gnome_settings_daemon_new calls many settings _init and _load functions. 
Time taken by these functions is shown below:

	gnome_settings_font_init
	gnome_settings_xsettings_init
	gnome_settings_mouse_init
	gnome_settings_keyboard_init
	gnome_settings_sound_init
	gnome_settings_wm_init
	gnome_settings_accessibility_keyboard_init
	gnome_settings_screensavor_init
	gnome_settings_default_editor_init
	gnome_settings_background_init
	gnome_settings_keybindings_init

	gnome_settings_font_load
	gnome_settings_xsettings_load
	gnome_settings_mouse_load
	gnome_settings_keyboard_load

The above functions take around 1 seconds to execute.

	gnome_settings_sound_load   =====> takes 0.5 second to execute.

    gnome_settings_wm_load
	gnome_settings_accessibility_keyboard_load
	gnome_settings_screensavor_load
	gnome_settings_default_editor_load
	gnome_settings_background_load
	gnome_settings_keybindings_load

Above 6 functions take less than 0.5 second to execute. 

gnome-settings-daemon takes around 5 seconds if the option "Enable Sound
Server Startup" under Desktop Preferences->Sound is enabled. Otherwise it 
just takes 2 second. And by default, this option is disabled.

And when this option is enabled, most of the time(more than 3.5 sec) is taken by 
gnome_settings_sound_load function. When this option is enabled, for each 
sound event(there are around 37 events), the sound file associated with 
that event is re-loaded during login. The function which re-loads the sound 
file is reload_foreach_cb in file gnome-settings-sound.c. This is consuming
the time. 

Even though this option is disabled, e-s-d daemon is always getting
started. Bug #91535 exists in bugzilla for this issue.

 
(e). Two seconds time spent in this section is for starting metacity 
     window-manager(takes more than 1 seconds) and gnome-smproxy(less than 
     1 second).

(f). Four seconds time is spent in executing gnome-panel. (This time is from 
     start of gnome-panel main to the end of end of gnome-panel main).Is it
     worth looking at Panel since it is taking 4 seconds to come up.??
     (Panel does not have any components loaded except for main menu when
     tested.)