Incorrect line numbers reported in traceStack of a byteman rule?

[jaikiran]

I am using Byteman in investigating some resource leaks within a project. Am currently using the latest released 3.0.10 version of Byteman. The class I'm interested in looks like this:

public abstract class A extends P implements C {

  public A(Foo foo) {
    this(foo.something, foo.otherthing);
  }

  public A(String s1, String s2) {
     .....
  }
}

Nothing fancy really - just an abstract class with 2 constructors. There are some classes which then extend this abstract class, but for the sake of this discussion (I don't think) they play a role.

My goal with the Byteman rule/script is to track the calls to the constructor of this class. So I've a rule (in additional to some other rules), which looks like:

RULE A trace create
CLASS org.myapp.A
METHOD <init>
AT ENTRY
IF TRUE
DO traceStack("*** create ")
ENDRULE

Again, a straightforward rule which dumps the stack trace AT ENTRY of the constructors. Things work fine - the rule gets applied and the thread dump too gets generated. However, the line numbers in the thread dump for this class are way off. For example:

***  create org.myapp.A.<init>(A.java:58)
org.myapp.A.<init>(A.java:73)
foo.bar.Hello.<init>(Hello.java:13)
....

Consider that above snippet to be the stacktrace. The line numbers 58 and 73 do not match the actual source of the class. I made sure the right class/jar was being picked up at runtime (using -verbose:class) and even decompiled the class to check if those line numbers match. They don't. One of that line number points to a non-code line (a closing } of the constructor) and the other points to a instance field initialization in that class.

How are these line numbers reported by the traceStack method?

[jaikiran]

I generated a javap output of that class with line number table included. Here's what it looks like (trimmed snippet):

public org.myapp.A(Foo);
    descriptor: ...
    flags: ACC_PUBLIC
    Code:
      stack=9, locals=2, args_size=2
        0: aload_0
        1: aload_1
        2: invokevirtual #1                  // Method Foo.a:()Ljava/lang/String;
        5: aload_1
        6: invokevirtual #2                  // Method Foo.b:()I
        9: aload_1
        10: invokevirtual #3                  // Method Foo.c:()Ljava/lang/String;
        13: aload_1
        14: invokevirtual #4                  // Method Foo.d:()Ljava/lang/String;
        17: aload_1
        18: invokevirtual #5                  // Method Foo.e:()[B
        21: aload_1
        22: invokevirtual #6                  // Method Foo.f:()Ljava/lang/String;
        25: aload_1
        26: invokevirtual #7                  // Method Foo.g:()I
        29: getstatic    #8                  // Field blah;
        32: invokespecial #9                  // Method "<init>":(Ljava/lang/String;ILjava/lang/String;)V
        35: return
      LineNumberTable:
        line 73: 0
        line 74: 22
        line 73: 32
        line 75: 35
      LocalVariableTable:
        Start  Length  Slot  Name  Signature
            0      36    0  this  LBlah;
            0      36    1  rsci  LBar;

  public org.myapp.A(java.lang.String, int, java.lang.String);
    descriptor: ...
    flags: ACC_PUBLIC
    Code:
      stack=5, locals=10, args_size=9
        0: aload_0
        1: invokespecial #10                // Method P."<init>":()V
        4: aload_0
        5: ldc          #12                // int 120000
        7: putfield      #13                // Field t:I
        ...
      LineNumberTable:
        line 78: 0
        line 58: 4
        ....

[adinn]

Hi Jaikiran,

Apologies for the slow response -- been on holiday for a week :-)

It is not exactly clear to me what line numbers you might be expecting here -- I'd need to have the full test program source to be sure what is going on. However, I think I may be able to explain why the lines you are seeing in the trace don't correspond to the ones you might be expecting. It may be to do with a specific restriction that applies on injecting into constructors.

When you specify CLASS Foo METHOD <init> AT ENTRY, Byteman cannot simply inject code at the start of any constructor for Foo. A constructor must always call its super constructor (or, possibly, an indirect constructor which -- eventually -- calls a super constructor) before executing any code that might attempt to access this. It can do certain operations such as access fields of input arguments etc but it cannot execute arbitrary code. That's necessary in order to ensure that the elements of this declared by the super class are initialized before the current constructor might try to use them.

Byteman respects this limitation by ensuring that code is not injected into a constructor's bytecode until it has seen an invokespecial call to a super constructor. That is necessary because Byteman passes this to the rule interpreter (or does other equivalent things for compiled rules). If Byteman attempted to inject code before the invokespecial it would fail with a verify error. So, your call to traceStack in the constructor for A shoudl appear to be on a line following the parent/indirect constructor call because that is indeed where it happens.

If that explanation fails to explain why you are seeing the line numbers in your trace then please post me the full source code for your test and I will see if there is some other error occurring.

To answer your question about how traceStack is implemented:

  Currently, it creates an Exception and uses the array of stack trace elements in the exception to derive  info regarding line numbers.

  Once jdk9 is available I hope to improve this to use the stack access API when running on JDK9, avoiding the need to create an Exception instance.

regards,

Andrew Dinn