Performance data for nautilus

["Anand Subramanian" <anand subra wipro com>]

Hello everyone.

On a sequel to the gedit performance data, we are attaching the
performance report for nautilus. The forte and quantify tools were used
to collect performance data. The attached html report details the
nautilus test scenarios, a brief  analysis and links to the performance
data. Please do get back to us in case you require any additional
information.

Thanks,
Muktha and Anand

Title:

Nautilus Performance Data Summary Report
(version 1.0)

1. Component Summary
 
 

Name of the Component	Nautilus
QA Contact	muktha narayan wipro com, anand subra wipro com
Test Setup	Config Parameter		Forte Setup		Quantify Setup
	Hardware Details		Sparc Ultra 10, 1 cpu		Sparc Ultra 250, 2 cpu
	Memory		128 MB		1024 MB
	Operating system		Solaris 9, 64 Bit		Solaris 8, 64 Bit
Build Details	Source Code Location			CVS
	CVS Branch			Multihead
	CVS Checkout Time Stamp			Forte	Quantify
				Fri Sep 27 01:49:37 2002	Thu Oct 3 01:29:16 2002
	Compiler (Version Infomation)			Forte
Performance Utilities Used	Quantify			qv
	Forte			collect  er_print
	Other Tools/Scripts			-
Total. No. Of tests Run	2

 

2. Brief Description of Tests Done to Collect Performance Data
 
 

Test No.	Test synopsis
Nautilus_01	Invoked Nautilus, copied files/folders (approx. 20 items), browsed to another folder in the same window and pasted them. Closed the nautilus window (Using File/Close Window).
Nautilus_02	Invoked nautilus, and created a new nautilus window (Using File/New Window). Closed all nautilus windows (Using File/Close All Windows).

Note: Nautilus was not used to draw the desktop.
 

3. Data

3.1 Test: Nautilus_01

As per the quantify data collected, the top five functions which consumed the maximum percentage of the total execution time, have been considered for the analysis.

The forte leaks data showed a total of 1.7 MB leak when a folder containing 20 items was copied and pasted.
 

Function Name	Caller	Callees	Quantify Details	Forte Details
_MiniXftStrCmpIgnoreCase	_sigon MiniXftConfigSubstitute  _MiniXftConfigCompareValue _MiniXftNameConstantLookup MiniXftNameGetType  MiniXftPatternFind  _MiniXftCompareString  _MiniXftCompareValueList  _MiniXftCompare	None	Called: 3767220 times Function time: 577935920 cycles ( 10.69% of .root.) Function+descendants time: 580237934 cycles ( 10.73% of .root.)	Exclusive time: 0.090 secs Inclusive time: 0.090 secs Attributed time: 0.090 secs
lookup_type_node_I	g_type_register_dynamic  type_data_ref_Wm  type_data_last_unref_Wm  type_data_finalize_class_U  g_type_interface_add_prerequisite  g_type_qname  g_type_set_qdata  type_iface_vtable_init_Wm  g_type_register_fundamental  g_type_depth  g_type_get_qdata  g_type_add_interface_static  check_add_interface_L  type_data_make_W  g_type_register_static  check_derivation_I  check_type_info_I  g_type_class_peek_parent  g_type_interfaces  g_type_check_class_is_a  type_class_init_Wm  g_type_name  g_type_interface_peek  g_type_class_peek  g_type_test_flags  type_node_fundamental_info_I  g_type_parent  g_type_free_instance  g_type_fundamental  g_type_class_unref  g_type_class_ref  g_type_create_instance  g_type_check_instance  g_type_check_class_cast  g_type_is_a  g_type_value_table_peek  type_check_is_value_type_U  g_type_check_instance_cast  g_type_check_instance_is_a	None	Called: 7504454 times Function time: 265918521 cycles ( 4.92% of .root.) Function+descendants time: 265918521 cycles ( 4.92% of .root.)	Exclusive time: 0.810 secs Inclusive time: 0.810 secs Attributed time: 0.810 secs
type_node_check_conformities_UorL	type_node_is_a_L type_node_conforms_to_U	None	Called: 2443819 times Function time: 198645181 cycles ( 3.67% of .root.) Function+descendants time: 198752566 cycles ( 3.68% of .root.)	Exclusive time: 0.510 secs Inclusive time: 0.510 secs Attributed time: 0.510 secs
composite	gdk_drawable_real_draw_pixbuf	None	Called: 483 times Function time: 184532174 cycles ( 3.41% of .root.) Function+descendants time: 184532174 cycles ( 3.41% of .root.)	Exclusive time: 0.270 secs Inclusive time: 0.270 secs Attributed time: 0.270 secs
rgb8	rgbconvert	None	Called: 549 times Function time: 146684518 cycles ( 2.71% of .root.) Function+descendants time: 146684518 cycles ( 2.71% of .root.)	Exclusive time: 0.190 secs Inclusive time: 0.190 secs Attributed time: 0.190 secs

 

