Add logging for queue submit and complet counts
[fio.git] / io_u.c
1 #include <unistd.h>
2 #include <fcntl.h>
3 #include <string.h>
4 #include <signal.h>
5 #include <time.h>
6 #include <assert.h>
7
8 #include "fio.h"
9 #include "hash.h"
10
11 /*
12  * Change this define to play with the timeout handling
13  */
14 #undef FIO_USE_TIMEOUT
15
16 struct io_completion_data {
17         int nr;                         /* input */
18
19         int error;                      /* output */
20         unsigned long bytes_done[2];    /* output */
21         struct timeval time;            /* output */
22 };
23
24 /*
25  * The ->file_map[] contains a map of blocks we have or have not done io
26  * to yet. Used to make sure we cover the entire range in a fair fashion.
27  */
28 static int random_map_free(struct fio_file *f, const unsigned long long block)
29 {
30         unsigned int idx = RAND_MAP_IDX(f, block);
31         unsigned int bit = RAND_MAP_BIT(f, block);
32
33         dprint(FD_RANDOM, "free: b=%llu, idx=%u, bit=%u\n", block, idx, bit);
34
35         return (f->file_map[idx] & (1UL << bit)) == 0;
36 }
37
38 /*
39  * Mark a given offset as used in the map.
40  */
41 static void mark_random_map(struct thread_data *td, struct io_u *io_u)
42 {
43         unsigned int min_bs = td->o.rw_min_bs;
44         struct fio_file *f = io_u->file;
45         unsigned long long block;
46         unsigned int blocks;
47         unsigned int nr_blocks;
48
49         block = (io_u->offset - f->file_offset) / (unsigned long long) min_bs;
50         blocks = 0;
51         nr_blocks = (io_u->buflen + min_bs - 1) / min_bs;
52
53         while (blocks < nr_blocks) {
54                 unsigned int idx, bit;
55
56                 /*
57                  * If we have a mixed random workload, we may
58                  * encounter blocks we already did IO to.
59                  */
60                 if ((td->o.ddir_nr == 1) && !random_map_free(f, block))
61                         break;
62
63                 idx = RAND_MAP_IDX(f, block);
64                 bit = RAND_MAP_BIT(f, block);
65
66                 fio_assert(td, idx < f->num_maps);
67
68                 f->file_map[idx] |= (1UL << bit);
69                 block++;
70                 blocks++;
71         }
72
73         if ((blocks * min_bs) < io_u->buflen)
74                 io_u->buflen = blocks * min_bs;
75 }
76
77 static inline unsigned long long last_block(struct thread_data *td,
78                                             struct fio_file *f,
79                                             enum fio_ddir ddir)
80 {
81         unsigned long long max_blocks;
82
83         max_blocks = f->io_size / (unsigned long long) td->o.min_bs[ddir];
84         if (!max_blocks)
85                 return 0;
86
87         return max_blocks;
88 }
89
90 /*
91  * Return the next free block in the map.
92  */
93 static int get_next_free_block(struct thread_data *td, struct fio_file *f,
94                                enum fio_ddir ddir, unsigned long long *b)
95 {
96         unsigned long long min_bs = td->o.rw_min_bs;
97         int i;
98
99         i = f->last_free_lookup;
100         *b = (i * BLOCKS_PER_MAP);
101         while ((*b) * min_bs < f->real_file_size) {
102                 if (f->file_map[i] != -1UL) {
103                         *b += fio_ffz(f->file_map[i]);
104                         if (*b > last_block(td, f, ddir))
105                                 break;
106                         f->last_free_lookup = i;
107                         return 0;
108                 }
109
110                 *b += BLOCKS_PER_MAP;
111                 i++;
112         }
113
114         dprint(FD_IO, "failed finding a free block\n");
115         return 1;
116 }
117
118 static int get_next_rand_offset(struct thread_data *td, struct fio_file *f,
119                                 enum fio_ddir ddir, unsigned long long *b)
120 {
121         unsigned long long r;
122         int loops = 5;
123
124         do {
125                 r = os_random_long(&td->random_state);
126                 dprint(FD_RANDOM, "off rand %llu\n", r);
127                 *b = (last_block(td, f, ddir) - 1)
128                         * (r / ((unsigned long long) RAND_MAX + 1.0));
129
130                 /*
131                  * if we are not maintaining a random map, we are done.
132                  */
133                 if (!file_randommap(td, f))
134                         return 0;
135
136                 /*
137                  * calculate map offset and check if it's free
138                  */
139                 if (random_map_free(f, *b))
140                         return 0;
141
142                 dprint(FD_RANDOM, "get_next_rand_offset: offset %llu busy\n",
143                                                                         *b);
144         } while (--loops);
145
146         /*
147          * we get here, if we didn't suceed in looking up a block. generate
148          * a random start offset into the filemap, and find the first free
149          * block from there.
150          */
151         loops = 10;
152         do {
153                 f->last_free_lookup = (f->num_maps - 1) * (r / (RAND_MAX+1.0));
154                 if (!get_next_free_block(td, f, ddir, b))
155                         return 0;
156
157                 r = os_random_long(&td->random_state);
158         } while (--loops);
159
160         /*
161          * that didn't work either, try exhaustive search from the start
162          */
163         f->last_free_lookup = 0;
164         return get_next_free_block(td, f, ddir, b);
165 }
166
167 /*
168  * For random io, generate a random new block and see if it's used. Repeat
169  * until we find a free one. For sequential io, just return the end of
170  * the last io issued.
171  */
172 static int get_next_offset(struct thread_data *td, struct io_u *io_u)
173 {
174         struct fio_file *f = io_u->file;
175         unsigned long long b;
176         enum fio_ddir ddir = io_u->ddir;
177
178         if (td_random(td) && (td->o.ddir_nr && !--td->ddir_nr)) {
179                 td->ddir_nr = td->o.ddir_nr;
180
181                 if (get_next_rand_offset(td, f, ddir, &b))
182                         return 1;
183         } else {
184                 if (f->last_pos >= f->real_file_size) {
185                         if (!td_random(td) ||
186                              get_next_rand_offset(td, f, ddir, &b))
187                                 return 1;
188                 } else
189                         b = (f->last_pos - f->file_offset) / td->o.min_bs[ddir];
190         }
191
192         io_u->offset = b * td->o.min_bs[ddir];
193         if (io_u->offset >= f->io_size) {
194                 dprint(FD_IO, "get_next_offset: offset %llu >= io_size %llu\n",
195                                         io_u->offset, f->io_size);
196                 return 1;
197         }
198
199         io_u->offset += f->file_offset;
200         if (io_u->offset >= f->real_file_size) {
201                 dprint(FD_IO, "get_next_offset: offset %llu >= size %llu\n",
202                                         io_u->offset, f->real_file_size);
203                 return 1;
204         }
205
206         return 0;
207 }
208
209 static unsigned int get_next_buflen(struct thread_data *td, struct io_u *io_u)
210 {
211         const int ddir = io_u->ddir;
212         unsigned int buflen;
213         long r;
214
215         if (td->o.min_bs[ddir] == td->o.max_bs[ddir])
216                 buflen = td->o.min_bs[ddir];
217         else {
218                 r = os_random_long(&td->bsrange_state);
219                 if (!td->o.bssplit_nr) {
220                         buflen = (unsigned int)
221                                         (1 + (double) (td->o.max_bs[ddir] - 1)
222                                         * r / (RAND_MAX + 1.0));
223                 } else {
224                         long perc = 0;
225                         unsigned int i;
226
227                         for (i = 0; i < td->o.bssplit_nr; i++) {
228                                 struct bssplit *bsp = &td->o.bssplit[i];
229
230                                 buflen = bsp->bs;
231                                 perc += bsp->perc;
232                                 if (r <= ((LONG_MAX / 100L) * perc))
233                                         break;
234                         }
235                 }
236                 if (!td->o.bs_unaligned) {
237                         buflen = (buflen + td->o.min_bs[ddir] - 1)
238                                         & ~(td->o.min_bs[ddir] - 1);
239                 }
240         }
241
242         if (io_u->offset + buflen > io_u->file->real_file_size) {
243                 dprint(FD_IO, "lower buflen %u -> %u (ddir=%d)\n", buflen,
244                                                 td->o.min_bs[ddir], ddir);
245                 buflen = td->o.min_bs[ddir];
246         }
247
248         return buflen;
249 }
250
251 static void set_rwmix_bytes(struct thread_data *td)
252 {
253         unsigned long issues;
254         unsigned int diff;
255
256         /*
257          * we do time or byte based switch. this is needed because
258          * buffered writes may issue a lot quicker than they complete,
259          * whereas reads do not.
260          */
261         issues = td->io_issues[td->rwmix_ddir] - td->rwmix_issues;
262         diff = td->o.rwmix[td->rwmix_ddir ^ 1];
263
264         td->rwmix_issues = td->io_issues[td->rwmix_ddir]
265                                 + (issues * ((100 - diff)) / diff);
266 }
267
268 static inline enum fio_ddir get_rand_ddir(struct thread_data *td)
269 {
270         unsigned int v;
271         long r;
272
273         r = os_random_long(&td->rwmix_state);
274         v = 1 + (int) (100.0 * (r / (RAND_MAX + 1.0)));
275         if (v < td->o.rwmix[DDIR_READ])
276                 return DDIR_READ;
277
278         return DDIR_WRITE;
279 }
280
281 /*
282  * Return the data direction for the next io_u. If the job is a
283  * mixed read/write workload, check the rwmix cycle and switch if
284  * necessary.
285  */
286 static enum fio_ddir get_rw_ddir(struct thread_data *td)
287 {
288         if (td_rw(td)) {
289                 /*
290                  * Check if it's time to seed a new data direction.
291                  */
292                 if (td->io_issues[td->rwmix_ddir] >= td->rwmix_issues) {
293                         unsigned long long max_bytes;
294                         enum fio_ddir ddir;
295
296                         /*
297                          * Put a top limit on how many bytes we do for
298                          * one data direction, to avoid overflowing the
299                          * ranges too much
300                          */
301                         ddir = get_rand_ddir(td);
302                         max_bytes = td->this_io_bytes[ddir];
303                         if (max_bytes >=
304                             (td->o.size * td->o.rwmix[ddir] / 100)) {
305                                 if (!td->rw_end_set[ddir])
306                                         td->rw_end_set[ddir] = 1;
307
308                                 ddir ^= 1;
309                         }
310
311                         if (ddir != td->rwmix_ddir)
312                                 set_rwmix_bytes(td);
313
314                         td->rwmix_ddir = ddir;
315                 }
316                 return td->rwmix_ddir;
317         } else if (td_read(td))
318                 return DDIR_READ;
319         else
320                 return DDIR_WRITE;
321 }
322
323 static void put_file_log(struct thread_data *td, struct fio_file *f)
324 {
325         int ret = put_file(td, f);
326
327         if (ret)
328                 td_verror(td, ret, "file close");
329 }
330
331 void put_io_u(struct thread_data *td, struct io_u *io_u)
332 {
333         assert((io_u->flags & IO_U_F_FREE) == 0);
334         io_u->flags |= IO_U_F_FREE;
335
336         if (io_u->file)
337                 put_file_log(td, io_u->file);
338
339         io_u->file = NULL;
340         list_del(&io_u->list);
341         list_add(&io_u->list, &td->io_u_freelist);
342         td->cur_depth--;
343 }
344
345 void requeue_io_u(struct thread_data *td, struct io_u **io_u)
346 {
347         struct io_u *__io_u = *io_u;
348
349         __io_u->flags |= IO_U_F_FREE;
350         if ((__io_u->flags & IO_U_F_FLIGHT) && (__io_u->ddir != DDIR_SYNC))
351                 td->io_issues[__io_u->ddir]--;
352
353         __io_u->flags &= ~IO_U_F_FLIGHT;
354
355         list_del(&__io_u->list);
356         list_add_tail(&__io_u->list, &td->io_u_requeues);
357         td->cur_depth--;
358         *io_u = NULL;
359 }
360
361 static int fill_io_u(struct thread_data *td, struct io_u *io_u)
362 {
363         if (td->io_ops->flags & FIO_NOIO)
364                 goto out;
365
366         /*
367          * see if it's time to sync
368          */
369         if (td->o.fsync_blocks &&
370            !(td->io_issues[DDIR_WRITE] % td->o.fsync_blocks) &&
371              td->io_issues[DDIR_WRITE] && should_fsync(td)) {
372                 io_u->ddir = DDIR_SYNC;
373                 goto out;
374         }
375
376         io_u->ddir = get_rw_ddir(td);
377
378         /*
379          * See if it's time to switch to a new zone
380          */
381         if (td->zone_bytes >= td->o.zone_size) {
382                 td->zone_bytes = 0;
383                 io_u->file->last_pos += td->o.zone_skip;
384                 td->io_skip_bytes += td->o.zone_skip;
385         }
386
387         /*
388          * No log, let the seq/rand engine retrieve the next buflen and
389          * position.
390          */
391         if (get_next_offset(td, io_u)) {
392                 dprint(FD_IO, "io_u %p, failed getting offset\n", io_u);
393                 return 1;
394         }
395
396         io_u->buflen = get_next_buflen(td, io_u);
397         if (!io_u->buflen) {
398                 dprint(FD_IO, "io_u %p, failed getting buflen\n", io_u);
399                 return 1;
400         }
401
402         if (io_u->offset + io_u->buflen > io_u->file->real_file_size) {
403                 dprint(FD_IO, "io_u %p, offset too large\n", io_u);
404                 dprint(FD_IO, "  off=%llu/%lu > %llu\n", io_u->offset,
405                                 io_u->buflen, io_u->file->real_file_size);
406                 return 1;
407         }
408
409         /*
410          * mark entry before potentially trimming io_u
411          */
412         if (td_random(td) && file_randommap(td, io_u->file))
413                 mark_random_map(td, io_u);
414
415         /*
416          * If using a write iolog, store this entry.
417          */
418 out:
419         dprint_io_u(io_u, "fill_io_u");
420         td->zone_bytes += io_u->buflen;
421         log_io_u(td, io_u);
422         return 0;
423 }
424
425 static void __io_u_mark_map(unsigned int *map, unsigned int nr)
426 {
427         int index = 0;
428
429         switch (nr) {
430         default:
431                 index = 6;
432                 break;
433         case 33 ... 64:
434                 index = 5;
435                 break;
436         case 17 ... 32:
437                 index = 4;
438                 break;
439         case 9 ... 16:
440                 index = 3;
441                 break;
442         case 5 ... 8:
443                 index = 2;
444                 break;
445         case 1 ... 4:
446                 index = 1;
447         case 0:
448                 break;
449         }
450
451         map[index]++;
452 }
453
454 void io_u_mark_submit(struct thread_data *td, unsigned int nr)
455 {
456         __io_u_mark_map(td->ts.io_u_submit, nr);
457         td->ts.total_submit++;
458 }
459
460 void io_u_mark_complete(struct thread_data *td, unsigned int nr)
461 {
462         __io_u_mark_map(td->ts.io_u_complete, nr);
463         td->ts.total_complete++;
464 }
465
466 void io_u_mark_depth(struct thread_data *td, unsigned int nr)
467 {
468         int index = 0;
469
470         switch (td->cur_depth) {
471         default:
472                 index = 6;
473                 break;
474         case 32 ... 63:
475                 index = 5;
476                 break;
477         case 16 ... 31:
478                 index = 4;
479                 break;
480         case 8 ... 15:
481                 index = 3;
482                 break;
483         case 4 ... 7:
484                 index = 2;
485                 break;
486         case 2 ... 3:
487                 index = 1;
488         case 1:
489                 break;
490         }
491
492         td->ts.io_u_map[index] += nr;
493 }
494
495 static void io_u_mark_lat_usec(struct thread_data *td, unsigned long usec)
496 {
497         int index = 0;
498
499         assert(usec < 1000);
500
501         switch (usec) {
502         case 750 ... 999:
503                 index = 9;
504                 break;
505         case 500 ... 749:
506                 index = 8;
507                 break;
508         case 250 ... 499:
509                 index = 7;
510                 break;
511         case 100 ... 249:
512                 index = 6;
513                 break;
514         case 50 ... 99:
515                 index = 5;
516                 break;
517         case 20 ... 49:
518                 index = 4;
519                 break;
520         case 10 ... 19:
521                 index = 3;
522                 break;
523         case 4 ... 9:
524                 index = 2;
525                 break;
526         case 2 ... 3:
527                 index = 1;
528         case 0 ... 1:
529                 break;
530         }
531
532         assert(index < FIO_IO_U_LAT_U_NR);
533         td->ts.io_u_lat_u[index]++;
534 }
535
536 static void io_u_mark_lat_msec(struct thread_data *td, unsigned long msec)
537 {
538         int index = 0;
539
540         switch (msec) {
541         default:
542                 index = 11;
543                 break;
544         case 1000 ... 1999:
545                 index = 10;
546                 break;
547         case 750 ... 999:
548                 index = 9;
549                 break;
550         case 500 ... 749:
551                 index = 8;
552                 break;
553         case 250 ... 499:
554                 index = 7;
555                 break;
556         case 100 ... 249:
557                 index = 6;
558                 break;
559         case 50 ... 99:
560                 index = 5;
561                 break;
562         case 20 ... 49:
563                 index = 4;
564                 break;
565         case 10 ... 19:
566                 index = 3;
567                 break;
568         case 4 ... 9:
569                 index = 2;
570                 break;
571         case 2 ... 3:
572                 index = 1;
573         case 0 ... 1:
574                 break;
575         }
576
577         assert(index < FIO_IO_U_LAT_M_NR);
578         td->ts.io_u_lat_m[index]++;
579 }
580
581 static void io_u_mark_latency(struct thread_data *td, unsigned long usec)
582 {
583         if (usec < 1000)
584                 io_u_mark_lat_usec(td, usec);
585         else
586                 io_u_mark_lat_msec(td, usec / 1000);
587 }
588
589 /*
590  * Get next file to service by choosing one at random
591  */
592 static struct fio_file *get_next_file_rand(struct thread_data *td, int goodf,
593                                            int badf)
594 {
595         struct fio_file *f;
596         int fno;
597
598         do {
599                 long r = os_random_long(&td->next_file_state);
600
601                 fno = (unsigned int) ((double) td->o.nr_files
602                         * (r / (RAND_MAX + 1.0)));
603                 f = td->files[fno];
604                 if (f->flags & FIO_FILE_DONE)
605                         continue;
606
607                 if ((!goodf || (f->flags & goodf)) && !(f->flags & badf)) {
608                         dprint(FD_FILE, "get_next_file_rand: %p\n", f);
609                         return f;
610                 }
611         } while (1);
612 }
613
614 /*
615  * Get next file to service by doing round robin between all available ones
616  */
617 static struct fio_file *get_next_file_rr(struct thread_data *td, int goodf,
618                                          int badf)
619 {
620         unsigned int old_next_file = td->next_file;
621         struct fio_file *f;
622
623         do {
624                 f = td->files[td->next_file];
625
626                 td->next_file++;
627                 if (td->next_file >= td->o.nr_files)
628                         td->next_file = 0;
629
630                 if (f->flags & FIO_FILE_DONE) {
631                         f = NULL;
632                         continue;
633                 }
634
635                 if ((!goodf || (f->flags & goodf)) && !(f->flags & badf))
636                         break;
637
638                 f = NULL;
639         } while (td->next_file != old_next_file);
640
641         dprint(FD_FILE, "get_next_file_rr: %p\n", f);
642         return f;
643 }
644
645 static struct fio_file *get_next_file(struct thread_data *td)
646 {
647         struct fio_file *f;
648
649         assert(td->o.nr_files <= td->files_index);
650
651         if (!td->nr_open_files || td->nr_done_files >= td->o.nr_files) {
652                 dprint(FD_FILE, "get_next_file: nr_open=%d, nr_done=%d,"
653                                 " nr_files=%d\n", td->nr_open_files,
654                                                   td->nr_done_files,
655                                                   td->o.nr_files);
656                 return NULL;
657         }
658
659         f = td->file_service_file;
660         if (f && (f->flags & FIO_FILE_OPEN) && td->file_service_left--)
661                 goto out;
662
663         if (td->o.file_service_type == FIO_FSERVICE_RR)
664                 f = get_next_file_rr(td, FIO_FILE_OPEN, FIO_FILE_CLOSING);
665         else
666                 f = get_next_file_rand(td, FIO_FILE_OPEN, FIO_FILE_CLOSING);
667
668         td->file_service_file = f;
669         td->file_service_left = td->file_service_nr - 1;
670 out:
671         dprint(FD_FILE, "get_next_file: %p\n", f);
672         return f;
673 }
674
675 static struct fio_file *find_next_new_file(struct thread_data *td)
676 {
677         struct fio_file *f;
678
679         if (!td->nr_open_files || td->nr_done_files >= td->o.nr_files)
680                 return NULL;
681
682         if (td->o.file_service_type == FIO_FSERVICE_RR)
683                 f = get_next_file_rr(td, 0, FIO_FILE_OPEN);
684         else
685                 f = get_next_file_rand(td, 0, FIO_FILE_OPEN);
686
687         return f;
688 }
689
690 static int set_io_u_file(struct thread_data *td, struct io_u *io_u)
691 {
692         struct fio_file *f;
693
694         do {
695                 f = get_next_file(td);
696                 if (!f)
697                         return 1;
698
699 set_file:
700                 io_u->file = f;
701                 get_file(f);
702
703                 if (!fill_io_u(td, io_u))
704                         break;
705
706                 /*
707                  * optimization to prevent close/open of the same file. This
708                  * way we preserve queueing etc.
709                  */
710                 if (td->o.nr_files == 1 && td->o.time_based) {
711                         put_file_log(td, f);
712                         fio_file_reset(f);
713                         goto set_file;
714                 }
715
716                 /*
717                  * td_io_close() does a put_file() as well, so no need to
718                  * do that here.
719                  */
720                 io_u->file = NULL;
721                 td_io_close_file(td, f);
722                 f->flags |= FIO_FILE_DONE;
723                 td->nr_done_files++;
724
725                 /*
726                  * probably not the right place to do this, but see
727                  * if we need to open a new file
728                  */
729                 if (td->nr_open_files < td->o.open_files &&
730                     td->o.open_files != td->o.nr_files) {
731                         f = find_next_new_file(td);
732
733                         if (!f || td_io_open_file(td, f))
734                                 return 1;
735
736                         goto set_file;
737                 }
738         } while (1);
739
740         return 0;
741 }
742
743
744 struct io_u *__get_io_u(struct thread_data *td)
745 {
746         struct io_u *io_u = NULL;
747
748         if (!list_empty(&td->io_u_requeues))
749                 io_u = list_entry(td->io_u_requeues.next, struct io_u, list);
750         else if (!queue_full(td)) {
751                 io_u = list_entry(td->io_u_freelist.next, struct io_u, list);
752
753                 io_u->buflen = 0;
754                 io_u->resid = 0;
755                 io_u->file = NULL;
756                 io_u->end_io = NULL;
757         }
758
759         if (io_u) {
760                 assert(io_u->flags & IO_U_F_FREE);
761                 io_u->flags &= ~IO_U_F_FREE;
762
763                 io_u->error = 0;
764                 list_del(&io_u->list);
765                 list_add(&io_u->list, &td->io_u_busylist);
766                 td->cur_depth++;
767         }
768
769         return io_u;
770 }
771
772 /*
773  * Return an io_u to be processed. Gets a buflen and offset, sets direction,
774  * etc. The returned io_u is fully ready to be prepped and submitted.
775  */
776 struct io_u *get_io_u(struct thread_data *td)
777 {
778         struct fio_file *f;
779         struct io_u *io_u;
780
781         io_u = __get_io_u(td);
782         if (!io_u) {
783                 dprint(FD_IO, "__get_io_u failed\n");
784                 return NULL;
785         }
786
787         /*
788          * from a requeue, io_u already setup
789          */
790         if (io_u->file)
791                 goto out;
792
793         /*
794          * If using an iolog, grab next piece if any available.
795          */
796         if (td->o.read_iolog_file) {
797                 if (read_iolog_get(td, io_u))
798                         goto err_put;
799         } else if (set_io_u_file(td, io_u)) {
800                 dprint(FD_IO, "io_u %p, setting file failed\n", io_u);
801                 goto err_put;
802         }
803
804         f = io_u->file;
805         assert(f->flags & FIO_FILE_OPEN);
806
807         if (io_u->ddir != DDIR_SYNC) {
808                 if (!io_u->buflen && !(td->io_ops->flags & FIO_NOIO)) {
809                         dprint(FD_IO, "get_io_u: zero buflen on %p\n", io_u);
810                         goto err_put;
811                 }
812
813                 f->last_pos = io_u->offset + io_u->buflen;
814
815                 if (td->o.verify != VERIFY_NONE)
816                         populate_verify_io_u(td, io_u);
817         }
818
819         /*
820          * Set io data pointers.
821          */
822         io_u->endpos = io_u->offset + io_u->buflen;
823         io_u->xfer_buf = io_u->buf;
824         io_u->xfer_buflen = io_u->buflen;
825
826         if (td->o.refill_buffers && io_u->ddir == DDIR_WRITE)
827                 io_u_fill_buffer(td, io_u, io_u->xfer_buflen);
828 out:
829         if (!td_io_prep(td, io_u)) {
830                 fio_gettime(&io_u->start_time, NULL);
831                 return io_u;
832         }
833 err_put:
834         dprint(FD_IO, "get_io_u failed\n");
835         put_io_u(td, io_u);
836         return NULL;
837 }
838
839 void io_u_log_error(struct thread_data *td, struct io_u *io_u)
840 {
841         const char *msg[] = { "read", "write", "sync" };
842
843         log_err("fio: io_u error");
844
845         if (io_u->file)
846                 log_err(" on file %s", io_u->file->file_name);
847
848         log_err(": %s\n", strerror(io_u->error));
849
850         log_err("     %s offset=%llu, buflen=%lu\n", msg[io_u->ddir],
851                                         io_u->offset, io_u->xfer_buflen);
852
853         if (!td->error)
854                 td_verror(td, io_u->error, "io_u error");
855 }
856
857 static void io_completed(struct thread_data *td, struct io_u *io_u,
858                          struct io_completion_data *icd)
859 {
860         unsigned long usec;
861
862         dprint_io_u(io_u, "io complete");
863
864         assert(io_u->flags & IO_U_F_FLIGHT);
865         io_u->flags &= ~IO_U_F_FLIGHT;
866
867         if (io_u->ddir == DDIR_SYNC) {
868                 td->last_was_sync = 1;
869                 return;
870         }
871
872         td->last_was_sync = 0;
873
874         if (!io_u->error) {
875                 unsigned int bytes = io_u->buflen - io_u->resid;
876                 const enum fio_ddir idx = io_u->ddir;
877                 int ret;
878
879                 td->io_blocks[idx]++;
880                 td->io_bytes[idx] += bytes;
881                 td->this_io_bytes[idx] += bytes;
882
883                 usec = utime_since(&io_u->issue_time, &icd->time);
884
885                 add_clat_sample(td, idx, usec);
886                 add_bw_sample(td, idx, &icd->time);
887                 io_u_mark_latency(td, usec);
888
889                 if (td_write(td) && idx == DDIR_WRITE &&
890                     td->o.do_verify &&
891                     td->o.verify != VERIFY_NONE)
892                         log_io_piece(td, io_u);
893
894                 icd->bytes_done[idx] += bytes;
895
896                 if (io_u->end_io) {
897                         ret = io_u->end_io(td, io_u);
898                         if (ret && !icd->error)
899                                 icd->error = ret;
900                 }
901         } else {
902                 icd->error = io_u->error;
903                 io_u_log_error(td, io_u);
904         }
905 }
906
907 static void init_icd(struct io_completion_data *icd, int nr)
908 {
909         fio_gettime(&icd->time, NULL);
910
911         icd->nr = nr;
912
913         icd->error = 0;
914         icd->bytes_done[0] = icd->bytes_done[1] = 0;
915 }
916
917 static void ios_completed(struct thread_data *td,
918                           struct io_completion_data *icd)
919 {
920         struct io_u *io_u;
921         int i;
922
923         for (i = 0; i < icd->nr; i++) {
924                 io_u = td->io_ops->event(td, i);
925
926                 io_completed(td, io_u, icd);
927                 put_io_u(td, io_u);
928         }
929 }
930
931 /*
932  * Complete a single io_u for the sync engines.
933  */
934 long io_u_sync_complete(struct thread_data *td, struct io_u *io_u)
935 {
936         struct io_completion_data icd;
937
938         init_icd(&icd, 1);
939         io_completed(td, io_u, &icd);
940         put_io_u(td, io_u);
941
942         if (!icd.error)
943                 return icd.bytes_done[0] + icd.bytes_done[1];
944
945         td_verror(td, icd.error, "io_u_sync_complete");
946         return -1;
947 }
948
949 /*
950  * Called to complete min_events number of io for the async engines.
951  */
952 long io_u_queued_complete(struct thread_data *td, int min_events)
953 {
954         struct io_completion_data icd;
955         struct timespec *tvp = NULL;
956         int ret;
957         struct timespec ts = { .tv_sec = 0, .tv_nsec = 0, };
958
959         dprint(FD_IO, "io_u_queued_completed: min=%d\n", min_events);
960
961         if (!min_events)
962                 tvp = &ts;
963
964         ret = td_io_getevents(td, min_events, td->cur_depth, tvp);
965         if (ret < 0) {
966                 td_verror(td, -ret, "td_io_getevents");
967                 return ret;
968         } else if (!ret)
969                 return ret;
970
971         init_icd(&icd, ret);
972         ios_completed(td, &icd);
973         if (!icd.error)
974                 return icd.bytes_done[0] + icd.bytes_done[1];
975
976         td_verror(td, icd.error, "io_u_queued_complete");
977         return -1;
978 }
979
980 /*
981  * Call when io_u is really queued, to update the submission latency.
982  */
983 void io_u_queued(struct thread_data *td, struct io_u *io_u)
984 {
985         unsigned long slat_time;
986
987         slat_time = utime_since(&io_u->start_time, &io_u->issue_time);
988         add_slat_sample(td, io_u->ddir, slat_time);
989 }
990
991 /*
992  * "randomly" fill the buffer contents
993  */
994 void io_u_fill_buffer(struct thread_data *td, struct io_u *io_u,
995                       unsigned int max_bs)
996 {
997         long *ptr = io_u->buf;
998
999         if (!td->o.zero_buffers) {
1000                 while ((void *) ptr - io_u->buf < max_bs) {
1001                         *ptr = rand() * GOLDEN_RATIO_PRIME;
1002                         ptr++;
1003                 }
1004         } else
1005                 memset(ptr, 0, max_bs);
1006 }
1007
1008 #ifdef FIO_USE_TIMEOUT
1009 void io_u_set_timeout(struct thread_data *td)
1010 {
1011         assert(td->cur_depth);
1012
1013         td->timer.it_interval.tv_sec = 0;
1014         td->timer.it_interval.tv_usec = 0;
1015         td->timer.it_value.tv_sec = IO_U_TIMEOUT + IO_U_TIMEOUT_INC;
1016         td->timer.it_value.tv_usec = 0;
1017         setitimer(ITIMER_REAL, &td->timer, NULL);
1018         fio_gettime(&td->timeout_end, NULL);
1019 }
1020
1021 static void io_u_dump(struct io_u *io_u)
1022 {
1023         unsigned long t_start = mtime_since_now(&io_u->start_time);
1024         unsigned long t_issue = mtime_since_now(&io_u->issue_time);
1025
1026         log_err("io_u=%p, t_start=%lu, t_issue=%lu\n", io_u, t_start, t_issue);
1027         log_err("  buf=%p/%p, len=%lu/%lu, offset=%llu\n", io_u->buf,
1028                                                 io_u->xfer_buf, io_u->buflen,
1029                                                 io_u->xfer_buflen,
1030                                                 io_u->offset);
1031         log_err("  ddir=%d, fname=%s\n", io_u->ddir, io_u->file->file_name);
1032 }
1033 #else
1034 void io_u_set_timeout(struct thread_data fio_unused *td)
1035 {
1036 }
1037 #endif
1038
1039 #ifdef FIO_USE_TIMEOUT
1040 static void io_u_timeout_handler(int fio_unused sig)
1041 {
1042         struct thread_data *td, *__td;
1043         pid_t pid = getpid();
1044         struct list_head *entry;
1045         struct io_u *io_u;
1046         int i;
1047
1048         log_err("fio: io_u timeout\n");
1049
1050         /*
1051          * TLS would be nice...
1052          */
1053         td = NULL;
1054         for_each_td(__td, i) {
1055                 if (__td->pid == pid) {
1056                         td = __td;
1057                         break;
1058                 }
1059         }
1060
1061         if (!td) {
1062                 log_err("fio: io_u timeout, can't find job\n");
1063                 exit(1);
1064         }
1065
1066         if (!td->cur_depth) {
1067                 log_err("fio: timeout without pending work?\n");
1068                 return;
1069         }
1070
1071         log_err("fio: io_u timeout: job=%s, pid=%d\n", td->o.name, td->pid);
1072
1073         list_for_each(entry, &td->io_u_busylist) {
1074                 io_u = list_entry(entry, struct io_u, list);
1075
1076                 io_u_dump(io_u);
1077         }
1078
1079         td_verror(td, ETIMEDOUT, "io_u timeout");
1080         exit(1);
1081 }
1082 #endif
1083
1084 void io_u_init_timeout(void)
1085 {
1086 #ifdef FIO_USE_TIMEOUT
1087         signal(SIGALRM, io_u_timeout_handler);
1088 #endif
1089 }