Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

AllLines not working, raises java.lang.VerifyError #456

Closed
decster opened this issue Mar 18, 2021 · 5 comments
Closed

AllLines not working, raises java.lang.VerifyError #456

decster opened this issue Mar 18, 2021 · 5 comments
Assignees
@jbachorik
Milestone
2.2.0

Comments

@decster
Copy link

decster commented Mar 18, 2021 •
edited
Loading 

code

@BTrace
public class AllLines {
    @OnMethod(
            clazz = "btracetest.Main",
	    method = "printOnce",
            location = @Location(value = Kind.LINE, line = -1)
    )
    public static void online(@ProbeClassName String pcn, @ProbeMethodName String pmn, int line) {
        print(pcn + "." + pmn + ":" + line + "\n");
    }
}

Note that change location = @Location(value = Kind.LINE, line = -1) to line = (a specific line) will work. It must be some issue with -1 to match all lines.

btrace -v 22199 AllLines.java debug=1

DEBUG: assuming default port 2020
DEBUG: assuming default classpath '.'
Attaching BTrace to PID: 22199
DEBUG: compiling AllLines.java
DEBUG: compiled AllLines.java
DEBUG: attaching to 22199
DEBUG: checking port availability: 2020
DEBUG: attached to 22199
DEBUG: loading /home/decster/.sdkman/candidates/btrace/2.0.3/libs/btrace-agent.jar
DEBUG: agent args: port=2020,statsd=,debug=true,bootClassPath=.,systemClassPath=/home/decster/.sdkman/candidates/java/11.0.10-open/lib/tools.jar,probeDescPath=.
DEBUG: loaded /home/decster/.sdkman/candidates/btrace/2.0.3/libs/btrace-agent.jar
DEBUG: registering shutdown hook
DEBUG: registering signal handler for SIGINT
DEBUG: submitting the BTrace program
DEBUG: opening socket to 2020
DEBUG: setting up client settings
DEBUG: sending instrument command: [debug=1]
DEBUG: entering into command loop
DEBUG: received org.openjdk.btrace.core.comm.RenameCommand@71def8f8
DEBUG: received org.openjdk.btrace.core.comm.OkayCommand@4d465b11
DEBUG: received org.openjdk.btrace.core.comm.RetransformationStartNotification@5562c41e
DEBUG: received org.openjdk.btrace.core.comm.MessageCommand@28f2a10f
[BTRACE WARN] Class verification failed: btracetest.Main (null)DEBUG: received org.openjdk.btrace.core.comm.OkayCommand@f736069


btrace DEBUG: java.lang.VerifyError
java.lang.VerifyError
	at java.instrument/sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at java.instrument/sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:167)
	at org.openjdk.btrace.agent.Client.retransformLoaded(Client.java:500)
	at org.openjdk.btrace.agent.Main$5.run(Main.java:869)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
@jbachorik
Copy link
Collaborator

Can you retry with BTrace 2.1.0?
If it would keep on failing could you provide the test class source?

I tried the script on my test class and it is working in 2.1.0 - but the failure may depend on the class structure so having also your test source would help a lot.

@jbachorik jbachorik self-assigned this Mar 20, 2021
@jbachorik jbachorik added this to the 2.1.1 milestone Mar 20, 2021
@decster
Copy link
Author

decster commented Mar 22, 2021

Sorry forgot to add source


decster@decster-MS-7C94:~/projects/tmps/demoagent$ cat app/src/main/java/com/decster/AppMain.java 
package com.decster;

public class AppMain {

	public static void main(String[] args) {
		AppMain m = new AppMain();
		int i = 0;
		while (true) {
			try {
				Thread.sleep(1000);
			} catch (InterruptedException e) {

			}
			m.foo(i);
			m.bar(i);
			i++;
		}
	}

	void foo(int i) {
		System.out.println("foo 1 ");
		System.out.println("foo 2 ");
		System.out.println("foo 3 ");
	}

	void bar(int i) {
		System.out.println("bar " + i);
	}

}


AllLines.java

package example;

import org.openjdk.btrace.core.annotations.BTrace;
import org.openjdk.btrace.core.annotations.Kind;
import org.openjdk.btrace.core.annotations.Location;
import org.openjdk.btrace.core.annotations.OnMethod;
import org.openjdk.btrace.core.annotations.ProbeClassName;
import org.openjdk.btrace.core.annotations.ProbeMethodName;

import static org.openjdk.btrace.core.BTraceUtils.println;

/*
 * This sample prints a line every time any line
 * of code of java.lang.Thread class is reached.
 * The line param may be set to any particular
 * value so that the probe fires only when that line
 * is reached. But, the value -1 means all line numbers.
 */
@BTrace
public class AllLines {
    @OnMethod(
            clazz = "com.decster.AppMain",
            method = "foo",
            location = @Location(value = Kind.LINE, line = -1)
    )
    public static void online(@ProbeClassName String pcn, @ProbeMethodName String pmn, int line) {
        println(pmn);
        //print(pcn + "." + pmn + ":" + line + "\n");
    }
}


