gnome-settings-daemon takes waaaaaaaay too long to start

Bug #854101 reported by Chris Coulson
20
This bug affects 4 people
Affects Status Importance Assigned to Milestone
The Ubuntu Boot Speed Project
Fix Released
Undecided
Unassigned
gnome-desktop3 (Ubuntu)
Fix Released
High
Chris Coulson
Oneiric
Fix Released
High
Chris Coulson
gnome-settings-daemon (Ubuntu)
Fix Released
High
Chris Coulson
Oneiric
Fix Released
High
Chris Coulson

Bug Description

gnome-settings-daemon takes 5 seconds to register with the session manager, which is when compiz is started (see http://ubuntuone.com/0xKppDPyZiHP9aDzmzzPoR - and this *isn't* a slow machine). I turned on the profiling support in g-s-d, and modified the profiling function to print the profile markers to stdout, with some timestamps. This is what I see (on a cold start):

0. 0 0. 0 MARK: (null) main: start
0. 78 0. 78 MARK: (null) parse_args: start
0. 6019 0. 5941 MARK: gnome-settings-daemon parse_args: end
0. 6032 0. 13 MARK: gnome-settings-daemon main: start opening gtk display
0. 17026 0. 10994 MARK: gnome-settings-daemon main: end opening gtk display
0. 17321 0. 295 MARK: gnome-settings-daemon main: start gnome_settings_manager_new
0. 17467 0. 146 MARK: gnome-settings-daemon main: end gnome_settings_manager_new
0. 17479 0. 12 MARK: gnome-settings-daemon gnome_settings_manager_start: start
0. 17489 0. 10 MARK: gnome-settings-daemon gnome_settings_manager_start: start initializing plugins
0. 18032 0. 543 MARK: gnome-settings-daemon _load_all: start
0. 18041 0. 9 MARK: gnome-settings-daemon _load_dir: start
0. 18117 0. 76 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0. 18178 0. 61 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0. 18317 0. 139 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0. 18747 0. 430 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0. 18765 0. 18 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0. 18773 0. 8 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0. 18846 0. 73 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0. 18899 0. 53 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0. 18915 0. 16 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0. 18923 0. 8 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0. 19077 0. 154 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0. 19130 0. 53 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0. 19147 0. 17 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/xsettings.gnome-settings-plugin
0. 19154 0. 7 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/xsettings.gnome-settings-plugin
0. 19306 0. 152 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/xsettings.gnome-settings-plugin
0. 19358 0. 52 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/xsettings.gnome-settings-plugin
0. 19375 0. 17 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/background.gnome-settings-plugin
0. 19381 0. 6 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/background.gnome-settings-plugin
0. 19536 0. 155 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/background.gnome-settings-plugin
0. 19588 0. 52 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/background.gnome-settings-plugin
0. 19605 0. 17 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/smartcard.gnome-settings-plugin
0. 19612 0. 7 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/smartcard.gnome-settings-plugin
0. 19685 0. 73 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/smartcard.gnome-settings-plugin
0. 19760 0. 75 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/smartcard.gnome-settings-plugin
0. 19778 0. 18 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/keyboard.gnome-settings-plugin
0. 19785 0. 7 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/keyboard.gnome-settings-plugin
0. 19927 0. 142 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/keyboard.gnome-settings-plugin
0. 19991 0. 64 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/keyboard.gnome-settings-plugin
0. 20005 0. 14 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/media-keys.gnome-settings-plugin
0. 20010 0. 5 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/media-keys.gnome-settings-plugin
0. 20148 0. 138 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/media-keys.gnome-settings-plugin
0. 20193 0. 45 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/media-keys.gnome-settings-plugin
0. 20207 0. 14 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/housekeeping.gnome-settings-plugin
0. 20211 0. 4 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/housekeeping.gnome-settings-plugin
0. 20261 0. 50 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/housekeeping.gnome-settings-plugin
0. 20299 0. 38 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/housekeeping.gnome-settings-plugin
0. 20311 0. 12 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/xrandr.gnome-settings-plugin
0. 20315 0. 4 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/xrandr.gnome-settings-plugin
0. 20414 0. 99 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/xrandr.gnome-settings-plugin
0. 20454 0. 40 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/xrandr.gnome-settings-plugin
0. 20466 0. 12 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/color.gnome-settings-plugin
0. 20470 0. 4 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/color.gnome-settings-plugin
0. 20541 0. 71 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/color.gnome-settings-plugin
0. 20602 0. 61 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/color.gnome-settings-plugin
0. 20616 0. 14 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/wacom.gnome-settings-plugin
0. 20621 0. 5 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/wacom.gnome-settings-plugin
0. 20682 0. 61 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/wacom.gnome-settings-plugin
0. 20724 0. 42 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/wacom.gnome-settings-plugin
0. 20737 0. 13 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/a11y-settings.gnome-settings-plugin
0. 20746 0. 9 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/a11y-settings.gnome-settings-plugin
0. 20844 0. 98 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/a11y-settings.gnome-settings-plugin
0. 209
(gnome-settings-daemon:1723): GnomeDesktop-WARNING **: could not get output property for eDP1, rc: 15

(gnome-settings-daemon:1723): GnomeDesktop-WARNING **: could not get output property for HDMI1, rc: 15

(gnome-settings-daemon:1723): power-plugin-WARNING **: not connected
01 0. 57 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/a11y-settings.gnome-settings-plugin
0. 20939 0. 38 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/keybindings.gnome-settings-plugin
0. 20947 0. 8 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/keybindings.gnome-settings-plugin
0. 21099 0. 152 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/keybindings.gnome-settings-plugin
0. 21164 0. 65 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/keybindings.gnome-settings-plugin
0. 21182 0. 18 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/print-notifications.gnome-settings-plugin
0. 21189 0. 7 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/print-notifications.gnome-settings-plugin
0. 21313 0. 124 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/print-notifications.gnome-settings-plugin
0. 21353 0. 40 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/print-notifications.gnome-settings-plugin
0. 21366 0. 13 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/power.gnome-settings-plugin
0. 21371 0. 5 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/power.gnome-settings-plugin
0. 21440 0. 69 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/power.gnome-settings-plugin
0. 21477 0. 37 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/power.gnome-settings-plugin
0. 21488 0. 11 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/gconf.gnome-settings-plugin
0. 21492 0. 4 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/gconf.gnome-settings-plugin
0. 21541 0. 49 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/gconf.gnome-settings-plugin
0. 21575 0. 34 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/gconf.gnome-settings-plugin
0. 21588 0. 13 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/a11y-keyboard.gnome-settings-plugin
0. 21592 0. 4 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/a11y-keyboard.gnome-settings-plugin
0. 21691 0. 99 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/a11y-keyboard.gnome-settings-plugin
0. 21726 0. 35 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/a11y-keyboard.gnome-settings-plugin
0. 21738 0. 12 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/mouse.gnome-settings-plugin
0. 21742 0. 4 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/mouse.gnome-settings-plugin
0. 21836 0. 94 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/mouse.gnome-settings-plugin
0. 21878 0. 42 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/mouse.gnome-settings-plugin
0. 21892 0. 14 MARK: gnome-settings-daemon _load_dir: end
0. 21902 0. 10 MARK: gnome-settings-daemon load_plugin_module: start power
0. 23619 0. 1717 MARK: gnome-settings-daemon load_plugin_module: end power
0. 23633 0. 14 MARK: gnome-settings-daemon gsd_power_manager_start: start
0.568517 0.544884 MARK: gnome-settings-daemon gsd_power_manager_start: end
0.568545 0. 28 MARK: gnome-settings-daemon load_plugin_module: start color
0.569574 0. 1029 MARK: gnome-settings-daemon load_plugin_module: end color
0.569608 0. 34 MARK: gnome-settings-daemon gsd_color_manager_start: start
1. 83437 0.513829 MARK: gnome-settings-daemon gsd_color_manager_start: end
1. 83461 0. 24 MARK: gnome-settings-daemon load_plugin_module: start xrandr
1. 84065 0. 604 MARK: gnome-settings-daemon load_plugin_module: end xrandr
1. 84080 0. 15 MARK: gnome-settings-daemon gsd_xrandr_manager_start: start
3.201221 2.117141 MARK: gnome-settings-daemon gsd_xrandr_manager_start: end
3.201248 0. 27 MARK: gnome-settings-daemon load_plugin_module: start xsettings
3.201916 0. 668 MARK: gnome-settings-daemon load_plugin_module: end xsettings
3.201929 0. 13 MARK: gnome-settings-daemon gnome_xsettings_manager_start: start
3.203385 0. 1456 MARK: gnome-settings-daemon update_xft_settings: start
3.203436 0. 51 MARK: gnome-settings-daemon xft_settings_set_xsettings: start
3.203445 0. 9 MARK: gnome-settings-daemon xft_settings_set_xsettings: end
3.203448 0. 3 MARK: gnome-settings-daemon xft_settings_set_xresources: start
3.204478 0. 1030 MARK: gnome-settings-daemon xft_settings_set_xresources: end
3.204488 0. 10 MARK: gnome-settings-daemon update_xft_settings: end
3.204499 0. 11 MARK: gnome-settings-daemon start_fontconfig_monitor: start
3.207579 0. 3080 MARK: gnome-settings-daemon start_fontconfig_monitor: end
3.207592 0. 13 MARK: gnome-settings-daemon gnome_xsettings_manager_start: end
3.207609 0. 17 MARK: gnome-settings-daemon load_plugin_module: start sound
3.209490 0. 1881 MARK: gnome-settings-daemon load_plugin_module: end sound
3.209498 0. 8 MARK: gnome-settings-daemon gsd_sound_manager_start: start
3.209729 0. 231 MARK: gnome-settings-daemon gsd_sound_manager_start: end
3.209742 0. 13 MARK: gnome-settings-daemon load_plugin_module: start wacom
3.211220 0. 1478 MARK: gnome-settings-daemon load_plugin_module: end wacom
3.211225 0. 5 MARK: gnome-settings-daemon gsd_wacom_manager_start: start
3.211232 0. 7 MARK: gnome-settings-daemon gsd_wacom_manager_start: end
3.211241 0. 9 MARK: gnome-settings-daemon load_plugin_module: start keyboard
3.217492 0. 6251 MARK: gnome-settings-daemon load_plugin_module: end keyboard
3.217501 0. 9 MARK: gnome-settings-daemon gsd_keyboard_manager_start: start
3.217510 0. 9 MARK: gnome-settings-daemon gsd_keyboard_manager_start: end
3.217524 0. 14 MARK: gnome-settings-daemon load_plugin_module: start mouse
3.219010 0. 1486 MARK: gnome-settings-daemon load_plugin_module: end mouse
3.219015 0. 5 MARK: gnome-settings-daemon gsd_mouse_manager_start: start
3.219237 0. 222 MARK: gnome-settings-daemon gsd_mouse_manager_start: end
3.219252 0. 15 MARK: gnome-settings-daemon load_plugin_module: start a11y-keyboard
3.219790 0. 538 MARK: gnome-settings-daemon load_plugin_module: end a11y-keyboard
3.219796 0. 6 MARK: gnome-settings-daemon gsd_a11y_keyboard_manager_start: start
3.219802 0. 6 MARK: gnome-settings-daemon gsd_a11y_keyboard_manager_start: end
3.219811 0. 9 MARK: gnome-settings-daemon load_plugin_module: start a11y-settings
3.219939 0. 128 MARK: gnome-settings-daemon load_plugin_module: end a11y-settings
3.219945 0. 6 MARK: gnome-settings-daemon gsd_a11y_settings_manager_start: start
3.220044 0. 99 MARK: gnome-settings-daemon gsd_a11y_settings_manager_start: end
3.220057 0. 13 MARK: gnome-settings-daemon load_plugin_module: start smartcard
3.223644 0. 3587 MARK: gnome-settings-daemon load_plugin_module: end smartcard
3.223661 0. 17 MARK: gnome-settings-daemon load_plugin_module: start keybindings
3.224899 0. 1238 MARK: gnome-settings-daemon load_plugin_module: end keybindings
3.224906 0. 7 MARK: gnome-settings-daemon gsd_keybindings_manager_start: start
3.257586 0. 32680 MARK: gnome-settings-daemon gsd_keybindings_manager_start: end
3.257637 0. 51 MARK: gnome-settings-daemon load_plugin_module: start background
3.258175 0. 538 MARK: gnome-settings-daemon load_plugin_module: end background
3.258184 0. 9 MARK: gnome-settings-daemon gsd_background_manager_start: start
3.259876 0. 1692 MARK: gnome-settings-daemon gsd_background_manager_start: end
3.259907 0. 31 MARK: gnome-settings-daemon load_plugin_module: start media-keys
3.260819 0. 912 MARK: gnome-settings-daemon load_plugin_module: end media-keys
3.260826 0. 7 MARK: gnome-settings-daemon gsd_media_keys_manager_start: start
3.260829 0. 3 MARK: gnome-settings-daemon gsd_media_keys_manager_start: start gvc_mixer_control_new
4.361620 1.100791 MARK: gnome-settings-daemon gsd_media_keys_manager_start: end gvc_mixer_control_new
4.361737 0. 117 MARK: gnome-settings-daemon gsd_media_keys_manager_start: end
4.361772 0. 35 MARK: gnome-settings-daemon load_plugin_module: start print-notifications
4.365416 0. 3644 MARK: gnome-settings-daemon load_plugin_module: end print-notifications
4.365424 0. 8 MARK: gnome-settings-daemon gsd_print_notifications_manager_start: start
4.372061 0. 6637 MARK: gnome-settings-daemon gsd_print_notifications_manager_start: end
4.372103 0. 42 MARK: gnome-settings-daemon load_plugin_module: start clipboard
4.372920 0. 817 MARK: gnome-settings-daemon load_plugin_module: end clipboard
4.372930 0. 10 MARK: gnome-settings-daemon gsd_clipboard_manager_start: start
4.372943 0. 13 MARK: gnome-settings-daemon gsd_clipboard_manager_start: end
4.372955 0. 12 MARK: gnome-settings-daemon load_plugin_module: start cursor
4.373246 0. 291 MARK: gnome-settings-daemon load_plugin_module: end cursor
4.373253 0. 7 MARK: gnome-settings-daemon gsd_cursor_manager_start: start
4.373259 0. 6 MARK: gnome-settings-daemon gsd_cursor_manager_start: end
4.373269 0. 10 MARK: gnome-settings-daemon load_plugin_module: start gconf
4.373471 0. 202 MARK: gnome-settings-daemon load_plugin_module: end gconf
4.392716 0. 19245 MARK: gnome-settings-daemon load_plugin_module: start housekeeping
4.393398 0. 682 MARK: gnome-settings-daemon load_plugin_module: end housekeeping
4.393407 0. 9 MARK: gnome-settings-daemon gsd_housekeeping_manager_start: start
4.393702 0. 295 MARK: gnome-settings-daemon gsd_housekeeping_manager_start: end
4.393716 0. 14 MARK: gnome-settings-daemon _load_all: end
4.393722 0. 6 MARK: gnome-settings-daemon gnome_settings_manager_start: end initializing plugins
4.393728 0. 6 MARK: gnome-settings-daemon gnome_settings_manager_start: end
5.494764 1.101036 MARK: gnome-settings-daemon draw_background: start
5.973256 0.478492 MARK: gnome-settings-daemon draw_background: end
6. 27754 0. 54498 MARK: gnome-settings-daemon start_fontconfig_monitor_idle_cb: start
6. 32690 0. 4936 MARK: gnome-settings-daemon start_fontconfig_monitor_idle_cb: end
6. 32707 0. 17 MARK: gnome-settings-daemon gsd_wacom_manager_idle_cb: start
6. 35909 0. 3202 MARK: gnome-settings-daemon gsd_wacom_manager_idle_cb: end
6. 35972 0. 63 MARK: gnome-settings-daemon start_keyboard_idle_cb: start
6. 41936 0. 5964 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: start
6. 61196 0. 19260 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: start xkl_engine_get_instance
6. 61210 0. 14 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: end xkl_engine_get_instance
6. 62754 0. 1544 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: start xkl_engine_start_listen
6. 72335 0. 9581 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: end xkl_engine_start_listen
6. 72345 0. 10 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: start apply_desktop_settings
6. 72689 0. 344 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: end apply_desktop_settings
6. 72697 0. 8 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: start apply_xkb_settings
6. 73528 0. 831 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: end apply_xkb_settings
6. 73538 0. 10 MARK: gnome-settings-daemon gsd_keyboard_xkb_init: end
6. 73806 0. 268 MARK: gnome-settings-daemon start_keyboard_idle_cb: end
6. 73816 0. 10 MARK: gnome-settings-daemon gsd_mouse_manager_idle_cb: start
6.108116 0. 34300 MARK: gnome-settings-daemon gsd_mouse_manager_idle_cb: end
6.108134 0. 18 MARK: gnome-settings-daemon start_a11y_keyboard_idle_cb: start
6.108395 0. 261 MARK: gnome-settings-daemon set_server_from_gsettings: start
6.108783 0. 388 MARK: gnome-settings-daemon set_server_from_gsettings: end
6.108812 0. 29 MARK: gnome-settings-daemon start_a11y_keyboard_idle_cb: end
6.108823 0. 11 MARK: gnome-settings-daemon start_media_keys_idle_cb: start
6.108964 0. 141 MARK: gnome-settings-daemon init_kbd: start
6.114105 0. 5141 MARK: gnome-settings-daemon init_kbd: end
6.114116 0. 11 MARK: gnome-settings-daemon start_media_keys_idle_cb: start gdk_window_add_filter
6.114131 0. 15 MARK: gnome-settings-daemon start_media_keys_idle_cb: end gdk_window_add_filter
6.114136 0. 5 MARK: gnome-settings-daemon start_media_keys_idle_cb: end
6.114146 0. 10 MARK: gnome-settings-daemon start_clipboard_idle_cb: start
6.115167 0. 1021 MARK: gnome-settings-daemon start_clipboard_idle_cb: end
6.115181 0. 14 MARK: gnome-settings-daemon gsd_cursor_manager_idle_cb: start
6.116256 0. 1075 MARK: gnome-settings-daemon gsd_cursor_manager_idle_cb: end

The point at which g-s-d registers with the session manage is just after its main loop starts to run, which happens straight after this point:

4.393722 0. 6 MARK: gnome-settings-daemon gnome_settings_manager_start: end initializing plugins.

So, that's 4.39 seconds there, before the session even begins to load anything else. Looking through the data shows 3 fairly long delays:

0. 23633 0. 14 MARK: gnome-settings-daemon gsd_power_manager_start: start
0.568517 0.544884 MARK: gnome-settings-daemon gsd_power_manager_start: end

0.569608 0. 34 MARK: gnome-settings-daemon gsd_color_manager_start: start
1. 83437 0.513829 MARK: gnome-settings-daemon gsd_color_manager_start: end

So, the color and power plugins eat up a total of 1 second between them. There surely should be no reason at all for this. The big culprit however, is:

1. 84080 0. 15 MARK: gnome-settings-daemon gsd_xrandr_manager_start: start
3.201221 2.117141 MARK: gnome-settings-daemon gsd_xrandr_manager_start: end

Ouch! Didn't we fix this once already?

Changed in gnome-settings-daemon (Ubuntu Oneiric):
assignee: nobody → Canonical Desktop Team (canonical-desktop-team)
Martin Pitt (pitti)
Changed in gnome-settings-daemon (Ubuntu Oneiric):
status: New → Triaged
Changed in ubuntu-boot-speed:
status: New → Confirmed
Revision history for this message
Chris Coulson (chrisccoulson) wrote :

No surprises, but the biggest culprit in both the color and power plugins are gnome_rr_screen_new, accounting for almost all of that 1 second

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

I tried sharing a single GnomeRRScreen instance between plugins, and it shaves a fair bit of time off (it certainly gets rid of the 1 second from the power/color plugins. This bootchart seems to suggest it saves even more though, although I think that's more likely to be some anomaly, like not having my external screen attached)

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

Actually, I misread the bootchart - I measured up until pulseaudio starting, rather than compiz. That makes more sense now - my change saved over a second compared to the original bootchart

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

I think we can probably defer the media-keys plugin intialization too, which is what starts Pulseaudio. I just noticed that's adding another second:

4.361620 1.100791 MARK: gnome-settings-daemon gsd_media_keys_manager_start: end gvc_mixer_control_new

Changed in gnome-settings-daemon (Ubuntu Oneiric):
importance: Undecided → High
assignee: Canonical Desktop Team (canonical-desktop-team) → Chris Coulson (chrisccoulson)
Revision history for this message
Chris Coulson (chrisccoulson) wrote :
Download full text (19.1 KiB)

Ok, so here it is again with the media-keys initialization deferred to the main loop. The session loading time is looking much etter, but still too slow ;)

Here is the profiling log this time (up until the main loop runs):

0.000000 0.000000 MARK: (null) main: start
0.000071 0.000071 MARK: (null) parse_args: start
0.007133 0.007062 MARK: gnome-settings-daemon parse_args: end
0.007147 0.000014 MARK: gnome-settings-daemon main: start opening gtk display
0.017005 0.009858 MARK: gnome-settings-daemon main: end opening gtk display
0.017275 0.000270 MARK: gnome-settings-daemon main: start gnome_settings_manager_new
0.017582 0.000307 MARK: gnome-settings-daemon main: end gnome_settings_manager_new
0.017598 0.000016 MARK: gnome-settings-daemon gnome_settings_manager_start: start
0.017605 0.000007 MARK: gnome-settings-daemon gnome_settings_manager_start: start initializing plugins
0.018212 0.000607 MARK: gnome-settings-daemon _load_all: start
0.018224 0.000012 MARK: gnome-settings-daemon _load_dir: start
0.018293 0.000069 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0.018344 0.000051 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0.018489 0.000145 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0.018908 0.000419 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/sound.gnome-settings-plugin
0.018924 0.000016 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0.018931 0.000007 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0.019000 0.000069 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0.019058 0.000058 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/cursor.gnome-settings-plugin
0.019071 0.000013 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/ubuntuone.gnome-settings-plugin
0.019076 0.000005 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/ubuntuone.gnome-settings-plugin
0.019126 0.000050 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/ubuntuone.gnome-settings-plugin
0.019158 0.000032 MARK: gnome-settings-daemon _load_file: end /usr/lib/gnome-settings-daemon-3.0/ubuntuone.gnome-settings-plugin
0.019169 0.000011 MARK: gnome-settings-daemon _load_file: start /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0.019174 0.000005 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: start /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0.019270 0.000096 MARK: gnome-settings-daemon gnome_settings_plugin_info_fill_from_file: end /usr/lib/gnome-settings-daemon-3.0/clipboard.gnome-settings-plugin
0.019306 0....

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

The xrandr plugin tries to apply each configuration (backup, intended, default) in turn, and takes half a second for each one even when they don't exist. This seems to be because each call to gnome_rr_config_apply_from_filename_with_time does a gnome_rr_screen_refresh. We should fix it to check if there is even a configuration file first, and then skip all of that if there isn't

Changed in gnome-desktop3 (Ubuntu Oneiric):
assignee: nobody → Chris Coulson (chrisccoulson)
importance: Undecided → High
status: New → Triaged
Revision history for this message
Chris Coulson (chrisccoulson) wrote :

So, I've got gsd startup down from >5s to ~0.8s now. Using unity-2d here, my entire session is usable ~2.5s, after entering my password

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

Ok, I've uploaded gnome-desktop and gnome-settings-daemon packages to the ubuntu-desktop PPA [1] now. I'd appreciate some testers for those, just to make sure I've not broken anything and to see if other people get some startup time wins too

[1] - https://launchpad.net/~ubuntu-desktop/+archive/ppa/

Revision history for this message
Sebastien Bacher (seb128) wrote :

the updates work fine for me and reduced the login time from 5 seconds to 3.5 seconds on my config.

Revision history for this message
Sebastien Bacher (seb128) wrote :

in fact the libgnome-desktop-3-2 update leads to have the xrandr session config not applied at login so there is a bug there

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

I've fixed that problem now :)

One thing I've noticed, is that gsd is still calling XRRGetScreenResources twice if you have a monitor config (monitors.xml - ie, you have this if you've ever changed your display configuration), because gnome_rr_config_apply_from_filename_with_time() does gnome_rr_screen_refresh() before doing anything else. It seems a bit unnecessary to do this more than once at session start, and it sucks that people who have ever changed a monitor setting are hit by that.

