Re: UT_Vector IS slowing us down


Subject: Re: UT_Vector IS slowing us down
From: Paul Rohr (paul@abisource.com)
Date: Thu Jun 08 2000 - 13:18:45 CDT


At 06:33 AM 6/8/00 +0000, Aaron Lehmann wrote:
>At the advice of a few people on this list who know more about application
>development than I do, I profiled AbiWord with a very simple test: typing
>a paragraph full of 'a' 's. The results were pretty interesting.

Aaron,

Thanks for getting the ball rolling on this. It's always cool to have real
data to start looking at.

>pt_PieceTable::getSpanPtr gets called over 786,000 times during this
>simple test, and it accounts for 6.87 percent of the time. And now, the
>award for most-called function: UT_Vector::getNthItem, called over a
>million times and accounting for 1.79 percent of the time the program took
>to run.
>
>I think a good way to optimize would be to prevent functions like
>pt_PieceTable::getSpanPtr, PD_Document::getSpanPtr,
>pt_VarSet::getPointer, pf_Frag_Text::getBufIndex, and
>fl_BlockLayout::getSpanPtr from being called on the order of 800,000 times
>for this simple test as they do now. AFAIK, the app really should not
>need to get a span pointer almost a million times for inserting under
>500 characters. Any ideas of how to go about doing this?

You're definitely on the right track here. Before we consider trying to
speed up UT_Vector, we certainly want to find out whether it needs to be
called so often.

I really need to get back to fields, but after a quick peek at your data,
here are some places for you to zero in on.

Question #1: Who's making all those calls to getNthItem?
===========

I get the general impression from your results that you inserted something
close to 644 characters to generate a paragraph of somewhere between 4 and 8
lines. I'm also guessing that you didn't put spaces between your "a"
characters, which meant you wound up in a very particular special case in
the line breaker.

Here are the most frequent callers of this method:

-----------------------------------------------
                [ ... ]
                0.00 0.00 638/1006262 fp_Line::clearScreen(void)
[352]
                0.00 0.00 644/1006262
PD_Document::signalListeners(unsigned int) const [7]
                0.00 0.00 644/1006262
PD_Document::notifyListeners(pf_Frag_Strux *, PX_ChangeRecord const *)
const [26]
                0.00 0.00 704/1006262 fp_Page::draw(dg_DrawArgs
*) [18]
                0.00 0.00 763/1006262
FL_DocLayout::getHeight(void) [327]
                0.00 0.00 1343/1006262
FL_DocLayout::deleteEmptyPages(void) [117]
                0.00 0.00 1932/1006262
px_ChangeHistory::getUndo(PX_ChangeRecord **) const [323]
                0.00 0.00 2212/1006262
fp_Line::mapXYToPosition(int, int, unsigned int &, unsigned char &,
unsigned char &) [274]
                0.00 0.00 2623/1006262 fp_Line::draw(GR_Graphics
*) [169]
                0.00 0.00 2902/1006262
fp_Container::draw(dg_DrawArgs *) [19]
                0.00 0.00 2936/1006262 fp_Column::layout(void) [118]
                0.00 0.00 3180/1006262
fp_Line::clearScreenFromRunToEnd(unsigned int) [192]
                0.00 0.00 4149/1006262
FL_DocLayout::getFirstPage(void) [115]
                0.00 0.00 4670/1006262
pf_Frag_Strux::getFmtHandle(unsigned int) const [299]
                0.00 0.00 17108/1006262
FV_View::getBlockFormat(char const ***, unsigned char) [49]
                0.00 0.00 18270/1006262
FV_View::getCharFormat(char const ***, unsigned char) [40]
                0.00 0.00 33753/1006262
pp_TableAttrProp::getAP(unsigned int) const [109]
                0.00 0.00 57536/1006262
XAP_UnixFont::getGdkFont(unsigned int) [73]
                0.01 0.00 207691/1006262
fp_Line::recalcHeight(void) [51]
                0.01 0.00 207691/1006262 fp_Line::layout(void) [43]
                0.01 0.00 207697/1006262
