1N/AThe following are demonstrations of the fsrw.d script.
1N/A
1N/A
1N/AHere the fsrw.d script was running while a 50 Kbyte file was read,
1N/A
1N/A # ./fsrw.d
1N/A Event Device RW Size Offset Path
1N/A sc-read . R 8192 0 /extra1/50k
1N/A fop_read . R 8192 0 /extra1/50k
1N/A disk_io cmdk0 R 8192 0 /extra1/50k
1N/A disk_ra cmdk0 R 8192 8 /extra1/50k
1N/A sc-read . R 8192 8 /extra1/50k
1N/A fop_read . R 8192 8 /extra1/50k
1N/A disk_ra cmdk0 R 34816 16 /extra1/50k
1N/A sc-read . R 8192 16 /extra1/50k
1N/A fop_read . R 8192 16 /extra1/50k
1N/A sc-read . R 8192 24 /extra1/50k
1N/A fop_read . R 8192 24 /extra1/50k
1N/A sc-read . R 8192 32 /extra1/50k
1N/A fop_read . R 8192 32 /extra1/50k
1N/A sc-read . R 8192 40 /extra1/50k
1N/A fop_read . R 8192 40 /extra1/50k
1N/A sc-read . R 8192 48 /extra1/50k
1N/A fop_read . R 8192 48 /extra1/50k
1N/A sc-read . R 8192 50 /extra1/50k
1N/A fop_read . R 8192 50 /extra1/50k
1N/A ^C
1N/A
1N/ABy looking closely at the Offset (Kbytes) and Size of each transaction, we
1N/Acan see how the read() system calls (sc-read) were satisfied by the file
1N/Asystem. There were 8 read() system calls, and 3 disk events - 2 of which were
1N/AUFS read-ahead (disk_ra). The final read-ahead was for 34 Kbytes and began
1N/Awith an offset of 16 Kbytes, which read the remaining file data (34 + 16 = 50
1N/AKbytes). The subsequent read() system calls and corresponding fop_read() calls
1N/Areturned from the page cache.
1N/A
1N/A
1N/A
1N/AThe following demonstrates how a logical I/O is broken up into multiple
1N/Aphysical I/O events. Here a dd command was used to read 1 Mbytes from the
1N/A/var/sadm/install/contents file while fsrw.d was tracing.
1N/A
1N/A # ./fsrw.d
1N/A Event Device RW Size Offset Path
1N/A sc-read . R 1048576 0 /var/sadm/install/contents
1N/A fop_read . R 1048576 0 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 4096 72 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 8192 96 <none>
1N/A disk_ra cmdk0 R 57344 96 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 152 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 208 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 49152 264 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 312 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 368 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 424 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 480 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 536 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 592 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 648 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 704 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 760 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 816 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 872 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 928 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 984 /var/sadm/install/contents
1N/A disk_ra cmdk0 R 57344 1040 /var/sadm/install/contents
1N/A ^C
1N/A
1N/ABoth the read() syscall (sc-read) and the fop_read() call asked the file system
1N/Afor 1048576 bytes, which was then broken into numerous disk I/O events of up to
1N/A56 Kbytes in size. The 8192 byte read with a path of "<none>" is likely to be
1N/Athe file system reading the indirect block pointers for the
1N/A/var/sadm/install/contents file (something DTrace could confirm in detail).
1N/A
1N/A
1N/A
1N/A
1N/AThe following traces activity as a cp command copies a 50 Kbyte file.
1N/A
1N/A # ./fsrw.d
1N/A Event Device RW Size Offset Path
1N/A disk_io dad1 R 1024 0 /extra1
1N/A disk_io dad1 R 8192 0 <none>
1N/A disk_io dad1 R 8192 0 <none>
1N/A disk_io dad1 R 2048 0 <none>
1N/A disk_io dad1 R 2048 0 <none>
1N/A sc-write . W 51200 0 /extra1/outfile
1N/A fop_write . W 51200 0 /extra1/outfile
1N/A disk_io dad1 R 8192 0 /extra1/50k
1N/A disk_ra dad1 R 8192 8 /extra1/50k
1N/A disk_ra dad1 R 34816 16 /extra1/50k
1N/A disk_io dad1 R 2048 0 <none>
1N/A disk_io dad1 W 49152 0 /extra1/outfile
1N/A ^C
1N/A
1N/AReads including UFS read-ahead can be seen as the file is read.
1N/AThe output finishes with disk writes as the new file is flushed to disk.
1N/AThe syscall write() and fop_write() can be seen to the /extra1/outfile,
1N/Ahowever there is no syscall read() or fop_read() to /extra1/50k - which
1N/Awe may have expected to occur before the writes. This is due to the way
1N/Athe cp command now works, it uses mmap() to map files in for reading.
1N/AThis activity can be seen if we also trace fop_getpage() and fop_putpage(),
1N/Aas the fspaging.d dtrace script does.
1N/A
1N/A # ./fspaging.d
1N/A Event Device RW Size Offset Path
1N/A disk_io dad1 R 1024 0 /extra1
1N/A disk_io dad1 R 8192 0 <none>
1N/A disk_io dad1 R 2048 0 <none>
1N/A sc-write . W 51200 0 /extra1/outfile
1N/A fop_write . W 51200 0 /extra1/outfile
1N/A fop_getpage . R 8192 0 /extra1/50k
1N/A disk_io dad1 R 8192 0 /extra1/50k
1N/A disk_ra dad1 R 8192 8 /extra1/50k
1N/A fop_getpage . R 8192 8 /extra1/50k
1N/A disk_ra dad1 R 34816 16 /extra1/50k
1N/A fop_getpage . R 8192 16 /extra1/50k
1N/A fop_getpage . R 8192 24 /extra1/50k
1N/A fop_getpage . R 8192 32 /extra1/50k
1N/A fop_getpage . R 8192 40 /extra1/50k
1N/A fop_getpage . R 8192 48 /extra1/50k
1N/A fop_putpage . W 8192 0 /extra1/outfile
1N/A fop_putpage . W 8192 8 /extra1/outfile
1N/A fop_putpage . W 8192 16 /extra1/outfile
1N/A fop_putpage . W 8192 24 /extra1/outfile
1N/A fop_putpage . W 8192 32 /extra1/outfile
1N/A fop_putpage . W 8192 40 /extra1/outfile
1N/A disk_io dad1 W 51200 0 /extra1/outfile
1N/A