What we need is a ubuntu_rr_config_apply_from_filename_with_time_without_refresh() for gsd to call ;)

/me runs and hides

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

In fact, isn't this refresh totally bogus anyway? After all, with X being asynchronous anyway, the information could already be out-of-date on the server by the time we've finished the XRRGetScreenResources call. And for applications that call gnome_rr_config_apply_from_filename_with_time from some event source off its main loop, then gnome-desktop already refreshes it's state from the server on each RRScreenChangeNotify notification anyway.

Revision history for this message
Chris Coulson (chrisccoulson) wrote :

Sorry, thinking out aloud now ;)

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package gnome-desktop3 - 3.1.92-0ubuntu2

---------------
gnome-desktop3 (3.1.92-0ubuntu2) oneiric; urgency=low

  * Fix LP: #854101
  * debian/patches/01_avoid_refresh_on_config_apply.patch.patch:
    - In gnome_rr_config_apply_from_filename_with_time(), don't call
      gnome_rr_screen_refresh(). This is pointless due to the async nature
      of X, and the protocol already guards agains the possiblilty that the
      client view of the display configuration is out-of-date. This function is
      also called 3 times during the critical path at startup by
      gnome-settings-daemon (for each possible display config file), which
      wastes around 1.5s
 -- Chris Coulson <email address hidden> Thu, 22 Sep 2011 15:29:40 +0100

