Ceki Gülcü wrote:
>
> Hi Alan,
>
> >So, have you done any testing to determine which part of the above operation takes
>the most time? Is it the creation of the Throwable object or the parsing of the
>stack trace that makes getting location information so slow?
>
> I think that most of the cost is in the creation of the throwable altough I am not
>sure. Really, I could be completely off base.
>
> >I'll try to do some testing of my own to anwer that question, but any insight you
>have would be greatly appreciated.
>
> Please test it and let us know.
>
I was involved with some performance tuning work last week that stumbled
on this very thing. On this particular engagement, it seems that I am
constantly defending log4j performance because it's easier for the
programmers to blame the logging mechanism for poor performance than
actually profile their code.
Last Thursday was no different. This particular coder was more
experience than the ones before, but I was so sick of hearing the "It's
log4j" knee-jerk reaction I immediatly dismissed it. When she was able
to show that the individual log4j statements were taking 3 seconds each,
I was stumped. I suggested removing the %M and %C from the
PatternLayout configuration and response became sub-second.
This isn't the first time I've seen this kind of behavior with stack
trace heavy code. Three months before log4j was introduced, we were
using a helper class to determine method names in our print statements.
It used the same scheme as log4j does now: create an exception, generate
its stack trace and analyze it for the method name. The code ran fine
on NT. On AIX it was horrible. After a week of profiling, the AIX
gurus found that 20% of the CPU time was spent in a portion of the Java
DLL that generates stack traces. We changed the helper class by
commenting out the stack tracing and just returning "????". The
performance on AIX flew. Oddly enough, the performance on NT wasn't
affected nearly as much.
The code we were profiling last Thursday ran fine in VA Java WebSphere
Test Environment, but slow in WebSphere itself on NT. It runs find on
the 390 but slow on WebSphere 390. In both cases, WebSphere 3.0 was
being used. This in turn uses a (no longer supported) old JVM.
My guess is that some JVMs seem to have a lot of trouble generating
stack traces for exception creation. Others don't. Perhaps the
expectation is that one shouldn't be generating that many exceptions in
a short amount of time.
I mainly work with distributed apps where a remote call is an order of
magnitude greater than a local one. Normally the overhead introduced by
generating the LocationInfo is not significant. But there are certain
combinations of platform-JVM that make it prohibitive.
- Paul
--
Beware of bugs in the above code. I have
only proved it correct, not tried it.
-Don Knuth
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
