1 /*
2 * This file contains format parsing code for blkparse, allowing you to
3 * customize the individual action format and generel output format.
4 */
5 #include <stdio.h>
6 #include <string.h>
7 #include <stdlib.h>
8 #include <unistd.h>
9 #include <ctype.h>
10 #include <time.h>
11
12 #include "blktrace.h"
13
14 #define VALID_SPECS "ABCDFGIMPQRSTUWX"
15
16 #define HEADER "%D %2c %8s %5T.%9t %5p %2a %3d "
17
18 static char *override_format[256];
19
valid_spec(int spec)20 static inline int valid_spec(int spec)
21 {
22 return strchr(VALID_SPECS, spec) != NULL;
23 }
24
set_all_format_specs(char * option)25 void set_all_format_specs(char *option)
26 {
27 char *p;
28
29 for (p = VALID_SPECS; *p; p++)
30 if (override_format[(int)(*p)] == NULL)
31 override_format[(int)(*p)] = strdup(option);
32 }
33
add_format_spec(char * option)34 int add_format_spec(char *option)
35 {
36 int spec = optarg[0];
37
38 if (!valid_spec(spec)) {
39 fprintf(stderr,"Bad format specifier %c\n", spec);
40 return 1;
41 }
42 if (optarg[1] != ',') {
43 fprintf(stderr,"Bad format specifier - need ',' %s\n", option);
44 return 1;
45 }
46 option += 2;
47
48 override_format[spec] = strdup(option);
49
50 return 0;
51 }
52
fill_rwbs(char * rwbs,struct blk_io_trace * t)53 static inline void fill_rwbs(char *rwbs, struct blk_io_trace *t)
54 {
55 int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
56 int a = t->action & BLK_TC_ACT(BLK_TC_AHEAD);
57 int s = t->action & BLK_TC_ACT(BLK_TC_SYNC);
58 int m = t->action & BLK_TC_ACT(BLK_TC_META);
59 int d = t->action & BLK_TC_ACT(BLK_TC_DISCARD);
60 int f = t->action & BLK_TC_ACT(BLK_TC_FLUSH);
61 int u = t->action & BLK_TC_ACT(BLK_TC_FUA);
62 int i = 0;
63
64 if (f)
65 rwbs[i++] = 'F'; /* flush */
66
67 if (d)
68 rwbs[i++] = 'D';
69 else if (w)
70 rwbs[i++] = 'W';
71 else if (t->bytes)
72 rwbs[i++] = 'R';
73 else
74 rwbs[i++] = 'N';
75
76 if (u)
77 rwbs[i++] = 'F'; /* fua */
78 if (a)
79 rwbs[i++] = 'A';
80 if (s)
81 rwbs[i++] = 'S';
82 if (m)
83 rwbs[i++] = 'M';
84
85 rwbs[i] = '\0';
86 }
87
88 static const char *
print_time(unsigned long long timestamp)89 print_time(unsigned long long timestamp)
90 {
91 static char timebuf[128];
92 struct tm *tm;
93 time_t sec;
94 unsigned long nsec;
95
96 sec = abs_start_time.tv_sec + SECONDS(timestamp);
97 nsec = abs_start_time.tv_nsec + NANO_SECONDS(timestamp);
98 if (nsec >= 1000000000) {
99 nsec -= 1000000000;
100 sec += 1;
101 }
102
103 tm = localtime(&sec);
104 snprintf(timebuf, sizeof(timebuf),
105 "%02u:%02u:%02u.%06lu",
106 tm->tm_hour,
107 tm->tm_min,
108 tm->tm_sec,
109 nsec / 1000);
110 return timebuf;
111 }
112
pdu_rest_is_zero(unsigned char * pdu,int len)113 static inline int pdu_rest_is_zero(unsigned char *pdu, int len)
114 {
115 static char zero[4096];
116
117 return !memcmp(pdu, zero, len);
118 }
119
dump_pdu(unsigned char * pdu_buf,int pdu_len)120 static char *dump_pdu(unsigned char *pdu_buf, int pdu_len)
121 {
122 static char p[4096];
123 int i, len;
124
125 if (!pdu_buf || !pdu_len)
126 return NULL;
127
128 for (len = 0, i = 0; i < pdu_len; i++) {
129 if (i)
130 len += sprintf(p + len, " ");
131
132 len += sprintf(p + len, "%02x", pdu_buf[i]);
133
134 /*
135 * usually dump for cdb dumps where we can see lots of
136 * zeroes, stop when the rest is just zeroes and indicate
137 * so with a .. appended
138 */
139 if (!pdu_buf[i] && pdu_rest_is_zero(pdu_buf + i, pdu_len - i)) {
140 sprintf(p + len, " ..");
141 break;
142 }
143 }
144
145 return p;
146 }
147
148 #define pdu_start(t) (((void *) (t) + sizeof(struct blk_io_trace)))
149
get_pdu_int(struct blk_io_trace * t)150 static unsigned int get_pdu_int(struct blk_io_trace *t)
151 {
152 __u64 *val = pdu_start(t);
153
154 return be64_to_cpu(*val);
155 }
156
get_pdu_remap(struct blk_io_trace * t,struct blk_io_trace_remap * r)157 static void get_pdu_remap(struct blk_io_trace *t, struct blk_io_trace_remap *r)
158 {
159 struct blk_io_trace_remap *__r = pdu_start(t);
160 __u64 sector_from = __r->sector_from;
161
162 r->device_from = be32_to_cpu(__r->device_from);
163 r->device_to = be32_to_cpu(__r->device_to);
164 r->sector_from = be64_to_cpu(sector_from);
165 }
166
print_field(char * act,struct per_cpu_info * pci,struct blk_io_trace * t,unsigned long long elapsed,int pdu_len,unsigned char * pdu_buf,char field,int minus,int has_w,int width)167 static void print_field(char *act, struct per_cpu_info *pci,
168 struct blk_io_trace *t, unsigned long long elapsed,
169 int pdu_len, unsigned char *pdu_buf, char field,
170 int minus, int has_w, int width)
171 {
172 char format[64];
173
174 if (has_w) {
175 if (minus)
176 sprintf(format, "%%-%d", width);
177 else
178 sprintf(format, "%%%d", width);
179 } else
180 sprintf(format, "%%");
181
182 switch (field) {
183 case 'a':
184 fprintf(ofp, strcat(format, "s"), act);
185 break;
186 case 'c':
187 fprintf(ofp, strcat(format, "d"), pci->cpu);
188 break;
189 case 'C': {
190 char *name = find_process_name(t->pid);
191
192 fprintf(ofp, strcat(format, "s"), name);
193 break;
194 }
195 case 'd': {
196 char rwbs[8];
197
198 fill_rwbs(rwbs, t);
199 fprintf(ofp, strcat(format, "s"), rwbs);
200 break;
201 }
202 case 'D': /* format width ignored */
203 fprintf(ofp,"%3d,%-3d", MAJOR(t->device), MINOR(t->device));
204 break;
205 case 'e':
206 fprintf(ofp, strcat(format, "d"), t->error);
207 break;
208 case 'M':
209 fprintf(ofp, strcat(format, "d"), MAJOR(t->device));
210 break;
211 case 'm':
212 fprintf(ofp, strcat(format, "d"), MINOR(t->device));
213 break;
214 case 'n':
215 fprintf(ofp, strcat(format, "u"), t_sec(t));
216 break;
217 case 'N':
218 fprintf(ofp, strcat(format, "u"), t->bytes);
219 break;
220 case 'p':
221 fprintf(ofp, strcat(format, "u"), t->pid);
222 break;
223 case 'P': { /* format width ignored */
224 char *p = dump_pdu(pdu_buf, pdu_len);
225 if (p)
226 fprintf(ofp, "%s", p);
227 break;
228 }
229 case 's':
230 fprintf(ofp, strcat(format, "ld"), t->sequence);
231 break;
232 case 'S':
233 fprintf(ofp, strcat(format, "lu"), t->sector);
234 break;
235 case 't':
236 sprintf(format, "%%0%dlu", has_w ? width : 9);
237 fprintf(ofp, format, NANO_SECONDS(t->time));
238 break;
239 case 'T':
240 fprintf(ofp, strcat(format, "d"), SECONDS(t->time));
241 break;
242 case 'u':
243 if (elapsed == -1ULL) {
244 fprintf(stderr, "Expecting elapsed value\n");
245 exit(1);
246 }
247 fprintf(ofp, strcat(format, "llu"), elapsed / 1000);
248 break;
249 case 'U':
250 fprintf(ofp, strcat(format, "u"), get_pdu_int(t));
251 break;
252 case 'z':
253 fprintf(ofp, strcat(format, "s"), print_time(t->time));
254 break;
255 default:
256 fprintf(ofp,strcat(format, "c"), field);
257 break;
258 }
259 }
260
parse_field(char * act,struct per_cpu_info * pci,struct blk_io_trace * t,unsigned long long elapsed,int pdu_len,unsigned char * pdu_buf,char * master_format)261 static char *parse_field(char *act, struct per_cpu_info *pci,
262 struct blk_io_trace *t, unsigned long long elapsed,
263 int pdu_len, unsigned char *pdu_buf,
264 char *master_format)
265 {
266 int minus = 0;
267 int has_w = 0;
268 int width = 0;
269 char *p = master_format;
270
271 if (*p == '-') {
272 minus = 1;
273 p++;
274 }
275 if (isdigit(*p)) {
276 has_w = 1;
277 do {
278 width = (width * 10) + (*p++ - '0');
279 } while ((*p) && (isdigit(*p)));
280 }
281 if (*p) {
282 print_field(act, pci, t, elapsed, pdu_len, pdu_buf, *p++,
283 minus, has_w, width);
284 }
285 return p;
286 }
287
process_default(char * act,struct per_cpu_info * pci,struct blk_io_trace * t,unsigned long long elapsed,int pdu_len,unsigned char * pdu_buf)288 static void process_default(char *act, struct per_cpu_info *pci,
289 struct blk_io_trace *t, unsigned long long elapsed,
290 int pdu_len, unsigned char *pdu_buf)
291 {
292 struct blk_io_trace_remap r = { .device_from = 0, };
293 char rwbs[8];
294 char *name;
295
296 fill_rwbs(rwbs, t);
297
298 /*
299 * For remaps we have to modify the device using the remap structure
300 * passed up.
301 */
302 if (act[0] == 'A') {
303 get_pdu_remap(t, &r);
304 t->device = r.device_to;
305 }
306
307 /*
308 * The header is always the same
309 */
310 fprintf(ofp, "%3d,%-3d %2d %8d %5d.%09lu %5u %2s %3s ",
311 MAJOR(t->device), MINOR(t->device), pci->cpu, t->sequence,
312 (int) SECONDS(t->time), (unsigned long) NANO_SECONDS(t->time),
313 t->pid, act, rwbs);
314
315 name = find_process_name(t->pid);
316
317 switch (act[0]) {
318 case 'R': /* Requeue */
319 case 'C': /* Complete */
320 if (t->action & BLK_TC_ACT(BLK_TC_PC)) {
321 char *p = dump_pdu(pdu_buf, pdu_len);
322 if (p)
323 fprintf(ofp, "(%s) ", p);
324 fprintf(ofp, "[%d]\n", t->error);
325 } else {
326 if (elapsed != -1ULL) {
327 if (t_sec(t))
328 fprintf(ofp, "%llu + %u (%8llu) [%d]\n",
329 (unsigned long long) t->sector,
330 t_sec(t), elapsed, t->error);
331 else
332 fprintf(ofp, "%llu (%8llu) [%d]\n",
333 (unsigned long long) t->sector,
334 elapsed, t->error);
335 } else {
336 if (t_sec(t))
337 fprintf(ofp, "%llu + %u [%d]\n",
338 (unsigned long long) t->sector,
339 t_sec(t), t->error);
340 else
341 fprintf(ofp, "%llu [%d]\n",
342 (unsigned long long) t->sector,
343 t->error);
344 }
345 }
346 break;
347
348 case 'D': /* Issue */
349 case 'I': /* Insert */
350 case 'Q': /* Queue */
351 case 'B': /* Bounce */
352 if (t->action & BLK_TC_ACT(BLK_TC_PC)) {
353 char *p;
354 fprintf(ofp, "%u ", t->bytes);
355 p = dump_pdu(pdu_buf, pdu_len);
356 if (p)
357 fprintf(ofp, "(%s) ", p);
358 fprintf(ofp, "[%s]\n", name);
359 } else {
360 if (elapsed != -1ULL) {
361 if (t_sec(t))
362 fprintf(ofp, "%llu + %u (%8llu) [%s]\n",
363 (unsigned long long) t->sector,
364 t_sec(t), elapsed, name);
365 else
366 fprintf(ofp, "(%8llu) [%s]\n", elapsed,
367 name);
368 } else {
369 if (t_sec(t))
370 fprintf(ofp, "%llu + %u [%s]\n",
371 (unsigned long long) t->sector,
372 t_sec(t), name);
373 else
374 fprintf(ofp, "[%s]\n", name);
375 }
376 }
377 break;
378
379 case 'M': /* Back merge */
380 case 'F': /* Front merge */
381 case 'G': /* Get request */
382 case 'S': /* Sleep request */
383 if (t_sec(t))
384 fprintf(ofp, "%llu + %u [%s]\n",
385 (unsigned long long) t->sector, t_sec(t), name);
386 else
387 fprintf(ofp, "[%s]\n", name);
388 break;
389
390 case 'P': /* Plug */
391 fprintf(ofp, "[%s]\n", name);
392 break;
393
394 case 'U': /* Unplug IO */
395 case 'T': /* Unplug timer */
396 fprintf(ofp, "[%s] %u\n", name, get_pdu_int(t));
397 break;
398
399 case 'A': /* remap */
400 get_pdu_remap(t, &r);
401 fprintf(ofp, "%llu + %u <- (%d,%d) %llu\n",
402 (unsigned long long) t->sector, t_sec(t),
403 MAJOR(r.device_from), MINOR(r.device_from),
404 (unsigned long long) r.sector_from);
405 break;
406
407 case 'X': /* Split */
408 fprintf(ofp, "%llu / %u [%s]\n", (unsigned long long) t->sector,
409 get_pdu_int(t), name);
410 break;
411
412 case 'm': /* Message */
413 fprintf(ofp, "%*s\n", pdu_len, pdu_buf);
414 break;
415
416 default:
417 fprintf(stderr, "Unknown action %c\n", act[0]);
418 break;
419 }
420
421 }
422
process_fmt(char * act,struct per_cpu_info * pci,struct blk_io_trace * t,unsigned long long elapsed,int pdu_len,unsigned char * pdu_buf)423 void process_fmt(char *act, struct per_cpu_info *pci, struct blk_io_trace *t,
424 unsigned long long elapsed, int pdu_len,
425 unsigned char *pdu_buf)
426 {
427 char *p = override_format[(int) *act];
428
429 if (!p) {
430 process_default(act, pci, t, elapsed, pdu_len, pdu_buf);
431 return;
432 }
433
434 while (*p) {
435 switch (*p) {
436 case '%': /* Field specifier */
437 p++;
438 if (*p == '%')
439 fprintf(ofp, "%c", *p++);
440 else if (!*p)
441 fprintf(ofp, "%c", '%');
442 else
443 p = parse_field(act, pci, t, elapsed,
444 pdu_len, pdu_buf, p);
445 break;
446 case '\\': { /* escape */
447 switch (p[1]) {
448 case 'b': fprintf(ofp, "\b"); break;
449 case 'n': fprintf(ofp, "\n"); break;
450 case 'r': fprintf(ofp, "\r"); break;
451 case 't': fprintf(ofp, "\t"); break;
452 default:
453 fprintf(stderr,
454 "Invalid escape char in format %c\n",
455 p[1]);
456 exit(1);
457 /*NOTREACHED*/
458 }
459 p += 2;
460 break;
461 }
462 default:
463 fprintf(ofp, "%c", *p++);
464 break;
465 }
466 }
467 }
468
469
470