Example
Examine the following output from mpstat(1M):
CPU minf mjf xcal intr ithr csw icsw migr smtx srw syscl usr sys wt idl
12 90 22 5760 422 299 435 26 71 116 11 1372 5 19 17 60
13 46 18 4585 193 162 431 25 69 117 12 1039 3 17 14 66
14 33 13 3186 405 381 397 21 58 105 10 770 2 17 11 70
15 34 19 4769 109 78 417 23 57 115 13 962 3 14 14 69
16 74 16 4421 437 406 448 29 77 111 8 1020 4 23 14 59
17 51 15 4493 139 110 378 23 62 109 9 928 4 18 14 65
18 41 14 4204 494 468 360 23 56 102 9 849 4 17 12 68
19 37 14 4229 115 87 363 22 50 106 10 845 3 15 14 67
20 78 17 5170 200 169 456 26 69 108 9 1119 5 21 25 49
21 53 16 4817 78 51 394 22 56 106 9 978 4 17 22 57
22 32 13 3474 486 463 347 22 48 106 9 769 3 17 17 63
23 43 15 4572 59 34 361 21 46 102 10 947 4 15 22 59
From the above output, you might conclude that the xcal field seems too
high, especially given the relative idleness of the system. mpstat determines the
value in the xcal field by examining the xcalls field of the sys
kernel statistic. This aberration can therefore be explored easily by enabling the xcalls
sysinfo probe, as shown in the following example:
# dtrace -n xcalls'{@[execname] = count()}'
dtrace: description 'xcalls' matched 4 probes
^C
dtterm 1
nsrd 1
in.mpathd 2
top 3
lockd 4
java_vm 10
ksh 19
iCald.pl6+RPATH 28
nwadmin 30
fsflush 34
nsrindexd 45
in.rlogind 56
in.routed 100
dtrace 153
rpc.rstatd 246
imapd 377
sched 431
nfsd 1227
find 3767The output shows where to look for the source of the cross-calls.
Some number of find(1) processes are causing the majority of the cross-calls. The following
D script can be used to understand the problem in further detail:
syscall:::entry
/execname == "find"/
{
self->syscall = probefunc;
self->insys = 1;
}
sysinfo:::xcalls
/execname == "find"/
{
@[self->insys ? self->syscall : "<none>"] = count();
}
syscall:::return
/self->insys/
{
self->insys = 0;
self->syscall = NULL;
}This script uses the syscall provider to attribute cross-calls from find to a
particular system call. Some cross-calls, such as those resulting from page faults, might
not emanate from system calls. The script prints “<none>” in these cases. Running the
script results in output similar to the following example:
# dtrace -s ./find.d
dtrace: script './find.d' matched 444 probes
^C
<none> 2
lstat64 2433
getdents64 14873
This output indicates that the majority of cross-calls induced by find are
in turn induced by getdents(2) system calls. Further exploration would depend on the
direction you want to explore. If you want to understand why find processes
are making calls to getdents, you could write a D script to aggregate
on ustack() when find induces a cross-call. If you want to understand
why calls to getdents are inducing cross-calls, you could write a D
script to aggregate on stack() when find induces a cross-call. Whatever your next step,
the presence of the xcalls probe has enabled you to quickly discover the
root cause of the unusual monitoring output.
