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