JakeWharton / hugo

Annotation-triggered method call logging for your debug builds.
Apache License 2.0
7.92k stars 797 forks source link

java.lang.VerifyError while using @DebugLog anywhere in my app #9

Closed MufriA closed 9 years ago

MufriA commented 10 years ago
        dalvikvm  W  VFY: invoke type does not match method type of Lcom/example/MyActivity;.someMethodToLog
                    W  VFY:  rejecting opcode 0x6f at 0x0000
                    W  VFY:  rejected Lcom/example/MyActivity;.access$1000 (Lcom/example/MyActivity;)V
                    W  Verifier rejected class Lcom/example/MyActivity;
                    W  Class init failed in newInstance call (Lcom/example/MyActivity;)
    AndroidRuntime  D  Shutting down VM
          dalvikvm  W  threadid=1: thread exiting with uncaught exception (group=0x417d3898)
    AndroidRuntime  E  FATAL EXCEPTION: main
                    E  java.lang.VerifyError: com/example/MyActivity
                    E      at java.lang.Class.newInstanceImpl(Native Method)
                    E      at java.lang.Class.newInstance(Class.java:1130)
                    E      at android.app.Instrumentation.newActivity(Instrumentation.java:1078)
                    E      at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2220)
                    E      at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2359)
                    E      at android.app.ActivityThread.access$700(ActivityThread.java:165)
                    E      at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1326)
                    E      at android.os.Handler.dispatchMessage(Handler.java:99)
                    E      at android.os.Looper.loop(Looper.java:137)
                    E      at android.app.ActivityThread.main(ActivityThread.java:5455)
                    E      at java.lang.reflect.Method.invokeNative(Native Method)
                    E      at java.lang.reflect.Method.invoke(Method.java:525)
                    E      at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1187)
                    E      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)
                    E      at dalvik.system.NativeStart.main(Native Method)
JulienDev commented 10 years ago

Same here :+1:

12-07 21:29:02.132  15116-15116/com.jumy.twitterclient W/dalvikvm﹕ VFY: invoke type does not match method type of Lcom/jumy/twitterclient/ui/UserFragment;.setLoadingVisibility
12-07 21:29:02.132  15116-15116/com.jumy.twitterclient W/dalvikvm﹕ VFY:  rejecting opcode 0x6f at 0x0000
12-07 21:29:02.132  15116-15116/com.jumy.twitterclient W/dalvikvm﹕ VFY:  rejected Lcom/jumy/twitterclient/ui/UserFragment;.access$600 (Lcom/jumy/twitterclient/ui/UserFragment;Z)V
12-07 21:29:02.132  15116-15116/com.jumy.twitterclient W/dalvikvm﹕ Verifier rejected class Lcom/jumy/twitterclient/ui/UserFragment;
12-07 21:29:02.132  15116-15116/com.jumy.twitterclient D/AndroidRuntime﹕ Shutting down VM
12-07 21:29:02.132  15116-15116/com.jumy.twitterclient W/dalvikvm﹕ threadid=1: thread exiting with uncaught exception (group=0x4152cba8)
12-07 21:29:02.132  15116-15116/com.jumy.twitterclient E/AndroidRuntime﹕ FATAL EXCEPTION: main
    Process: com.jumy.twitterclient, PID: 15116
    java.lang.VerifyError: com/jumy/twitterclient/ui/UserFragment
            at com.jumy.twitterclient.ui.UserActivity.showUserFragment(UserActivity.java:139)
            at com.jumy.twitterclient.ui.UserActivity.onCreate(UserActivity.java:94)
            at android.app.Activity.performCreate(Activity.java:5231)
            at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1087)
            at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2159)
            at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2245)
            at android.app.ActivityThread.access$800(ActivityThread.java:135)
            at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1196)
            at android.os.Handler.dispatchMessage(Handler.java:102)
            at android.os.Looper.loop(Looper.java:136)
            at android.app.ActivityThread.main(ActivityThread.java:5017)
            at java.lang.reflect.Method.invokeNative(Native Method)
            at java.lang.reflect.Method.invoke(Method.java:515)
            at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:779)
            at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:595)
            at dalvik.system.NativeStart.main(Native Method)
JakeWharton commented 10 years ago

Provide more info. Method signature, android version, etc.

MufriA commented 10 years ago

