Hi all,
Over the past year, or maybe even longer, I've been annoyed at how long
it takes for Inkscape to start. Admittedly, I get easily annoyed because
it takes only about 10 seconds for the main window to be drawn, but
still.... After that it takes another 10 to 15 seconds before the CPU
gets idle again, but during that second period Inkscape can already be
used.
On launchpad I've seen reports that this could be related to the number
of fonts installed, which could indeed be part of the problem. But I
also noticed this across many systems, even when not that many fonts
were installed. So I figured that the only way to find out was to do
some profiling. I've attached only a part of the profiling output below
(If you want all of it then I'll gladly send you the 18 MB file).
Roughly the first 10 seconds have been profiled, because I immediately
quit Inkscape as soon as the main window was drawn. (Actually the first
phase takes a lot longer than 10 seconds when profiling; those 10
seconds have been measured with all debugging and profiling flags disabled)
What I found out was that it is prerender_icon() that causes the biggest
part of the delay during those first 10 seconds. Maybe this is a public
secret, but I just wanted to share this with you. I have no intention
currently of improving this, but this at least allows us to respond
accurately to some bug reports.
Regards,
Diederik
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
13.69 0.72 0.72 356031 0.00 0.01
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int)
6.65 1.07 0.35 435568 0.00 0.00
Inkscape::Preferences::_getNode(Glib::ustring const&, bool)
5.51 1.36 0.29 28329840 0.00 0.00
Inkscape::XML::SimpleNode::attribute(char const*) const
4.85 1.62 0.26 57980026 0.00 0.00
Inkscape::Util::List<Inkscape::XML::AttributeRecord const>::operator->()
const
4.18 1.84 0.22 28131371 0.00 0.00
_ZNK8Inkscape4Util10ptr_sharedIcEcvPKT_IcEEv
3.80 2.04 0.20 26795143 0.00 0.00
Inkscape::XML::SimpleNode::next()
3.42 2.22 0.18 32836208 0.00 0.00
Geom::Matrix::operator[](unsigned int) const
2.28 2.34 0.12 1236181 0.00 0.00
nr_object_check_instance_type(void const*, unsigned int)
2.28 2.46 0.12 797442 0.00 0.00
Geom::operator*(Geom::Matrix const&, Geom::Matrix const&)
1.81 2.55 0.10 30331635 0.00 0.00
Inkscape::Util::List<Inkscape::XML::AttributeRecord const>::operator
bool() const
1.81 2.65 0.10 virtual thunk to
Inkscape::XML::SimpleNode::attribute(char const*) const
1.71 2.74 0.09 1898740 0.00 0.00
Geom::operator*(Geom::Point const&, Geom::Matrix const&)
1.52 2.82 0.08 1661332 0.00 0.00
Geom::Bezier::at1() const
1.52 2.90 0.08 203312 0.00 0.01
nr_arena_shape_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int)
1.24 2.96 0.07 9319609 0.00 0.00
Geom::Point::operator[](Geom::Dim2) const
0.95 3.01 0.05 813223 0.00 0.00
boost::shared_ptr<Geom::Curve const>::operator*() const
0.95 3.06 0.05 152487 0.00 0.00
nr_arena_group_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int)
0.76 3.10 0.04 2750545 0.00 0.00
std::vector<Shape::dg_arete, std::allocator<Shape::dg_arete>
>::operator[](unsigned long) const
0.76 3.14 0.04 2036510 0.00 0.00
cr_utils_read_char_from_utf8_buf
0.76 3.18 0.04 1558360 0.00 0.00
Geom::Matrix::operator=(Geom::Matrix const&)
0.76 3.22 0.04 1165706 0.00 0.00
NRArenaShape::Paint::type() const
% the percentage of the total running time of the
time program used by this function.
cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.
self the number of seconds accounted for by this
seconds function alone. This is the major sort for this
listing.
calls the number of times this function was invoked, if
this function is profiled, else blank.
self the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.
total the average number of milliseconds spent in this
ms/call function and its descendents per call, if this
function is profiled, else blank.
name the name of the function. This is the minor sort
for this listing. The index shows the location of
the function in the gprof listing. If the index is
in parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
Call graph (explanation follows)
granularity: each sample hit covers 2 byte(s) for 0.19% of 5.26 seconds
index % time self children called name
0.00 0.27 6/102
Inkscape::queueIconPrerender(Glib::ustring const&, Inkscape::IconSize) [33]
0.00 1.18 26/102
icon_prerender_task(void*) [15]
0.00 3.19 70/102
imageMapNamedCB(_GtkWidget*, void*) [5]
[1] 88.3 0.00 4.64 102 prerender_icon(char const*,
GtkIconSize, unsigned int) [1]
0.00 4.64 87/87 load_svg_pixels(char
const*, unsigned int, unsigned int) [2]
0.00 0.00 182/186
std::set<Glib::ustring, std::less<Glib::ustring>,
std::allocator<Glib::ustring> >::find(Glib::ustring const&) [545]
0.00 0.00 78/82
std::set<Glib::ustring, std::less<Glib::ustring>,
std::allocator<Glib::ustring> >::insert(Glib::ustring const&) [640]
0.00 0.00 87/87
std::map<Glib::ustring, _GdkPixbuf*, std::less<Glib::ustring>,
std::allocator<std::pair<Glib::ustring const, _GdkPixbuf*> >
>::operator[](Glib::ustring const&) [1199]
0.00 0.00 102/102
get_cached_pixbuf(Glib::ustring const&) [1229]
0.00 0.00 87/87
addToIconSet(_GdkPixbuf*, char const*, GtkIconSize, unsigned int) [1466]
0.00 0.00 1/663464
Inkscape::Preferences::get() <cycle 1> [340]
0.00 0.00 1/663464
Inkscape::Preferences::getBool(Glib::ustring const&, bool) <cycle 1> [271]
0.00 0.00 182/186
std::set<Glib::ustring, std::less<Glib::ustring>,
std::allocator<Glib::ustring> >::end() const [6073]
0.00 0.00 102/102 icon_cache_key(char
const*, unsigned int) [6298]
0.00 0.00 95/99
std::_Rb_tree_const_iterator<Glib::ustring>::operator!=(std::_Rb_tree_const_iterator<Glib::ustring>
const&) const [6311]
0.00 0.00 87/87
std::_Rb_tree_const_iterator<Glib::ustring>::operator==(std::_Rb_tree_const_iterator<Glib::ustring>
const&) const [6385]
-----------------------------------------------
0.00 4.64 87/87 prerender_icon(char
const*, GtkIconSize, unsigned int) [1]
[2] 88.2 0.00 4.64 87 load_svg_pixels(char
const*, unsigned int, unsigned int) [2]
0.00 4.51 87/87 sp_icon_doc_icon [3]
0.02 0.11 1/2
sp_item_invoke_show(SPItem*, NRArena*, unsigned int, unsigned int)
<cycle 5> [46]
0.00 0.01 1/13
sp_document_ensure_up_to_date(SPDocument*) [59]
0.00 0.00 1/2 sp_document_new(char
const*, unsigned int, bool) [695]
0.00 0.00 174/174
std::map<Glib::ustring, svg_doc_cache_t*, std::less<Glib::ustring>,
std::allocator<std::pair<Glib::ustring const, svg_doc_cache_t*> >
>::find(Glib::ustring const&) [1328]
0.00 0.00 1/1
std::map<Glib::ustring, svg_doc_cache_t*, std::less<Glib::ustring>,
std::allocator<std::pair<Glib::ustring const, svg_doc_cache_t*> >
>::operator[](Glib::ustring const&) [1797]
0.00 0.00 1/2 NRArena::create() [1862]
0.00 0.00 261/276 std::list<char*,
std::allocator<char*> >::end() [5914]
0.00 0.00 261/267
std::_List_iterator<char*>::operator!=(std::_List_iterator<char*>
const&) const [5930]
0.00 0.00 174/183
std::_List_iterator<char*>::operator*() const [6076]
0.00 0.00 174/175
std::map<Glib::ustring, svg_doc_cache_t*, std::less<Glib::ustring>,
std::allocator<std::pair<Glib::ustring const, svg_doc_cache_t*> >
>::end() [6084]
0.00 0.00 174/174
std::_Rb_tree_iterator<std::pair<Glib::ustring const, svg_doc_cache_t*>
>::operator!=(std::_Rb_tree_iterator<std::pair<Glib::ustring const,
svg_doc_cache_t*> > const&) const [6087]
0.00 0.00 174/178
std::_List_iterator<char*>::operator++() [6080]
0.00 0.00 88/256
Inkscape::IO::file_test(char const*, GFileTest) [5942]
0.00 0.00 87/87 icons_svg_paths() [6378]
0.00 0.00 87/99 std::list<char*,
std::allocator<char*> >::begin() [6313]
0.00 0.00 86/86
std::_Rb_tree_iterator<std::pair<Glib::ustring const, svg_doc_cache_t*>
>::operator->() const [6395]
0.00 0.00 1/8
sp_item_display_key_new(unsigned int) [7822]
0.00 0.00 1/95963 sp_item_get_type() [2923]
-----------------------------------------------
0.00 4.51 87/87 load_svg_pixels(char
const*, unsigned int, unsigned int) [2]
[3] 85.7 0.00 4.51 87 sp_icon_doc_icon [3]
0.84 3.29 135/136
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [6]
0.00 0.37 87/87
nr_arena_item_invoke_render(_cairo*, NRArenaItem*, NRRectL const*,
NRPixBlock*, unsigned int) <cycle 11> [26]
0.00 0.00 87/4399
SPItem::getBounds(Geom::Matrix const&, SPItem::BBoxType, unsigned int)
const [84]
0.00 0.00 135/3802
nr_arena_item_set_transform(NRArenaItem*, Geom::Matrix const&) [210]
0.00 0.00 174/663464
Inkscape::Preferences::get() <cycle 1> [340]
0.00 0.00 174/663464
Inkscape::Preferences::getBool(Glib::ustring const&, bool) <cycle 1> [271]
0.00 0.00 87/89
sp_item_i2doc_affine(SPItem const*) [1110]
0.00 0.00 135/142 Geom::Scale::operator
Geom::Matrix() const [1396]
0.00 0.00 540/225255
boost::optional<Geom::D2<Geom::Interval> >::operator->() [538]
0.00 0.00 87/684872
Geom::OptRect::~OptRect() [113]
0.00 0.00 87/428739
boost::optional<Geom::D2<Geom::Interval> >::operator bool
(boost::optional_detail::optional_base<Geom::D2<Geom::Interval> >::*)()
const() const [382]
0.00 0.00 270/9489
Geom::D2<Geom::Interval>::min() const [1164]
0.00 0.00 270/9505
Geom::D2<Geom::Interval>::max() const [1163]
0.00 0.00 135/1010
Geom::Scale::Scale(double, double) [1517]
0.00 0.00 540/1789678
Geom::Point::operator[](Geom::Dim2) [2831]
0.00 0.00 261/95963 sp_item_get_type() [2923]
0.00 0.00 135/8015
Geom::Matrix::setIdentity() [3556]
0.00 0.00 87/5269
SPDocument::getObjectById(char const*) [3796]
0.00 0.00 87/712709 NRGC::NRGC(NRGC
const*) [2849]
0.00 0.00 87/103582 int const&
std::max<int>(int const&, int const&) [2919]
0.00 0.00 87/453
nr_pixblock_setup_extern(NRPixBlock*, NR_PIXBLOCK_MODE, int, int, int,
int, unsigned char*, int, bool, bool) [5696]
0.00 0.00 87/1997
nr_pixblock_release(NRPixBlock*) [4561]
-----------------------------------------------
[4] 79.2 0.85 3.31 136+711791 <cycle 10 as a whole> [4]
0.72 1.95 356031+291
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [6]
0.08 1.21 203312
nr_arena_shape_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [14]
0.05 0.15 152487
nr_arena_group_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [40]
0.00 0.00 97
nr_arena_glyphs_group_update(NRArenaItem*, NRRectL*, NRGC*, unsigned
int, unsigned int) <cycle 10> [1516]
-----------------------------------------------
<spontaneous>
[5] 60.6 0.00 3.19
imageMapNamedCB(_GtkWidget*, void*) [5]
0.00 3.19 70/102 prerender_icon(char
const*, GtkIconSize, unsigned int) [1]
0.00 0.00 70/103
sp_icon_get_phys_size(int) [1462]
0.00 0.00 10554/10554
__gnu_cxx::__normal_iterator<preRenderItem*, std::vector<preRenderItem,
std::allocator<preRenderItem> > >::operator->() const [3445]
0.00 0.00 10458/10778
Glib::operator==(Glib::ustring const&, char const*) [3438]
0.00 0.00 10458/10659
std::vector<preRenderItem, std::allocator<preRenderItem> >::end() [3442]
0.00 0.00 10458/10554 bool
__gnu_cxx::operator!=<preRenderItem*, std::vector<preRenderItem,
std::allocator<preRenderItem> >
>(__gnu_cxx::__normal_iterator<preRenderItem*,
std::vector<preRenderItem, std::allocator<preRenderItem> > > const&,
__gnu_cxx::__normal_iterator<preRenderItem*, std::vector<preRenderItem,
std::allocator<preRenderItem> > > const&) [3444]
0.00 0.00 10388/10388
__gnu_cxx::__normal_iterator<preRenderItem*, std::vector<preRenderItem,
std::allocator<preRenderItem> > >::operator++() [3452]
0.00 0.00 70/132
std::vector<preRenderItem, std::allocator<preRenderItem> >::begin() [6218]
0.00 0.00 70/96
std::vector<preRenderItem, std::allocator<preRenderItem>
>::erase(__gnu_cxx::__normal_iterator<preRenderItem*,
std::vector<preRenderItem, std::allocator<preRenderItem> > >) [6348]
-----------------------------------------------
291
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [6]
291
nr_arena_shape_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [14]
355604
nr_arena_group_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [40]
0.01 0.02 1/136
sp_canvas_arena_update(SPCanvasItem*, Geom::Matrix const&, unsigned int)
[122]
0.84 3.29 135/136 sp_icon_doc_icon [3]
[6] 50.8 0.72 1.95 356031+291
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [6]
0.00 1.79 203797/215263
nr_arena_item_request_render(NRArenaItem*) [7]
0.07 0.00 712606/1236181
nr_object_check_instance_type(void const*, unsigned int) [53]
0.03 0.03 178043/797442
Geom::operator*(Geom::Matrix const&, Geom::Matrix const&) [35]
0.01 0.00 534327/1558360
Geom::Matrix::operator=(Geom::Matrix const&) [103]
0.00 0.01 356284/356284 NRGC::operator=(NRGC
const&) [437]
0.01 0.00 356284/521878
nr_arena_group_get_type() [379]
0.00 0.00 97/97
nr_arena_image_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) [689]
0.00 0.00 388/388
nr_arena_glyphs_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) [744]
0.00 0.00 291/30393
nr_rect_l_intersect(NRRectL*, NRRectL const*, NRRectL const*) [393]
0.00 0.00 356322/712709 NRGC::NRGC(NRGC
const*) [2849]
0.00 0.00 356322/863943
nr_arena_item_get_type() [2845]
203312
nr_arena_shape_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [14]
152390
nr_arena_group_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [40]
97
nr_arena_glyphs_group_update(NRArenaItem*, NRRectL*, NRGC*, unsigned
int, unsigned int) <cycle 10> [1516]
291
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [6]
-----------------------------------------------
0.00 0.00 2/215263
nr_arena_item_unparent(NRArenaItem*) [1319]
0.00 0.00 3/215263
nr_arena_item_set_clip(NRArenaItem*, NRArenaItem*) [1253]
0.00 0.00 4/215263
nr_arena_glyphs_set_path(NRArenaGlyphs*, SPCurve*, unsigned int,
font_instance*, int, Geom::Matrix const*) [1214]
0.00 0.00 4/215263
nr_arena_glyphs_group_add_component(NRArenaGlyphsGroup*, font_instance*,
int, Geom::Matrix const&) [1092]
0.00 0.00 97/215263
nr_arena_image_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) [689]
0.00 0.02 1932/215263
nr_arena_item_set_transform(NRArenaItem*, Geom::Matrix const*) [212]
0.00 0.02 2096/215263
nr_arena_shape_set_path(NRArenaShape*, SPCurve*, bool) [166]
0.00 0.03 3664/215263
nr_arena_item_set_opacity(NRArenaItem*, double) [116]
0.00 0.03 3664/215263
nr_arena_item_set_visible(NRArenaItem*, unsigned int) [117]
0.00 1.79 203797/215263
nr_arena_item_invoke_update(NRArenaItem*, NRRectL*, NRGC*, unsigned int,
unsigned int) <cycle 10> [6]
[7] 35.9 0.00 1.89 215263
nr_arena_item_request_render(NRArenaItem*) [7]
0.02 1.85 215263/215263
nr_arena_request_render_rect(NRArena*, NRRectL*) [9]
0.02 0.00 215263/1236181
nr_object_check_instance_type(void const*, unsigned int) [53]
0.00 0.00 215263/863943
nr_arena_item_get_type() [2845]
-----------------------------------------------
[8] 35.7 0.08 1.80 663464+1538951 <cycle 1 as a whole> [8]
0.01 1.45 431095
Inkscape::Preferences::getInt(Glib::ustring const&, int) <cycle 1> [12]
0.00 0.14 2482
sp_style_merge_from_style_string(SPStyle*, char const*) <cycle 1> [49]
0.01 0.05 25012 sp_path_set(SPObject*,
unsigned int, char const*) <cycle 1> [80]
0.01 0.04 459+28821
sp_repr_svg_read_node(Inkscape::XML::Document*, _xmlNode*, char const*,
_GHashTable*) <cycle 1> [85]
0.00 0.03 35384+37576
Inkscape::XML::CompositeNodeObserver::notifyAttributeChanged(Inkscape::XML::Node&,
unsigned int, Inkscape::Util::ptr_shared<char>,
Inkscape::Util::ptr_shared<char>) <cycle 1> [125]
0.01 0.01 36965
Inkscape::XML::SimpleNode::setAttribute(char const*, char const*, bool)
<cycle 1> [180]
0.00 0.02 2272
sigc::internal::signal_emit2<void, SPObject*, SPObject*,
sigc::nil>::emit(sigc::internal::signal_impl*, SPObject* const&,
SPObject* const&) <cycle 1> [230]
0.01 0.00 81742
sp_object_read_attr(SPObject*, char const*) <cycle 1> [260]
0.00 0.01 3622
Inkscape::Preferences::getBool(Glib::ustring const&, bool) <cycle 1> [271]
0.00 0.01 1739
sp_path_update_patheffect(SPLPEItem*, bool) <cycle 1> [297]
0.00 0.01 135
sp_svg_write_path(std::vector<Geom::Path, std::allocator<Geom::Path> >
const&) <cycle 1> [303]
0.01 0.00 650246
Inkscape::Preferences::get() <cycle 1> [340]
0.01 0.00 20173
sp_style_merge_style_from_decl(SPStyle*, _CRDeclaration const*) <cycle
1> [348]
0.01 0.00 5361 sp_arc_set(SPObject*,
unsigned int, char const*) <cycle 1> [349]
0.00 0.01 20+518
Inkscape::XML::SimpleNode::mergeFrom(Inkscape::XML::Node const*, char
const*) <cycle 1> [474]
0.00 0.00 3666
sp_style_read(SPStyle*, SPObject*, Inkscape::XML::Node*) <cycle 1> [526]
0.00 0.00 130
sp_genericellipse_update_patheffect(SPLPEItem*, bool) <cycle 1> [532]
0.00 0.00 4330
sp_object_invoke_build(SPObject*, SPDocument*, Inkscape::XML::Node*,
unsigned int) <cycle 1> [569]
0.00 0.00 2270
Inkscape::URIReference::attach(Inkscape::URI const&) <cycle 1> [593]
0.00 0.00 11780
Inkscape::URIReference::_setObject(SPObject*) <cycle 1> [594]
0.00 0.00 457
sp_repr_do_read(_xmlDoc*, char const*) <cycle 1> [662]
0.00 0.00 47873 sp_item_set(SPObject*,
unsigned int, char const*) <cycle 1> [674]
0.00 0.00 73
sigc::internal::signal_emit1<void, SPObject*,
sigc::nil>::emit(sigc::internal::signal_impl*, SPObject* const&) <cycle
1> [800]
0.00 0.00 4330
sp_object_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[901]
0.00 0.00 3976
SPGradientImpl::setGradientAttr(SPObject*, unsigned int, char const*)
<cycle 1> [925]
0.00 0.00 12196
sp_style_merge_ipaint(SPStyle*, SPIPaint*, SPIPaint const*) <cycle 1> [993]
0.00 0.00 4
LivePathEffectObject::livepatheffect_set(SPObject*, unsigned int, char
const*) <cycle 1> [1003]
0.00 0.00 965
sp_use_href_changed(SPObject*, SPObject*, SPUse*) <cycle 1> [1089]
0.00 0.00 6
sp_string_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[1113]
0.00 0.00 2
sp_star_update_patheffect(SPLPEItem*, bool) <cycle 1> [1148]
0.00 0.00 861
sp_style_set_ipaint_to_uri(SPStyle*, SPIPaint*, Inkscape::URI const*,
SPDocument*) <cycle 1> [1170]
0.00 0.00 962
sp_path_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [1243]
0.00 0.00 497
SPGradientImpl::build(SPObject*, SPDocument*, Inkscape::XML::Node*)
<cycle 1> [1245]
0.00 0.00 882 sp_stop_set(SPObject*,
unsigned int, char const*) <cycle 1> [1338]
0.00 0.00 58799 SPIPaint::clear()
<cycle 1> [1543]
0.00 0.00 245
Inkscape::XML::(anonymous
namespace)::VectorNodeObserver::notifyAttributeChanged(Inkscape::XML::Node&,
unsigned int, Inkscape::Util::ptr_shared<char>,
Inkscape::Util::ptr_shared<char>) <cycle 1> [1545]
0.00 0.00 962
sp_path_set_original_curve(SPPath*, SPCurve*, unsigned int, bool) <cycle
1> [1610]
0.00 0.00 135
Inkscape::SVG::PathString::PathString() <cycle 1> [1635]
0.00 0.00 252
SPStop::readStopColor(Glib::ustring const&, unsigned int) <cycle 1> [1664]
0.00 0.00 2+27 (anonymous
namespace)::strip_ids_recursively(Inkscape::XML::Node*) <cycle 1> [1681]
0.00 0.00 1
LivePathEffectObject::livepatheffect_build(SPObject*, SPDocument*,
Inkscape::XML::Node*) <cycle 1> [1686]
0.00 0.00 2
sp_namedview_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle
1> [1692]
0.00 0.00 10
sp_guide_set(SPObject*, unsigned int, char const*) <cycle 1> [1714]
0.00 0.00 2
Inkscape::Preferences::_load() <cycle 1> [1734]
0.00 0.00 2
sp_root_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [1740]
0.00 0.00 20
sp_image_set(SPObject*, unsigned int, char const*) <cycle 1> [1756]
0.00 0.00 2
Inkscape::loadImpl(std::string const&, Glib::ustring&) <cycle 1> [1758]
0.00 0.00 9000
sp_group_set(SPObject*, unsigned int, char const*) <cycle 1> [1760]
0.00 0.00 8267
sp_style_clear(SPStyle*) <cycle 1> [1771]
0.00 0.00 23
sp_marker_set(SPObject*, unsigned int, char const*) <cycle 1> [1776]
0.00 0.00 3
sp_clippath_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle
1> [1778]
0.00 0.00 2
sp_metadata_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle
1> [1800]
0.00 0.00 1
sp_image_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[1807]
0.00 0.00 1
Inkscape::DocumentSubset::Relations::remove(SPObject*, bool) <cycle 1>
[1808]
0.00 0.00 281
sp_style_unref(SPStyle*) <cycle 1> [1847]
0.00 0.00 431095
Inkscape::Preferences::Entry::getInt(int) const <cycle 1> [2869]
0.00 0.00 81741
sp_object_set(SPObject*, unsigned int, char const*) <cycle 1> [2938]
0.00 0.00 37957
sp_lpe_item_set(SPObject*, unsigned int, char const*) <cycle 1> [3015]
0.00 0.00 29557
sp_shape_set(SPObject*, unsigned int, char const*) <cycle 1> [3073]
0.00 0.00 20560
sp_object_private_set(SPObject*, unsigned int, char const*) <cycle 1> [3174]
0.00 0.00 2482+17691
sp_style_merge_from_decl_list(SPStyle*, _CRDeclaration const*) <cycle 1>
[4360]
0.00 0.00 20173
sp_style_merge_property(SPStyle*, int, char const*) <cycle 1> [3178]
0.00 0.00 17680 sp_rect_set(SPObject*,
unsigned int, char const*) <cycle 1> [3222]
0.00 0.00 17406 sp_use_set(SPObject*,
unsigned int, char const*) <cycle 1> [3224]
0.00 0.00 9381
Inkscape::URIReference::detach() <cycle 1> [3498]
0.00 0.00 7832
sp_style_merge_from_parent(SPStyle*, SPStyle const*) <cycle 1> [3567]
0.00 0.00 5772
SPConnEndPair::setAttr(unsigned int, char const*) <cycle 1> [3748]
0.00 0.00 5748
sp_lineargradient_set(SPObject*, unsigned int, char const*) <cycle 1> [3752]
0.00 0.00 4710 SPIPaint::read(char
const*, SPStyle&, SPDocument*) <cycle 1> [3864]
0.00 0.00 4601
sp_style_new(SPDocument*) <cycle 1> [3890]
0.00 0.00 3664
sp_style_read_from_object(SPStyle*, SPObject*) <cycle 1> [4083]
0.00 0.00 3664
sp_item_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [4084]
0.00 0.00 3639
Inkscape::Preferences::Entry::getBool(bool) const <cycle 1> [4113]
0.00 0.00 2907
SPDocument::bindObjectToId(char const*, SPObject*) <cycle 1> [4277]
0.00 0.00 2694
sp_lpe_item_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle
1> [4332]
0.00 0.00 2272 sigc::signal2<void,
SPObject*, SPObject*, sigc::nil>::emit(SPObject* const&, SPObject*
const&) const <cycle 1> [4403]
0.00 0.00 2094
sp_shape_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[4547]
0.00 0.00 1924
SPConnEnd::setAttacherHref(char const*, SPPath*) <cycle 1> [4625]
0.00 0.00 1518
sp_lpe_item_update_patheffect(SPLPEItem*, bool, bool) <cycle 1> [4797]
0.00 0.00 967
sp_use_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [5025]
0.00 0.00 965
sigc::internal::slot_call2<sigc::bind_functor<-1,
sigc::pointer_functor3<SPObject*, SPObject*, SPUse*, void>, SPUse*,
sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil>, void,
SPObject*, SPObject*>::call_it(sigc::internal::slot_rep*, SPObject*
const&, SPObject* const&) <cycle 1> [5081]
0.00 0.00 965 sigc::bind_functor<-1,
sigc::pointer_functor3<SPObject*, SPObject*, SPUse*, void>, SPUse*,
sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil,
sigc::nil>::deduce_result_type<SPObject* const&, SPObject* const&, void,
void, void, void, void>::type sigc::bind_functor<-1,
sigc::pointer_functor3<SPObject*, SPObject*, SPUse*, void>, SPUse*,
sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil,
sigc::nil>::operator()<SPObject* const&, SPObject* const&>(SPObject*
const&, SPObject* const&) <cycle 1> [5056]
0.00 0.00 965
sigc::adaptor_functor<sigc::pointer_functor3<SPObject*, SPObject*,
SPUse*, void> >::deduce_result_type<SPObject* const&, SPObject* const&,
SPUse*&, void, void, void, void>::type
sigc::adaptor_functor<sigc::pointer_functor3<SPObject*, SPObject*,
SPUse*, void> >::operator()<SPObject* const&, SPObject* const&,
SPUse*&>(SPObject* const&, SPObject* const&, SPUse*&) const <cycle 1> [5092]
0.00 0.00 965
sigc::pointer_functor3<SPObject*, SPObject*, SPUse*,
void>::operator()(SPObject* const&, SPObject* const&, SPUse* const&)
const <cycle 1> [5093]
0.00 0.00 962
sp_conn_end_pair_build(SPObject*) <cycle 1> [5101]
0.00 0.00 884
sp_rect_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [5189]
0.00 0.00 857
sp_style_set_ipaint_to_uri_string(SPStyle*, SPIPaint*, char const*)
<cycle 1> [5236]
0.00 0.00 555+144
sp_group_update_patheffect(SPLPEItem*, bool) <cycle 1> [5495]
0.00 0.00 600
sp_group_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[5470]
0.00 0.00 479
sp_lineargradient_build(SPObject*, SPDocument*, Inkscape::XML::Node*)
<cycle 1> [5608]
0.00 0.00 339 sp_repr_read_mem(char
const*, int, char const*) <cycle 1> [5848]
0.00 0.00 245
sp_object_repr_attr_changed(Inkscape::XML::Node*, char const*, char
const*, char const*, bool, void*) <cycle 1> [5982]
0.00 0.00 244
sp_arc_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [5983]
0.00 0.00 234
sp_radialgradient_set(SPObject*, unsigned int, char const*) <cycle 1> [6007]
0.00 0.00 129
sigc::internal::slot_call1<sigc::bound_mem_functor1<void,
Inkscape::URIReference, SPObject*>, void,
SPObject*>::call_it(sigc::internal::slot_rep*, SPObject* const&) <cycle
1> [6225]
0.00 0.00 129
sigc::adaptor_functor<sigc::bound_mem_functor1<void,
Inkscape::URIReference, SPObject*> >::deduce_result_type<SPObject*
const&, void, void, void, void, void, void>::type
sigc::adaptor_functor<sigc::bound_mem_functor1<void,
Inkscape::URIReference, SPObject*> >::operator()<SPObject*
const&>(SPObject* const&) const <cycle 1> [6226]
0.00 0.00 129
sigc::bound_mem_functor1<void, Inkscape::URIReference,
SPObject*>::operator()(SPObject* const&) const <cycle 1> [6228]
0.00 0.00 126
sp_stop_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [6232]
0.00 0.00 101
sp_namedview_set(SPObject*, unsigned int, char const*) <cycle 1> [6301]
0.00 0.00 100 sp_star_set(SPObject*,
unsigned int, char const*) <cycle 1> [6304]
0.00 0.00 73 sigc::signal1<void,
SPObject*, sigc::nil>::emit(SPObject* const&) const <cycle 1> [6444]
0.00 0.00 67
Inkscape::URIReference::~URIReference() <cycle 1> [6521]
0.00 0.00 50 sp_root_set(SPObject*,
unsigned int, char const*) <cycle 1> [6616]
0.00 0.00 42
SPPaintServerReference::~SPPaintServerReference() <cycle 1> [6663]
0.00 0.00 42
SPPaintServerReference::~SPPaintServerReference() <cycle 1> [6664]
0.00 0.00 21
SPFilterReference::~SPFilterReference() <cycle 1> [7119]
0.00 0.00 21
SPFilterReference::~SPFilterReference() <cycle 1> [7120]
0.00 0.00 19
sp_tspan_set(SPObject*, unsigned int, char const*) <cycle 1> [7182]
0.00 0.00 19 sp_text_set(SPObject*,
unsigned int, char const*) <cycle 1> [7181]
0.00 0.00 18
sp_radialgradient_build(SPObject*, SPDocument*, Inkscape::XML::Node*)
<cycle 1> [7221]
0.00 0.00 12
sp_clippath_set(SPObject*, unsigned int, char const*) <cycle 1> [7450]
0.00 0.00 6
sp_metadata_set(SPObject*, unsigned int, char const*) <cycle 1> [8073]
0.00 0.00 4
sp_star_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1> [8631]
0.00 0.00 2
Inkscape::Preferences::Preferences() <cycle 1> [10292]
0.00 0.00 2
sp_guide_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[9769]
0.00 0.00 1+1
Inkscape::DocumentSubset::Relations::_doRemoveSubtree(SPObject*) <cycle
1> [13194]
0.00 0.00 2
Inkscape::DocumentSubset::Relations::_doRemove(SPObject*) <cycle 1> [10302]
0.00 0.00 2
sigc::internal::slot_call2<sigc::bind_functor<-1,
sigc::pointer_functor3<SPObject*, SPObject*, SPDesktop*, void>,
SPDesktop*, sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil,
sigc::nil>, void, SPObject*,
SPObject*>::call_it(sigc::internal::slot_rep*, SPObject* const&,
SPObject* const&) <cycle 1> [10229]
0.00 0.00 2 sigc::bind_functor<-1,
sigc::pointer_functor3<SPObject*, SPObject*, SPDesktop*, void>,
SPDesktop*, sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil,
sigc::nil>::deduce_result_type<SPObject* const&, SPObject* const&, void,
void, void, void, void>::type sigc::bind_functor<-1,
sigc::pointer_functor3<SPObject*, SPObject*, SPDesktop*, void>,
SPDesktop*, sigc::nil, sigc::nil, sigc::nil, sigc::nil, sigc::nil,
sigc::nil>::operator()<SPObject* const&, SPObject* const&>(SPObject*
const&, SPObject* const&) <cycle 1> [10002]
0.00 0.00 2
sigc::adaptor_functor<sigc::pointer_functor3<SPObject*, SPObject*,
SPDesktop*, void> >::deduce_result_type<SPObject* const&, SPObject*
const&, SPDesktop*&, void, void, void, void>::type
sigc::adaptor_functor<sigc::pointer_functor3<SPObject*, SPObject*,
SPDesktop*, void> >::operator()<SPObject* const&, SPObject* const&,
SPDesktop*&>(SPObject* const&, SPObject* const&, SPDesktop*&) const
<cycle 1> [10526]
0.00 0.00 2
sigc::pointer_functor3<SPObject*, SPObject*, SPDesktop*,
void>::operator()(SPObject* const&, SPObject* const&, SPDesktop* const&)
const <cycle 1> [10530]
0.00 0.00 2
_layer_hierarchy_changed(SPObject*, SPObject*, SPDesktop*) <cycle 1> [9775]
0.00 0.00 2
Inkscape::Preferences::_loadDefaults() <cycle 1> [10291]
0.00 0.00 1
sp_marker_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[12398]
0.00 0.00 1
sp_text_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[12392]
0.00 0.00 1
sp_tspan_build(SPObject*, SPDocument*, Inkscape::XML::Node*) <cycle 1>
[12394]
0.00 0.00 1
sigc::internal::slot_call1<sigc::bound_mem_functor1<void,
Inkscape::LayerManager, SPObject*>, void,
SPObject*>::call_it(sigc::internal::slot_rep*, SPObject* const&) <cycle
1> [13018]
0.00 0.00 1
sigc::adaptor_functor<sigc::bound_mem_functor1<void,
Inkscape::LayerManager, SPObject*> >::deduce_result_type<SPObject*
const&, void, void, void, void, void, void>::type
sigc::adaptor_functor<sigc::bound_mem_functor1<void,
Inkscape::LayerManager, SPObject*> >::operator()<SPObject*
const&>(SPObject* const&) const <cycle 1> [13666]
0.00 0.00 1
sigc::bound_mem_functor1<void, Inkscape::LayerManager,
SPObject*>::operator()(SPObject* const&) const <cycle 1> [13680]
0.00 0.00 1
Inkscape::LayerManager::_selectedLayerChanged(SPObject*) <cycle 1> [13181]
0.00 0.00 1
sigc::internal::slot_call1<sigc::bound_mem_functor1<void,
Inkscape::DocumentSubset::Relations, SPObject*>, void,
SPObject*>::call_it(sigc::internal::slot_rep*, SPObject* const&) <cycle
1> [13019]
0.00 0.00 1
sigc::adaptor_functor<sigc::bound_mem_functor1<void,
Inkscape::DocumentSubset::Relations, SPObject*>
>::deduce_result_type<SPObject* const&, void, void, void, void, void,
void>::type sigc::adaptor_functor<sigc::bound_mem_functor1<void,
Inkscape::DocumentSubset::Relations, SPObject*> >::operator()<SPObject*
const&>(SPObject* const&) const <cycle 1> [13667]
0.00 0.00 1
sigc::bound_mem_functor1<void, Inkscape::DocumentSubset::Relations,
SPObject*>::operator()(SPObject* const&) const <cycle 1> [13681]
0.00 0.00 1
Inkscape::DocumentSubset::Relations::_release_object(SPObject*) <cycle
1> [13193]
0.00 0.00 1
Inkscape::LivePathEffect::LPEObjectReference::link(char const*) <cycle
1> [13201]
-----------------------------------------------
0.02 1.85 215263/215263
nr_arena_item_request_render(NRArenaItem*) [7]
[9] 35.5 0.02 1.85 215263
nr_arena_request_render_rect(NRArena*, NRRectL*) [9]
0.05 1.17 430526/663464
Inkscape::Preferences::getInt(Glib::ustring const&, int) <cycle 1> [12]
0.02 0.58 215263/663464
Inkscape::Preferences::get() <cycle 1> [340]
0.02 0.00 215263/1236181
nr_object_check_instance_type(void const*, unsigned int) [53]
0.00 0.00 215263/219029 nr_arena_get_type() [2885]
-----------------------------------------------
0.00 1.46 435423/435423
Inkscape::Preferences::getEntry(Glib::ustring const&) [11]
[10] 27.8 0.00 1.46 435423
Inkscape::Preferences::_getRawValue(Glib::ustring const&, char const*&) [10]
0.35 1.10 435423/435568
Inkscape::Preferences::_getNode(Glib::ustring const&, bool) [13]
0.00 0.01 432741/28329840
Inkscape::XML::SimpleNode::attribute(char const*) const [16]
0.00 0.00 435423/435530
Inkscape::Preferences::_keySplit(Glib::ustring const&, Glib::ustring&,
Glib::ustring&) [2863]
-----------------------------------------------
This table describes the call tree of the program, and was sorted by
the total amount of time spent in each function and its children.
Each entry in this table consists of several lines. The line with the
index number at the left hand margin lists the current function.
The lines above it list the functions that called this function,
and the lines below it list the functions this one called.
This line lists:
index A unique number given to each element of the table.
Index numbers are sorted numerically.
The index number is printed next to every function name so
it is easier to look up where the function in the table.
% time This is the percentage of the `total' time that was spent
in this function and its children. Note that due to
different viewpoints, functions excluded by options, etc,
these numbers will NOT add up to 100%.
self This is the total amount of time spent in this function.
children This is the total amount of time propagated into this
function by its children.
called This is the number of times the function was called.
If the function called itself recursively, the number
only includes non-recursive calls, and is followed by
a `+' and the number of recursive calls.
name The name of the current function. The index number is
printed after it. If the function is a member of a
cycle, the cycle number is printed between the
function's name and the index number.
For the function's parents, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the function into this parent.
children This is the amount of time that was propagated from
the function's children into this parent.
called This is the number of times this parent called the
function `/' the total number of times the function
was called. Recursive calls to the function are not
included in the number after the `/'.
name This is the name of the parent. The parent's index
number is printed after it. If the parent is a
member of a cycle, the cycle number is printed between
the name and the index number.
If the parents of the function cannot be determined, the word
`<spontaneous>' is printed in the `name' field, and all the other
fields are blank.
For the function's children, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the child into the function.
children This is the amount of time that was propagated from the
child's children to the function.
called This is the number of times the function called
this child `/' the total number of times the child
was called. Recursive calls by the child are not
listed in the number after the `/'.
name This is the name of the child. The child's index
number is printed after it. If the child is a
member of a cycle, the cycle number is printed
between the name and the index number.
If there are any cycles (circles) in the call graph, there is an
entry for the cycle-as-a-whole. This entry shows who called the
cycle (as parents) and the members of the cycle (as children.)
The `+' recursive calls entry shows the number of function calls that
were internal to the cycle, and the calls entry for each member shows,
for that member, how many times it was called from other members of
the cycle.