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 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 * 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 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 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 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 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 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 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 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 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
