OutputModel performance

[Andreas Pakulat]

Hi,

On Wed, Feb 6, 2013 at 4:59 PM, Kevin Funk <krf at gmx.de> wrote:
> On Wednesday 06 February 2013, 17:32, Alexander Shaduri wrote:
>> Hello,
>>
>> On Wed, 06 Feb 2013 13:25:17 +0100
>>
>> Kevin Funk wrote:
>> > I recently noticed that I get serious UI lockups when running a 'make
>> > install' job inside KDevelop for larger projects such as kdelibs. 'make
>> > install' here may produce roughly ~4500 lines of output in just a few
>> > seconds.
>> > ...
>> > So, the question here:
>> > - Did anyone of you guys experience similar issues just to begin with?
>>
>> Just from the user's point of view:
>> KDevelop is essentially unusable when I'm compiling my project (9 parallel
>> make jobs). It seems that the outputview just cannot handle it quickly
>> enough.
>>
>> It's a typical cmake/Qt project compiled with make -j9, the full compilation
>> takes about 30 seconds and produces ~500KB output (~2300 lines).
>> CMAKE_VERBOSE_MAKEFILE is on.
>>
>> If I set make jobs to 1 or CMAKE_VERBOSE_MAKEFILE to off, it's all fine.
>>
>> I'd be grateful if you added this as a test case. Compiling, say, KDevelop
>> with the same settings should give you the same drop in performance.
>>
>> Thanks,
>> Alexander
>
> Just for the record -- I just measured the time it takes to complete
> addLineBatch():
>
> (...)
> KDevelop::OutputModel::addLineBatch: elapsed time:  20 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  10 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  22 ms, processed lines: 2
> KDevelop::OutputModel::addLineBatch: elapsed time:  8 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  8 ms, processed lines: 2
> KDevelop::OutputModel::addLineBatch: elapsed time:  7 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  7 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  12 ms, processed lines: 3
> KDevelop::OutputModel::addLineBatch: elapsed time:  9 ms, processed lines: 2
> KDevelop::OutputModel::addLineBatch: elapsed time:  7 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  8 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  11 ms, processed lines: 4
> KDevelop::OutputModel::addLineBatch: elapsed time:  7 ms, processed lines: 1
> KDevelop::OutputModel::addLineBatch: elapsed time:  7 ms, processed lines: 1
> (...)
>
> IMO that clearly shows that this takes way too much processing time / line.

Well, unless you're using a high-precision timer I'm not sure how much
you can trust those timings for a single line, it would be more
interesting to see an average over 100 calls with the same
(non-matching or matching) line or so. IIRC the code for matching is
pretty much separate from the rest so it ought to be possible to
writeup a test that does this which can then also be better
valgrind'ed.

Are callgrind files cross-platform? If so you could upload your data
as well, so others can investigate this a bit already (I'm
particularly interested in which Qt function all the time is spent,
i.e. which is the biggest self-time function).

Andreas