3.1.1 Forte Collect Data
 
 

Sl. No.	Data Collected	Pointer to Data
1	er_print callers-callees data	Gunzipped Text File (101 KB)
2	er_print leaks data (for the top 500 leaks)[1]	Gunzipped Text File (56 KB)

 

3.1.2 Quantify Data
 
 

Sl. No.	Data description	Pointer to Data
1	Functions list	Gunzipped Text File (69 KB)
2	Export File	Gunzipped Text File (628 KB)
3	Annotated source files for the top five expensive functions	- MiniXftStrCmpIgnoreCase (2 KB) - lookup_type_node_I (69 KB) - type_node_check_conformities_UorL (69 KB) - composite (15 KB) - rgb8 (9 KB)

[1] Due to huge sizes of the er_print data for leaks, the data in the attached gunzipped files have been limited to the top 500 leaks only. The complete leaks information is however available and can be provided, if required.
 
 

3.2 Test: Nautilus_02

As per the quantify data collected, the top five functions which consumed the maximum percentage of the total execution time, have been considered for the analysis. The top five also included functions like 'match_re_C', '_free_unlocked', that are related to libc and libthread. These functions are excluded from the table, below.

The forte leaks data showed a total of 1.4 MB leak when a new nautilus window was invoked from an existing window, and all the windows closed.
 

Function Name	Caller	Callees	Quantify Details	Forte Details
_MiniXftStrCmpIgnoreCase	_sigon  MiniXftConfigSubstitute  _MiniXftConfigCompareValue  _MiniXftNameConstantLookup  MiniXftNameGetType  MiniXftPatternFind  _MiniXftCompareString  _MiniXftCompareValueList  _MiniXftCompare	None	Called: 1152885 times Function time: 176248175 cycles ( 5.21% of .root.) Function+descendants time: 176898539 cycles ( 5.23% of .root.)	Exclusive time: 0.100 secs Inclusive time: 0.100 secs Attributed time: 0.100 secs
lookup_type_node_I	g_type_register_dynamic  type_data_ref_Wm  type_data_last_unref_Wm  type_data_finalize_class_U  g_type_interface_add_prerequisite  g_type_qname  g_type_set_qdata  type_iface_vtable_init_Wm  g_type_register_fundamental  g_type_depth  g_type_get_qdata  g_type_add_interface_static  check_add_interface_L  type_data_make_W  g_type_register_static  check_derivation_I  check_type_info_I  g_type_class_peek_parent  g_type_interfaces  g_type_check_class_is_a  type_class_init_Wm  g_type_name  g_type_interface_peek  g_type_class_peek  g_type_test_flags  type_node_fundamental_info_I  g_type_parent  g_type_free_instance  g_type_fundamental  g_type_class_unref  g_type_class_ref  g_type_create_instance  g_type_check_instance  g_type_check_class_cast  g_type_is_a  g_type_value_table_peek  type_check_is_value_type_U  g_type_check_instance_cast  g_type_check_instance_is_a	None	Called: 4103986 times Function time: 144444113 cycles ( 4.27% of .root.) Function+descendants time: 144444113 cycles ( 4.27% of .root.)	Exclusive time: 0.490 secs Inclusive time: 0.490 secs Attributed time: 0.490 secs
type_node_check_conformities_UorL	type_node_is_a_L  type_node_conforms_to_U	None	Called: 1474848 times Function time: 119955353 cycles ( 3.54% of .root.) Function+descendants time: 120068916 cycles ( 3.55% of .root.)	Exclusive time:0.44 secs Inclusive time: 0.44 secs Attributed time: 0.44 secs
g_type_check_instance_cast	gdk_x11_gc_set_values _gdk_x11_gc_flush gdk_event_translate gdk_x11_draw_glyphs get_size_groups gnome_canvas_request_redraw gtk_container_destroy gtk_menu_item_forall gtk_object_get_data_by_id gtk_widget_propagate_hierarchy_changed_recurse gtk_widget_real_unmap gtk_widget_set_parent impl_bonobo_ui_sync_menu_state _gdk_window_destroy_hierarchy _gdk_window_process_expose bonobo_socket_size_request bonobo_ui_sync_do_show_hide do_size_request draw_or_measure_label_text fm_icon_view_compare_files g_param_spec_int gdk_check_xpending get_docked_item_by_name get_icon_info gtk_bin_remove gtk_container_add gtk_container_get_resize_container gtk_container_propagate_expose gtk_container_remove gtk_frame_forall gtk_grab_notify_foreach gtk_hpaned_size_request gtk_image_clear gtk_image_menu_item_forall gtk_label_destroy gtk_object_init gtk_object_set_data_by_id gtk_selection_target_list_remove gtk_vbox_size_allocate gtk_widget_dispose gtk_widget_finalize gtk_widget_get_extension_events gtk_widget_get_pango_context gtk_widget_propagate_state gtk_widget_real_get_accessible gtk_widget_reset_rc_style gtk_widget_send_expose impl_bonobo_ui_sync_menu_get_widgets pango_fontset_simple_get_font real_queue_resize size_allocate_helper widget_new_accel_closure gtk_object_dispose gtk_signal_emit	type_node_conforms_to_U lookup_type_node_I	Called: 591038 times Function time: 78017016 cycles ( 2.30% of .root.) Function+descendants time: 195727938 cycles ( 5.78% of .root.)	Exclusive time: 0.340 secs Inclusive time: 0.700 secs Attributed time: 0.340 secs
g_type_check_instance_is_a	g_object_unref g_param_spec_unref g_object_get_qdata g_param_spec_ref gdk_draw_points nautilus_file_is_local g_object_ref gdk_draw_segments gtk_signal_emit _gtk_container_queue_resize _gtk_menu_refresh_accel_paths bonobo_object_check_env bonobo_object_unref bonobo_ui_component_set_prop bonobo_ui_toolbar_item_get_expandable g_object_get_data g_object_run_dispose g_param_value_validate gdk_draw_glyphs gdk_drawable_get_colormap gdk_drawable_get_depth gdk_drawable_get_screen gdk_drawable_set_colormap gdk_gc_set_clip_origin gdk_gc_set_ts_origin gdk_gc_set_values gdk_pixmap_real_get_colormap gdk_screen_get_display gdk_window_impl_x11_set_colormap gdk_window_real_get_colormap gdk_x11_gc_set_values gdk_xid_table_lookup_for_display get_file_node gtk_label_select_region_index gtk_menu_item_forall gtk_object_get_data_by_id gtk_object_set_data gtk_widget_get_screen_unchecked gtk_widget_realize gtk_widget_set_parent gtk_widget_unref impl_bonobo_ui_sync_menu_ignore_widget nautilus_file_new_from_info pango_ft2_font_set_glyph_cache_destroy gdk_draw_line gtk_widget_queue_resize	type_node_conforms_to_U lookup_type_node_I	Called: 675085 times Function time: 74226606 cycles ( 2.19% of .root.) Function+descendants time: 210270960 cycles ( 6.21% of .root.)	Exclusive time: 0.190 secs Inclusive time: 0.670 secs Attributed time: 0.190 secs

 

