Solaris DTrace
Это совсем-совсем черновик
DTrace
(дополненный текст отсюда: http://experience.openquality.ru/dtrace-use-cases/)
Подробная дока:
http://wikis.sun.com/display/DTrace/Documentation
Коротко о DTRACE
По сравнению с другими средствами сбора информации о системе и отладки приложений, DTrace обладает рядом уникальных свойств:
- накапливает информацию о системе, работающей под максимальной нагрузкой – с низкими накладными расходами на сбор информации;
- собирает любую информацию из любых уголков системы, позволяя наблюдать как за работой приложений, так и за работой самого ядра системы;
- может показать, какие аргументы передаются от одной функции к другой, независимо от того, доступен ли исходный код функций;
- собирает информацию о том, как долго исполняются вызываемые функции, какой процент времени занимает исполнение каждой из них, сколько раз каждая из них была вызвана;
- фильтрует информацию любым заданным образом – например, позволяет ограничить область наблюдения одним приложением, одним потоком команд, или определенной областью (скажем, измерять время выполнения только конкретного системного вызова, а об остальном не заботиться);
- может реагировать на определенные события (ввод-вывод, вызов заданных функций, завершение программы, запуск нового потока и пр.);
- имеет как средства низкоуровнего наблюдения (можно изучать ход работы драйвера устройства), так и средства высокоуровневые, например, позволяет отслеживать определенные события при исполнении скриптов на PHP или вызов методов в приложении, написанном на Java;
- позволяет выполнять трассировку вызовов, с одновременным отслеживанием любых параметров – времени выполнения, переданных аргументов и пр.
Короткая подсказка
Все пояснения - ниже, это просто короткая подсказка наиболее употребимых конструкций. Список всех проб (очень удобно)
dtrace -n 'fbt:::entry { @[probefunc] = count(); }' -c 'ping host' frequency count grep foo /opt/DTT/Bin/* DTraceToolkit Probe Arguments syscall::: man syscallname fbt::: Kernel source
Probes BEGIN program start END program end tick-1sec run once per sec, one CPU only syscall::read*:entry process reads syscall::write*:entry process writes syscall::open*:entry file open proc:::exec-success process create io:::start,io:::done disk or NFS I/O request lockstat:::adaptive-block blocked thread acquired kernel mutex sysinfo:::xcalls cross calls sched:::off-cpu thread leaves CPU fbt:::entry entire kernel profile-123 sample at 123Hz perl*::: Perl provider probes javascript*::: JavaScript provider probes Vars execname on-CPU process name pid, tid on-CPU PID, Thread ID cpu CPU ID timestamp time, nanoseconds vtimestamp time thread was on-CPU, ns arg0...N probe args (uint64) args[0]...[N] probe args (typed) curthread pointer to current thread probemod module name probefunc function name probename probe name self->foo thread-local this->foo clause-local $1...$N CLI args, int $$1...$$N CLI args, str $target -p PID, -c command curpsinfo procfs style process statistics
Структура программы на языке D
Each probe clause has the general form:
probe descriptions
/ predicate /
{
action statements
}
или, если по-русски:
провайдер:модуль:функция:датчик
/условие/
{
действия
}
Провайдер – это модуль ядра или модуль приложения, обеспечивающий регистрацию своих датчиков DTrace в системе. Например, провайдер syscall регистрирует датчики, расположенные в системных вызовах, провайдер mysql – датчики, встроенные в сервер MySQL.
Модуль – это название модуля или библиотеки, например, libc.
Функция – имя функции, датчик в которой нам интересен, например, fopen.
Датчик – название датчика (во многих случаях датчик называется entry или return).
Условие задает ситуацию, когда следует выполнить действие при срабатывании датчика. Например, надо выполнить его только тогда, когда датчик сработал в приложении top. Тогда условие выглядит так:
/execname == top/
Действия – это то, что обеспечивает сбор информации и вывод ее на экран. Из примеров ниже будет ясно, какими они бывают.
Например:
syscall::read:entry
/ execname == "ssh"/
{
printf ("%s: read (%i, %p, %i)\n",
execname , arg0 , arg1 , arg2 );
}
скрипт выше означает: при вызове syscall::read:entry програмой ssh выполнить
printf ("%s: read (%i, %p, %i)\n", execname , arg0 , arg1 , arg2 );
Проба
syscall::read:entry
означает - в провайдере syscall, все модули, системные вызовы read (об этом чуть ниже)
Еще пример:
dtrace -qn 'syscall::exec*:return /execname == "ls" / { printf("%Y %s\n",walltimestamp,curpsinfo->pr_psargs); }'
Эта комманда будет мониторить все вызовы (syscall::exec*:return) программы ls (/execname == "ls" /). Соответвенно, если убрать /execname == "ls" / то мониториться будут все вызовы.
Встроенные переменные
Для понимания того что именно выводит printf полезно знать встроенные переменные. Ниже я приведу список переменных и примеры
использования.
Подробнее о переменных - тут: http://wikis.sun.com/display/DTrace/Variables
Type and Name Description int64_t arg0, ..., arg9 Первые 10 аргументов (int 64) If fewer than ten arguments are passed to the current probe, the remaining variables return zero.
args[] The typed arguments to the current probe, if any. The args[] array is accessed using an integer index, but each element is defined to be the type corresponding to the given probe argument. For example, if args[] is referenced by a read(2) system call probe, args[0] is of type int, args[1] is of type void *, and args[2] is of type size_t. uintptr_t caller The program counter location of the current kernel thread at the time the probe fired. uintptr_t ucaller The program counter location of the current user thread at the time the probe fired. chipid_t chip The CPU chip identifier for the current physical chip. See Chapter 26, sched Provider for more information. processorid_t cpu The CPU identifier for the current CPU. See Chapter 26, sched Provider for more information. cpuinfo_t *curcpu The CPU information for the current CPU. See Chapter 26, sched Provider for more information. lwpsinfo_t *curlwpsinfo The lightweight process (LWP) state of the LWP associated with the current thread. This structure is described in further detail in theproc(4) man page. psinfo_t *curpsinfo The process state of the process associated with the current thread. This structure is described in further detail in the proc(4) man page. kthread_t *curthread The address of the operating system kernel's internal data structure for the current thread, the kthread_t. The kthread_t is defined in <sys/thread.h>. Refer to Solaris Internals for more information on this variable and other operating system data structures. string cwd The name of the current working directory of the process associated with the current thread. uint_t epid The enabled probe ID (EPID) for the current probe. This integer uniquely identifiers a particular probe that is enabled with a specific predicate and set of actions. int errno The error value returned by the last system call executed by this thread. string execname The name that was passed to exec(2) to execute the current process. gid_t gid The real group ID of the current process. uint_t id The probe ID for the current probe. This ID is the system-wide unique identifier for the probe as published by DTrace and listed in the output of dtrace -l. uint_t ipl The interrupt priority level (IPL) on the current CPU at probe firing time. Refer to Solaris Internals for more information on interrupt levels and interrupt handling in the Solaris operating system kernel. lgrp_id_t lgrp The latency group ID for the latency group of which the current CPU is a member. See Chapter 26, sched Provider for more information. pid_t pid The process ID of the current process. pid_t ppid The parent process ID of the current process. string probefunc The function name portion of the current probe's description. string probemod The module name portion of the current probe's description. string probename The name portion of the current probe's description. string probeprov The provider name portion of the current probe's description. psetid_t pset The processor set ID for the processor set containing the current CPU. See Chapter 26, sched Provider for more information. string root The name of the root directory of the process associated with the current thread. uint_t stackdepth The current thread's stack frame depth at probe firing time. id_t tid The thread ID of the current thread. For threads associated with user processes, this value is equal to the result of a call to pthread_self(3C). uint64_t timestamp The current value of a nanosecond timestamp counter. This counter increments from an arbitrary point in the past and should only be used for relative computations. uid_t uid The real user ID of the current process. uint64_t uregs[] The current thread's saved user-mode register values at probe firing time. Use of the uregs[] array is discussed in Chapter 33, User Process Tracing. uint64_t vtimestamp The current value of a nanosecond timestamp counter that is virtualized to the amount of time that the current thread has been running on a CPU, minus the time spent in DTrace predicates and actions. This counter increments from an arbitrary point in the past and should only be used for relative time computations. uint64_t walltimestamp The current number of nanoseconds since 00:00 Universal Coordinated Time, January 1, 1970.
Описание пробы/Probe Descriptions
Каждая проба описывается в формате:
provider:module:function:name
If one or more fields of the probe description are omitted, the specified fields are interpreted from right to left by the D compiler. For example, the probe description foo:bar would match a probe with function foo and name bar regardless of the value of the probe's provider and module fields. Therefore, a probe description is really more accurately viewed as a pattern that can be used to match one or more probes based on their names.
You should write your D probe descriptions specifying all four field delimiters so that you can specify the desired provider on the left-hand side. If you don't specify the provider, you might obtain unexpected results if multiple providers publish probes with the same name. Similarly, future versions of DTrace might include new providers whose probes unintentionally match your partially specified probe descriptions. You can specify a provider but match any of its probes by leaving any of the module, function, and name fields blank. For example, the description syscall::: can be used to match every probe published by the DTrace syscall provider.
Probe descriptions also support a pattern matching syntax similar to the shell globbing pattern matching syntax described in sh(1). Before matching a probe to a description, DTrace scans each description field for the characters *, ?, and [. If one of these characters appears in a probe description field and is not preceded by a \, the field is regarded as a pattern. The description pattern must match the entire corresponding field of a given probe. The complete probe description must match on every field in order to successfully match and enable a probe. A probe description field that is not a pattern must exactly match the corresponding field of the probe. A description field that is empty matches any probe.
The special characters in the following table are recognized in probe name patterns:
Probe Name Pattern Matching Characters Symbol Description * Matches any string, including the null string. ? Matches any single character. [ ... ] Matches any one of the enclosed characters. A pair of characters separated by - matches any character between the pair, inclusive. If the first character after the [ is !, any character not enclosed in the set is matched. \ Interpret the next character as itself, without any special meaning.
Pattern match characters can be used in any or all of the four fields of your probe descriptions. You can also use patterns to list matching probes by using the patterns on the command line with dtrace -l. For example, the command dtrace -l -f kmem_* lists all DTrace probes in functions whose names begin with the prefix kmem_.
If you want to specify the same predicate and actions for more than one probe description or description pattern, you can place the descriptions in a comma-separated list. For example, the following D program would trace a timestamp each time probes associated with entry to system calls containing the words “lwp” or “sock” fire:
syscall::*lwp*:entry, syscall::*sock*:entry
{
trace(timestamp);
}
A probe description may also specify a probe using its integer probe ID. For example, the clause:
12345
{
trace(timestamp);
}
could be used to enable probe ID 12345, as reported by dtrace -l -i 12345. You should always write your D programs using human-readable probe descriptions. Integer probe IDs are not guaranteed to remain consistent as DTrace provider kernel modules are loaded and unloaded or following a reboot.
Predicates
Predicates are expressions enclosed in slashes / / that are evaluated at probe firing time to determine whether the associated actions should be executed. Predicates are the primary conditional construct used for building more complex control flow in a D program. You can omit the predicate section of the probe clause entirely for any probe, in which case the actions are always executed when the probe fires.
Predicate expressions can use any of the previously described D operators and may refer to any D data objects such as variables and constants. The predicate expression must evaluate to a value of integer or pointer type so that it can be considered as true or false. As with all D expressions, a zero value is interpreted as false and any non-zero value is interpreted as true.
Actions
Probe actions are described by a list of statements separated by semicolons (;) and enclosed in braces { }. If you only want to note that a particular probe fired on a particular CPU without tracing any data or performing any additional actions, you can specify an empty set of braces with no statements inside.
Order of Execution
Each clause is represented by its predicate, if any, and the clause's actions. When an enabled probe fires, its actions will execute if the predicate evaluates to true or if no predicate is given. Program order determines the order in which actions are executed. Two or more clauses that enable the same probe will also execute in program order.
Еще редактировать тут
Cкрипт, выдающий количество функций, написать легко. В качестве затравки рассмотрим несколько вариантов, а затем перейдем к синтаксису скриптов. Например, вот такой скрипт выдает количество вызовов любых функций при работе программы ls (вначале на экран будет выдан результат ее работы, а потом – список функций с количеством вызовов для каждой в порядке возрастания):
А вот таким скриптом можно посчитать количество функций, вызванных конкретным процессом с PID=2355; для получения результата надо прервать выполнение скрипта с помощью Ctrl-C:
А вот так можно посчитать количество системных вызовов в том же процессе:
Итак, в скриптах на языке D всегда используется следующий синтаксис:
Простой пример того, как я использую DTrace в повседневной жизни: после переноса пользовательских настроек с одного компьютера на другой система на не захотела работать с принтером, как раньше. Было ясно, что какой-то из файлов настроек отчего-то не скопирован. Но какой именно? Их же сотни… Банальные /etc/printers и /etc/lp/* были проверены и разгадки не дали. Тогда пришлось задействовать DTrace. Простой скрипт дает возможность заглянуть в недра программы lpstat (наиболее безвредная программа из тех, что работает с принтером) и посмотреть, какие файлы она пытается открыть:
lpstat -s scheduler is running system default printer: eaqvap21 aqvap21: unknown printer aqvap21: unknown printer
Чтобы запустить программу и подсунуть ее PID скрипту на DTrace надо использовать ключ -c :
dtrace -n 'pid$target::fopen:entry {printf("%s",copyinstr(arg0));}' -c "lpstat -s"
dtrace: description 'pid$target::fopen:entry ' matched 1 probe
scheduler is running
system default printer: eaqvap21
aqvap21: unknown printer
aqvap21: unknown printer
dtrace: pid 11156 has exited
CPU ID FUNCTION:NAME
0 59882 fopen:entry /etc/default/init
0 59882 fopen:entry /etc/lp/ppd/eaqvap21.ppd
0 59882 fopen:entry /export/home/filip/.printers
0 59882 fopen:entry /export/home/filip/.printers
0 59882 fopen:entry /export/home/filip/.printers
0 59882 fopen:entry /etc/printers.conf
0 59882 fopen:entry /export/home/filip/.printers
0 59882 fopen:entry /etc/printers.conf
1 59882 fopen:entry /etc/nsswitch.conf
1 59882 fopen:entry /export/home/filip/.printers
1 59882 fopen:entry /export/home/filip/.printers
1 59882 fopen:entry /etc/printers.conf
Вот и все: я забыл, что надо почистить файл .printers в домашнем каталоге:
rm /export/home/filip/.printers
Замечание: подсовывать PID программы скрипту надо потому, что провайдер pid требует указания PID изучаемого с помощью DTrace процесса, а знакомый нам всем вызов fopen как раз относится к этому провайдеру DTrace.
Вообще, сбор информации о том, какие файлы открываются в системе, часто дает разгадку сисадмину. Поэтому иногда я использую и такую модификацию скрипта:
pfexec dtrace -n 'syscall::open*:entry {printf("%s\n",copyinstr(arg0));}'
Этот скрипт валит в кучу данные от всех системных вызовов, имена которых начинаются на open, что неудобно, но зато его легче всего вспомнить и проще всего применить к уже запущенным приложениям, а полученной информации может хватить для анализа.
Наконец, для тех, кто отлаживает веб-приложения, может пригодиться скрипт, который вылавливает SQL-операторы из сервера БД перед тем, как сервер их запустит. Это позволяет выяснить, какие именно операторы исполняются; такая информация поможет, если кажется, что скрипт, работающий с БД, все делает верно, а база данных возвращает неожиданный результат: может оказаться, что либо SQL-выражение формируется неверно, либо соединние происходит не с той базой данных, что надо, либо какой-то параметр передается СУБД без должного оформления (например, без кавычек или с лишними кавычками).
Вот этот скрипт: (не работает)
#!/usr/sbin/dtrace -s
#pragma D option quiet
dtrace:::BEGIN
{
printf("%-20s %-20s %-40s %-9s\n", "Who", "Database", "Query", "Time(ms)");
}
mysql*:::query-start
{
self->query = copyinstr(arg0);
self->connid = arg1;
self->db = copyinstr(arg2);
self->who = strjoin(copyinstr(arg3),strjoin("@",copyinstr(arg4)));
self->querystart = timestamp;
}
mysql*:::query-done
{
printf("%-20s %-20s %-40s %-9d\n",self->who,self->db,self->query,
(timestamp - self->querystart) / 1000000);
}
Запустив его, можно наблюдать картину работы сервера (осторожно! там может быть очень много информации, если сервер сильно нагружен запросами!):
$ pfexec ./mysql.d Who Database Query Time(ms) root@localhost data SELECT DATABASE() 0 root@localhost test show tables 0 root@localhost test SELECT DATABASE() 0 root@localhost mysql select * from users 0 root@localhost mysql select * from host 0
C помощью измерения времени между срабатываниями датчиков query-start и query-done вычисляется время исполнения SQL-оператора, и DTrace позволяет строить графики распределения времени исполнения по операторам. Так можно найти те обращения к базе данных, которые отнимают много времени при выполнении конкретных приложений. Большое преимущество DTrace в том, что все эти измерения можно производить в условиях реальной нагрузки на сервер, так как накладные расходы на работу самого DTrace минимальны и не будут мешать работе сервера.
Замечание: время выполнения запросов меньше 1 ms, а в скрипте выполняется целочисленное деление, поэтому результат получается 0. Можно считать в микросекундах, а не в миллисекундах, тогда будет какое-то небольшое значение.
Из приведенных примеров видно, что датчики DTrace расставлены в системе и приложениях Solaris повсюду. Изучить, какие аргументы, связанные с датчиками, можно использовать так, как показано выше, можно в документации по системе (man) и в документации по конкретным приложениям (например, по серверу MySQL на сайте mysql.com).
Значительно больше примеров скриптов для dtrace можно найти в следующих источниках:
- каталог /opt/DTT/ (Solaris)
- http://blogs.sun.com/brendan/category/DTrace
- http://www.brendangregg.com/DTrace/dtrace_oneliners.txt
Примеры
# dtrace_oneliners.txt - DTrace one liners. Handy commands.
#
# 25-Apr-2005, ver 0.70 (first release)
#
# Standard Disclaimer: This is freeware, use at your own risk.
#
# 25-Apr-2005 Brendan Gregg Created this.
#
# Contents
#
DTrace One Liners,
# New processes with arguments,
dtrace -n 'proc:::exec-success { trace(curpsinfo->pr_psargs); }'
# Files opened by process,
dtrace -n 'syscall::open*:entry { printf("%s %s",execname,copyinstr(arg0)); }'
# Syscall count by program,
dtrace -n 'syscall:::entry { @num[execname] = count(); }'
# Syscall count by syscall,
dtrace -n 'syscall:::entry { @num[probefunc] = count(); }'
# Syscall count by process,
dtrace -n 'syscall:::entry { @num[pid,execname] = count(); }'
# Read bytes by process,
dtrace -n 'sysinfo:::readch { @bytes[execname] = sum(arg0); }'
# Write bytes by process,
dtrace -n 'sysinfo:::writech { @bytes[execname] = sum(arg0); }'
# Read size distribution by process,
dtrace -n 'sysinfo:::readch { @dist[execname] = quantize(arg0); }'
# Write size distribution by process,
dtrace -n 'sysinfo:::writech { @dist[execname] = quantize(arg0); }'
# Disk size by process,
dtrace -n 'io:::start { printf("%d %s %d",pid,execname,args[0]->b_bcount); }'
# Pages paged in by process,
dtrace -n 'vminfo:::pgpgin { @pg[execname] = sum(arg0); }'
# Minor faults by process,
dtrace -n 'vminfo:::as_fault { @mem[execname] = sum(arg0); }'
# Interrupts by CPU,
dtrace -n 'sdt:::interrupt-start { @num[cpu] = count(); }'
DTrace Longer One Liners,
# New processes with arguments and time,
dtrace -qn 'syscall::exec*:return { printf("%Y %s\n",walltimestamp,curpsinfo->pr_psargs); }'
# Successful signal details,
dtrace -n 'proc:::signal-send /pid/ { printf("%s -%d %d",execname,args[2],args[1]->pr_pid); }'
#
# Examples
#
### New processes with arguments,
# dtrace -n 'proc:::exec-success { trace(curpsinfo->pr_psargs); }'
dtrace: description 'proc:::exec-success ' matched 1 probe
CPU ID FUNCTION:NAME
0 3297 exec_common:exec-success man ls
0 3297 exec_common:exec-success sh -c cd /usr/share/man; tbl /usr/share/man/man1/ls.1 |neqn /usr/share/lib/pub/
0 3297 exec_common:exec-success tbl /usr/share/man/man1/ls.1
0 3297 exec_common:exec-success neqn /usr/share/lib/pub/eqnchar -
0 3297 exec_common:exec-success nroff -u0 -Tlp -man -
0 3297 exec_common:exec-success col -x
0 3297 exec_common:exec-success sh -c trap '' 1 15; /usr/bin/mv -f /tmp/mpzIaOZF /usr/share/man/cat1/ls.1 2> /d
0 3297 exec_common:exec-success /usr/bin/mv -f /tmp/mpzIaOZF /usr/share/man/cat1/ls.1
0 3297 exec_common:exec-success sh -c more -s /tmp/mpzIaOZF
0 3297 exec_common:exec-success more -s /tmp/mpzIaOZF
### Files opened by process,
# dtrace -n 'syscall::open*:entry { printf("%s %s",execname,copyinstr(arg0)); }'
dtrace: description 'syscall::open*:entry ' matched 2 probes
CPU ID FUNCTION:NAME
0 14 open:entry gnome-netstatus- /dev/kstat
0 14 open:entry man /var/ld/ld.config
0 14 open:entry man /lib/libc.so.1
0 14 open:entry man /usr/share/man/man.cf
0 14 open:entry man /usr/share/man/windex
0 14 open:entry man /usr/share/man/man1/ls.1
0 14 open:entry man /usr/share/man/man1/ls.1
0 14 open:entry man /tmp/mpqea4RF
0 14 open:entry sh /var/ld/ld.config
0 14 open:entry sh /lib/libc.so.1
0 14 open:entry neqn /var/ld/ld.config
0 14 open:entry neqn /lib/libc.so.1
0 14 open:entry neqn /usr/share/lib/pub/eqnchar
0 14 open:entry tbl /var/ld/ld.config
0 14 open:entry tbl /lib/libc.so.1
0 14 open:entry tbl /usr/share/man/man1/ls.1
0 14 open:entry nroff /var/ld/ld.config
[...]
### Syscall count by program,
# dtrace -n 'syscall:::entry { @num[execname] = count(); }'
dtrace: description 'syscall:::entry ' matched 228 probes
^C
snmpd 1
utmpd 2
inetd 2
nscd 7
svc.startd 11
sendmail 31
poold 133
dtrace 1720
### Syscall count by syscall,
# dtrace -n 'syscall:::entry { @num[probefunc] = count(); }'
dtrace: description 'syscall:::entry ' matched 228 probes
^C
fstat 1
setcontext 1
lwp_park 1
schedctl 1
mmap 1
sigaction 2
pset 2
lwp_sigmask 2
gtime 3
sysconfig 3
write 4
brk 6
pollsys 7
p_online 558
ioctl 579
### Syscall count by process,
# dtrace -n 'syscall:::entry { @num[pid,execname] = count(); }'
dtrace: description 'syscall:::entry ' matched 228 probes
^C
1109 svc.startd 1
4588 svc.startd 2
7 svc.startd 2
3950 svc.startd 2
1626 nscd 2
870 svc.startd 2
82 nscd 6
5011 sendmail 10
6010 poold 74
8707 dtrace 1720
### Read bytes by process,
# dtrace -n 'sysinfo:::readch { @bytes[execname] = sum(arg0); }'
dtrace: description 'sysinfo:::readch ' matched 4 probes
^C
mozilla-bin 16
gnome-smproxy 64
metacity 64
dsdm 64
wnck-applet 64
xscreensaver 96
gnome-terminal 900
ttymon 5952
Xorg 17544
### Write bytes by process,
# dtrace -n 'sysinfo:::writech { @bytes[execname] = sum(arg0); }'
dtrace: description 'sysinfo:::writech ' matched 4 probes
^C
dtrace 1
gnome-settings-d 8
xscreensaver 8
gnome-panel 8
nautilus 8
date 29
wnck-applet 120
bash 210
mozilla-bin 1497
ls 1947
metacity 3172
Xorg 7424
gnome-terminal 51955
### Read size distribution by process,
# dtrace -n 'sysinfo:::readch { @dist[execname] = quantize(arg0); }'
dtrace: description 'sysinfo:::readch ' matched 4 probes
^C
[...]
gnome-terminal
value ------------- Distribution ------------- count
16 | 0
32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 15
64 |@@@ 1
128 | 0
Xorg
value ------------- Distribution ------------- count
-1 | 0
0 |@@@@@@@@@@@@@@@@@@@ 26
1 | 0
2 | 0
4 | 0
8 |@@@@ 6
16 |@ 2
32 |@ 2
64 | 0
128 |@@@@@@@@ 11
256 |@@@ 4
512 | 0
### Write size distribution by process,
# dtrace -n 'sysinfo:::writech { @dist[execname] = quantize(arg0); }'
dtrace: description 'sysinfo:::writech ' matched 4 probes
^C
[...]
Xorg
value ------------- Distribution ------------- count
16 | 0
32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 169
64 |@@@ 16
128 |@@ 10
256 | 0
gnome-terminal
value ------------- Distribution ------------- count
0 | 0
1 |@@ 6
2 | 0
4 | 0
8 | 1
16 |@ 2
32 |@@@ 7
64 | 0
128 |@@@@@@@@@@@@@@@@@@@@@@@ 63
256 |@@@@ 10
512 | 1
1024 |@@@@@ 13
2048 |@ 2
4096 |@@@ 7
### Disk size by process,
# dtrace -n 'io:::start { printf("%d %s %d",pid,execname,args[0]->b_bcount); }'
0 3271 bdev_strategy:start 16459 tar 1024
0 3271 bdev_strategy:start 16459 tar 1024
0 3271 bdev_strategy:start 16459 tar 2048
0 3271 bdev_strategy:start 16459 tar 1024
0 3271 bdev_strategy:start 16459 tar 1024
0 3271 bdev_strategy:start 16459 tar 1024
0 3271 bdev_strategy:start 16459 tar 8192
0 3271 bdev_strategy:start 16459 tar 8192
0 3271 bdev_strategy:start 16459 tar 16384
0 3271 bdev_strategy:start 16459 tar 2048
0 3271 bdev_strategy:start 16459 tar 1024
0 3271 bdev_strategy:start 16459 tar 1024
### Pages paged in by process,
# dtrace -n 'vminfo:::pgpgin { @pg[execname] = sum(arg0); }'
dtrace: description 'vminfo:::pgpgin ' matched 1 probe
^C
ttymon 1
bash 1
mozilla-bin 36
tar 6661
### Minor faults by process,
# dtrace -n 'vminfo:::as_fault { @mem[execname] = sum(arg0); }'
dtrace: description 'vminfo:::as_fault ' matched 1 probe
^C
mozilla-bin 18
dtrace 57
find 64
bash 150
tar 501
### Interrupts by CPU,
# dtrace -n 'sdt:::interrupt-start { @num[cpu] = count(); }'
dtrace: description 'sdt:::interrupt-start ' matched 1 probe
^C
513 2
515 4
3 39
2 39
### New processes with arguments and time,
# dtrace -qn 'syscall::exec*:return { printf("%Y %s\n",walltimestamp,curpsinfo->pr_psargs); }'
2005 Apr 25 19:15:09 man ls
2005 Apr 25 19:15:09 sh -c cd /usr/share/man; tbl /usr/share/man/man1/ls.1 |...
2005 Apr 25 19:15:09 neqn /usr/share/lib/pub/eqnchar -
2005 Apr 25 19:15:09 tbl /usr/share/man/man1/ls.1
2005 Apr 25 19:15:09 nroff -u0 -Tlp -man -
2005 Apr 25 19:15:09 col -x
2005 Apr 25 19:15:10 sh -c trap '' 1 15; /usr/bin/mv -f /tmp/mpRZaqTF /usr/s...
2005 Apr 25 19:15:10 /usr/bin/mv -f /tmp/mpRZaqTF /usr/share/man/cat1/ls.1
2005 Apr 25 19:15:10 sh -c more -s /tmp/mpRZaqTF
2005 Apr 25 19:15:10 more -s /tmp/mpRZaqTF
[...]
### Successful signal details,
# dtrace -n 'proc:::signal-send /pid/ { printf("%s -%d %d",execname,args[2],args[1]->pr_pid); }'
dtrace: description 'proc:::signal-send ' matched 1 probe
CPU ID FUNCTION:NAME
0 3303 sigtoproc:signal-send bash -15 16442
0 3303 sigtoproc:signal-send bash -9 16443
^C
Еще Примеры
DTrace: следим за размером файла и не даем прочитать /etc/passwd Джон Хэслэм с sunblogs предлагает тройку D-скриптов, которые могут быть полезны в практике. Первый позволяет следить за размером файла (файл должен лежать в ufs-партиции) - наверняка у многих возникала подобная задача, DTrace справляется с этим блестяще:
следим за размером файла
#!/usr/sbin/dtrace -s
#pragma D option quiet
BEGIN
{
size = 0;
}
/* wrip does the real work for a ufs write. The first argument is a struct inode* so
we can extract everything we need (vnode, size) from this */
fbt::wrip:entry
/(self->file = stringof(args[0]->i_vnode->v_path)) == $$1 /
{
self->inode = args[0];
}
/* If the file in question has changed size tell us */
fbt::wrip:return
/self->inode && size != self->inode->i_ic.ic_lsize/
{
printf("File %s changed size: size = %d\n",
self->file, self->inode->i_ic.ic_lsize);
size = self->inode->i_ic.ic_lsize;
self->inode = 0;
self->file = 0;
}
fbt::wrip:return
/self->inode && size == self->inode->i_ic.ic_lsize/
{
self->inode = 0;
self->file = 0;
}
Тестируем:
# ./file.d /var/tmp/bigfile
File /var/tmp/bigfile changed size: size = 132120576
File /var/tmp/bigfile changed size: size = 133169152
File /var/tmp/bigfile changed size: size = 134217728
File /var/tmp/bigfile changed size: size = 134712950
следить за обращениями к заданному файлу
Второй маленький скрипт позволяет следить за обращениями к заданному файлу (пусть это будет /etc/passwd), сообщает uid и пресекает попытки:
#!/usr/sbin/dtrace -ws
ufs_read:entry
/ stringof(args[0]->v_path) == $$1 /
{
printf("File %s read by %d\n", $$1, curpsinfo->pr_uid);
raise(SIGKILL);
}
Запускаем в одном терминале скрипт, в другом пытаемся прочесть файл паролей:
$ more /etc/passwd
Скрипт выводит инфо и убивает процесс more:
dtrace# ./read.d /etc/passwd: script './read.d' matched 1 probe dtrace: allowing destructive actions CPU ID FUNCTION:NAME 0 15625 ufs_read:entry File /etc/passwd read by 100
запуске setuid-программ
Третий скрипт сообщает о запуске setuid-программ пользователем:
#!/usr/sbin/dtrace -s
#pragma D option quiet
inline int PRIV_SETUGID = 0x04;
execsetid:entry
{
self->file = stringof(args[0]->v_path);
}
execsetid:return
/ (self->file != NULL) && (args[1] & PRIV_SETUGID) &&
(curpsinfo->pr_gid != $1 || curpsinfo->pr_egid != $1) /
{
printf("setuid/setgid file %s executed by uid %d\n", self->file,
curpsinfo->pr_uid);
self->file = 0;
}
Также запускаем скрипт в одном окне, а в другом - различные программы:
# ./group.d 14 setuid/setgid file /usr/bin/su executed by uid 100 setuid/setgid file /usr/sbin/../lib/fs/ufs/quota executed by uid 30079 setuid/setgid file /usr/bin/mail executed by uid 30079
Дисковая Активность
Сегодня приведу полезный скрипт, показывающий, к каким файлам шли частые обращения за 10-ти секундный интервал. Скрипт работает непрерывно до его прерывания. Применение – можно увидеть, почему вдруг увеличилась нагрузка на систему из-за дисковой активности.
Скрипт:
$ cat 02_openfiles.d
#!/usr/sbin/dtrace -s
io:::start
{
@[args[2]->fi_pathname] = count();
}
tick-10s
{
trunc(@, 10);
printa(@);
trunc(@, 0);
}
Выставить права на запуск:
$ chmod +x 02_openfiles.d
Запуск:
$ sudo ./02_openfiles.d
Второй вариант запуска – в одну строку:
$ sudo dtrace -n 'io:::start {@[args[2]->fi_pathname] = count();} tick-10s {trunc(@, 10); printa(@); trunc(@, 0);}'
Пример работы:
0 129269 :tick-10s ??/Logs/FileSyncAgent.log 1 ??/Russian.lproj/Dictionary.dat 1 ??/DiagnosticMessages/StoreData 3 ??/DiagnosticMessages/2010.11.30.asl 6 ??/com.apple.Safari/Cache.db-journal 8 ??/com.apple.Safari/Cache.db 51 0 129269 :tick-10s ??/bands/114 1 ??/bands/ef 2 ??/Cookies/Cookies.plist_tmp_67927_0.dat 3 ??/bands/115 3 ??/bands/a0 3 ??/bands/0 4 ??/bands/59 5 ??/com.apple.Safari/Cache.db-journal 6 ??/com.apple.Safari/Cache.db 12 ??/unknown (NULL v_parent)/unknown (NULL v_name) 16
По этим примерам можно сказать, что Safari активно пишет в кеш, и система синхронизирует iDisk.
Почему iDisk? /bands/114 указывает на Sparse Bundle Image, Time Machine вне подозрения (TimeCapsule далеко), а поиск find’ом показал каталог ctrld_iDisk.sparsebundle:
$ sudo find / -name 114 /Users/ctrld/Library/FileSync/0025bcdcddae/ctrld_iDisk.sparsebundle/bands/114
Указанный пример очень прост, есть гораздо более впечатляющие примеры. Хотите узнать больше? Смотрите OpenSolaris Community Group dtrace.
