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