Friday, October 31, 2014

Gem of Java: BTrace; Debugging production code on the fly

But the question is now how do u debug? Generally the loggers we kept are in-sufficient or in production they disabled debug, info levels of log4j; now how? or say we forgot logging a variable.. now how to debug the issue?

wouldnt it be nice if i have an agent sitting outside the main JVM and printing out the variable i wanted? is it possible? the answer is YES!!!

BTrace is the gem in Java-s Crown. So it works like this

  1. The original JVM runs on some PID
  2. The Btrace program runs outside and connects to this pid; printing ur variable as u wanted
You need to download the BTrace package; Create a java program; Typically it looks as follows

package my;

import services.reports.ReportContext;

import com.insideview.industryProfiles.IndustryProfile;
import com.insideview.industryProfiles.IndustrySic;
import com.sun.btrace.BTraceUtils;
import com.sun.btrace.annotations.BTrace;
import com.sun.btrace.annotations.Kind;
import com.sun.btrace.annotations.Location;
import com.sun.btrace.annotations.OnMethod;
import com.sun.btrace.annotations.Return;

public class Tracer {
        @OnMethod( clazz="",  method="appendSection", location=@Location(Kind.RETURN))
        public static void operate(@Return ReportContext rc  ){
         IndustryProfile industryProfile = (IndustryProfile) (rc.get("industryProfile"));
         IndustrySic sic = industryProfile.getSic();

If u see the highlighted area; they are the custom objects in the JVM running; now this program will print them when ever the method: CompanyIndustryProfile.appendSection() is hit injecting the return variable (i.e.. @Return)

In the dowloaded package, open the btrace file located in bin folder and in the end change to the below. The line is to the end of the file


it will be initially set to false; Now run the command; below is the sample output.

[jboss@iv build]$ ../bin/btrace -cp "btrace-agent.jar:btrace-boot.jar:btrace-client.jar:velocity-1.7-dep.jar:company.jar" 26009

DEBUG: btrace debug mode is set
DEBUG: btrace unsafe mode is set
DEBUG: accepting classpath btrace-agent.jar:btrace-boot.jar:btrace-client.jar:velocity-1.7-dep.jar:commpany.jar
DEBUG: assuming default port 2020
DEBUG: compiling
DEBUG: compiled
DEBUG: attaching to 8995
DEBUG: checking port availability: 2020
DEBUG: attached to 8995
DEBUG: loading /tmp/btrace/build/btrace-agent.jar
DEBUG: agent args: port=2020,debug=true,unsafe=true,systemClassPath=/usr/jdk1.6.0_29/lib/tools.jar,probeDescPath=.
DEBUG: loaded /tmp/btrace/build/btrace-agent.jar
DEBUG: registering shutdown hook
DEBUG: registering signal handler for SIGINT
DEBUG: submitting the BTrace program
DEBUG: opening socket to 2020
DEBUG: sending instrument command
DEBUG: entering into command loop
DEBUG: received com.sun.btrace.comm.OkayCommand@566711b0
DEBUG: received com.sun.btrace.comm.RetransformationStartNotification@8ba6621
DEBUG: received com.sun.btrace.comm.OkayCommand@5870501
DEBUG: received com.sun.btrace.comm.MessageCommand@2e2b5ba8
{industryDescription=null, industryId=564,abc=xyx,etc=etc], sizeStructureDescription=etc_etc}
DEBUG: received com.sun.btrace.comm.MessageCommand@26284112

DEBUG: received com.sun.btrace.comm.MessageCommand@1cc81850
$$$$$$$$$$$DEBUG: received com.sun.btrace.comm.MessageCommand@14b43af3
{id=7375, description=CBI Services, }

Issues to lookout
  1. If u havent changed btrace file, ran the above process and then modifed the unsafe to true on running the btrace u see VerificationError.
  2. As said here it happens because the 1st run made the target JVM to mark any unsafe to false
  3. for this u will have to restart the target m/c


  1. Hello man, hope you see this ! When i run my dbtrace it will hang on DEBUG: checking port availability: 2020 forever. Any idea what might cause this ? Thanks

  2. this shouldnt happen. Make sure you are able to connect to the port via telnet --ensuring the port is open for the connection first