Incorrect LineNumbers with try-with-resources

CoderBaron commented 8 years ago

I have created the default project and edited the robovm.xml to include <useLineNumbers>true</useLineNumbers>. I also edited the MyViewController class and in the touch up inside listener I throw a RuntimeException.

The stack trace looks like this:

java.lang.RuntimeException: TEST
    at com.mycompany.myapp.MyViewController.lambda$new$0(MyViewController.java:32)
    at com.mycompany.myapp.MyViewController$$Lambda$1.onTouchUpInside(Unknown Source)
    at org.robovm.apple.uikit.UIControl$ListenerWrapper.handleTouchEvent(UIControl.java:108)
    at org.robovm.apple.uikit.UIControl$ListenerWrapper.$cb$handleTouchEvent(UIControl.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:365)
    at com.mycompany.myapp.Main.main(Main.java:30)

The only correct line number is UIControl.java:108.

Now I changed the MyViewController class and removed all code from the constructor and instead throw a RuntimeException. Also removed all fields and unused imports.

Now the stack trace looks like this:

java.lang.RuntimeException: TEST
    at com.mycompany.myapp.MyViewController.<init>(MyViewController.java:32)
    at com.mycompany.myapp.Main.didFinishLaunching(Main.java:17)
    at com.mycompany.myapp.Main.$cb$application$didFinishLaunchingWithOptions$(Main.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:365)
    at com.mycompany.myapp.Main.main(Main.java:30)

Once again, there is only one correct line number: Main.java:17 The MyViewController class has only 11 lines of code, still it says again line number 32.

florianf commented 8 years ago

Interesting. I just did the same as you:

Created a new RoboVM iOS Project
Commented out all code in the MyViewController constructor (also made the fields non final)
Inserted a throw new RuntimeException on the first line

I get the correct linenumbers:

java.lang.RuntimeException: I should be on line 13
    at MyViewController.<init>(MyViewController.java:13)
    at IOSTest.didFinishLaunching(IOSTest.java:17)
    at IOSTest.$cb$application$didFinishLaunchingWithOptions$(IOSTest.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:365)
    at IOSTest.main(IOSTest.java:30)

I tested it on an iOS 9 iPhone simulator. Did you run it on a device?

florianf commented 8 years ago

If you want do dig deeper, the mechanism is fairly simple:

The ShadowFramesPlugin generates rvmPushShadowFrame IR instruction for every method call with the method's memory address. For every line a rvmPushShadowFrameLinenumber instruction is inserted with the current line number. When an exception is thrown the line numbers are resolved for every stack frame in methods.c. The runtime code for the shadow frames is in shadowframes.c

Relevant commit: https://github.com/MobiDevelop/robovm/commit/4770f7e4ac34663f4f0aff44388e41860eed9dd2

intrigus commented 8 years ago

The problem is probably retro lambda messing with the line numbers.

CoderBaron commented 8 years ago

I tested with device and simulator, iOS 9 and iOS 10, Xcode beta and stable and it's always the same wrong line numbers.

My class looks as simple as this:

package com.mycompany.myapp;

import org.robovm.apple.uikit.UIViewController;

public class MyViewController extends UIViewController {

    public MyViewController() {
        throw new RuntimeException("I should be on line 9");
    }
}

I'm using the latest stable IntelliJ IDEA plugin. I created an iOS device run configuration.

I really can't explain why it works for you @florianf, while it fails for me. I'm not using retro lambda for this project (I just created the default project with the wizard in idea).

@florianf Do you maybe have some local uncomitted changes that prevent the problem from happening?

florianf commented 8 years ago

The only difference I see, is that I'm using eclipse, could you try this too?

If you're running RoboVM in the debugging mode (as described in the hacking guide) you could take a look at the .robovm/cache/ios/x86_64/debug/... LLVM IR files (MyViewController.ll) and check if the linenumbers are correctly set there.

F.ex. the IR for the constructor for me looks like this:

