DTrace и Mac OS X
Аннотация
Когда я работал над очередной версией приложения Tasks Explorer, мне было необходимо получить информацию о запуске приложений в реальном времени. Эту информацию можно было получить разными способами, но самым простым было использование фрэймворка DTrace.
Осознав, насколько DTrace может облегчить жизнь разработчикам ПО, я решил написать эту статью. В ней рассматриваются возможности приложения DTrace при его использовании в Mac OS X, начиная от архитектуры фрэймворка, заканчивая написанием D скриптов и использованием библиотеки libdtrace.
Введение
Основной целью статьи является детальное рассмотрение DTrace, начиная его архитектурой и заканчивая разработкой скриптов и использованием библиотеки libdtrace. Представленные в статье скрипты могут использоваться для оптимизации и сбора информации о запущенных приложения в реальном времени. Все приведенные примеры протестированы под Mac OS X 10.6.
Что такое DTrace?
Я уверен, что большинство Mac OS X разработчиков не раз использовало приложение Instruments для оптимизации разработываемого ПО. Тем не менее, мало кто слышал про DTrace, хотя именно этот фрэймворк является ядром приложения Instruments.
DTrace — это фрэймворк для динамических трассировок, встроенный в ядро Mac OS X. Этот фрэймворк был разработан Sun Microsystems для операционной системы Solaris и позже выпущен под свободной лицензией CCDL. На данный момент DTrace портирован на FreeBSD 7.1 (в качестве замены для ktrace), Mac OS X 10.5, и сейчас идут работы по обеспечению поддержки QNX.
В отличие от дебаггера (например GDB), использование DTrace безопасно по отношению к результирующей системе и не требует перезапуска системы либо приложения. Также DTrace может быть полезен для поиска сложновоспроизводимых ошибок, таких как гонки и реверс инжиниринга.
Архитектура DTrace
Фрэймворк DTrace состоит из 4-х частей:
- фронт-энда (обычно это приложение dtrace либо Instruments),
- библиотеки libdtrace,
- фрэймворка DTrace уровня ядра,
- DTrace провайдеров.
Типичным Mac OS X фронт-эндом для фрэймворка DTrace является приложение Instruments и утилита dtrace. Эти приложения используют библиотеку libdtrace для получения информации от DTrace провайдеров. Также провайдером могут выступать другие пользовательские приложения, которые были написаны с использованием библиотеки libdtrace.
Библиотека libdtrace предоставляет интерфейсы для доступа к DTrace фрэймворку уровня ядра и компилирует код на языке D в формат DIF (Dtrace Intermediate Format — RISC-подобный набор инструкций). Взаимодействие между пользовательским уровнем и уровнем ядра осуществляется при помощи вызовов ioctl и псевдоустройства dtrace.
Фрэймворк DTrace уровня ядра выполняет DIF код и управляет набором DTrace провайдеров. В свою очередь, DTrace провайдеры отвечают за создание датчиков посредством инструментирования различных частей системы.
Датчики — это расположение (например, функция) либо активность, которые отслеживаются DTrace и могут быть использованны для ряда действий, таких как получение стека вызовов, штампа времени либо аргументов функции.
Описания интерфейсов взаимодействия между библиотекой libdtrace, фрэймворком DTrace уровня ядра и провайдерами можно найти в комментариях в файле <sys/dtrace.h>. Внутренная архитектура DTrace описана в комментариях в файле <sys/dtrace_impl.h>.
Язык D скрипт
Язык написания скриптов для DTrace D имеет Си-подобный синтаксис и используется для описания трассировок. Типичный скрипт на языке D состоит из директив компилятору, описания типов, предикат, переменных и описания датчиков. Каждое описание датчика включает в себя описание, предикаты и действия.
BEGIN
{
initialization
}
probe descriptions
/ predicates /
{
actions
}
END
{
termination
}
Когда скрипт D запускается на выполнение, все датчики активизируются и самым первым срабатывает датчик BEGIN. Действия, описываемые в датчиках, выполняются в том случае, если датчик сработал и предикат датчика имеет значение истина.
Датчики
Описание каждого из датчиков состоит из четырех полей, разделенных символом двоеточие.
provider:module:function:name
- Provider — уровень инструментирования. Например, вызов функции, статитика использования памяти, создание или завершение проекта и т.д.
- Module — инструментируемый модуль. Например libSystem, libc и т.д.
- Function — инструментируемая функция.
- Name — расположение датчика по отношению к функции. Напрмер enter, return, tick-Nsec.
Поле provider является обязательным; поля module, function и name опциональными. В именах можно использовать подстановки, такие как *, ? и […]. Например, следующий скрипт выводит информацию о вызовых функций write* для всех активных процессов.
syscall::write*:entry
{
printf("(%d):%s write call called", pid, execname);
}
Предикаты используются в качестве предусловий для определения необходимости выполенения действий датчика. Действия датчика будут всегда выполняться, если предиката отсутствует.
/pid == 12345/ /execname = "bash"/
Переменные
В языке D существует два типа переменных: скалярные переменные и ассоциативные массивы.
BEGIN
{
x = 100;
arr1["hello"] = 100;
arr2["hello", 10] = 100;
}
В приведенном примере x является скалярной переменной типа int. arr1 — переменная типа ассоциативный массив, содержащий значение 100 по ключу «hello». arr2 — переменная типа ассоциативный массив, содержащий значение 100 с использованием в качестве ключа кортеж со значением [«hello», 10]. Как видно из приведенного ранее примера, D, в отличие от C или Java, не требует явного определения типа переменной.
Кроме того, переменные можно разделить по типу хранения на глобальные, локальные-для-потока и локальные-для-датчика.
Локальные-для-потока переменные
Локальные-для-потока переменные используются в тех случаях, когда данные необходимо разделить по потокам приложения. Для доступа к локальным-для-потока переменным используется идентификатор self с оператором ->.
syscall::write*:entry
{
self->write = 1;
}
syscall::write*:return
/self->write == 1/
{
self->write = 0;
}
По окончании использования локальной-для-потока переменной она должна быть выставленна в 0, что позволит DTrace ее повторное использование.
Локальные-для-датчика переменные
Локальные-для-датчика переменные схожи по поведению с автоматическими переменными из C или C++. Доступ к локальным-для-датчика переменным осуществляется посредствам идентификатора this и оператора ->.
syscall::write*:entry
{
this->i = 10;
...
}
Локальные-для-датчика переменные будут автоматически переиспользованы при следующем вызове.
Структуры
Для упрощения скрипта на языке D переменные могут быть сгруппированы вместе в структуры. Синтаксис структур в D схож с синтаксисом C.
struct struct_name {
int a;
int b[string];
};
struct struct_name arr[string];
Переменная arr является ассоциативным массивом, содержащим стуктуры struct_name.
Макро переменные
Компилятор D предоставляет набор заранее определенных макро переменных, которые могут быть использованны в скриптах. Макро переменные начинаются с символа $ и разворачиваются компилятором D в процессе обработке скрипта.
Список наиболее часто используемых макро переменных:
- $1 — первый дополнительный операнд в командной строке.
- $pid — ID процесса dtrace.
- $target — ID процесса, указанного посредствам ключа -p либо запущенного посредствам ключа -c.
pid$target:::entry
{
@[probefunc] = count();
}
... matchString 9217 malloc_zone_malloc 9712 szone_malloc 9712 szone_malloc_should_clear 9743 memmove 10324 tiny_free_list_add_ptr 10522 object_getClass 11244 __CFStringHash 13019 CFHash 13095 ___CFBasicHashFindBucket1 13748 CFAllocatorDeallocate 13923 _CFRetain 15354 CFRetain 15372 __CFStringEqual 15861 ...
Приведенный пример демонстрирует использование макро переменной $target. Скрипт может использоваться для определения списка наиболее часто вызываемых функций.
Агрегации
Агрегации используются для сбора выводимой информации в виде таблиц с последующим выводом информации. Агрегации имеют следующий синтаксис:
@name[ keys ] = aggfunc ( args );
Переменные, используемые для агрегирования, имеют специальный префикс @. Переменные, используемые для агрегирования, не могут быть локальными-для-датчика либо локальными-для-потока переменными. DTrace выводит агрегированную информацию по завершении приложения либо по нажатии пользователем Control-C.
count
Функция count возвращает количество вызовов функции. Пример скрипта, выводящего список вызовов с информацией о том, как часто была вызванна та или иная функция:
pid$1:::entry
{
@[strjoin(strjoin(probemod,"`"), probefunc)]=count();
}
.... CoreFoundation`CFBasicHashApply 14 CoreFoundation`CFDictionaryApplyFunction
avg
Функция avg возвращает среднеарифметическое для выражения. Пример скрипта, выводящего среднее время, потраченное на вызов каждой из функций, в микросекундах:
pid$1:::entry
{
self->timestamp = timestamp;
}
pid$1:::return
/self->timestamp/
{
@[strjoin(strjoin(probemod,"`"), probefunc)] = avg((timestamp - self->timestamp) / 1000);
self->timestamp = 0;
}
... tasksexplorerd`build_killed_array 14 CoreFoundation`CFDictionaryGetCount 15 libSystem.B.dylib`get_input_bytes 15 libSystem.B.dylib`pid_for_task 15 libSystem.B.dylib`xdrrec_endofrecord 15 libSystem.B.dylib`xdrrec_skiprecord 15 libSystem.B.dylib`OSSpinLockUnlock 16 libSystem.B.dylib`mig_get_reply_port 16 libSystem.B.dylib`xdr_void 16 libSystem.B.dylib`read$NOCANCEL 17 libSystem.B.dylib`szo
normalize и trunc
Функции normalize и trunc используются для модификации агрегированной информации. Функция trunk возвращает первые X записей для агрегированного результата. В приведенном ниже примере она используется для получения 10 первых записей. Функция normalize устанавливает фактор нормализации для всей агрегированной информации, в приведенном ниже коде эта функция используется для представления времени в микросекундах.
pid$1:::entry
{
self->timestamp = timestamp;
}
pid$1:::return
/self->timestamp/
{
@result[strjoin(strjoin(probemod,"`"), probefunc)] = avg(timestamp - self->timestamp);
self->timestamp = 0;
}
END
{
normalize(@result, 1000);
trunc(@result, 10);
}
libSystem.B.dylib`t
Провайдеры
syscall
Провайдер syscall позволяет получить информацию обо всех системных вызовах. Данный провайдер предоставляет пары датчиков для каждого из вызовов: entry и return. Следующий скрипт отображает стек вызовов для всех системных вызовов приложения.
syscall:::entry
/pid == $target/
{
@result[ustack()] = count();
}
... libSystem.B.dylib`__getdirentries64+0xa libSystem.B.dylib`readdir$INODE64+0x43 CoreFoundation`_CFBundleCopyDi
objc
Провайдер objc предоставляет информацию о Objective-C сообщениях. Например, данный провайдер позволяет создать скрипт для сбора информации о 10 наиболее часто посылаемых Objective-C сообщениях и отобразить стек вызовов.
objc$target:ProcessInfo::entry
{
@result[ustack()] = count();
}
END
{
trunc(@result, 10);
}
... Tasks Explorer`-[ProcessInfo pid] Tasks Explorer`-[TasksInfoManager updateInfo]+0x3e5 Foundation`__NSFireTimer+0x72 CoreFoundation`__CFRunLoopRun+0x1958 CoreFoundation`CFRun
io
Провайдер io позволяет создавать датчики для отслеживания дисковых операций ввода/вывода. Доступны 4 типа датчиков:
- start — срабатывает при появлении запроса ввода/вывода.
- done — срабатывает по завершении обработки запроса ввода/вывода.
- wait-start — срабатывает перед тем, как поток начинает ожидать отложенную операцию ввода/вывода.
- wait-done — срабатывает, когда поток завершает ожидание отложенной операции ввода/вывода.
Данные датчики принимают 3 аргумента: struct buf* as arg[0], devinfo_t* as arg[1] and fileinfo_t* as arg[2].
typedef struct bufinfo
{
int b_flags; /* flags */
size_t b_bcount; /* number of bytes */
caddr_t b_addr; /* buffer address */
uint64_t b_blkno; /* expanded block # on device */
uint64_t b_lblkno; /* block # on device */
size_t b_resid; /* # of bytes not transferred */
size_t b_bufsize; /* size of allocated buffer */
caddr_t b_iodone; /* I/O completion routine */
dev_t b_edev; /* extended device */
} bufinfo_t;
typedef struct devinfo
{
int dev_major; /* major number */
int dev_minor; /* minor number */
int dev_instance; /* instance number */
string dev_name; /* name of device */
string dev_statname; /* name of device + instance/minor */
string dev_pathname; /* pathname of device */
} devinfo_t;
typedef struct fileinfo
{
string fi_name; /* name (basename of fi_pathname) */
string fi_dirname; /* directory (dirname of fi_pathname) */
string fi_pathname; /* full pathname */
offset_t fi_offset; /* offset within file */
string fi_fs; /* filesystem */
string fi_mount; /* mount point of file system */
} fileinfo_t;
Рассморим скрипт, собирающий информацию об операциях ввода/вываода и выводящий имя файла, с кототорым происходит операция, имя приложения, PID приложения и тип операции (чтение/запись).
#pragma D option quiet
BEGIN
{
printf("%30s %20s %2sn", "FILE NAME", "APP NAME(PID)", "RW");
}
io:::start
{
printf("%30s%15s(%5d)%2sn", args[2]->fi_name, execname, pid, args[0]->b_flags & B_READ ? "R" : "W");
}
FILE NAME APP NAME(PID) RW
test.d TextMate( 562) W
.dat088c.005 quicklookd( 2188) W
index.sqlite-journal quicklookd( 2188) W
index.sqlite-journal quicklookd( 2188) W
index.sqlite quicklookd( 2188) W
index.sqlite quicklookd( 2188) W
thumbnails.data quicklookd( 2188) W
thumbnails.data quicklookd( 2188) W
pid
Провайдер pid очень похож на провайдер objc и предоставляет схожий функционал. Этот провайдер позволяет собирать информацию о вызовах функций пользователя. Например, известно, что в приложении есть функция task_explorer_update_1_svc и необходимо построить стек вызовов. Приведенный ниже скрип реализует данный функционал.
pid$target::task_explor
1 -> task_explorer_update_1_svc 1 | task_explorer_update_1_svc:1 1 | task_explorer_update_1_svc:4 1 | task_explorer_update_1_svc:6 1 -> task_info_manager_update 1 | task_info_manager_update:0 1 -> KeysHashFunc 1 | KeysHashFunc:0 1 <- KeysHashFunc ...
proc
Провайдер proc создает датчики, срабатывающие при создании либо завершении потоков или процессов. Приведенный ниже скрипт позволяет получить список процессов, запущенных приложением с заданным PID. В выводе показан список процессов, запущенных XCode в процессе сборки проекта, так же указанно сколько раз тот или иной процесс был запущен.
proc:::exec-success
/ppid == $target/
{
@[execname] = count();
}
touch 1 bash 2 sh 2 gcc-4.2 31 xcexec 33
Из вывода следующиего скрипта видно, что среднее время выполнения приложения gcc колеблется между 1/4 и 1/2 секунды для 14 запусков и 1/2 и 1 секундой для 13 запусков.
proc:::start
/ppid == $target/
{
self->start = timestamp;
}
proc:::exit
/self->start/
{
@[execname] = quantize((timestamp - self->start) / 1000000);
self->start = 0;
}
gcc-4.2
value --- Distribution --- count
32 | 0
64 |@@@ 2
128 |@ 1
256 |@@@@@@@@@@@@@@@@@@ 14
512 |@@@@@@@@@@@@@@@@@ 13
1024 | 0
2048 |@ 1
4096 | 0
Использование библиотеки libdtraсe
Библиотека libdtrace предоставляет следующие интерфейсы:
- dtrace_open — инициализация фрэймворка DTrace.
- dtrace_program_strcompile, dtrace_program_fcompile — функции, используемые для компилирования D скрипта.
- dtrace_handle_* — используется для регистрации пользовательских функций в качестве call-back функций для получения информации о событиях DTrace фрэймворка.
- dtrace_program_exec — активизирует пробы и инструментирует систему.
- dtrace_setopt — позволяет установить дополнительные параметры для фрэймворка.
- dtrace_go — запускает D скрипт на выполнение.
- dtrace_sleep — ожидает появления новых данных.
- dtrace_work — анализирует полученные данные и возвращает результат посредствам call-back функций либо прямой записи в файл. Если второй параметр функции FILE* не равен NULL, call-back функции, зарегистрированные при помощи dtrace_handle_buffered, не вызываются, а собранная информация выводится при помощи переданного дескриптора в файл.
- dtrace_aggregate_print — вызывает переданные call-back функции с результатми агрегации. Обычно это последний вызов в жизненном цикле DTrace клиента.
Жизненный цикл DTrace клиента:
Функции chew, chewrec и dcmdbuffered являются не функциями библиотеки libdtrace, а пользовательскими call-back функциями.
#include "dtrace.h"
#include "stdio.h"
#include "stdlib.h"
#include "mach/mach.h"
#include "mach-o/loader.h"
#include "mach-o/dyld.h"
#include "mach-o/fat.h"
#include "sys/sysctl.h"
#include "signal.h"
static dtrace_hdl_t *g_dtp;
static int g_intr;
static const char *g_prog =
//"tick-1s"
//"{"
//" printf(\"Found %s on CPU %d\\n\",execname,cpu);"
//"}";
//"proc:::exec-success"
//"{"
//" printf(\"%d\\n\", pid);"
//"}";
"syscall::write:entry"
"{"
" @counts[\"write calls count\", execname] = count();"
"}";
static int dcmdbuffered(const dtrace_bufdata_t *bufdata, void *arg)
{
printf("Print buffer:: %s", bufdata->dtbda_buffered);
return(DTRACE_HANDLE_OK);
}
static void dprog_compile(void)
{
int err;
dtrace_prog_t *prog;
dtrace_proginfo_t info;
if ((g_dtp = dtrace_open(DTRACE_VERSION, DTRACE_O_ILP32, &err)) == NULL){
printf("failed to initialize dtrace: %s\n",
dtrace_errmsg(NULL, err));
exit(1);
}
if ((prog = dtrace_program_strcompile(g_dtp, g_prog, DTRACE_PROBESPEC_NAME, 0, 0, NULL)) == NULL){
printf("failed to compile program");
exit(1);
}
if (dtrace_handle_buffered(g_dtp, dcmdbuffered, NULL) == -1) {
printf("Couldn't add buffered handler");
exit(1);
}
if (dtrace_program_exec(g_dtp, prog, &info) == -1){
printf("failed to enable probes");
exit(1);
}
}
static void dprog_setopts(void)
{
(void) dtrace_setopt(g_dtp, "strsize", "32");
(void) dtrace_setopt(g_dtp, "bufsize", "4m");
(void) dtrace_setopt(g_dtp, "aggsize", "256k");
(void) dtrace_setopt(g_dtp, "stacksymbols", "enabled");
(void) dtrace_setopt(g_dtp, "arch", "x86_64");
(void) dtrace_setopt(g_dtp, "aggsortrev", NULL);
(void) dtrace_setopt(g_dtp, "aggrate", "1sec");
}
static int chew(const dtrace_probedata_t *data, void *arg)
{
dtrace_probedesc_t *pd = data->dtpda_pdesc;
processorid_t cpu = data->dtpda_cpu;
char name[DTRACE_FUNCNAMELEN + DTRACE_NAMELEN + 2];
(void) snprintf(name, sizeof (name), "%s:%s",
pd->dtpd_func, pd->dtpd_name);
printf("%3d %6d %32s ", cpu, pd->dtpd_id, name);
return (DTRACE_CONSUME_THIS);
}
static int chewrec(const dtrace_probedata_t *data, const dtrace_recdesc_t *rec, void *arg)
{
if (rec == NULL) {
printf("\n");
return (DTRACE_CONSUME_NEXT);
}
return (DTRACE_CONSUME_THIS);
}
static void intr(int signo)
{
g_intr = 1;
}
int main(int argc, char **argv)
{
int done=0;
struct sigaction act;
dprog_compile();
dprog_setopts();
if (dtrace_go(g_dtp) != 0){
printf("Error in dtrace_go()n");
exit(1);
}
(void) sigemptyset(&act.sa_mask);
act.sa_flags = 0;
act.sa_handler = intr;
(void) sigaction(SIGINT, &act, NULL);
(void) sigaction(SIGTERM, &act, NULL);
do {
if (!g_intr && !done)
dtrace_sleep(g_dtp);
if (done || g_intr) {
done = 1;
if (dtrace_stop(g_dtp) == -1)
printf("couldn't stop tracing");
}
switch (dtrace_work(g_dtp, stdout, chew, chewrec, NULL)) {
case DTRACE_WORKSTATUS_DONE:
done = 1;
break;
case DTRACE_WORKSTATUS_OKAY:
break;
default:
printf("processing aborted");
}
} while (!done);
dtrace_aggregate_print(g_dtp, stdout, NULL);
dtrace_close(g_dtp);
return(0);
}