Commit | Line | Data |
---|---|---|
9e066e23 CM |
1 | /* |
2 | * Copyright (C) 2012 Fusion-io | |
3 | * | |
4 | * This program is free software; you can redistribute it and/or | |
5 | * modify it under the terms of the GNU General Public | |
6 | * License v2 as published by the Free Software Foundation. | |
7 | * | |
8 | * This program is distributed in the hope that it will be useful, | |
9 | * but WITHOUT ANY WARRANTY; without even the implied warranty of | |
10 | * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the | |
11 | * GNU General Public License for more details. | |
12 | * | |
13 | * You should have received a copy of the GNU General Public License | |
14 | * along with this program; if not, write to the Free Software | |
15 | * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA | |
16 | * | |
17 | * Parts of this file were imported from Jens Axboe's blktrace sources (also GPL) | |
18 | */ | |
19 | #include <sys/types.h> | |
20 | #include <sys/stat.h> | |
21 | #include <fcntl.h> | |
22 | #include <unistd.h> | |
23 | #include <stdlib.h> | |
24 | #include <stdio.h> | |
25 | #include <math.h> | |
26 | #include <inttypes.h> | |
27 | #include <string.h> | |
28 | #include <asm/types.h> | |
29 | #include <errno.h> | |
30 | #include <sys/mman.h> | |
31 | #include <time.h> | |
32 | #include <math.h> | |
33 | ||
34 | #include "plot.h" | |
35 | #include "blkparse.h" | |
36 | #include "list.h" | |
37 | #include "tracers.h" | |
38 | ||
39 | #define IO_HASH_TABLE_BITS 11 | |
40 | #define IO_HASH_TABLE_SIZE (1 << IO_HASH_TABLE_BITS) | |
41 | static struct list_head io_hash_table[IO_HASH_TABLE_SIZE]; | |
42 | static u64 ios_in_flight = 0; | |
43 | ||
0a43b43f JK |
44 | #define PROCESS_HASH_TABLE_BITS 7 |
45 | #define PROCESS_HASH_TABLE_SIZE (1 << PROCESS_HASH_TABLE_BITS) | |
46 | static struct list_head process_hash_table[PROCESS_HASH_TABLE_SIZE]; | |
47 | ||
f2e40ddd | 48 | extern int plot_io_action; |
0a43b43f | 49 | extern int io_per_process; |
9e066e23 CM |
50 | |
51 | /* | |
52 | * Trace categories | |
53 | */ | |
54 | enum { | |
55 | BLK_TC_READ = 1 << 0, /* reads */ | |
56 | BLK_TC_WRITE = 1 << 1, /* writes */ | |
57 | BLK_TC_FLUSH = 1 << 2, /* flush */ | |
58 | BLK_TC_SYNC = 1 << 3, /* sync */ | |
59 | BLK_TC_QUEUE = 1 << 4, /* queueing/merging */ | |
60 | BLK_TC_REQUEUE = 1 << 5, /* requeueing */ | |
61 | BLK_TC_ISSUE = 1 << 6, /* issue */ | |
62 | BLK_TC_COMPLETE = 1 << 7, /* completions */ | |
63 | BLK_TC_FS = 1 << 8, /* fs requests */ | |
64 | BLK_TC_PC = 1 << 9, /* pc requests */ | |
65 | BLK_TC_NOTIFY = 1 << 10, /* special message */ | |
66 | BLK_TC_AHEAD = 1 << 11, /* readahead */ | |
67 | BLK_TC_META = 1 << 12, /* metadata */ | |
68 | BLK_TC_DISCARD = 1 << 13, /* discard requests */ | |
69 | BLK_TC_DRV_DATA = 1 << 14, /* binary driver data */ | |
70 | BLK_TC_FUA = 1 << 15, /* fua requests */ | |
71 | ||
72 | BLK_TC_END = 1 << 15, /* we've run out of bits! */ | |
73 | }; | |
74 | ||
75 | #define BLK_TC_SHIFT (16) | |
76 | #define BLK_TC_ACT(act) ((act) << BLK_TC_SHIFT) | |
77 | #define BLK_DATADIR(a) (((a) >> BLK_TC_SHIFT) & (BLK_TC_READ | BLK_TC_WRITE)) | |
78 | ||
79 | /* | |
80 | * Basic trace actions | |
81 | */ | |
82 | enum { | |
83 | __BLK_TA_QUEUE = 1, /* queued */ | |
84 | __BLK_TA_BACKMERGE, /* back merged to existing rq */ | |
85 | __BLK_TA_FRONTMERGE, /* front merge to existing rq */ | |
86 | __BLK_TA_GETRQ, /* allocated new request */ | |
87 | __BLK_TA_SLEEPRQ, /* sleeping on rq allocation */ | |
88 | __BLK_TA_REQUEUE, /* request requeued */ | |
89 | __BLK_TA_ISSUE, /* sent to driver */ | |
90 | __BLK_TA_COMPLETE, /* completed by driver */ | |
91 | __BLK_TA_PLUG, /* queue was plugged */ | |
92 | __BLK_TA_UNPLUG_IO, /* queue was unplugged by io */ | |
93 | __BLK_TA_UNPLUG_TIMER, /* queue was unplugged by timer */ | |
94 | __BLK_TA_INSERT, /* insert request */ | |
95 | __BLK_TA_SPLIT, /* bio was split */ | |
96 | __BLK_TA_BOUNCE, /* bio was bounced */ | |
97 | __BLK_TA_REMAP, /* bio was remapped */ | |
98 | __BLK_TA_ABORT, /* request aborted */ | |
99 | __BLK_TA_DRV_DATA, /* binary driver data */ | |
100 | }; | |
101 | ||
1582ecc9 JK |
102 | #define BLK_TA_MASK ((1 << BLK_TC_SHIFT) - 1) |
103 | ||
9e066e23 CM |
104 | /* |
105 | * Notify events. | |
106 | */ | |
107 | enum blktrace_notify { | |
108 | __BLK_TN_PROCESS = 0, /* establish pid/name mapping */ | |
109 | __BLK_TN_TIMESTAMP, /* include system clock */ | |
110 | __BLK_TN_MESSAGE, /* Character string message */ | |
111 | }; | |
112 | ||
113 | /* | |
114 | * Trace actions in full. Additionally, read or write is masked | |
115 | */ | |
116 | #define BLK_TA_QUEUE (__BLK_TA_QUEUE | BLK_TC_ACT(BLK_TC_QUEUE)) | |
117 | #define BLK_TA_BACKMERGE (__BLK_TA_BACKMERGE | BLK_TC_ACT(BLK_TC_QUEUE)) | |
118 | #define BLK_TA_FRONTMERGE (__BLK_TA_FRONTMERGE | BLK_TC_ACT(BLK_TC_QUEUE)) | |
119 | #define BLK_TA_GETRQ (__BLK_TA_GETRQ | BLK_TC_ACT(BLK_TC_QUEUE)) | |
120 | #define BLK_TA_SLEEPRQ (__BLK_TA_SLEEPRQ | BLK_TC_ACT(BLK_TC_QUEUE)) | |
121 | #define BLK_TA_REQUEUE (__BLK_TA_REQUEUE | BLK_TC_ACT(BLK_TC_REQUEUE)) | |
122 | #define BLK_TA_ISSUE (__BLK_TA_ISSUE | BLK_TC_ACT(BLK_TC_ISSUE)) | |
123 | #define BLK_TA_COMPLETE (__BLK_TA_COMPLETE| BLK_TC_ACT(BLK_TC_COMPLETE)) | |
124 | #define BLK_TA_PLUG (__BLK_TA_PLUG | BLK_TC_ACT(BLK_TC_QUEUE)) | |
125 | #define BLK_TA_UNPLUG_IO (__BLK_TA_UNPLUG_IO | BLK_TC_ACT(BLK_TC_QUEUE)) | |
126 | #define BLK_TA_UNPLUG_TIMER (__BLK_TA_UNPLUG_TIMER | BLK_TC_ACT(BLK_TC_QUEUE)) | |
127 | #define BLK_TA_INSERT (__BLK_TA_INSERT | BLK_TC_ACT(BLK_TC_QUEUE)) | |
128 | #define BLK_TA_SPLIT (__BLK_TA_SPLIT) | |
129 | #define BLK_TA_BOUNCE (__BLK_TA_BOUNCE) | |
130 | #define BLK_TA_REMAP (__BLK_TA_REMAP | BLK_TC_ACT(BLK_TC_QUEUE)) | |
131 | #define BLK_TA_ABORT (__BLK_TA_ABORT | BLK_TC_ACT(BLK_TC_QUEUE)) | |
132 | #define BLK_TA_DRV_DATA (__BLK_TA_DRV_DATA | BLK_TC_ACT(BLK_TC_DRV_DATA)) | |
133 | ||
134 | #define BLK_TN_PROCESS (__BLK_TN_PROCESS | BLK_TC_ACT(BLK_TC_NOTIFY)) | |
135 | #define BLK_TN_TIMESTAMP (__BLK_TN_TIMESTAMP | BLK_TC_ACT(BLK_TC_NOTIFY)) | |
136 | #define BLK_TN_MESSAGE (__BLK_TN_MESSAGE | BLK_TC_ACT(BLK_TC_NOTIFY)) | |
137 | ||
138 | #define BLK_IO_TRACE_MAGIC 0x65617400 | |
139 | #define BLK_IO_TRACE_VERSION 0x07 | |
140 | /* | |
141 | * The trace itself | |
142 | */ | |
143 | struct blk_io_trace { | |
144 | __u32 magic; /* MAGIC << 8 | version */ | |
145 | __u32 sequence; /* event number */ | |
146 | __u64 time; /* in nanoseconds */ | |
147 | __u64 sector; /* disk offset */ | |
148 | __u32 bytes; /* transfer length */ | |
149 | __u32 action; /* what happened */ | |
150 | __u32 pid; /* who did it */ | |
151 | __u32 device; /* device identifier (dev_t) */ | |
152 | __u32 cpu; /* on what cpu did it happen */ | |
153 | __u16 error; /* completion error */ | |
154 | __u16 pdu_len; /* length of data after this trace */ | |
155 | }; | |
156 | ||
157 | struct pending_io { | |
158 | /* sector offset of this IO */ | |
159 | u64 sector; | |
160 | ||
161 | /* time this IO was dispatched */ | |
162 | u64 dispatch_time; | |
163 | /* time this IO was finished */ | |
164 | u64 completion_time; | |
165 | struct list_head hash_list; | |
0a43b43f JK |
166 | /* process which queued this IO */ |
167 | u32 pid; | |
168 | }; | |
169 | ||
170 | struct pid_map { | |
171 | struct list_head hash_list; | |
172 | u32 pid; | |
173 | int index; | |
174 | char name[0]; | |
9e066e23 CM |
175 | }; |
176 | ||
177 | #define MINORBITS 20 | |
178 | #define MINORMASK ((1 << MINORBITS) - 1) | |
179 | #define SECONDS(x) ((unsigned long long)(x) / 1000000000) | |
180 | #define NANO_SECONDS(x) ((unsigned long long)(x) % 1000000000) | |
181 | #define DOUBLE_TO_NANO_ULL(d) ((unsigned long long)((d) * 1000000000)) | |
182 | #define CHECK_MAGIC(t) (((t)->magic & 0xffffff00) == BLK_IO_TRACE_MAGIC) | |
183 | ||
184 | void init_io_hash_table(void) | |
185 | { | |
186 | int i; | |
187 | struct list_head *head; | |
188 | ||
189 | for (i = 0; i < IO_HASH_TABLE_SIZE; i++) { | |
190 | head = io_hash_table + i; | |
191 | INIT_LIST_HEAD(head); | |
192 | } | |
193 | } | |
194 | ||
195 | /* taken from the kernel hash.h */ | |
196 | static inline u64 hash_sector(u64 val) | |
197 | { | |
198 | u64 hash = val; | |
199 | ||
200 | /* Sigh, gcc can't optimise this alone like it does for 32 bits. */ | |
201 | u64 n = hash; | |
202 | n <<= 18; | |
203 | hash -= n; | |
204 | n <<= 33; | |
205 | hash -= n; | |
206 | n <<= 3; | |
207 | hash += n; | |
208 | n <<= 3; | |
209 | hash -= n; | |
210 | n <<= 4; | |
211 | hash += n; | |
212 | n <<= 2; | |
213 | hash += n; | |
214 | ||
215 | /* High bits are more random, so use them. */ | |
216 | return hash >> (64 - IO_HASH_TABLE_BITS); | |
217 | } | |
218 | ||
0a43b43f | 219 | static int io_hash_table_insert(struct pending_io *ins_pio) |
9e066e23 CM |
220 | { |
221 | u64 sector = ins_pio->sector; | |
222 | int slot = hash_sector(sector); | |
223 | struct list_head *head; | |
224 | struct pending_io *pio; | |
225 | ||
226 | head = io_hash_table + slot; | |
227 | list_for_each_entry(pio, head, hash_list) { | |
228 | if (pio->sector == sector) | |
229 | return -EEXIST; | |
230 | } | |
231 | list_add_tail(&ins_pio->hash_list, head); | |
232 | return 0; | |
233 | } | |
234 | ||
0a43b43f | 235 | static struct pending_io *io_hash_table_search(u64 sector) |
9e066e23 CM |
236 | { |
237 | int slot = hash_sector(sector); | |
238 | struct list_head *head; | |
239 | struct pending_io *pio; | |
240 | ||
241 | head = io_hash_table + slot; | |
242 | list_for_each_entry(pio, head, hash_list) { | |
243 | if (pio->sector == sector) | |
244 | return pio; | |
245 | } | |
246 | return NULL; | |
247 | } | |
248 | ||
0a43b43f | 249 | static int hash_queued_io(struct blk_io_trace *io) |
9e066e23 CM |
250 | { |
251 | struct pending_io *pio; | |
252 | int ret; | |
253 | ||
254 | pio = calloc(1, sizeof(*pio)); | |
255 | pio->sector = io->sector; | |
0a43b43f | 256 | pio->pid = io->pid; |
9e066e23 | 257 | |
0a43b43f JK |
258 | ret = io_hash_table_insert(pio); |
259 | if (ret < 0) { | |
260 | /* crud, the IO is there already */ | |
9e066e23 | 261 | free(pio); |
0a43b43f | 262 | return ret; |
9e066e23 | 263 | } |
0a43b43f JK |
264 | return 0; |
265 | } | |
266 | ||
267 | static int hash_dispatched_io(struct blk_io_trace *io) | |
268 | { | |
269 | struct pending_io *pio; | |
270 | ||
271 | pio = io_hash_table_search(io->sector); | |
272 | if (!pio) { | |
273 | /* crud, the IO isn't here */ | |
274 | return -EEXIST; | |
275 | } | |
276 | pio->dispatch_time = io->time; | |
277 | return 0; | |
9e066e23 CM |
278 | } |
279 | ||
280 | static struct pending_io *hash_completed_io(struct blk_io_trace *io) | |
281 | { | |
282 | struct pending_io *pio; | |
283 | ||
0a43b43f | 284 | pio = io_hash_table_search(io->sector); |
9e066e23 CM |
285 | |
286 | if (!pio) | |
287 | return NULL; | |
288 | return pio; | |
289 | } | |
290 | ||
0a43b43f JK |
291 | void init_process_hash_table(void) |
292 | { | |
293 | int i; | |
294 | struct list_head *head; | |
295 | ||
296 | for (i = 0; i < PROCESS_HASH_TABLE_SIZE; i++) { | |
297 | head = process_hash_table + i; | |
298 | INIT_LIST_HEAD(head); | |
299 | } | |
300 | } | |
301 | ||
302 | static u32 hash_pid(u32 pid) | |
303 | { | |
304 | u32 hash = pid; | |
305 | ||
306 | hash ^= pid >> 3; | |
307 | hash ^= pid >> 3; | |
308 | hash ^= pid >> 4; | |
309 | hash ^= pid >> 6; | |
310 | return (hash & (PROCESS_HASH_TABLE_SIZE - 1)); | |
311 | } | |
312 | ||
313 | static struct pid_map *process_hash_search(u32 pid) | |
314 | { | |
315 | int slot = hash_pid(pid); | |
316 | struct list_head *head; | |
317 | struct pid_map *pm; | |
318 | ||
319 | head = process_hash_table + slot; | |
320 | list_for_each_entry(pm, head, hash_list) { | |
321 | if (pm->pid == pid) | |
322 | return pm; | |
323 | } | |
324 | return NULL; | |
325 | } | |
326 | ||
327 | static struct pid_map *process_hash_insert(u32 pid, char *name) | |
328 | { | |
329 | int slot = hash_pid(pid); | |
330 | struct pid_map *pm; | |
331 | int old_index = 0; | |
332 | char buf[16]; | |
333 | ||
334 | pm = process_hash_search(pid); | |
335 | if (pm) { | |
336 | /* Entry exists and name shouldn't be changed? */ | |
337 | if (!name || !strcmp(name, pm->name)) | |
338 | return pm; | |
339 | list_del(&pm->hash_list); | |
340 | old_index = pm->index; | |
341 | free(pm); | |
342 | } | |
343 | if (!name) { | |
344 | sprintf(buf, "[%u]", pid); | |
345 | name = buf; | |
346 | } | |
347 | pm = malloc(sizeof(struct pid_map) + strlen(name) + 1); | |
348 | pm->pid = pid; | |
349 | pm->index = old_index; | |
350 | strcpy(pm->name, name); | |
351 | list_add_tail(&pm->hash_list, process_hash_table + slot); | |
352 | ||
353 | return pm; | |
354 | } | |
355 | ||
9e066e23 CM |
356 | static void handle_notify(struct trace *trace) |
357 | { | |
358 | struct blk_io_trace *io = trace->io; | |
359 | void *payload = (char *)io + sizeof(*io); | |
360 | u32 two32[2]; | |
361 | ||
0a43b43f JK |
362 | if (io->action == BLK_TN_PROCESS) { |
363 | if (io_per_process) | |
364 | process_hash_insert(io->pid, payload); | |
365 | return; | |
366 | } | |
9e066e23 CM |
367 | |
368 | if (io->action != BLK_TN_TIMESTAMP) | |
369 | return; | |
370 | ||
371 | if (io->pdu_len != sizeof(two32)) | |
372 | return; | |
373 | ||
374 | memcpy(two32, payload, sizeof(two32)); | |
375 | trace->start_timestamp = io->time; | |
376 | trace->abs_start_time.tv_sec = two32[0]; | |
377 | trace->abs_start_time.tv_nsec = two32[1]; | |
378 | if (trace->abs_start_time.tv_nsec < 0) { | |
379 | trace->abs_start_time.tv_sec--; | |
380 | trace->abs_start_time.tv_nsec += 1000000000; | |
381 | } | |
382 | } | |
383 | ||
384 | int next_record(struct trace *trace) | |
385 | { | |
386 | int skip = trace->io->pdu_len; | |
387 | u64 offset; | |
388 | ||
389 | trace->cur += sizeof(*trace->io) + skip; | |
390 | offset = trace->cur - trace->start; | |
391 | if (offset >= trace->len) | |
392 | return 1; | |
393 | ||
394 | trace->io = (struct blk_io_trace *)trace->cur; | |
395 | return 0; | |
396 | } | |
397 | ||
398 | void first_record(struct trace *trace) | |
399 | { | |
400 | trace->cur = trace->start; | |
401 | trace->io = (struct blk_io_trace *)trace->cur; | |
402 | } | |
403 | ||
bfb0e441 CM |
404 | int is_io_event(struct blk_io_trace *test) |
405 | { | |
406 | char *message; | |
407 | if (!(test->action & BLK_TC_ACT(BLK_TC_NOTIFY))) | |
408 | return 1; | |
409 | if (test->action == BLK_TN_MESSAGE) { | |
410 | int len = test->pdu_len; | |
411 | if (len < 3) | |
412 | return 0; | |
413 | message = (char *)(test + 1); | |
414 | if (strncmp(message, "fio ", 4) == 0) { | |
415 | return 1; | |
416 | } | |
417 | } | |
418 | return 0; | |
419 | } | |
420 | ||
9e066e23 CM |
421 | u64 find_last_time(struct trace *trace) |
422 | { | |
423 | char *p = trace->start + trace->len; | |
424 | struct blk_io_trace *test; | |
425 | int search_len = 0; | |
426 | u64 found = 0; | |
427 | ||
428 | if (trace->len < sizeof(*trace->io)) | |
429 | return 0; | |
430 | p -= sizeof(*trace->io); | |
431 | while (p >= trace->start) { | |
432 | test = (struct blk_io_trace *)p; | |
bfb0e441 | 433 | if (CHECK_MAGIC(test) && is_io_event(test)) { |
9e066e23 CM |
434 | u64 offset = p - trace->start; |
435 | if (offset + sizeof(*test) + test->pdu_len == trace->len) { | |
436 | return test->time; | |
437 | } | |
438 | } | |
439 | p--; | |
440 | search_len++; | |
441 | if (search_len > 8192) { | |
442 | break; | |
443 | } | |
444 | } | |
445 | ||
446 | /* searching backwards didn't work out, we'll have to scan the file */ | |
447 | first_record(trace); | |
448 | while (1) { | |
bfb0e441 | 449 | if (is_io_event(trace->io)) |
9e066e23 CM |
450 | found = trace->io->time; |
451 | if (next_record(trace)) | |
452 | break; | |
453 | } | |
454 | first_record(trace); | |
455 | return found; | |
456 | } | |
457 | ||
bfb0e441 CM |
458 | int parse_fio_bank_message(struct trace *trace, u64 *bank_ret, u64 *offset_ret, |
459 | u64 *num_banks_ret) | |
460 | { | |
461 | char *s; | |
462 | char *next; | |
463 | char *message; | |
464 | struct blk_io_trace *test = trace->io; | |
465 | int len = test->pdu_len; | |
466 | u64 bank; | |
467 | u64 offset; | |
468 | u64 num_banks; | |
469 | ||
470 | if (!(test->action & BLK_TC_ACT(BLK_TC_NOTIFY))) | |
471 | return -1; | |
472 | if (test->action != BLK_TN_MESSAGE) | |
473 | return -1; | |
474 | ||
475 | /* the message is fio rw bank offset num_banks */ | |
476 | if (len < 3) | |
477 | return -1; | |
478 | message = (char *)(test + 1); | |
479 | if (strncmp(message, "fio r ", 6) != 0) | |
480 | return -1; | |
481 | ||
482 | message = strndup(message, len); | |
483 | s = strchr(message, ' '); | |
484 | if (!s) | |
485 | goto out; | |
486 | s++; | |
487 | s = strchr(s, ' '); | |
488 | if (!s) | |
489 | goto out; | |
490 | ||
491 | bank = strtoll(s, &next, 10); | |
492 | if (s == next) | |
493 | goto out; | |
494 | s = next; | |
495 | ||
496 | offset = strtoll(s, &next, 10); | |
497 | if (s == next) | |
498 | goto out; | |
499 | s = next; | |
500 | ||
501 | num_banks = strtoll(s, &next, 10); | |
502 | if (s == next) | |
503 | goto out; | |
504 | ||
505 | *bank_ret = bank; | |
506 | *offset_ret = offset; | |
507 | *num_banks_ret = num_banks; | |
508 | ||
509 | return 0; | |
510 | out: | |
511 | free(message); | |
512 | return -1; | |
513 | } | |
514 | ||
9b9fa04b JK |
515 | void find_extreme_offsets(struct trace *trace, u64 *min_ret, u64 *max_ret, u64 *max_bank_ret, |
516 | u64 *max_offset_ret) | |
9e066e23 CM |
517 | { |
518 | u64 found = 0; | |
9b9fa04b | 519 | u64 max = 0, min = ~(u64)0; |
bfb0e441 CM |
520 | u64 max_bank = 0; |
521 | u64 max_bank_offset = 0; | |
522 | u64 num_banks = 0; | |
9e066e23 CM |
523 | first_record(trace); |
524 | while (1) { | |
525 | if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) { | |
526 | found = trace->io->sector << 9; | |
9b9fa04b JK |
527 | if (found < min) |
528 | min = found; | |
9e066e23 | 529 | |
9b9fa04b JK |
530 | found += trace->io->bytes; |
531 | if (max < found) | |
9e066e23 | 532 | max = found; |
bfb0e441 CM |
533 | } else { |
534 | u64 bank; | |
535 | u64 offset; | |
536 | if (!parse_fio_bank_message(trace, &bank, | |
537 | &offset, &num_banks)) { | |
538 | if (bank > max_bank) | |
539 | max_bank = bank; | |
540 | if (offset > max_bank_offset) | |
541 | max_bank_offset = offset; | |
542 | } | |
9e066e23 CM |
543 | } |
544 | if (next_record(trace)) | |
545 | break; | |
546 | } | |
547 | first_record(trace); | |
9b9fa04b | 548 | *min_ret = min; |
bfb0e441 CM |
549 | *max_ret = max; |
550 | *max_bank_ret = max_bank; | |
551 | *max_offset_ret = max_bank_offset; | |
9e066e23 CM |
552 | } |
553 | ||
9b9fa04b | 554 | int filter_outliers(struct trace *trace, u64 min_offset, u64 max_offset, |
9e066e23 CM |
555 | u64 *yzoom_min, u64 *yzoom_max) |
556 | { | |
557 | int hits[11]; | |
558 | u64 max_per_bucket[11]; | |
9b9fa04b JK |
559 | u64 min_per_bucket[11]; |
560 | u64 bytes_per_bucket = (max_offset - min_offset + 1) / 10; | |
9e066e23 CM |
561 | int slot; |
562 | int fat_count = 0; | |
563 | ||
564 | memset(hits, 0, sizeof(int) * 11); | |
565 | memset(max_per_bucket, 0, sizeof(u64) * 11); | |
9b9fa04b | 566 | memset(min_per_bucket, 0xff, sizeof(u64) * 11); |
9e066e23 CM |
567 | first_record(trace); |
568 | while (1) { | |
41fdf407 JK |
569 | if (!(trace->io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) && |
570 | (trace->io->action & BLK_TA_MASK) == __BLK_TA_QUEUE) { | |
9b9fa04b JK |
571 | u64 off = (trace->io->sector << 9) - min_offset; |
572 | ||
573 | slot = (int)(off / bytes_per_bucket); | |
574 | hits[slot]++; | |
575 | if (off < min_per_bucket[slot]) | |
576 | min_per_bucket[slot] = off; | |
577 | ||
578 | off += trace->io->bytes; | |
579 | slot = (int)(off / bytes_per_bucket); | |
9e066e23 | 580 | hits[slot]++; |
9b9fa04b JK |
581 | if (off > max_per_bucket[slot]) |
582 | max_per_bucket[slot] = off; | |
9e066e23 CM |
583 | } |
584 | if (next_record(trace)) | |
585 | break; | |
586 | } | |
587 | first_record(trace); | |
588 | for (slot = 0; slot < 11; slot++) { | |
589 | if (hits[slot] > fat_count) { | |
590 | fat_count = hits[slot]; | |
591 | } | |
592 | } | |
593 | ||
594 | *yzoom_max = max_offset; | |
595 | for (slot = 10; slot >= 0; slot--) { | |
596 | double d = hits[slot]; | |
597 | ||
598 | if (d >= (double)fat_count * .05) { | |
9b9fa04b | 599 | *yzoom_max = max_per_bucket[slot] + min_offset; |
9e066e23 CM |
600 | break; |
601 | } | |
602 | } | |
603 | ||
9b9fa04b | 604 | *yzoom_min = min_offset; |
9e066e23 CM |
605 | for (slot = 0; slot < 10; slot++) { |
606 | double d = hits[slot]; | |
607 | ||
608 | if (d >= (double)fat_count * .05) { | |
9b9fa04b | 609 | *yzoom_min = min_per_bucket[slot] + min_offset; |
9e066e23 CM |
610 | break; |
611 | } | |
612 | } | |
613 | return 0; | |
614 | } | |
615 | ||
616 | static char *find_trace_file(char *filename) | |
617 | { | |
618 | int ret; | |
619 | struct stat st; | |
620 | char line[1024]; | |
621 | char *dot; | |
622 | char *try; | |
623 | ||
624 | ret = stat(filename, &st); | |
625 | if (ret == 0) | |
626 | return strdup(filename); | |
627 | ||
628 | snprintf(line, 1024, "%s.%s", filename, "dump"); | |
e199d546 | 629 | ret = stat(line, &st); |
9e066e23 CM |
630 | if (ret == 0) |
631 | return strdup(line); | |
632 | ||
633 | try = strdup(filename); | |
634 | dot = strrchr(try, '.'); | |
635 | if (!dot || strcmp(".dump", dot) != 0) { | |
e95ba659 | 636 | if (dot && dot != try) |
9e066e23 CM |
637 | *dot = '\0'; |
638 | snprintf(line, 1024, "%s%s", try, ".blktrace.0"); | |
639 | ret = stat(line, &st); | |
640 | if (ret == 0) { | |
641 | blktrace_to_dump(try); | |
642 | snprintf(line, 1024, "%s.%s", try, "dump"); | |
643 | ret = stat(line, &st); | |
644 | if (ret == 0) { | |
645 | free(try); | |
646 | return strdup(line); | |
647 | } | |
648 | } | |
649 | } | |
650 | free(try); | |
651 | return NULL; | |
652 | } | |
653 | struct trace *open_trace(char *filename) | |
654 | { | |
655 | int fd; | |
656 | char *p; | |
657 | struct stat st; | |
658 | int ret; | |
659 | struct trace *trace; | |
660 | char *found_filename; | |
661 | ||
662 | trace = calloc(1, sizeof(*trace)); | |
663 | if (!trace) { | |
664 | fprintf(stderr, "unable to allocate memory for trace\n"); | |
665 | return NULL; | |
666 | } | |
667 | ||
668 | found_filename = find_trace_file(filename); | |
669 | if (!found_filename) { | |
670 | fprintf(stderr, "Unable to find trace file %s\n", filename); | |
671 | goto fail; | |
672 | } | |
9e066e23 CM |
673 | filename = found_filename; |
674 | ||
675 | fd = open(filename, O_RDONLY); | |
676 | if (fd < 0) { | |
677 | fprintf(stderr, "Unable to open trace file %s err %s\n", filename, strerror(errno)); | |
678 | goto fail; | |
679 | } | |
680 | ret = fstat(fd, &st); | |
681 | if (ret < 0) { | |
682 | fprintf(stderr, "stat failed on %s err %s\n", filename, strerror(errno)); | |
683 | goto fail_fd; | |
684 | } | |
685 | p = mmap(NULL, st.st_size, PROT_READ, MAP_PRIVATE, fd, 0); | |
686 | if (p == MAP_FAILED) { | |
687 | fprintf(stderr, "Unable to mmap trace file %s, err %s\n", filename, strerror(errno)); | |
688 | goto fail_fd; | |
689 | } | |
690 | trace->fd = fd; | |
691 | trace->len = st.st_size; | |
692 | trace->start = p; | |
693 | trace->cur = p; | |
694 | trace->io = (struct blk_io_trace *)p; | |
695 | return trace; | |
696 | ||
697 | fail_fd: | |
698 | close(fd); | |
699 | fail: | |
700 | free(trace); | |
701 | return NULL; | |
702 | } | |
703 | static inline int tput_event(struct trace *trace) | |
704 | { | |
705 | if (trace->found_completion) | |
706 | return __BLK_TA_COMPLETE; | |
707 | if (trace->found_issue) | |
708 | return __BLK_TA_ISSUE; | |
709 | if (trace->found_queue) | |
710 | return __BLK_TA_QUEUE; | |
711 | ||
712 | return __BLK_TA_COMPLETE; | |
713 | } | |
714 | ||
f2e40ddd JK |
715 | int action_char_to_num(char action) |
716 | { | |
717 | switch (action) { | |
718 | case 'Q': | |
719 | return __BLK_TA_QUEUE; | |
720 | case 'D': | |
721 | return __BLK_TA_ISSUE; | |
722 | case 'C': | |
723 | return __BLK_TA_COMPLETE; | |
724 | } | |
725 | return -1; | |
726 | } | |
727 | ||
9e066e23 CM |
728 | static inline int io_event(struct trace *trace) |
729 | { | |
f2e40ddd JK |
730 | if (plot_io_action) |
731 | return plot_io_action; | |
9e066e23 CM |
732 | if (trace->found_queue) |
733 | return __BLK_TA_QUEUE; | |
734 | if (trace->found_issue) | |
735 | return __BLK_TA_ISSUE; | |
736 | if (trace->found_completion) | |
737 | return __BLK_TA_COMPLETE; | |
738 | ||
739 | return __BLK_TA_COMPLETE; | |
740 | } | |
741 | ||
742 | void add_tput(struct trace *trace, struct graph_line_data *gld) | |
743 | { | |
744 | struct blk_io_trace *io = trace->io; | |
1582ecc9 | 745 | int action = io->action & BLK_TA_MASK; |
9e066e23 CM |
746 | int seconds; |
747 | ||
748 | if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) | |
749 | return; | |
750 | ||
751 | if (action != tput_event(trace)) | |
752 | return; | |
753 | ||
754 | seconds = SECONDS(io->time); | |
35686f9b JK |
755 | if (seconds > gld->max_seconds) |
756 | return; | |
9e066e23 CM |
757 | |
758 | gld->data[seconds].sum += io->bytes; | |
759 | gld->data[seconds].count = 1; | |
760 | if (gld->data[seconds].sum > gld->max) | |
761 | gld->max = gld->data[seconds].sum; | |
762 | } | |
763 | ||
0a43b43f JK |
764 | #define GDD_PTR_ALLOC_STEP 16 |
765 | ||
766 | static struct pid_map *get_pid_map(struct trace_file *tf, u32 pid) | |
767 | { | |
768 | struct pid_map *pm; | |
769 | ||
770 | if (!io_per_process) { | |
771 | if (!tf->io_plots) | |
772 | tf->io_plots = 1; | |
773 | return NULL; | |
774 | } | |
775 | ||
776 | pm = process_hash_insert(pid, NULL); | |
777 | /* New entry? */ | |
778 | if (!pm->index) { | |
779 | if (tf->io_plots == tf->io_plots_allocated) { | |
780 | tf->io_plots_allocated += GDD_PTR_ALLOC_STEP; | |
781 | tf->gdd_reads = realloc(tf->gdd_reads, tf->io_plots_allocated * sizeof(struct graph_dot_data *)); | |
782 | if (!tf->gdd_reads) | |
783 | abort(); | |
784 | tf->gdd_writes = realloc(tf->gdd_writes, tf->io_plots_allocated * sizeof(struct graph_dot_data *)); | |
785 | if (!tf->gdd_writes) | |
786 | abort(); | |
787 | memset(tf->gdd_reads + tf->io_plots_allocated - GDD_PTR_ALLOC_STEP, | |
788 | 0, GDD_PTR_ALLOC_STEP * sizeof(struct graph_dot_data *)); | |
789 | memset(tf->gdd_writes + tf->io_plots_allocated - GDD_PTR_ALLOC_STEP, | |
790 | 0, GDD_PTR_ALLOC_STEP * sizeof(struct graph_dot_data *)); | |
791 | } | |
792 | pm->index = tf->io_plots++; | |
793 | ||
794 | return pm; | |
795 | } | |
796 | return pm; | |
797 | } | |
798 | ||
799 | void add_io(struct trace *trace, struct trace_file *tf) | |
9e066e23 CM |
800 | { |
801 | struct blk_io_trace *io = trace->io; | |
1582ecc9 | 802 | int action = io->action & BLK_TA_MASK; |
9e066e23 | 803 | u64 offset; |
0a43b43f JK |
804 | int index; |
805 | char *label; | |
806 | struct pid_map *pm; | |
9e066e23 CM |
807 | |
808 | if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) | |
809 | return; | |
810 | ||
811 | if (action != io_event(trace)) | |
812 | return; | |
813 | ||
814 | offset = io->sector << 9; | |
815 | ||
0a43b43f JK |
816 | pm = get_pid_map(tf, io->pid); |
817 | if (!pm) { | |
818 | index = 0; | |
819 | label = ""; | |
820 | } else { | |
821 | index = pm->index; | |
822 | label = pm->name; | |
823 | } | |
824 | if (BLK_DATADIR(io->action) & BLK_TC_READ) { | |
825 | if (!tf->gdd_reads[index]) | |
826 | tf->gdd_reads[index] = alloc_dot_data(tf->min_seconds, tf->max_seconds, tf->min_offset, tf->max_offset, tf->stop_seconds, pick_color(), strdup(label)); | |
827 | set_gdd_bit(tf->gdd_reads[index], offset, io->bytes, io->time); | |
828 | } else if (BLK_DATADIR(io->action) & BLK_TC_WRITE) { | |
829 | if (!tf->gdd_writes[index]) | |
830 | tf->gdd_writes[index] = alloc_dot_data(tf->min_seconds, tf->max_seconds, tf->min_offset, tf->max_offset, tf->stop_seconds, pick_color(), strdup(label)); | |
831 | set_gdd_bit(tf->gdd_writes[index], offset, io->bytes, io->time); | |
832 | } | |
9e066e23 CM |
833 | } |
834 | ||
835 | void add_pending_io(struct trace *trace, struct graph_line_data *gld) | |
836 | { | |
837 | int ret; | |
838 | int seconds; | |
839 | struct blk_io_trace *io = trace->io; | |
1582ecc9 | 840 | int action = io->action & BLK_TA_MASK; |
9e066e23 CM |
841 | double avg; |
842 | ||
843 | if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) | |
844 | return; | |
845 | ||
0a43b43f JK |
846 | if (action == __BLK_TA_QUEUE) { |
847 | hash_queued_io(trace->io); | |
848 | return; | |
849 | } | |
9e066e23 CM |
850 | if (action != __BLK_TA_ISSUE) |
851 | return; | |
852 | ||
853 | seconds = SECONDS(io->time); | |
35686f9b JK |
854 | if (seconds > gld->max_seconds) |
855 | return; | |
9e066e23 CM |
856 | |
857 | ret = hash_dispatched_io(trace->io); | |
858 | if (ret) | |
859 | return; | |
860 | ||
861 | ios_in_flight++; | |
862 | ||
863 | gld->data[seconds].sum += ios_in_flight; | |
864 | gld->data[seconds].count++; | |
865 | ||
866 | avg = (double)gld->data[seconds].sum / gld->data[seconds].count; | |
867 | if (gld->max < (u64)avg) { | |
868 | gld->max = avg; | |
869 | } | |
870 | } | |
871 | ||
872 | void add_completed_io(struct trace *trace, | |
873 | struct graph_line_data *latency_gld) | |
874 | { | |
875 | struct blk_io_trace *io = trace->io; | |
876 | int seconds; | |
1582ecc9 | 877 | int action = io->action & BLK_TA_MASK; |
9e066e23 CM |
878 | struct pending_io *pio; |
879 | double avg; | |
880 | u64 latency; | |
881 | ||
882 | if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) | |
883 | return; | |
884 | ||
885 | if (action != __BLK_TA_COMPLETE) | |
886 | return; | |
887 | ||
888 | seconds = SECONDS(io->time); | |
889 | ||
890 | pio = hash_completed_io(trace->io); | |
891 | if (!pio) | |
892 | return; | |
893 | ||
894 | if (ios_in_flight > 0) | |
895 | ios_in_flight--; | |
896 | if (io->time >= pio->dispatch_time) { | |
897 | latency = io->time - pio->dispatch_time; | |
898 | latency_gld->data[seconds].sum += latency; | |
899 | latency_gld->data[seconds].count++; | |
900 | } | |
901 | ||
902 | list_del(&pio->hash_list); | |
903 | free(pio); | |
904 | ||
905 | avg = (double)latency_gld->data[seconds].sum / | |
906 | latency_gld->data[seconds].count; | |
907 | if (latency_gld->max < (u64)avg) { | |
908 | latency_gld->max = avg; | |
909 | } | |
910 | } | |
911 | ||
912 | void add_iop(struct trace *trace, struct graph_line_data *gld) | |
913 | { | |
914 | struct blk_io_trace *io = trace->io; | |
1582ecc9 | 915 | int action = io->action & BLK_TA_MASK; |
9e066e23 CM |
916 | int seconds; |
917 | ||
918 | if (io->action & BLK_TC_ACT(BLK_TC_NOTIFY)) | |
919 | return; | |
920 | ||
921 | /* iops and tput use the same events */ | |
922 | if (action != tput_event(trace)) | |
923 | return; | |
924 | ||
925 | seconds = SECONDS(io->time); | |
35686f9b JK |
926 | if (seconds > gld->max_seconds) |
927 | return; | |
9e066e23 CM |
928 | |
929 | gld->data[seconds].sum += 1; | |
930 | gld->data[seconds].count = 1; | |
931 | if (gld->data[seconds].sum > gld->max) | |
932 | gld->max = gld->data[seconds].sum; | |
933 | } | |
934 | ||
935 | void check_record(struct trace *trace) | |
936 | { | |
937 | struct blk_io_trace *io = trace->io; | |
1582ecc9 | 938 | int action = io->action & BLK_TA_MASK; |
9e066e23 CM |
939 | |
940 | if (!(io->action & BLK_TC_ACT(BLK_TC_NOTIFY))) { | |
941 | switch (action) { | |
942 | case __BLK_TA_COMPLETE: | |
943 | trace->found_completion = 1; | |
944 | break; | |
945 | case __BLK_TA_ISSUE: | |
946 | trace->found_issue = 1; | |
947 | break; | |
948 | case __BLK_TA_QUEUE: | |
949 | trace->found_queue = 1; | |
950 | break; | |
951 | }; | |
952 | } | |
953 | handle_notify(trace); | |
954 | } |