iopending_example.txt revision 1.1 1 1.1 christos The following is a demonstration of the iopending tool,
2 1.1 christos
3 1.1 christos Here we run it with a sample interval of 1 second,
4 1.1 christos
5 1.1 christos # iopending 1
6 1.1 christos Tracing... Please wait.
7 1.1 christos 2006 Jan 6 20:21:59, load: 0.02, disk_r: 0 KB, disk_w: 0 KB
8 1.1 christos
9 1.1 christos value ------------- Distribution ------------- count
10 1.1 christos < 0 | 0
11 1.1 christos 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1010
12 1.1 christos 1 | 0
13 1.1 christos
14 1.1 christos 2006 Jan 6 20:22:00, load: 0.03, disk_r: 0 KB, disk_w: 0 KB
15 1.1 christos
16 1.1 christos value ------------- Distribution ------------- count
17 1.1 christos < 0 | 0
18 1.1 christos 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1000
19 1.1 christos 1 | 0
20 1.1 christos
21 1.1 christos 2006 Jan 6 20:22:01, load: 0.03, disk_r: 0 KB, disk_w: 0 KB
22 1.1 christos
23 1.1 christos value ------------- Distribution ------------- count
24 1.1 christos < 0 | 0
25 1.1 christos 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1000
26 1.1 christos 1 | 0
27 1.1 christos
28 1.1 christos ^C
29 1.1 christos
30 1.1 christos The iopending tool samples at 1000 Hz, and prints a distribution of how many
31 1.1 christos disk events were "pending" completion. In the above example the disks are
32 1.1 christos quiet - for all the samples there are zero disk events pending.
33 1.1 christos
34 1.1 christos
35 1.1 christos
36 1.1 christos Now iopending is run with no arguments. It will default to an interval of 5
37 1.1 christos seconds,
38 1.1 christos
39 1.1 christos # iopending
40 1.1 christos Tracing... Please wait.
41 1.1 christos 2006 Jan 6 19:15:41, load: 0.03, disk_r: 3599 KB, disk_w: 0 KB
42 1.1 christos
43 1.1 christos value ------------- Distribution ------------- count
44 1.1 christos < 0 | 0
45 1.1 christos 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4450
46 1.1 christos 1 |@@@ 390
47 1.1 christos 2 |@ 80
48 1.1 christos 3 | 40
49 1.1 christos 4 | 20
50 1.1 christos 5 | 30
51 1.1 christos 6 | 0
52 1.1 christos
53 1.1 christos ^C
54 1.1 christos
55 1.1 christos In the above output there was a little disk activity. For 390 samples there
56 1.1 christos was 1 I/O event pending; for 80 samples there was 2, and so on.
57 1.1 christos
58 1.1 christos
59 1.1 christos
60 1.1 christos
61 1.1 christos In the following example iopending is run during heavy disk activity. We
62 1.1 christos print output every 10 seconds,
63 1.1 christos
64 1.1 christos # iopending 10
65 1.1 christos Tracing... Please wait.
66 1.1 christos 2006 Jan 6 20:58:07, load: 0.03, disk_r: 25172 KB, disk_w: 33321 KB
67 1.1 christos
68 1.1 christos value ------------- Distribution ------------- count
69 1.1 christos < 0 | 0
70 1.1 christos 0 |@@@@@@@@@ 2160
71 1.1 christos 1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6720
72 1.1 christos 2 |@@@@ 1000
73 1.1 christos 3 | 50
74 1.1 christos 4 | 30
75 1.1 christos 5 | 20
76 1.1 christos 6 | 10
77 1.1 christos 7 | 10
78 1.1 christos 8 | 10
79 1.1 christos 9 | 0
80 1.1 christos
81 1.1 christos 2006 Jan 6 20:58:17, load: 0.05, disk_r: 8409 KB, disk_w: 12449 KB
82 1.1 christos
83 1.1 christos value ------------- Distribution ------------- count
84 1.1 christos < 0 | 0
85 1.1 christos 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7260
86 1.1 christos 1 |@@@@@@@ 1700
87 1.1 christos 2 |@ 300
88 1.1 christos 3 | 0
89 1.1 christos 4 | 10
90 1.1 christos 5 | 10
91 1.1 christos 6 | 10
92 1.1 christos 7 | 20
93 1.1 christos 8 | 0
94 1.1 christos 9 | 0
95 1.1 christos 10 | 0
96 1.1 christos 11 | 0
97 1.1 christos 12 | 0
98 1.1 christos 13 | 0
99 1.1 christos 14 | 0
100 1.1 christos 15 | 0
101 1.1 christos 16 | 0
102 1.1 christos 17 | 10
103 1.1 christos 18 | 20
104 1.1 christos 19 | 0
105 1.1 christos 20 | 0
106 1.1 christos 21 | 0
107 1.1 christos 22 | 0
108 1.1 christos 23 | 0
109 1.1 christos 24 | 0
110 1.1 christos 25 | 0
111 1.1 christos 26 | 0
112 1.1 christos 27 | 0
113 1.1 christos 28 | 0
114 1.1 christos 29 | 0
115 1.1 christos 30 | 0
116 1.1 christos 31 | 10
117 1.1 christos >= 32 |@@@ 650
118 1.1 christos
119 1.1 christos ^C
120 1.1 christos
121 1.1 christos In the first output, most of the time (67%) there was 1 event pending,
122 1.1 christos and for a short time there were 8 events pending. In the second output we
123 1.1 christos see many samples were off the scale - 650 samples at 32 or more pending
124 1.1 christos events. For this sample I had typed "sync" in another window, which
125 1.1 christos queued many disk events immediately which were eventually completed.
126 1.1 christos
127