FBT を使用すると、カーネルの実装を簡単に調べることができます。以下に、xclock プロセスの最初の ioctl(2) を記録し、カーネル経由で続きのコードパスをたどるスクリプトの例を示します。
/* * 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); }
このスクリプトを実行すると、次のような出力が得られます。
# 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 |
上記の出力では、xclock プロセスが、ソケットと関連付けられているように見えるファイル記述子で ioctl() を呼び出しています。
FBT で、カーネルドライバに関する情報を得ることもできます。たとえば、ssd(7D) ドライバには、EIO を返すコードパスが多数あります。FBT を使用すると、エラーを出した正確なコードパスを簡単に突き止めることができます。次の例を参照してください。
fbt:ssd::return /arg1 == EIO/ { printf("%s+%x returned EIO.", probefunc, arg0); }
EIO の詳細情報を得たい場合は、すべての fbt プローブを投機的にトレースし、関数の戻り値に基づいて commit() (または discard()) を実行します。投機トレースについては、第 13 章投機トレースを参照してください。
FBT を使って、指定のモジュール内で呼び出された関数の情報を得ることもできます。以下は、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 498 |
カーネル関数の引数の目的を理解している場合は、FBT を使って、この関数を呼び出す理由やその方法を確認できます。たとえば、putnext(9F) の最初のメンバーは、queue(9S) 構造体のポインタになります。queue 構造体の q_qinfo メンバーは、qinit(9S) 構造体のポインタになります。qinit 構造体の qi_minfo メンバーは、module_info(9S) 構造体のポインタを持っています。module_info 構造体の mi_idname メンバーには、モジュール名が格納されます。以下の例では、putnext 内で FBT プローブを使用することによってこの情報をまとめ、モジュール名から putnext(9F) 呼び出しを追跡します。
fbt::putnext:entry { @calls[stringof(args[0]->q_qinfo->qi_minfo->mi_idname)] = count(); }
このスクリプトを実行すると、次のような出力が得られます。
# 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 |
FBT を使って、特定の関数で消費された時間を調べることもできます。以下の例では、DDI 遅延ルーチン drv_usecwait(9F) と 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; }
このスクリプトは、ブート中に実行されることに意味があります。システムブート中の匿名トレースの実行手順については、第 36 章匿名トレースで説明します。リブート時に、次のような出力が得られます。
# 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 |