define weak void @"[J]MyViewController.<init>()V"(%Env* %p0, %Object* %p1) nounwind noinline optsize {
label0:
    %r0 = alloca %Object*
    %funcAddr = bitcast void (%Env*, %Object*)* @"[J]MyViewController.<init>()V" to i8*

    call void @"rvmPushShadowFrame"(%Env* %p0, i8* %funcAddr)
    %$r1 = alloca %Object*
    call void @"checkso"()
    call void @"rvmPushShadowFrameLineNumber"(%Env* %p0, i32 12)
    store %Object* %p1, %Object** %r0
    %t0 = load %Object** %r0
    call void @"[j]org.robovm.apple.uikit.UIViewController.<init>()V[Invokespecial(MyViewController,MyViewController)]"(%Env* %p0, %Object* %t0)
    call void @"rvmPushShadowFrameLineNumber"(%Env* %p0, i32 13)
    %t1 = call %Object* @"[j]java.lang.RuntimeException[New(MyViewController)]"(%Env* %p0)
    store %Object* %t1, %Object** %$r1
    %t2 = load %Object** %$r1
    %t3 = call %Object* @"[j]str_I_20should_20be_20on_20line_2022_00[ldcstring]"(%Env* %p0)
    call void @"[j]java.lang.RuntimeException.<init>(Ljava/lang/String;)V[Invokespecial(MyViewController,java/lang/RuntimeException)]"(%Env* %p0, %Object* %t2, %Object* %t3)
    %t4 = load %Object** %$r1
    call void @"_bcThrow"(%Env* %p0, %Object* %t4)
    unreachable
}

CoderBaron commented 8 years ago

I can confirm that line numbers are correct when using Eclipse. I retried with IDEA with Gradle and without but in both cases line numbers where incorrect.

Tom-Ski commented 8 years ago

Is that running from source or just with the eclipse plugin?

CoderBaron commented 8 years ago

I just ran with the Eclipse plugin (Run As iOS Device App) -> Line numbers perfect. Run with IDEA plugin (iOS device run configuration) -> Line numbers partially wrong.

Tom-Ski commented 8 years ago

OK, something probably up with the IDEA artifact then, I've had some other reports regarding IDEA so that could be it. I'll be able to test in a couple of days (getting a new dev environment setup) and I'll try to see whats going on on the IDEA end. Could you send over the LLVM IR as @florianf said?

CoderBaron commented 8 years ago

That's good to hear @Tom-Ski! It seems that ATM there's no way to put the IDEA plugin into debug mode and generate those files, only in Eclipse.

CoderBaron commented 8 years ago

I got it to work, the IDEA plugin now runs in debug mode! Here are the contents of MyViewController.class.ll: http://pastebin.com/h09kBF10

The IR for the constructor looks exactly the same as the one @florianf posted.

Tom-Ski commented 8 years ago

Did you try with the latest IDEA plugin snapshot? http://robovm.mobidevelop.com/downloads/snapshots/idea/

CoderBaron commented 8 years ago

I am already using the latest snapshot.

I have now created twice the same project, once with the old RoboVM and once with the fork. These are the stack traces when building with IDEA:

Old RoboVM:

java.lang.RuntimeException: I should be on line 5!
    at com.mycompany.myapp.TestB.crash(TestB.java:5)
    at com.mycompany.myapp.TestA.crash(TestA.java:5)
    at com.mycompany.myapp.MyViewController.lambda$new$0(MyViewController.java:33)
    at com.mycompany.myapp.MyViewController$$Lambda$1.onTouchUpInside(Unknown Source)
    at org.robovm.apple.uikit.UIControl$ListenerWrapper.handleTouchEvent(UIControl.java:105)
    at org.robovm.apple.uikit.UIControl$ListenerWrapper.$cb$handleTouchEvent(UIControl.java)
    at org.robovm.apple.uikit.UIApplication.main(Native Method)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:413)
    at com.mycompany.myapp.Main.main(Main.java:31)

RoboVM Fork:

