Solaris DTrace

Материал из naname.com.ua
Перейти к навигацииПерейти к поиску

Это совсем-совсем черновик

DTrace

(дополненный текст отсюда: http://experience.openquality.ru/dtrace-use-cases/) Подробная дока:
http://wikis.sun.com/display/DTrace/Documentation

Коротко о DTRACE

По сравнению с другими средствами сбора информации о системе и отладки приложений, DTrace обладает рядом уникальных свойств:

  1. накапливает информацию о системе, работающей под максимальной нагрузкой – с низкими накладными расходами на сбор информации;
  2. собирает любую информацию из любых уголков системы, позволяя наблюдать как за работой приложений, так и за работой самого ядра системы;
  3. может показать, какие аргументы передаются от одной функции к другой, независимо от того, доступен ли исходный код функций;
  4. собирает информацию о том, как долго исполняются вызываемые функции, какой процент времени занимает исполнение каждой из них, сколько раз каждая из них была вызвана;
  5. фильтрует информацию любым заданным образом – например, позволяет ограничить область наблюдения одним приложением, одним потоком команд, или определенной областью (скажем, измерять время выполнения только конкретного системного вызова, а об остальном не заботиться);
  6. может реагировать на определенные события (ввод-вывод, вызов заданных функций, завершение программы, запуск нового потока и пр.);
  7. имеет как средства низкоуровнего наблюдения (можно изучать ход работы драйвера устройства), так и средства высокоуровневые, например, позволяет отслеживать определенные события при исполнении скриптов на PHP или вызов методов в приложении, написанном на Java;
  8. позволяет выполнять трассировку вызовов, с одновременным отслеживанием любых параметров – времени выполнения, переданных аргументов и пр.

Короткая подсказка

Все пояснения - ниже, это просто короткая подсказка наиболее употребимых конструкций. Список всех проб (очень удобно)

dtrace -l | grep foo keyword search

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.

Note: У меня не заработали датчики MySQL на Solaris 10 x86


Модуль – это название модуля или библиотеки, например, 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 (вначале на экран будет выдан результат ее работы, а потом – список функций с количеством вызовов для каждой в порядке возрастания):

pfexec dtrace -n 'pid$target:::entry {@funсtions[probefunc]=count();}' -c ls

А вот таким скриптом можно посчитать количество функций, вызванных конкретным процессом с PID=2355; для получения результата надо прервать выполнение скрипта с помощью Ctrl-C:

pfexec dtrace -n 'pid2355:::entry {@funсtions[probefunc]=count();}'

А вот так можно посчитать количество системных вызовов в том же процессе:

pfexec dtrace -n 'syscall:::entry /pid==2355/ {@funсtions[probefunc]=count();}'


Итак, в скриптах на языке 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 можно найти в следующих источниках:

Примеры

# 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.