BTrace is a safe, dynamic tracing tool for the Java platform. BTrace can be used to dynamically trace a running Java program (similar to DTrace for OpenSolaris applications and OS).
Shortly, the tool allows to inject tracing points without restarting or reconfiguring your Java application while it's running. Moreover, though there are several ways to do that, the one I would like to discuss today is using JVisualVM tool from standard JDK bundle.
What is very cool, BTrace itself uses Java language to define injection trace points. The approach looks very familiar if you ever did aspect-oriented programming (AOP).
So let's get started with a problem: we have an application which uses one of the NoSQL databases (f.e., let it be MongoDB) and suddenly starts to experience significant performance slowdown. Developers suspect that application runs too many queries or updates but cannot say it with confidence. Here BTrace can help.
First thing first, let's run JVisualVM and install BTrace plugin:
JVisualVM should be restarted in order for plugin to appear. Now, while our application is up and running, let's right click on it in JVisualVM applications tree:
The following very intuitive BTrace editor (with simple toolbar) should appear:
This is a place where tracing instrumentation could be defined and dynamically injected into the running application. BTrace has a very rich model in order to define what exactly should be traced: methods, constructors, method returns, errors, .... Also it supports aggregations out of the box so it quite easy to collect a bunch of metrics while application is running. For our problem, we would like to see which methods related to MongoDB are being executed.
As my application uses Spring Data MongoDB, I am interested in which methods of any implementation of org.springframework.data.mongodb.core.MongoOperations interface are being called by application and how long every call takes. So I have defined a very simple BTrace script:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 | import com.sun.btrace.*;import com.sun.btrace.annotations.*;import static com.sun.btrace.BTraceUtils.*;@BTracepublic class TracingScript { @TLS private static String method; @OnMethod( clazz = "+org.springframework.data.mongodb.core.MongoOperations", method = "/.*/" ) public static void onMongo( @ProbeClassName String className, @ProbeMethodName String probeMethod, AnyType[] args ) { method = strcat( strcat( className, "::" ), probeMethod ); } @OnMethod( clazz = "+org.springframework.data.mongodb.core.MongoOperations", method = "/.*/", location = @Location( Kind.RETURN ) ) public static void onMongoReturn( @Duration long duration ) { println( strcat( strcat( strcat( strcat( "Method ", method ), " executed in " ), str( duration / 1000 ) ), "ms" ) ); }} |
Let me explain briefly what I am doing here. Basically, I would like to know when any method of any implementation of org.springframework.data.mongodb.core.MongoOperations is called (onMongo marks that) and duration of the call (onMongoReturn marks that in turn). Thread-local variable method holds full qualified method name (with a class), while thanks to useful BTrace predefined annotation, duration parameter holds the method execution time (in nanoseconds). Though it's pure Java, BTrace allows only small subset of Java classes to be used. It's not a problem as com.sun.btrace.BTraceUtils class provides a lot of useful methods (f.e., strcat) to fill the gaps. Running this script produces following output:
** Compiling the BTrace script ... *** Compiled ** Instrumenting 1 classes ... Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 25ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 3ms Method org.springframework.data.mongodb.core.MongoTemplate::getDb executed in 22ms Method org.springframework.data.mongodb.core.MongoTemplate::prepareCollection executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::prepareCollection executed in 19ms Method org.springframework.data.mongodb.core.MongoTemplate::access$100 executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::access$100 executed in 1ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 3ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::getDb executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::prepareCollection executed in 1ms Method org.springframework.data.mongodb.core.MongoTemplate::prepareCollection executed in 6ms Method org.springframework.data.mongodb.core.MongoTemplate::access$100 executed in 1ms Method org.springframework.data.mongodb.core.MongoTemplate::access$100 executed in 0ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 1ms Method org.springframework.data.mongodb.core.MongoTemplate::getDb executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::prepareCollection executed in 1ms Method org.springframework.data.mongodb.core.MongoTemplate::prepareCollection executed in 6ms Method org.springframework.data.mongodb.core.MongoTemplate::access$100 executed in 1ms Method org.springframework.data.mongodb.core.MongoTemplate::access$100 executed in 0ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 2ms Method org.springframework.data.mongodb.core.MongoTemplate::maybeEmitEvent executed in 1ms ...
As you can see, output contains bunch of inner classes which could easily be eliminated by providing more precise method name templates (or maybe even tracing MongoDB driver instead).
I have just started to discover BTrace but I definitely see a great value for me as a developer from using this awesome tool. Thanks to BTrace guys!
Posts
3 comments:
Hey, I'm a community blog curator for DZone. I wanted to talk with you about potentially featuring your blog on DZone's content portals. Send me an email at allenc [at] dzone [dot] com and I'll explain the details.
Thank you a lot, I will try to discover and share more interesting, useful topics and concepts.
thanks.
Okay, that simplifies things! Here's the revised process, assuming you're not using SDKMAN!:
Process: Using BTrace with VisualVM (Standard Setup)
Assumptions:
JDK Installed: You have a Java Development Kit (JDK) installed on your system.
VisualVM Installed: You're using the VisualVM included in JDK 8 (or have downloaded it separately for later JDK versions).
PowerShell (Administrator): You're using PowerShell with Administrator privileges (though often admin rights aren't strictly needed, it's a good practice to avoid potential permission issues).
Steps:
Open PowerShell (Administrator):
Right-click on the PowerShell icon and select "Run as administrator."
Start VisualVM:
jvisualvm
This assumes jvisualvm.exe is in your system's PATH. If you get an error, you'll need to provide the full path to the executable within your JDK or VisualVM installation directory. For example:
"C:\Program Files\Java\jdk1.8.0_301\bin\jvisualvm.exe"
IGNORE_WHEN_COPYING_START
content_copy
download
Use code with caution.
Powershell
IGNORE_WHEN_COPYING_END
(Replace jdk1.8.0_301 with your actual JDK version). If you downloaded VisualVM separately, use the correct download path.
Install the BTrace Plugin in VisualVM:
In VisualVM, go to Tools > Plugins.
Click on the Available Plugins tab.
Look for the BTrace Workbench plugin.
Select the plugin and click Install.
Follow the on-screen instructions. Restart VisualVM if prompted.
Locate Your Target Java Process:
In VisualVM's left-hand sidebar, find the Java process you want to trace. It will be identified by its class name (e.g., TradeCast) or a custom application name.
Create a New BTrace Script:
Right-click on the target Java process in the left-hand sidebar.
Select BTrace > New BTrace Script. A new editor window will open.
Paste the BTrace Script:
Copy the corrected BTrace script (the one from the immediately preceding response that compiles without errors) and paste it into the editor window.
Run the BTrace Script:
Click the "Run" button (green play icon) in the BTrace script editor.
Observe the Output:
A new "BTrace Output" tab will appear in VisualVM. The tracing output from your script will be displayed there.
Post a Comment