fp_Line::resetJustification(void) [53]
                0.01 0.00 225276/1006262 fp_Line::draw(dg_DrawArgs
*) [20]
[62] 1.8 0.06 0.00 1006262 UT_Vector::getNthItem(unsigned
int) const [62]
-----------------------------------------------

Question #2: what's going on in the fp_Line logic?
===========

For 644 characters inserted, we'll need to reformat the document 644 times,
so some of the earlier entries above make total sense. However, the
explosion (over 300 calls per insert) happens in the fp_Line logic. Why?

Bump up a level and take a look:

-----------------------------------------------
                0.05 0.58 2902/2902
fp_Container::draw(dg_DrawArgs *) [19]
[20] 18.8 0.05 0.58 2902 fp_Line::draw(dg_DrawArgs *) [20]
                0.17 0.40 225276/227899 fp_Run::draw(dg_DrawArgs
*) [23]
                0.01 0.00 225276/1006262
UT_Vector::getNthItem(unsigned int) const [62]
                0.00 0.00 2902/153085
UT_Vector::getItemCount(void) const [127]

-----------------------------------------------
                0.00 0.00 1/2689
fl_BlockLayout::_insertFakeTextRun(void) [268]
                0.01 0.18 2688/2689
fb_LineBreaker::breakParagraph(fl_BlockLayout *) [12]
[43] 5.6 0.01 0.18 2689 fp_Line::layout(void) [43]
                0.06 0.04 2689/2689
fp_Line::recalcHeight(void) [51]
                0.03 0.00 207691/207691 fp_Run::setX(int) [79]
                0.03 0.00 207691/207691
fb_Alignment_left::getMove(fp_Run const *) [78]
                0.01 0.00 207691/1006262
UT_Vector::getNthItem(unsigned int) const [62]
                0.00 0.00 636/636
fb_Alignment_left::eraseLineFromRun(fp_Line *, unsigned int) [193]
                0.00 0.00 2689/153085
UT_Vector::getItemCount(void) const [127]
                0.00 0.00 2689/2689
fb_Alignment_left::initialize(fp_Line *) [583]
                0.00 0.00 2689/2689
fb_Alignment_left::getStartPosition(void) [582]
-----------------------------------------------
                0.06 0.04 2689/2689 fp_Line::layout(void) [43]
[51] 3.1 0.06 0.04 2689 fp_Line::recalcHeight(void) [51]
                0.02 0.00 207691/207691
fp_TextRun::isSuperscript(void) const [86]
                0.01 0.00 207691/1006262
UT_Vector::getNthItem(unsigned int) const [62]
                0.01 0.00 207691/207691
fp_TextRun::isSubscript(void) const [128]
                0.00 0.00 2689/153085
UT_Vector::getItemCount(void) const [127]
                0.00 0.00 8/22 fp_Line::clearScreen(void)
[352]
                0.00 0.00 2689/2689
fl_BlockLayout::getLineSpacing(double &, double &,
fl_BlockLayout::_eSpacingPolicy &) const [581]
-----------------------------------------------
                0.06 0.03 2688/2688
fb_LineBreaker::breakParagraph(fl_BlockLayout *) [12]
[53] 2.8 0.06 0.03 2688
fp_Line::resetJustification(void) [53]
                0.02 0.00 207697/207697
fp_TextRun::resetJustification(void) [85]
                0.01 0.00 207697/1006262
UT_Vector::getNthItem(unsigned int) const [62]
                0.00 0.00 2688/153085
UT_Vector::getItemCount(void) const [127]

It seems plausible that each of these four fp_Line methods would get called
this often, assuming that there are on average four lines in the document.

Question #3: are there 100 runs per line? why?
============

Now you've got two choices:

  1. ask the original author (Eric) and/or
  2. start reading code.

Hope that helps.

Paul,
going back to fields now



This archive was generated by hypermail 2b25 : Thu Jun 08 2000 - 13:13:09 CDT