java.lang.RuntimeException: I should be on line 5!
    at com.mycompany.myapp.TestB.crash(TestB.java:32)
    at com.mycompany.myapp.TestA.crash(TestA.java:5)
    at com.mycompany.myapp.MyViewController.lambda$new$0(MyViewController.java:33)
    at com.mycompany.myapp.MyViewController$$Lambda$1.onTouchUpInside(Unknown Source)
    at org.robovm.apple.uikit.UIControl$ListenerWrapper.handleTouchEvent(UIControl.java:108)
    at org.robovm.apple.uikit.UIControl$ListenerWrapper.$cb$handleTouchEvent(UIControl.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:0)
    at org.robovm.apple.uikit.UIApplication.main(UIApplication.java:365)
    at com.mycompany.myapp.Main.main(Main.java:30)

These are my findings:

When using IntelliJ IDEA with the fork, the last line number is always 32.
The line numbers for generated callback methods (like $cb$handleTouchEvent) will be always 0, they are removed in the old RoboVM version.
Native methods are named as such in the old RoboVM version.
The line numbers for UIApplication.main and Main.main are wrong in this fork version.
Note: The UIControl.java:108 line number is correct, it is really different in this fork version.
All rvmPushShadowFrameLineNumber instructions are generated with the correct line numbers.

I'm not sure but I guess the issue lies somewhere here: https://github.com/MobiDevelop/robovm/commit/4770f7e4ac34663f4f0aff44388e41860eed9dd2#diff-c4abf2a20a8e9931fc488c597557feaeR416

florianf commented 8 years ago

That's weird. One last request (for now ;-): Could you try a simple RoboVM console project? Does it happen there too? And with "old RoboVM" do you mean the latest official release? Because they used a completly different mechanism for generating the linenumbers (LLVM metadata).

CoderBaron commented 8 years ago

Same problem with console but different line number:

java.lang.RuntimeException: I should be on line 5!
    at com.mycompany.myapp.TestB.crash(TestB.java:11)
    at com.mycompany.myapp.TestA.crash(TestA.java:5)
    at com.mycompany.myapp.Main.main(Main.java:10)

Am I the only one having these line number issues on IDEA? Or can you also reproduce them? But the stack trace from Eclipse you posted also has some wrong line numbers (IOSTest.java:30 should be 31; and UIApplication.java:365 should be something around 400...).

With "old RoboVM" I meant the latest official release. Yes, they used different ways to generate the line numbers but I created the same project just to see what the line numbers should actually look like.

florianf commented 8 years ago

Thanks for your patience!

I didn't test with IDEA yet, because I haven't set it up on my Mac.That's why I was asking if the problem occurs also in a console project, than I can try on my Linux workstation with IDEA installed.

If you want to help further, you could try to debug the binary with LLDB, the whole stacktrace unwinding is done in C and completly debuggable with LLDB.

intrigus commented 8 years ago

Console projects works fine here with latest plugin (org.robovm.idea-2.2.1-SNAPSHOT-plugin-dist.jar ) for IDEA 15 CE. I'm using this gist for testing. Linenumbers on iOS also don't work for me using this gist. Can I also debug this binary via LLDB? If so, how?

florianf commented 8 years ago

Yup debugging the simulator works too: http://stackoverflow.com/questions/10112164/terminal-command-line-debug-of-ios-simulator-apps IIRC you need to specify the full name of the app, like "IOSTest.app" but I'm not sure anymore.

I've two rough ideas what possibly could go wrong:

Perhaps a multithreading issue on iOS, see my comment here https://github.com/MobiDevelop/robovm/pull/21#issuecomment-228532409
Something wrong with the function addresses (64bit, maybe) since the generated IR is correct.

Tom-Ski commented 7 years ago

Seems to be unrelated to IDEA (perhaps before the artifacts were no good) so I've changed the issue title. Working on trying to get try-with-resources running happily.

florianf commented 7 years ago

I just commited a fix as discussed on gitter yesterday. Please give it a spin and report back.

florianf commented 7 years ago

Fixed in current master via pr #116

MobiVM / robovm

Incorrect LineNumbers with try-with-resources #37