Changed in gnome-desktop3 (Ubuntu Oneiric):
status: Triaged → Fix Released
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package gnome-settings-daemon - 3.1.92-0ubuntu3

---------------
gnome-settings-daemon (3.1.92-0ubuntu3) oneiric; urgency=low

  * Fix LP: #854101 - various startup time improvements:
  * debian/patches/46_share_rr_screen.patch:
    - Share a single GnomeRRScreen across plugins, rather than having the
      xrandr, color and power plugins each create their own, which results
      in 3 reprobes before running the main loop. Thanks to Rodrigo Moya for
      tidying this up a bit.
  * debian/patches/47_delay_pa_connect_to_idle.patch:
    - Don't connect to pulseaudio until we are running the main loop. Starting
      pulseaudio seems to block for around a second here on my machine
  * debian/patches/48_register_client_before_idle_callbacks.patch:
    - Create the GDBusProxy for gnome-session synchronously, and then schedule
      the RegisterClient call with a higher priority. This ensures that we
      register with the session manager as soon as we start the main loop, and
      before running any other idle callbacks

  * debian/patches/16_use_synchronous_notifications.patch:
    - Make the volume notifications work correctly again
 -- Chris Coulson <email address hidden> Thu, 22 Sep 2011 15:44:40 +0100

Changed in gnome-settings-daemon (Ubuntu Oneiric):
status: Triaged → Fix Released
Martin Pitt (pitti)
Changed in ubuntu-boot-speed:
status: Confirmed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.