Solaris Dynamic Tracing Guide
|
|||
|
2. Types, Operators, and Expressions 8. Type and Constant Definitions 34. Statically Defined Tracing for User Applications |
ExamplesYou can use FBT to easily explore the kernel's implementation. The following example script records the first ioctl(2) from any xclock process and then follows the subsequent code path through the kernel: /*
* To make the output more readable, we want to indent every function entry
* (and unindent every function return). This is done by setting the
* "flowindent" option.
*/
#pragma D option flowindent
syscall::ioctl:entry
/execname == "xclock" && guard++ == 0/
{
self->traceme = 1;
printf("fd: %d", arg0);
}
fbt:::
/self->traceme/
{}
syscall::ioctl:return
/self->traceme/
{
self->traceme = 0;
exit(0);
}Running this script results in output similar to the following example: # dtrace -s ./xioctl.d dtrace: script './xioctl.d' matched 26254 probes CPU FUNCTION 0 => ioctl fd: 3 0 -> ioctl 0 -> getf 0 -> set_active_fd 0 <- set_active_fd 0 <- getf 0 -> fop_ioctl 0 -> sock_ioctl 0 -> strioctl 0 -> job_control_type 0 <- job_control_type 0 -> strcopyout 0 -> copyout 0 <- copyout 0 <- strcopyout 0 <- strioctl 0 <- sock_ioctl 0 <- fop_ioctl 0 -> releasef 0 -> clear_active_fd 0 <- clear_active_fd 0 -> cv_broadcast 0 <- cv_broadcast 0 <- releasef 0 <- ioctl 0 <= ioctl The output shows that an xclock process called ioctl() on a file descriptor that appears to be associated with a socket. You can also use FBT when trying to understand kernel drivers. For example, the ssd(7D) driver has many code paths by which EIO may be returned. FBT can be easily used to determine the precise code path that resulted in an error condition, as shown in the following example: fbt:ssd::return
/arg1 == EIO/
{
printf("%s+%x returned EIO.", probefunc, arg0);
}For more information on any one return of EIO, one may wish to speculatively trace all fbt probes, and then commit()(or discard()) based on the return value of a specific function. See Chapter 13, Speculative Tracing for details on speculative tracing. Alternatively, you can use FBT to understand the functions called within a specified module. The following example lists all of the functions called in UFS: # dtrace -n fbt:ufs::entry'{@a[probefunc] = count()}'
dtrace: description 'fbt:ufs::entry' matched 353 probes
^C
ufs_ioctl 1
ufs_statvfs 1
ufs_readlink 1
ufs_trans_touch 1
wrip 1
ufs_dirlook 1
bmap_write 1
ufs_fsync 1
ufs_iget 1
ufs_trans_push_inode 1
ufs_putpages 1
ufs_putpage 1
ufs_syncip 1
ufs_write 1
ufs_trans_write_resv 1
ufs_log_amt 1
ufs_getpage_miss 1
ufs_trans_syncip 1
getinoquota 1
ufs_inode_cache_constructor 1
ufs_alloc_inode 1
ufs_iget_alloced 1
ufs_iget_internal 2
ufs_reset_vnode 2
ufs_notclean 2
ufs_iupdat 2
blkatoff 3
ufs_close 5
ufs_open 5
ufs_access 6
ufs_map 8
ufs_seek 11
ufs_addmap 15
rdip 15
ufs_read 15
ufs_rwunlock 16
ufs_rwlock 16
ufs_delmap 18
ufs_getattr 19
ufs_getpage_ra 24
bmap_read 25
findextent 25
ufs_lockfs_begin 27
ufs_lookup 46
ufs_iaccess 51
ufs_imark 92
ufs_lockfs_begin_getpage 102
bmap_has_holes 102
ufs_getpage 102
ufs_itimes_nolock 107
ufs_lockfs_end 125
dirmangled 498
dirbadname 498If you know the purpose or arguments of a kernel function, you can use FBT to understand how or why the function is being called. For example, putnext(9F) takes a pointer to a queue(9S) structure as its first member. The q_qinfo member of the queue structure is a pointer to a qinit(9S) structure. The qi_minfo member of the qinit structure has a pointer to a module_info(9S) structure, which contains the module name in its mi_idname member. The following example puts this information together by using the FBT probe in putnext to track putnext(9F) calls by module name: fbt::putnext:entry
{
@calls[stringof(args[0]->q_qinfo->qi_minfo->mi_idname)] = count();
}Running the above script results in output similar to the following example: # dtrace -s ./putnext.d ^C iprb 1 rpcmod 1 pfmod 1 timod 2 vpnmod 2 pts 40 conskbd 42 kb8042 42 tl 58 arp 108 tcp 126 ptm 249 ip 313 ptem 340 vuid2ps2 361 ttcompat 412 ldterm 413 udp 569 strwhead 624 mouse8042 726 You can also use FBT to determine the time spent in a particular function. The following example shows how to determine the callers of the DDI delaying routines drv_usecwait(9F) and delay(9F). fbt::delay:entry,
fbt::drv_usecwait:entry
{
self->in = timestamp
}
fbt::delay:return,
fbt::drv_usecwait:return
/self->in/
{
@snoozers[stack()] = quantize(timestamp - self->in);
self->in = 0;
}This example script is particularly interesting to run during boot. Chapter 36, Anonymous Tracing describes the procedure for performing anonymous tracing during system boot. Upon reboot, you might see output similar to the following example: # dtrace -ae
ata`ata_wait+0x34
ata`ata_id_common+0xf5
ata`ata_disk_id+0x20
ata`ata_drive_type+0x9a
ata`ata_init_drive+0xa2
ata`ata_attach+0x50
genunix`devi_attach+0x75
genunix`attach_node+0xb2
genunix`i_ndi_config_node+0x97
genunix`i_ddi_attachchild+0x4b
genunix`devi_attach_node+0x3d
genunix`devi_config_one+0x1d0
genunix`ndi_devi_config_one+0xb0
devfs`dv_find+0x125
devfs`devfs_lookup+0x40
genunix`fop_lookup+0x21
genunix`lookuppnvp+0x236
genunix`lookuppnat+0xe7
genunix`lookupnameat+0x87
genunix`cstatat_getvp+0x134
value ------------- Distribution ------------- count
2048 | 0
4096 |@@@@@@@@@@@@@@@@@@@@@ 4105
8192 |@@@@ 783
16384 |@@@@@@@@@@@@@@ 2793
32768 | 16
65536 | 0
kb8042`kb8042_wait_poweron+0x29
kb8042`kb8042_init+0x22
kb8042`kb8042_attach+0xd6
genunix`devi_attach+0x75
genunix`attach_node+0xb2
genunix`i_ndi_config_node+0x97
genunix`i_ddi_attachchild+0x4b
genunix`devi_attach_node+0x3d
genunix`devi_config_one+0x1d0
genunix`ndi_devi_config_one+0xb0
genunix`resolve_pathname+0xa5
genunix`ddi_pathname_to_dev_t+0x16
consconfig_dacf`consconfig_load_drivers+0x14
consconfig_dacf`dynamic_console_config+0x6c
consconfig`consconfig+0x8
unix`stubs_common_code+0x3b
value ------------- Distribution ------------- count
262144 | 0
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 221
1048576 |@@@@ 29
2097152 | 0
usba`hubd_enable_all_port_power+0xed
usba`hubd_check_ports+0x8e
usba`usba_hubdi_attach+0x275
usba`usba_hubdi_bind_root_hub+0x168
uhci`uhci_attach+0x191
genunix`devi_attach+0x75
genunix`attach_node+0xb2
genunix`i_ndi_config_node+0x97
genunix`i_ddi_attachchild+0x4b
genunix`i_ddi_attach_node_hierarchy+0x49
genunix`attach_driver_nodes+0x49
genunix`ddi_hold_installed_driver+0xe3
genunix`attach_drivers+0x28
value ------------- Distribution ------------- count
33554432 | 0
67108864 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3
134217728 | 0
|
||
|