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 20 static inline int valid_spec(int spec) 21 { 22 return strchr(VALID_SPECS, spec) != NULL; 23 } 24 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 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 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 * 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 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 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 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 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 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 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 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 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
