Tamiflex (latest), DaCapo benchmarks, and Soot

[Ben Barham]

Hi again,

After running the Play-Out Agent on DaCapo and then running the output with Soot over the weekend, I've had the following errors:

From the Play-Out Agent, the Tradesoap benchmarks all fail due to a null pointer exception.  I've attached the log for tradesoap-small (all of them are basically the same).  Tradesoap successfully runs if I invoke the benchmark by itself (without the play out agent).

From Soot: the Tradebeans benchmarks fail due to not being able to find a field.  Also attached is the log for tradebeans-small (again, all the same).

Thanks, Ben

[Eric Bodden]

Hmm, this is pretty odd.

The exception happens at line 238 here:
http://grepcode.com/file/repo1.maven.org/maven2/org.apache.geronimo.daytrader/daytrader-ejb/2.1.7/org/apache/geronimo/samples/daytrader/TradeAction.java

This method does nothing with reflection, so it cannot be the root
cause of the problem.

I wonder if the problem still occurs when you disable the one or other
probe in TamiFlex.

Eric

--
Eric Bodden, Ph.D., http://sse.ec-spride.de/ http://bodden.de/
Head of Secure Software Engineering Group at EC SPRIDE
Tel: +49 6151 16-75422 Fax: +49 6151 16-72051
Room 3.2.14, Mornewegstr. 30, 64293 Darmstadt

[Andreas Sewe]

Hi Ben,

> After running the Play-Out Agent on DaCapo and then running the
> output with Soot over the weekend, I've had the following errors:
>
> From the Play-Out Agent, the Tradesoap benchmarks all fail due to a
> null pointer exception. I've attached the log for tradesoap-small
> (all of them are basically the same). Tradesoap successfully runs if
> I invoke the benchmark by itself (without the play out agent).

I leave the Soot stuff to Eric. However, as I am currently involved in
the DaCapo 12.x effort, I would be very interested finding out whether
the DaCapo problem you encountered really is problem with TamiFlex or a
more generic agent/tradesoap incompatibility. (The trade* are quite hard
to harness properly; lots of class loader weirdness going on there.)

Can you please try running the POA with all (or all but one)
transformation disabled? (See
<https://code.google.com/p/tamiflex/wiki/ConfigurationFile> for how to
configure this.)

Best wishes,

Andreas

[Ben Barham]

Hi Eric and Andreas,

Sorry for the late reply.  I tried running POA without any transformations enabled, but it fails with an assertion.  After that I ran POA with only one transformation at a time for each of the transformations available with Soot.  All pass except for the de.bodden.tamiflex.playout.transformation.field.FieldGetTransformation and it fails with the exact same trace as in my first post.

Any idea what the error is with Tradebeans and Soot?

Thanks again, Ben

[Eric Bodden]

Hi Ben.

> All pass except for the
> de.bodden.tamiflex.playout.transformation.field.FieldGetTransformation and
> it fails with the exact same trace as in my first post.
>
> Any idea what the error is with Tradebeans and Soot?

Thanks. We will next take a careful look at this transformation to see
if there is anything obviously wrong with it.

Eric

[Andreas Sewe]

Hi Ben,

> Sorry for the late reply. I tried running POA without any
> transformations enabled, but it fails with an assertion. After that I
> ran POA with only one transformation at a time for each of the
> transformations available with Soot. All pass except for the
> de.bodden.tamiflex.playout.transformation.field.FieldGetTransformation
> and it fails with the exact same trace as in my first post.

thanks for doing our work for us ;-).

But are you sure it is FieldGetTransformation? I was able to reproduce
the tradesoap failure, but *not* when FieldGetTransformation was the
only active transformation; then tradesoap passes just fine on my machine.

I was, however, able to reproduce the failure when was the only active
transformation was MethodGetNameTransformation. Weird!

Best wishes,

Andreas

[Andreas Sewe]

Hi Ben,

Remembering an observation we made in our ICSE paper, namely that the
creation of stack traces is our main performance bottleneck, which
primarily affects tradesoap (cf. Section 3.3/Figure 8,
<http://www.bodden.de/pubs/bss+11taming.pdf>, I did some further
experiments. And indeed it seems like the slow-down incurred by repeated
calls to ReflLogger.getInvokingFrame() triggers some timing-related
change in the behaviour of tradesoap (either a race condition or an
explicit time-out); at least, the failures disappear (with all
transformations enabled) if I change said method as follows:

private static final StackTraceElement DUMMY_FRAME =
Thread.currentThread().getStackTrace()[0];

private static StackTraceElement getInvokingFrame() {
return DUMMY_FRAME;
}

Can you try this workaround on your machine as well, to confirm that my
suspicion is correct?

Unfortunately, I am unaware of a way to obtain a partial stack trace
only on the JVM (we only a handful of frames), which would speed up this
method considerably and hence avoid timing perturbations. And
sun.reflect.Reflection.getCallerClass(int) only gives us a class some
frames further up, but not the call site (besides, this method is not
portable).

Hope this helps anyway.

Andreas

[Ben Barham]

Hi Andreas,

I've only been running with the transformations available to Soot on, so it definitely wasn't MethodGetNameTransformation.  When I was running it the other day, I'm positive FieldGetTransformation consistently causing the error - but today it isn't (running with all the transformations Soot understands still causes the exception though).

Thanks, Ben

[Ben Barham]

After giving your change a quick go and running it over tradesoap a fair number of times, I've had no exceptions.  My co-worker has also managed to successfully run the PlayOutAgent over all the benchmarks when giving the JVM 10GB of RAM to play with - given this I decided to run it with a little more RAM too (only 2GB though) and this too gets rid of the exception.  This seems a little strange, I would have expected it to fail with an out of memory error if it was a memory issue.

Thanks again, Ben

[Andreas Sewe]

Hi Ben,

> After giving your change a quick go and running it over tradesoap a
> fair number of times, I've had no exceptions. My co-worker has also
> managed to successfully run the PlayOutAgent over all the benchmarks
> when giving the JVM 10GB of RAM to play with - given this I decided
> to run it with a little more RAM too (only 2GB though) and this too
> gets rid of the exception. This seems a little strange, I would have
> expected it to fail with an out of memory error if it was a memory
> issue.

here's my guess: Creating a StackTraceElement[] requires quite a bit of
object allocation, especially if the call stack is very deep. If you are
unlucky (chances increase in benchmarks doing lots of reflection), this
triggers a garbage collection at least of the young generation in a
generational collector. And this change in timing might trigger a
timeout or (more likely) a data race; collecting the young generation
normally is quite fast (a few milliseconds) and I doubt any timeout
would be set to a value so small.

Now, I suspect that using a larger overall heap simply increases the
size of the younger generation accordingly, thereby lowering the chance
of filling it up when creating the StackTraceElement[]. So,
out-of-memory situations aren't the issue here -- GC timing is.

Hope this explanation makes sense. (If you are interested,
-XX:+PrintGCDetails might tell you how much time is spend during GC.)

Best wishes,

Andreas

[Ben Barham]

Ok - thanks for the explanation Andreas.