Android ver : 4.3 Built with: Android Studio with gradle Source compatibility : 1.7

Added debuglog in,

 @DebugLog
    private void doCheck() {

however error seems to be in importFromGoogleAuth, which doesn't have annotation

  private void importFromGoogleAuth() {
dalvikvm  W  VFY: invoke type does not match method type of Lcom/mufri/authenticatorplus/AuthenticatorActivity;.importFromGoogleAuth
                    W  VFY:  rejecting opcode 0x6f at 0x0000
                    W  VFY:  rejected Lcom/mufri/authenticatorplus/AuthenticatorActivity;.access$1000 (Lcom/mufri/authenticatorplus/AuthenticatorActivity;)V
                    W  Verifier rejected class Lcom/mufri/authenticatorplus/AuthenticatorActivity;
                    W  Class init failed in newInstance call (Lcom/mufri/authenticatorplus/AuthenticatorActivity;)
    AndroidRuntime  D  Shutting down VM
          dalvikvm  W  threadid=1: thread exiting with uncaught exception (group=0x4186d898)
    AndroidRuntime  E  FATAL EXCEPTION: main
                    E  java.lang.VerifyError: com/mufri/authenticatorplus/AuthenticatorActivity
                    E      at java.lang.Class.newInstanceImpl(Native Method)
                    E      at java.lang.Class.newInstance(Class.java:1130)
                    E      at android.app.Instrumentation.newActivity(Instrumentation.java:1078)
                    E      at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2220)
                    E      at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2359)
                    E      at android.app.ActivityThread.access$700(ActivityThread.java:165)
                    E      at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1326)
                    E      at android.os.Handler.dispatchMessage(Handler.java:99)
                    E      at android.os.Looper.loop(Looper.java:137)
                    E      at android.app.ActivityThread.main(ActivityThread.java:5455)
                    E      at java.lang.reflect.Method.invokeNative(Native Method)
                    E      at java.lang.reflect.Method.invoke(Method.java:525)
                    E      at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1187)
                    E      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)
                    E      at dalvik.system.NativeStart.main(Native Method)
JakeWharton commented 10 years ago

Are you able to reproduce this in a different, simple file? Something that plays more like an example that you'd be comfortable sharing. And then can you send both the java and the compiled class file over?

It's hard to see what's really going on with the generated code unless I have a class file to inspect.

MufriA commented 10 years ago

I'm unable to reproduce the issue in simple classes, always reproduced in few classes, I will try to reproduce and send you the logs,

JakeWharton commented 10 years ago

Thanks! On Dec 10, 2013 2:33 AM, "MufriA" notifications@github.com wrote:

I'm unable to reproduce the issue in simple classes, always reproduced in few classes, I will try to reproduce and send you the logs,

— Reply to this email directly or view it on GitHubhttps://github.com/JakeWharton/hugo/issues/9#issuecomment-30214711 .

DHuckaby commented 10 years ago

@JakeWharton In testing to boil down my class into an example I found I understand less and less about what is going on with this issue. I was able however to provide a simple example to reproduce it.

https://gist.github.com/DHuckaby/08258c12ab311d5374c2

JakeWharton commented 10 years ago

We just hit an app internally that does this as well. I'll try to look tonight.

If any eager souls out there want to give it a shot it'll start with running "javap -cp" on the compiled code and inspecting what the re-written bytecode looks like.


Jake Wharton http://about.me/jakewharton

On Tue, Dec 10, 2013 at 10:16 AM, Daniel Huckaby notifications@github.comwrote:

@JakeWharton https://github.com/JakeWharton In testing to boil down my basic class into an example I found I understand less and less about what is going on with this issue. I was able however able to provide a simple example to reproduce it.

https://gist.github.com/DHuckaby/08258c12ab311d5374c2

— Reply to this email directly or view it on GitHubhttps://github.com/JakeWharton/hugo/issues/9#issuecomment-30252990 .

danielkutik commented 10 years ago

@DHuckaby I just ran your code and couldn't find any issue:

D/Example﹕ ⇢ test()
D/Example﹕ ⇠ test [0ms]

I'm running this code on my Nexus 4 with API 19 (Android 4.4) with hugo 1.0.1.

JakeWharton commented 10 years ago

I have a compiled version of a class file that exhibits this behavior that I need to do inspect later.

@DHuckaby Can you post the compiled class file of the example above when it fails for you?

