1 The following are demonstrations of the fsrw.d script.
4 Here the fsrw.d script was running while a 50 Kbyte file was read,
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
29 By looking closely at the Offset (Kbytes) and Size of each transaction, we
30 can see how the read() system calls (sc-read) were satisfied by the file
31 system. There were 8 read() system calls, and 3 disk events - 2 of which were
32 UFS read-ahead (disk_ra). The final read-ahead was for 34 Kbytes and began
33 with an offset of 16 Kbytes, which read the remaining file data (34 + 16 = 50
34 Kbytes). The subsequent read() system calls and corresponding fop_read() calls
35 returned from the page cache.
39 The following demonstrates how a logical I/O is broken up into multiple
40 physical 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.
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
69 Both the read() syscall (sc-read) and the fop_read() call asked the file system
70 for 1048576 bytes, which was then broken into numerous disk I/O events of up to
71 56 Kbytes in size. The 8192 byte read with a path of "<none>" is likely to be
72 the file system reading the indirect block pointers for the
73 /var/sadm/install/contents file (something DTrace could confirm in detail).
78 The following traces activity as a cp command copies a 50 Kbyte file.
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
96 Reads including UFS read-ahead can be seen as the file is read.
97 The output finishes with disk writes as the new file is flushed to disk.
98 The syscall write() and fop_write() can be seen to the /extra1/outfile,
99 however there is no syscall read() or fop_read() to /extra1/50k - which
100 we may have expected to occur before the writes. This is due to the way
101 the cp command now works, it uses mmap() to map files in for reading.
102 This activity can be seen if we also trace fop_getpage() and fop_putpage(),
103 as the fspaging.d dtrace script does.
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