Сегодняшний пост о
BTrace, который я рассматриваю как скрытое сокровище для разработчика Java.
BTrace — безопасный, динамический инструмент трассировки для платформы Java. BTrace можно использовать для динамического отслеживания работающей программы Java (аналогично DTrace для приложений и ОС OpenSolaris).
Вкратце, инструмент позволяет вводить точки трассировки без перезапуска или перенастройки приложения Java во время его работы. Более того, хотя есть несколько способов сделать это, один из которых я хотел бы обсудить сегодня, это использовать инструмент JVisualVM из стандартного комплекта JDK.
Что очень круто, BTrace сам использует язык Java для определения точек трассировки инъекций. Подход выглядит очень знакомым, если вы когда-либо занимались аспектно-ориентированным программированием (AOP).
Итак, давайте начнем с проблемы: у нас есть приложение, которое использует одну из баз данных NoSQL (например, пусть это будет MongoDB) и внезапно начинает испытывать значительное снижение производительности. Разработчики подозревают, что приложение запускает слишком много запросов или обновлений, но не могут сказать это с уверенностью. Здесь BTrace может помочь.
Прежде всего, давайте запустим JVisualVM и установим плагин BTrace:
JVisualVM должен быть перезапущен для появления плагина. Теперь, когда наше приложение запущено, давайте щёлкнем по нему правой кнопкой мыши в дереве приложений JVisualVM :
Должен появиться следующий очень интуитивный редактор BTrace (с простой панелью инструментов):
Это место, где инструменты трассировки могут быть определены и динамически внедрены в работающее приложение. BTrace имеет очень богатую модель для того, чтобы определить, что именно следует отслеживать: методы, конструкторы, возвраты методов, ошибки, …. Также он поддерживает агрегаты из коробки, поэтому довольно просто собрать набор метрик, пока приложение Бег. Для нашей проблемы мы хотели бы увидеть, какие методы, связанные с MongoDB, выполняются.
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:
import com.sun.btrace.*;
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;
@BTrace
public 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!