chrisjenx commented 10 years ago

OK great we ran into this yesterday. +1

danielkutik commented 10 years ago

Can anybody share a bit of code that reproduces this issue?

chrisjenx commented 10 years ago

Not without giving away alot of internal code, but whats odd is its unrelated, it caused VerifyErrors on code which wasn't tagged with @DebugLog, very odd.

danielkutik commented 10 years ago

The class was not tagged at all? Be aware that line numbers might be incorrect.

chrisjenx commented 10 years ago

A calling parent method was, but was a method down the execution chain which threw the VerifyError. Sorry I can't be more helpful.. I'll see if I can pull out the offending code later.

chrisjenx commented 10 years ago

Oh and this might of already been established, but its is only an issue on Java7, change back to 1.6 and all is smooth sailing.

DHuckaby commented 10 years ago

@danielkutik Did you compile it against java 7?

@JakeWharton What exactly do you want? The .class file?

JulienDev commented 10 years ago

Also compiled using java 7

JakeWharton commented 10 years ago

Yes. The class file. Preferably in the smallest possible file you can get the error to occur in. I don't want to sift through thousands of bytecode instructions. On Dec 11, 2013 6:15 AM, "JulienDev" notifications@github.com wrote:

Also compiled using java 7

— Reply to this email directly or view it on GitHubhttps://github.com/JakeWharton/hugo/issues/9#issuecomment-30323089 .

DHuckaby commented 10 years ago

@JakeWharton http://cloud.tweedleapp.com/3W3B0S2g1q2q

JakeWharton commented 10 years ago

Excellent. Can you paste the verify logs that correspond to this file too?

DHuckaby commented 10 years ago

@JakeWharton I added it to the gist https://gist.github.com/DHuckaby/08258c12ab311d5374c2

JakeWharton commented 10 years ago

@DHuckaby Are you able to get a class file that was compiled with Java 6 that does not exhibit the failure.

DHuckaby commented 10 years ago

@JakeWharton Here you go, it works fine with Java 6. http://cloud.tweedleapp.com/3U122y0Z413S

JakeWharton commented 10 years ago

My best guess thus far is the ACC_SYNTHETIC access flag is causing the runtime to blow up. Does the Java 7-compiled version fail on Android 4.4?

JakeWharton commented 10 years ago

Actually ACC_SYNTHETIC is in the Java 6 version but not Java 7. Ugh. Question about 4.4 still stands, though.

DHuckaby commented 10 years ago

@JakeWharton It crashes on 4.4 also, tested on a stock Moto X.

chrisjenx commented 10 years ago

@JakeWharton same, HTC One GE 4.4.1 Java7 VerifyError.

On 11 December 2013 17:57, Daniel Huckaby notifications@github.com wrote:

@JakeWharton https://github.com/JakeWharton It crashes on 4.4 also, tested on a stock Moto X.

— Reply to this email directly or view it on GitHubhttps://github.com/JakeWharton/hugo/issues/9#issuecomment-30344241 .

danielkutik commented 10 years ago

I so far have never experienced this issue... I compiled https://gist.github.com/DHuckaby/08258c12ab311d5374c2 with java7 and android sdk 19 running it on my nexus 4 (4.4) (not 4.4.1!?). You guys are running Dalvik I guess.. ever cared to try ART? Just to narrow it down. We still don't know where the issue is:

I don't want to blame it simply on other projects :) but let's find a reproducible issue (environment + sourcecode)...

Please try to run the failing apk also on emulated environments (same OS version as well as different ones)

DHuckaby commented 10 years ago

@danielkutik From your comment it doesn't sound like you tested it using Dalvik. ART is an experimental runtime, I wouldn't use it for debugging anything at this point if it bombs out on the default runtime.

Here is a full example project importing the very simple example, and it still crashes: https://github.com/DHuckaby/HugoCrashExample

nealsanche commented 10 years ago

For me, Hugo crashes iff I add

    compileOptions {
        sourceCompatibility JavaVersion.VERSION_1_7
        targetCompatibility JavaVersion.VERSION_1_7
    }

