Commit | Line | Data |
---|---|---|
d0ca268b JA |
1 | #include <sys/types.h> |
2 | #include <sys/stat.h> | |
3 | #include <unistd.h> | |
4 | #include <stdio.h> | |
5 | #include <fcntl.h> | |
6 | #include <stdlib.h> | |
7 | ||
8 | #include "blktrace.h" | |
9 | ||
10 | #define NELEMS(pfi) ((pfi)->stat.st_size / sizeof(struct blk_io_trace)) | |
11 | ||
fd92da24 | 12 | #define MAX_CPUS (512) |
d0ca268b JA |
13 | |
14 | struct per_file_info { | |
15 | int cpu; | |
16 | int nelems; | |
17 | struct stat stat; | |
18 | ||
19 | int fd; | |
20 | char *fname; | |
21 | FILE *ofp; | |
22 | char *ofname; | |
23 | int dfd; | |
24 | char *dname; | |
25 | ||
26 | unsigned long long start_time; | |
27 | }; | |
28 | ||
29 | struct per_file_info per_file_info[MAX_CPUS]; | |
30 | struct per_file_info *current; | |
31 | ||
32 | static unsigned long qreads, qwrites, creads, cwrites, mreads, mwrites; | |
33 | static unsigned long long qread_kb, qwrite_kb, cread_kb, cwrite_kb; | |
34 | static unsigned long long events, missed_events; | |
35 | ||
36 | static inline void account_m(int rw, unsigned int bytes) | |
37 | { | |
38 | if (rw) { | |
39 | mwrites++; | |
40 | qwrite_kb += bytes >> 10; | |
41 | } else { | |
42 | mreads++; | |
43 | qread_kb += bytes >> 10; | |
44 | } | |
45 | } | |
46 | ||
47 | static inline void account_q(int rw, unsigned int bytes) | |
48 | { | |
49 | if (rw) { | |
50 | qwrites++; | |
51 | qwrite_kb += bytes >> 10; | |
52 | } else { | |
53 | qreads++; | |
54 | qread_kb += bytes >> 10; | |
55 | } | |
56 | } | |
57 | ||
58 | static inline void account_c(int rw, unsigned int bytes) | |
59 | { | |
60 | if (rw) { | |
61 | cwrites++; | |
62 | cwrite_kb += bytes >> 10; | |
63 | } else { | |
64 | creads++; | |
65 | cread_kb += bytes >> 10; | |
66 | } | |
67 | } | |
68 | ||
69 | void output(char *s) | |
70 | { | |
71 | printf("%s", s); | |
72 | fprintf(current->ofp,"%s",s); | |
73 | } | |
74 | ||
75 | char hstring[256]; | |
76 | char tstring[256]; | |
77 | ||
78 | inline char *setup_header(struct blk_io_trace *t, char act) | |
79 | { | |
80 | int w = t->action & BLK_TC_ACT(BLK_TC_WRITE); | |
81 | int b = t->action & BLK_TC_ACT(BLK_TC_BARRIER); | |
82 | int s = t->action & BLK_TC_ACT(BLK_TC_SYNC); | |
83 | char rwbs[4]; | |
84 | int i = 0; | |
85 | ||
86 | if (w) | |
87 | rwbs[i++] = 'W'; | |
88 | else | |
89 | rwbs[i++] = 'R'; | |
90 | if (b) | |
91 | rwbs[i++] = 'B'; | |
92 | if (s) | |
93 | rwbs[i++] = 'S'; | |
94 | ||
95 | rwbs[i] = '\0'; | |
96 | ||
97 | sprintf(hstring, "%3d %15ld %12Lu %5u %c %3s", current->cpu, | |
98 | (unsigned long)t->sequence, (unsigned long long)t->time, t->pid, | |
99 | act, rwbs); | |
100 | ||
101 | return hstring; | |
102 | } | |
103 | ||
104 | void log_complete(struct blk_io_trace *t, char act) | |
105 | { | |
106 | sprintf(tstring,"%s %Lu + %u [%d]\n", setup_header(t, act), | |
107 | (unsigned long long)t->sector, t->bytes >> 9, t->error); | |
108 | output(tstring); | |
109 | } | |
110 | ||
111 | void log_queue(struct blk_io_trace *t, char act) | |
112 | { | |
113 | sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act), | |
114 | (unsigned long long)t->sector, t->bytes >> 9); | |
115 | output(tstring); | |
116 | } | |
117 | ||
118 | void log_issue(struct blk_io_trace *t, char act) | |
119 | { | |
120 | sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act), | |
121 | (unsigned long long)t->sector, t->bytes >> 9); | |
122 | output(tstring); | |
123 | } | |
124 | ||
125 | void log_merge(struct blk_io_trace *t, char act) | |
126 | { | |
127 | sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act), | |
128 | (unsigned long long)t->sector, t->bytes >> 9); | |
129 | output(tstring); | |
130 | } | |
131 | ||
132 | void log_generic(struct blk_io_trace *t, char act) | |
133 | { | |
134 | sprintf(tstring,"%s %Lu + %u\n", setup_header(t, act), | |
135 | (unsigned long long)t->sector, t->bytes >> 9); | |
136 | output(tstring); | |
137 | } | |
138 | ||
139 | void log_pc(struct blk_io_trace *t, char act) | |
140 | { | |
141 | int i, ret; | |
142 | unsigned char buf[64]; | |
143 | ||
144 | sprintf(tstring,"%s\n", setup_header(t, act)); | |
145 | output(tstring); | |
146 | ||
147 | if (t->pdu_len > sizeof(buf)) { | |
148 | fprintf(stderr, "Payload too large %d\n", t->pdu_len); | |
149 | return; | |
150 | } | |
151 | ||
152 | ret = read(current->dfd, buf, t->pdu_len); | |
153 | if (ret != t->pdu_len) { | |
154 | fprintf(stderr,"read(%d) failed on %s - %d\n", t->pdu_len, | |
155 | current->dname, ret); | |
156 | exit(1); | |
157 | } | |
158 | ||
159 | for (i = 0; i < t->pdu_len; i++) { | |
160 | sprintf(tstring,"%02x ", buf[i]); | |
161 | output(tstring); | |
162 | } | |
163 | ||
164 | if (act == 'C') { | |
165 | sprintf(tstring,"[%d]", t->error); | |
166 | output(tstring); | |
167 | } | |
168 | ||
169 | printf("\n"); | |
170 | } | |
171 | ||
172 | void dump_trace_pc(struct blk_io_trace *t) | |
173 | { | |
174 | switch (t->action & 0xffff) { | |
175 | case __BLK_TA_QUEUE: | |
176 | log_generic(t, 'Q'); | |
177 | break; | |
178 | case __BLK_TA_GETRQ: | |
179 | log_generic(t, 'G'); | |
180 | break; | |
181 | case __BLK_TA_SLEEPRQ: | |
182 | log_generic(t, 'S'); | |
183 | break; | |
184 | case __BLK_TA_REQUEUE: | |
185 | log_generic(t, 'R'); | |
186 | break; | |
187 | case __BLK_TA_ISSUE: | |
188 | log_pc(t, 'D'); | |
189 | break; | |
190 | case __BLK_TA_COMPLETE: | |
191 | log_pc(t, 'C'); | |
192 | break; | |
193 | default: | |
194 | fprintf(stderr, "Bad pc action %x\n", t->action); | |
195 | return; | |
196 | } | |
197 | ||
198 | events++; | |
199 | } | |
200 | ||
201 | void dump_trace_fs(struct blk_io_trace *t) | |
202 | { | |
203 | int w = t->action & BLK_TC_ACT(BLK_TC_WRITE); | |
204 | ||
205 | switch (t->action & 0xffff) { | |
206 | case __BLK_TA_QUEUE: | |
207 | account_q(w, t->bytes); | |
208 | log_queue(t, 'Q'); | |
209 | break; | |
210 | case __BLK_TA_BACKMERGE: | |
211 | account_m(w, t->bytes); | |
212 | log_merge(t, 'M'); | |
213 | break; | |
214 | case __BLK_TA_FRONTMERGE: | |
215 | account_m(w, t->bytes); | |
216 | log_merge(t, 'F'); | |
217 | break; | |
218 | case __BLK_TA_GETRQ: | |
219 | log_generic(t, 'G'); | |
220 | break; | |
221 | case __BLK_TA_SLEEPRQ: | |
222 | log_generic(t, 'S'); | |
223 | break; | |
224 | case __BLK_TA_REQUEUE: | |
225 | log_queue(t, 'R'); | |
226 | break; | |
227 | case __BLK_TA_ISSUE: | |
228 | log_issue(t, 'D'); | |
229 | break; | |
230 | case __BLK_TA_COMPLETE: | |
231 | account_c(w, t->bytes); | |
232 | log_complete(t, 'C'); | |
233 | break; | |
234 | default: | |
235 | fprintf(stderr, "Bad fs action %x\n", t->action); | |
236 | return; | |
237 | } | |
238 | ||
239 | events++; | |
240 | } | |
241 | ||
242 | void dump_trace(struct blk_io_trace *t) | |
243 | { | |
244 | if (t->action & BLK_TC_ACT(BLK_TC_PC)) | |
245 | dump_trace_pc(t); | |
246 | else | |
247 | dump_trace_fs(t); | |
248 | } | |
249 | ||
250 | void show_stats(void) | |
251 | { | |
252 | printf("\nReads:"); | |
253 | printf("\tQueued: %'8lu, %'8LuKiB\n", qreads, qread_kb); | |
254 | printf("\tCompleted: %'8lu, %'8LuKiB\n", creads, cread_kb); | |
255 | printf("\tMerges: %'8lu\n", mreads); | |
256 | ||
257 | printf("Writes:"); | |
258 | printf("\tQueued: %'8lu, %'8LuKiB\n", qwrites, qwrite_kb); | |
259 | printf("\tCompleted: %'8lu, %'8LuKiB\n", cwrites, cwrite_kb); | |
260 | printf("\tMerges: %'8lu\n", mwrites); | |
261 | ||
262 | printf("Events: %'Lu\n", events); | |
263 | printf("Missed events: %'Lu\n", missed_events); | |
264 | } | |
265 | ||
266 | int compar(const void *t1, const void *t2) | |
267 | { | |
268 | long v1 = (long)(((struct blk_io_trace *)t1)->sequence); | |
269 | long v2 = (long)(((struct blk_io_trace *)t2)->sequence); | |
270 | ||
271 | return v1 - v2; | |
272 | } | |
273 | ||
274 | int main(int argc, char *argv[]) | |
275 | { | |
276 | char *p, *dev; | |
277 | int i, nfiles, nelems, nb, ret; | |
278 | struct per_file_info *pfi; | |
279 | struct blk_io_trace *traces, *tip; | |
280 | ||
281 | if (argc != 2) { | |
282 | fprintf(stderr, "Usage %s <dev>\n", argv[0]); | |
283 | return 1; | |
284 | } | |
285 | ||
286 | dev = argv[1]; | |
287 | ||
288 | printf("First pass:\n"); | |
289 | nfiles = nelems = 0; | |
290 | for (i = 0, pfi = &per_file_info[0]; i < MAX_CPUS; i++, pfi++) { | |
291 | pfi->cpu = i; | |
292 | pfi->start_time = 0; | |
293 | ||
294 | pfi->fname = malloc(128); | |
295 | sprintf(pfi->fname, "%s_out.%d", dev, i); | |
296 | if (stat(pfi->fname, &pfi->stat) < 0) | |
297 | break; | |
298 | if (!S_ISREG(pfi->stat.st_mode)) { | |
299 | fprintf(stderr, "Bad file type %s\n", pfi->fname); | |
300 | return 1; | |
301 | } | |
302 | ||
303 | nfiles++; | |
304 | pfi->nelems = NELEMS(pfi); | |
305 | nelems += pfi->nelems; | |
306 | printf("\t%2d %10s %15d\n", i, pfi->fname, pfi->nelems); | |
307 | ||
308 | } | |
309 | printf("\t %15d\n", nelems); | |
310 | ||
311 | if (!i) { | |
312 | fprintf(stderr, "No files found\n"); | |
313 | return 1; | |
314 | } | |
315 | ||
316 | traces = malloc(nelems * sizeof(struct blk_io_trace)); | |
317 | if (traces == NULL) { | |
318 | fprintf(stderr, "Can not allocate %d\n", | |
319 | nelems * (int) sizeof(struct blk_io_trace)); | |
320 | return 1; | |
321 | } | |
322 | ||
323 | printf("Second pass:\n"); | |
324 | p = (char *)traces; | |
325 | for (i = 0, pfi = per_file_info; i < nfiles; i++, pfi++) { | |
326 | pfi->fd = open(pfi->fname, O_RDONLY); | |
327 | if (pfi->fd < 0) { | |
328 | perror(pfi->fname); | |
329 | return 1; | |
330 | } | |
331 | ||
332 | pfi->dname = malloc(128); | |
96b34e39 | 333 | sprintf(pfi->dname, 127, "%s_dat.%d", dev, i); |
d0ca268b JA |
334 | pfi->dfd = open(pfi->dname, O_RDONLY); |
335 | if (pfi->dfd < 0) { | |
336 | perror(pfi->dname); | |
337 | return 1; | |
338 | } | |
339 | ||
340 | pfi->ofname = malloc(128); | |
96b34e39 | 341 | snprintf(pfi->ofname, 127, "%s_log.%d", dev, i); |
d0ca268b JA |
342 | pfi->ofp = fopen(pfi->ofname, "w"); |
343 | if (pfi->ofp == NULL) { | |
344 | perror(pfi->ofname); | |
345 | return 1; | |
346 | } | |
347 | ||
348 | printf("\tProcessing %s...", pfi->fname); fflush(stdout); | |
349 | nb = pfi->stat.st_size; | |
350 | ret = read(pfi->fd, p, nb); | |
351 | if (ret != nb) { | |
352 | perror(pfi->fname); | |
353 | fprintf(stderr,"\nFATAL: read(%d) -> %d\n", nb, ret); | |
354 | return 1; | |
355 | } | |
356 | printf("\n"); fflush(stdout); | |
357 | p += nb; | |
358 | close(pfi->fd); | |
359 | } | |
360 | ||
361 | printf("Sorting..."); fflush(stdout); | |
362 | qsort(traces, nelems, sizeof(struct blk_io_trace), compar); | |
363 | printf("\n\n"); | |
364 | ||
365 | for (i = 0, tip = traces; i < nelems; i++, tip++) { | |
fd92da24 JA |
366 | int cpu = tip->magic; |
367 | ||
368 | if (cpu >= MAX_CPUS) { | |
369 | fprintf(stderr, "CPU number too large (%d)\n", cpu); | |
370 | return 1; | |
371 | } | |
d0ca268b JA |
372 | |
373 | current = &per_file_info[cpu]; | |
374 | ||
375 | /* | |
376 | * offset time by first trace event. | |
377 | * | |
378 | * NOTE: This is *cpu* relative, thus you can not | |
379 | * compare times ACROSS cpus. | |
380 | */ | |
381 | if (current->start_time == 0) | |
382 | current->start_time = tip->time; | |
383 | ||
384 | tip->time -= current->start_time; | |
385 | ||
386 | dump_trace(tip); | |
387 | } | |
388 | ||
389 | show_stats(); | |
390 | return 0; | |
391 | } | |
392 | ||
393 |