1The following are demonstrations of the fsrw.d script. 2 3 4Here the fsrw.d script was running while a 50 Kbyte file was read, 5 6 # ./fsrw.d 7 Event Device RW Size Offset Path 8 sc-read . R 8192 0 /extra1/50k 9 fop_read . R 8192 0 /extra1/50k 10 disk_io cmdk0 R 8192 0 /extra1/50k 11 disk_ra cmdk0 R 8192 8 /extra1/50k 12 sc-read . R 8192 8 /extra1/50k 13 fop_read . R 8192 8 /extra1/50k 14 disk_ra cmdk0 R 34816 16 /extra1/50k 15 sc-read . R 8192 16 /extra1/50k 16 fop_read . R 8192 16 /extra1/50k 17 sc-read . R 8192 24 /extra1/50k 18 fop_read . R 8192 24 /extra1/50k 19 sc-read . R 8192 32 /extra1/50k 20 fop_read . R 8192 32 /extra1/50k 21 sc-read . R 8192 40 /extra1/50k 22 fop_read . R 8192 40 /extra1/50k 23 sc-read . R 8192 48 /extra1/50k 24 fop_read . R 8192 48 /extra1/50k 25 sc-read . R 8192 50 /extra1/50k 26 fop_read . R 8192 50 /extra1/50k 27 ^C 28 29By looking closely at the Offset (Kbytes) and Size of each transaction, we 30can see how the read() system calls (sc-read) were satisfied by the file 31system. There were 8 read() system calls, and 3 disk events - 2 of which were 32UFS read-ahead (disk_ra). The final read-ahead was for 34 Kbytes and began 33with an offset of 16 Kbytes, which read the remaining file data (34 + 16 = 50 34Kbytes). The subsequent read() system calls and corresponding fop_read() calls 35returned from the page cache. 36 37 38 39The following demonstrates how a logical I/O is broken up into multiple 40physical I/O events. Here a dd command was used to read 1 Mbytes from the 41/var/sadm/install/contents file while fsrw.d was tracing. 42 43 # ./fsrw.d 44 Event Device RW Size Offset Path 45 sc-read . R 1048576 0 /var/sadm/install/contents 46 fop_read . R 1048576 0 /var/sadm/install/contents 47 disk_ra cmdk0 R 4096 72 /var/sadm/install/contents 48 disk_ra cmdk0 R 8192 96 <none> 49 disk_ra cmdk0 R 57344 96 /var/sadm/install/contents 50 disk_ra cmdk0 R 57344 152 /var/sadm/install/contents 51 disk_ra cmdk0 R 57344 208 /var/sadm/install/contents 52 disk_ra cmdk0 R 49152 264 /var/sadm/install/contents 53 disk_ra cmdk0 R 57344 312 /var/sadm/install/contents 54 disk_ra cmdk0 R 57344 368 /var/sadm/install/contents 55 disk_ra cmdk0 R 57344 424 /var/sadm/install/contents 56 disk_ra cmdk0 R 57344 480 /var/sadm/install/contents 57 disk_ra cmdk0 R 57344 536 /var/sadm/install/contents 58 disk_ra cmdk0 R 57344 592 /var/sadm/install/contents 59 disk_ra cmdk0 R 57344 648 /var/sadm/install/contents 60 disk_ra cmdk0 R 57344 704 /var/sadm/install/contents 61 disk_ra cmdk0 R 57344 760 /var/sadm/install/contents 62 disk_ra cmdk0 R 57344 816 /var/sadm/install/contents 63 disk_ra cmdk0 R 57344 872 /var/sadm/install/contents 64 disk_ra cmdk0 R 57344 928 /var/sadm/install/contents 65 disk_ra cmdk0 R 57344 984 /var/sadm/install/contents 66 disk_ra cmdk0 R 57344 1040 /var/sadm/install/contents 67 ^C 68 69Both the read() syscall (sc-read) and the fop_read() call asked the file system 70for 1048576 bytes, which was then broken into numerous disk I/O events of up to 7156 Kbytes in size. The 8192 byte read with a path of "<none>" is likely to be 72the file system reading the indirect block pointers for the 73/var/sadm/install/contents file (something DTrace could confirm in detail). 74 75 76 77 78The following traces activity as a cp command copies a 50 Kbyte file. 79 80 # ./fsrw.d 81 Event Device RW Size Offset Path 82 disk_io dad1 R 1024 0 /extra1 83 disk_io dad1 R 8192 0 <none> 84 disk_io dad1 R 8192 0 <none> 85 disk_io dad1 R 2048 0 <none> 86 disk_io dad1 R 2048 0 <none> 87 sc-write . W 51200 0 /extra1/outfile 88 fop_write . W 51200 0 /extra1/outfile 89 disk_io dad1 R 8192 0 /extra1/50k 90 disk_ra dad1 R 8192 8 /extra1/50k 91 disk_ra dad1 R 34816 16 /extra1/50k 92 disk_io dad1 R 2048 0 <none> 93 disk_io dad1 W 49152 0 /extra1/outfile 94 ^C 95 96Reads including UFS read-ahead can be seen as the file is read. 97The output finishes with disk writes as the new file is flushed to disk. 98The syscall write() and fop_write() can be seen to the /extra1/outfile, 99however there is no syscall read() or fop_read() to /extra1/50k - which 100we may have expected to occur before the writes. This is due to the way 101the cp command now works, it uses mmap() to map files in for reading. 102This activity can be seen if we also trace fop_getpage() and fop_putpage(), 103as the fspaging.d dtrace script does. 104 105 # ./fspaging.d 106 Event Device RW Size Offset Path 107 disk_io dad1 R 1024 0 /extra1 108 disk_io dad1 R 8192 0 <none> 109 disk_io dad1 R 2048 0 <none> 110 sc-write . W 51200 0 /extra1/outfile 111 fop_write . W 51200 0 /extra1/outfile 112 fop_getpage . R 8192 0 /extra1/50k 113 disk_io dad1 R 8192 0 /extra1/50k 114 disk_ra dad1 R 8192 8 /extra1/50k 115 fop_getpage . R 8192 8 /extra1/50k 116 disk_ra dad1 R 34816 16 /extra1/50k 117 fop_getpage . R 8192 16 /extra1/50k 118 fop_getpage . R 8192 24 /extra1/50k 119 fop_getpage . R 8192 32 /extra1/50k 120 fop_getpage . R 8192 40 /extra1/50k 121 fop_getpage . R 8192 48 /extra1/50k 122 fop_putpage . W 8192 0 /extra1/outfile 123 fop_putpage . W 8192 8 /extra1/outfile 124 fop_putpage . W 8192 16 /extra1/outfile 125 fop_putpage . W 8192 24 /extra1/outfile 126 fop_putpage . W 8192 32 /extra1/outfile 127 fop_putpage . W 8192 40 /extra1/outfile 128 disk_io dad1 W 51200 0 /extra1/outfile 129 130