to my build.gradle. If I remove that (I'm not yet using any 1.7 language features) the crash described here does not occur.

Wavesonics commented 10 years ago

Yup, I've got my Java version set to 1.7 and also see this crash.

JakeWharton commented 10 years ago

mavenLocal() is broken, but after, here's a random shot in the dark: https://github.com/JakeWharton/hugo/compare/master...jw;match-source-compatibility

jjNford commented 10 years ago

@JakeWharton what is the status of this?

JakeWharton commented 10 years ago

It's far down on my todo list. If there was a heading at that level it would be "Tasks I Am Praying Someone Else Sends a Pull Request For".

vinc3m1 commented 10 years ago

Getting this too, and just to validate previous reports: this happens when you set language level to 7, and verify fails on private methods that would require synthetic accessors.

JakeWharton commented 10 years ago

private methods that would require synthetic accessors.

@vinc3m1 Can you elaborate on this?

vinc3m1 commented 10 years ago

e.g. private methods accessed from inner classes.

In the example from above: dalvikvm W VFY: invoke type does not match method type of Lcom/mufri/authenticatorplus/AuthenticatorActivity;.importFromGoogleAuth

If he makes importFromGoogleAuth non-private, the error will go away (at least for that method, chances are it will err at the next private method that needs a synthetic accessor). This seems to only happen in classes annotated with DebugLog though.

vinc3m1 commented 10 years ago

Does ajc accept -1.6 or -1.7 as a param? https://github.com/JakeWharton/hugo/blob/master/hugo-plugin/src/main/groovy/hugo/weaving/plugin/HugoPlugin.groovy#L48

Might be a language level compatibility problem. I would try this but I've never run a local gradle plugin before...

vinc3m1 commented 10 years ago

Actually, now that I'm trying to reproduce it with hugo-example, the only way to get a crash is to use include a synchronized block. Simply adding:

synchronized (Boolean.TRUE) {}

causes it to crash.

Then of course, if you make all your methods non-private after that, it will run fine....

loeschg commented 10 years ago

I'm getting this same issue. Haven't seen it work yet. Seems to blow up when I instantiate a fragment in a private internal class (internal FragmentStatePagerAdapter). I'm also using

compileOptions {
    sourceCompatibility JavaVersion.VERSION_1_7
    targetCompatibility JavaVersion.VERSION_1_7
}
jonasfa commented 10 years ago

https://github.com/JakeWharton/hugo/issues/9#issuecomment-37256047 and https://github.com/JakeWharton/hugo/issues/9#issuecomment-31412980 describe exactly how I get this error: Java 7 + private method accessed from a inner class

burgalon commented 10 years ago

In a weird way, this has happened to me several times and seemed to be related to ternary expressions

williamwebb commented 10 years ago

Just to add, i also experienced this bug when using JavaVersion.VERSION_1_7, switching to 1.6 does not cause the bug.

AndrewReitz commented 10 years ago

I'm seeing the same thing as vinc3m1, I have a method that when marked private it causes this issue. Change it to package protected, no problem. Any suggestions on where I can look to help figure out what is causing this?

thevoiceless commented 10 years ago

Same issue here after setting source and target compatibility to 1.7; The behavior I'm seeing (VerifyError when accessing private methods from inner classes) and the workaround (making everything either public or protected) match up with what @vinc3m1 found

yogurtearl commented 9 years ago

In my case:

This gives a VerifyError:

        final int value = 5 + (flag ? 4 : 7);

Switching to this works just fine ( no other changes ):

        final int value = (flag ? 4 : 7) + 5;

Putting that code in a minimal class for SSCCE didn't trigger the error. :( It only triggers VerifyError as part of my larger class.

The code above is NOT in a @DebugLog method.

The VerifyError points to another method in the same class ( also not a @DebugLog method ).

But if I remove all @DebugLog from that particular class, everything works fine...

( Using JDK 7 javac ) ( fails on ART/Lollipop as well )

fschoellhammer commented 9 years ago

I am not sure if this is related, I am using AspectJ in a different project, and I noticed if I use sdk buildtools 19 (19.1.0), then I get VerifyError when running advised code. If I e.g. switch to 21 (21.1.1) then it works.

yhartanto commented 9 years ago

I was able to reproduce this issue by adding the empty synchronized (Boolean.True) {} in the example code. I am sure the issue is not caused by hugo but it seems to be related to how the code generated in dex does not comply with Dalvik VM verification.

When I upgraded to the latest set of build tools, the issue goes away.

JakeWharton commented 9 years ago

Fixed by #62.