Subject: Re: General performance [was: drawing performance]
From: Aaron Lehmann (aaronl@vitelus.com)
Date: Mon Dec 18 2000 - 02:43:51 CST
On Mon, Dec 18, 2000 at 01:44:51AM +0100, Mike Nordell wrote:
> PP_lookupProperty was called 10691 times, only from PP_evalProperty,
> resulting in 163243 calls to UT_stricmp. During this test, PP_evalProperty
> and its calls was responsible for sucking up 45% CPU time (which in this
> case evaluated to *over one second*). PP_evalProperty itself was only using
> about 0.04% CPU.
Perhaps we need to rethink some core algorithms. 100 property lookups
per character insertion seems a bit unnecessary. Beyond that, the
property lookups could certainly be dramatically improved in terms of
overhead - according to your figures, UT_stricmp was called 10 times
per property lookup. Using a hash table or binary search would speed
this up, but it would be even quicker to use enumerated constants
rather than the clumsy, inefficient string-based approach now.
Oh yeah, and the fact that properties are case-insensitve makes it
even slower. Make them case-sensitive (as they should be!) and you
gain back some speed. But rewriting the property lookup system would
increase the speed by about an order of magnitude (for that part), it
seems.
Here's some evidence from my own testing:
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls us/call us/call name
19.05 0.04 0.04 238909 0.17 0.17 UT_stricmp
// Yow! 20%?? This function is a hog!
9.52 0.06 0.02 24090 0.83 1.10 pt_VarSet::getPointer(unsigned int) const
// Interesting... I have no idea what this is or why it is such a problem.
9.52 0.08 0.02 23332 0.86 1.96 pt_PieceTable::getSpanPtr(void const *, unsigned int, unsigned short const **, unsigned int *) const
// No idea about this
4.76 0.09 0.01 228579 0.04 0.04 UT_Vector::getNthItem(unsigned int) const
// We had found in the past that UT_Vector was slow. I don't like vectors in the first place.
4.76 0.10 0.01 37036 0.27 0.27 UT_GrowBuf::getPointer(uns
igned int) const
4.76 0.11 0.01 29113 0.34 0.34 UT_HashTable::findEntry(char const *) const
// Does anyone else see a recurring theme of the UT classes being slow and overused?
4.76 0.12 0.01 21318 0.47 2.23 fp_Run::draw(dg_DrawArgs *)
4.76 0.13 0.01 18146 0.55 0.55 fp_TextRun::resetJustification(void)
// Understandable.
4.76 0.14 0.01 9278 1.08 1.17 XAP_UnixFontHandle::explodeGdkFonts(_GdkFont *&, _GdkFont *&)
4.76 0.15 0.01 8004 1.25 1.25 GR_UnixGraphics::_setColor(_GdkColor &)
// These two are definately called way too much. Only three colors (black white & red) are ever used drawing the document. And one font. I will look at these..
This archive was generated by hypermail 2b25 : Mon Dec 18 2000 - 02:43:54 CST