Re: The cost of stack traces

[Andrew Haley <aph at redhat dot com>]

David Daney writes:
 > Andrew Haley wrote:
 > > As some of you may be aware, I've been doing benchmarking of servers
 > > with a mind to improving gcj performance.
 > > 
 > > I've recently come across a situation where stack traces greatly
 > > slowed down an application.  Basically, this all comes down to an
 > > interaction between the way that loggers work and the way we do stack
 > > traces.  We're using addr2line to get the line number and filename,
 > > but this leads to a huge number of addr2line process being spawned.
 > > 
 > > In the past we have considered building a reader for DWARF debug info
 > > into libgcj, but this may not help as much as we imagine: a perusal of
 > > the profile data for addr2line reveals that much of the CPU time is in
 > > libbfd itself -- the big effort isn't just spawning addr2line
 > > processes, it's actually doing the work of reading the debug info.
 > 
 > This is what I have been wanting to do.  I think the speedup would
 > be quite large in my usage cases (slow CPU, limited memory where
 > running addr2line causes thrashing).  On my little MIPS systems, I
 > can count the depth of a stack trace by listening to the disk.
 > There is a flurry of disk activity for each level as addr2line is
 > started. 

You must be *really* short of disk cache!  :-)

 > It goes brrt...brrt...brrt...  Without addr2line, it is literally
 > 10-20 times faster.
 > 
 > With an in-library line number decoder, if you cached knowledge
 > about line number availability for each .text section, you could
 > short circuit a lot of work on the second stack trace from a
 > section with no line number information.

That's true, but you are either going to keep re-reading that DWARF
data or you're cacheing a hell of a lot of stuff.

 > I have also been thinking about emitting the raw addresses (perhaps
 > with file and base address information) so that off-line analysis
 > of traces is easier.  This would give fast runtime performance, but
 > allow detailed postmortem analysis.  For statically linked
 > applications all you need is the address as they are all absolute.
 > Back in GCC-3.4 you could easily get the address to print out, but
 > that capability seems to have disappeared in the most recent libgcj
 > (and I want it back :-)).

Well, now that backtraces *require* us to use the DWARF unwinder
(because we don't have a frame pointer), the additional cost of
getting the name and class of the frame is quite low.  So, if you go
to all the trouble to get the hex address you might as well do the
name lookup.

 > > And all of this is often supremely pointless in Fedora, where many of
 > > the gcj libraries don't have any debuginfo to read.
 > > 
 > > The effect of all this is dramatic: running a test load in JOnAS is
 > > 
 > >    38m18s with addr2line, and
 > >    22m49s without.
 > 
 > I have noted this as well, and would like to see improvement.
 > 
 > > I suggest that we set the default use_addr2line to false.  People will
 > > still get the method info, just not the filename and line number of
 > > the source file.
 > > 
 > 
 > I have done this, and it does speed things up.  One thing I was
 > thinking was that you could leave use_addr2line set to true by
 > default, and have a way to override via an environment variable.

That alreay works.  But I'm trying to improve the default case -- the
one that most users of gcj-compiled applications see in practice.
They won't know or care about environment variables.  The only way to
do fix things for most people, as far as I can see, is to change the
default.

 > That way in your JOnAS startup script, you could turn it off if you
 > wanted to, but the default behavior would be similar to the JDK
 > where you get line numbers if available.

I've tried it, and it works, but I think that is a really bad idea.
The default should be fast: for debugging, we can turn it on if we
really need to.

 > > Another possibility is to keep the addr2line processes alive between
 > > invocations of stacktrace.  This is a fairly small change to
 > > NameFinder, but has the disadvantage of consuming a lot of long-term
 > > resources.
 > 
 > How is this much different than having the DWARF debug reader be
 > integrated in libgcj?

It has the same set of problems, more or less.

 > Not that we seem to have enough information to know, but this would
 > contradict your assertion above that it may not be worthwhile.

I don't say that it may not be worthwhile!  It's a classic space
vs. speed trade-off.

What I am saying is that even if we use our own DWRAF reader it's a
lot of effort for something that is not often useful.

Andrew.