decster@decster-MS-7C94:~/projects/tmps/btracetest$btrace -v 8425 AllLines.java debug=1
DEBUG: assuming default port 2020
DEBUG: assuming default classpath '.'
btrace INFO: Attaching BTrace to PID: 8425
DEBUG: compiling AllLines.java
DEBUG: compiled AllLines.java
DEBUG: Boot classpath: .
DEBUG: attaching to 8425
DEBUG: checking port availability: 2020
DEBUG: attached to 8425
DEBUG: loading /home/decster/.sdkman/candidates/btrace/2.1.0/libs/btrace-agent.jar
DEBUG: agent args: port=2020,statsd=,debug=true,bootClassPath=.,systemClassPath=/home/decster/.sdkman/candidates/java/8.0.282-open/jre/../lib/tools.jar,probeDescPath=.
DEBUG: loaded /home/decster/.sdkman/candidates/btrace/2.1.0/libs/btrace-agent.jar
DEBUG: registering shutdown hook
DEBUG: registering signal handler for SIGINT
DEBUG: submitting the BTrace program
DEBUG: opening socket to 2020
DEBUG: setting up client settings
DEBUG: sending instrument command: [debug=1]
DEBUG: entering into command loop
DEBUG: received org.openjdk.btrace.core.comm.RenameCommand@706a04ae
DEBUG: received org.openjdk.btrace.core.comm.StatusCommand@6eceb130
DEBUG: received org.openjdk.btrace.core.comm.RetransformationStartNotification@10a035a0
DEBUG: received org.openjdk.btrace.core.comm.MessageCommand@5c072e3f
[BTRACE WARN] Class verification failed: com.decster.AppMain (null)
DEBUG: received org.openjdk.btrace.core.comm.StatusCommand@4d1b0d2a
btrace INFO: Successfully started BTrace probe: AllLines.java
DEBUG: received org.openjdk.btrace.core.comm.StatusCommand@954b04f
^CPlease enter your option:
	1. exit
	2. send an event
	3. send a named event
	4. flush console output
	5. list probes
	6. detach client
1
DEBUG: sending exit command

App side output: 
btrace DEBUG: client accepted Socket[addr=/127.0.0.1,port=47754,localport=2020]
btrace DEBUG: got instrument command
btrace DEBUG: loading BTrace class
btrace DEBUG: verifying BTrace class ...
btrace DEBUG: BTrace class org.openjdk.btrace.runtime.aux.AllLines$1 verified
btrace DEBUG: preprocessing BTrace class org.openjdk.btrace.runtime.aux.AllLines$1 ...
btrace DEBUG: ... preprocessed
btrace DEBUG: loaded 'org.openjdk.btrace.runtime.aux.AllLines$1' successfully
btrace DEBUG: class renamed to org.openjdk.btrace.runtime.aux.AllLines$1
btrace DEBUG: client org.openjdk.btrace.runtime.aux.AllLines$1: got org.openjdk.btrace.core.comm.RenameCommand@5399ffd1
btrace DEBUG: creating BTraceRuntime instance for org.openjdk.btrace.runtime.aux.AllLines$1
btrace DEBUG: created BTraceRuntime instance for org.openjdk.btrace.runtime.aux.AllLines$1
btrace DEBUG: sending Okay command
btrace DEBUG: client org.openjdk.btrace.runtime.aux.AllLines$1: got org.openjdk.btrace.core.comm.StatusCommand@1c5aa37f
btrace DEBUG: about to defineClass org/openjdk/btrace/runtime/aux/AllLines$1
btrace DEBUG: init: clazz = null, cl = class org.openjdk.btrace.runtime.aux.AllLines$1
btrace DEBUG: init: timerHandlers = null
btrace DEBUG: defineClass succeeded for org.openjdk.btrace.runtime.aux.AllLines$1
btrace DEBUG: starting client command handler thread
btrace DEBUG: new Client created BTrace Client: b4cb228a-2b44-49d9-a7f8-02278f27af84[org.openjdk.btrace.runtime.aux.AllLines$1]
btrace DEBUG: retransforming loaded classes
btrace DEBUG: filtering loaded classes
btrace DEBUG: candidate class com.decster.AppMain added
btrace DEBUG: client org.openjdk.btrace.runtime.aux.AllLines$1: got org.openjdk.btrace.core.comm.RetransformationStartNotification@57230d5
btrace DEBUG: calling retransformClasses (1 classes to be retransformed)
btrace DEBUG: Attempting to retransform class: com.decster.AppMain
btrace DEBUG: transformed class com.decster.AppMain
btrace DEBUG: java.lang.VerifyError
btrace DEBUG: skipping transform for BTrace class java/lang/Throwable$WrappedPrintStream
btrace DEBUG: skipping transform for BTrace class java/lang/Throwable$PrintStreamOrWriter
btrace DEBUG: skipping transform for BTrace class java/util/IdentityHashMap$KeySet
java.lang.VerifyError
	at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:144)
	at org.openjdk.btrace.agent.Client.retransformLoaded(Client.java:520)
	at org.openjdk.btrace.agent.Main$6.run(Main.java:890)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

@decster
Copy link
Author

decster commented Mar 22, 2021

Can you retry with BTrace 2.1.0?

Yes, tried 2.0.3 and 2.1.0 both failed, jdk is 1.8

openjdk version "1.8.0_282"
OpenJDK Runtime Environment (build 1.8.0_282-b08)
OpenJDK 64-Bit Server VM (build 25.282-b08, mixed mode)

@jbachorik
Copy link
Collaborator

Thanks for the reproducer.
The culprit is injecting the probe callback to a constructor if the line number happens to point before the call to super.<init>().

@nik-suri
Copy link

@jbachorik I am facing this same error when I attempt to use @Location(value = Kind.LINE, line = -1). When starting btrace against a running server, I see multiple messages such as this:

[BTRACE WARN] Class verification failed: com.mypackage.myclass1 (null)
[BTRACE WARN] Class verification failed: com.mypackage.myclass2 (null)
[BTRACE WARN] Class verification failed: com.mypackage.myclass3 (null)
...

Then when I hit an API endpoint for my server, I see the same java.lang.VerifyError for each of the classes which threw the [BTRACE WARN] above.

I am using the latest release (2.1.0). When will the new version be released?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@jbachorik jbachorik

Labels
None yet
Projects
None yet
Milestone
2.2.0
Development

No branches or pull requests
3 participants
@decster @jbachorik @nik-suri