gnome-settings-daemon takes waaaaaaaay too long to start

Bug #854101 reported by Chris Coulson on 2011-09-19
20
This bug affects 4 people
Affects Status Importance Assigned to Milestone
The Ubuntu Boot Speed Project
Undecided
Unassigned
gnome-desktop3 (Ubuntu)
High
Chris Coulson
Oneiric
High
Chris Coulson
gnome-settings-daemon (Ubuntu)
High
Chris Coulson
Oneiric
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) on 2011-09-19
Changed in gnome-settings-daemon (Ubuntu Oneiric):
status: New → Triaged
Changed in ubuntu-boot-speed:
status: New → Confirmed
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

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)

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

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)
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....

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
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

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/

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.

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

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

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.

Chris Coulson (chrisccoulson) wrote :

Sorry, thinking out aloud now ;)

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
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) on 2011-09-28
Changed in ubuntu-boot-speed:
status: Confirmed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers