Практическое применение DTrace

Вглубь Java

Мы уже знаем, что с помощью DTrace можно выяснить, какие конкретно функции вызываются, в каком порядке, какие аргументы передаются и сколько времени потрачено на их выполнение. Все это могло вдохновить системных администраторов и разработчиков на языках С и С++, а интересы программистов на Java оставались в стороне. В этой статье мы рассмотрим, как можно использовать DTrace для отладки приложений на Java.

Для предоставления такой возможности Sun Microsystems встроила в код JVM (начиная с JDK 6.0) датчики двух провайдеров – hotspot и hotspot_jni. В JDK 5.0 был провайдер dvm. Для тех, кто привык им пользоваться, есть хорошая новость – датчики провайдера hotspot носят такие же имена, как и датчики провайдера dvm.

Провайдер hotspot имеет ряд датчиков, с помощью которых можно отслеживать запуск и работу сборщика мусора в JVM (garbage collector). Если количество запусков сборщика мусора растет (особенно, если быстро растет) во время работы приложения или время работы постоянно увеличивается – это верный признак утечки памяти в приложении.

Провайдер hotspot_jni требуется для отслеживания событий, связанных с обращениями через JNI (Java native interface – интерфейс Java с машинным кодом, т.е. ранее написанными и скомпилированными методами, реализованными на языке С). Строго говоря, это может быть программа не только на языке С, ибо JNI описывает интерфейс между программой на Java и машинным кодом, и в нем не указано, компилятор с какого языка должен создать этот код.

Уже было упомянуто, что провайдеры hotspot и hotspot_jni основаны на провайдере sdt и на их датчики можно ссылаться только с упоминанием идентификатора процесса самой машины Java (JVM). Вот пример скрипта, который показывает частоту вызова GC:

hotspot$target:::gc-begin
{
printf("GC called at %Y\n", walltimestamp);
}

Если запустить выполнение программы на java, скажем, демонстрационный пример /usr/jdk/instances/jdk1.6.0/demo/jfc/Java2D/Java2Demo.jar, а затем этот скрипт, то он покажет, в какие моменты запускался сборщик мусора:

# java -jar /usr/jdk/instances/jdk1.6.0/demo/jfc/Java2D/Java2Demo.jar &
[1] 1147
# dtrace -qn 'hotspot$target:::gc-begin
{
printf("GC called at %Y\n", walltimestamp);
}' -p 1147
GC called at 2008 Feb 7 01:50:15
GC called at 2008 Feb 7 01:50:16
GC called at 2008 Feb 7 01:50:17
GC called at 2008 Feb 7 01:50:18
GC called at 2008 Feb 7 01:50:19
GC called at 2008 Feb 7 01:50:20
GC called at 2008 Feb 7 01:50:21
GC called at 2008 Feb 7 01:50:25

А что, если нам надо выяснить, какие методы вызываются в приложении Java? Возьмем вот такое приложение:

# cat Greeting.java
public class Greeting {
public void greet() {
System.out.println("Hello DTrace!");
}
}
# cat TestGreeting.java
public class TestGreeting {
public static void main(String[] args) {
Greeting hello = new Greeting();
while (true) {
hello.greet();
try {
Thread.currentThread().sleep(1000);
} catch (InterruptedException e) {
}
}
}
}

Скомпилируем его:

javac TestGreeting.java

Теперь надо запустить получившееся приложение (мирно лежащее в TestGreeting.class ). Однако прежде надо разобраться, как включать датчики в Java SE 6. По умолчанию в виртуальной машине Java доступен лишь небольшой набор датчиков – тех, которые практически не влияют на производительность. Эти датчики позволяют отследить не все события: сборку мусора, компиляцию методов, создание нового потока команд и загрузку класса.

Вызов метода, например, в этот список не входит, потому что соответствующий датчик оказывает значимое влияние на производительность и оттого по умолчанию недоступен. К таким датчикам, кроме датчиков вызова методов, также относятся датчики создания объектов и датчики событий, связанных с мониторами Java. Чтобы сделать такой датчик доступным и "видимым" для dtrace, надо запускать java с ключами, разрешающими использование этих датчиков, или (если JVM уже запущена) использовать команду jinfo для управления JVM.

Доступны следующие ключи при запуске java:

-XX:+DTraceAllocProbes
-XX:+DTraceMethodProbes
-XX:+DTraceMonitorProbes
-XX:+ExtendedDTraceProbes

Первые три ключа разрешают использование датчиков создания объектов, вызова методов и датчиков событий, связанных с мониторами Java соответственно, а четвертый разрешает использование всех датчиков в JVM. Фактическое влияние включенных датчиков на производительность может быть различным в зависимости от частоты вызова кода, содержащего встроенный датчик.

Запускаем наше приложение:

# java -XX:+ExtendedDTraceProbes TestGreeting &
[1] 1448
Hello DTrace!
Hello DTrace!
Hello DTrace!
Hello DTrace!

Возьмем скрипт hs.d, вот такой:

# cat hs.d
hotspot$target:::method-entry
{
printf("%s.\%s %s\n",copyinstr(arg1,arg2),copyinstr(arg3,arg4),
copyinstr(arg5,arg6));
}
tick-5ms
{
exit(0);
}

Конструкция hotspot$target означает, что вместо $target будет подставлен аргумент, переданный с ключом p при запуске dtrace (это будет идентификатор процесса java).

Из описания датчиков провайдера hotspot (http://java.sun.com/ javase/6/docs/technotes/guides/vm/dtrace.html) известно, что аргументы датчика method-entry следующие:

Сигнатура метода – это совокупность имени функции, типа возвращаемого значения и списка аргументов с указанием порядка их следования и типов. Подробнее об обозначениях, применяемых в сигнатурах, можно прочесть, например, в разделе Type Signatures в спецификации JNI, размещенной по адресу http://java.sun.com/j2se/1.3/docs/guide/jni/spec/types.doc.html.

Наш скрипт должен при каждом срабатывании датчика methodentry, т.е. при каждом вызове любого метода в нашем приложении на Java, выводить имя класса, имя метода и подпись. Обратите внимание на использование функции copyinstr для вывода строк.

Для автоматического завершения скрипта через 5 миллисекунд добавлена конструкция tick-5ms.

Запустим скрипт в соседнем окне терминала:

# dtrace -qs hs.d -p 1448
Greeting.\greet ()V
java/io/PrintStream.\println (Ljava/lang/String;)V
java/io/PrintStream.\print (Ljava/lang/String;)V
java/io/PrintStream.\write (Ljava/lang/String;)V
java/io/PrintStream.\ensureOpen ()V
java/io/Writer.\write (Ljava/lang/String;)V
java/io/BufferedWriter.\write (Ljava/lang/String;II)V
java/io/BufferedWriter.\ensureOpen ()V
java/io/BufferedWriter.\min (II)I
java/lang/String.\getChars (II[CI)V
java/lang/System.\arraycopy (Ljava/lang/Object;ILjava/lang/Object;II)V
java/io/BufferedWriter.\flushBuffer ()V
java/io/BufferedWriter.\ensureOpen ()V
java/io/OutputStreamWriter.\write ([CII)V
sun/nio/cs/StreamEncoder.\write ([CII)V
sun/nio/cs/StreamEncoder.\ensureOpen ()V
sun/nio/cs/StreamEncoder.\implWrite ([CII)V
java/nio/CharBuffer.\wrap ([CII)Ljava/nio/CharBuffer;
java/nio/HeapCharBuffer.\<init> ([CII)V
java/nio/CharBuffer.\<init> (IIII[CI)V
java/nio/Buffer.\<init> (IIII)V
java/lang/Object.\<init> ()V