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