3.2.1 Forte Collect Data
 
 

Sl. No.	Data Collected	Pointer to Data
1	er_print callers-callees data	Gunzipped Text File (91 KB)
2	er_print leaks data (for the top 500 leaks)[1]	Gunzipped Text File (56 KB)

 

3.2.2 Quantify Data
 
 

Sl. No.	Data description	Pointer to Data
1	Functions list	Gunzipped Text File (63 KB)
2	Export File	Gunzipped Text File (589 KB)
3	Annotated source files for the top five expensive functions	- MiniXftStrCmpIgnoreCase (2 KB) - lookup_type_node_I (66 KB) - type_node_check_conformities_UorL (66 KB) - g_type_check_instance_cast (66 KB) - g_type_check_instance_is_a (66 KB)

[1] Due to huge sizes of the er_print data for leaks, the data in the attached gunzipped files have been limited to the top 500 leaks only. The complete leaks information is however available and can be provided, if required.

4. Appendix

4.1 Forte data

Data is collected using the 'collect' and 'er_print' forte profiling tools. Data can be collected using the 'collect'command. All data can be converted into performance metrics computed against functions, callers and callees of any functions, and against source and disassembly of the target program. The 'er_print' command is used to get an ASCII output of the performance metrics obtained from the 'collect' command. 

Three types of function-level metrics can be computed using the performance analysis tools:

Exclusive metrics: are calculated from events which occur inside the function itself: they exclude metrics coming from calls to other functions. 

Inclusive metrics: are collected from events which occur inside the function and any functions it calls: they include metrics coming from calls to other functions

Attributed metrics:are the parts of the inclusive metric of the selected function that are due to calls from a caller or calls to a callee.
 

Exclusive user CPU time is the amount of time spent in the function itself, in seconds

Inclusive user CPU time is the amount of time spent in the function itself and any functions it calls, in seconds
 

Callers-callees data: Prints the callers-callees panel for each of the functions, in the order in which they are sorted. The selected (middle) function is marked with an asterisk. The callers of the selected function are shown above. The functions which the selected function calls are listed below.

Leaks data: The ?Leaks? report shows what memory has been leaked while the program was running.
 
 

4.2 Quantify data

Functions list: Displays the list of function calls sorted by percentage of '.root'

Exports file: Is the ASCII version of the quantify data. Elaborates on all the callers of a particular function, the number of times the function was called, propagated time, the function descendant time and many more metrics.

Annotated source: Presents a line by line performance data using the functions source code.