Collect startup output before logging it
[fio.git] / ioengines.c
1 /*
2  * The io parts of the fio tool, includes workers for sync and mmap'ed
3  * io, as well as both posix and linux libaio support.
4  *
5  * sync io is implemented on top of aio.
6  *
7  * This is not really specific to fio, if the get_io_u/put_io_u and
8  * structures was pulled into this as well it would be a perfectly
9  * generic io engine that could be used for other projects.
10  *
11  */
12 #include <stdlib.h>
13 #include <unistd.h>
14 #include <string.h>
15 #include <dlfcn.h>
16 #include <fcntl.h>
17 #include <assert.h>
18
19 #include "fio.h"
20 #include "diskutil.h"
21 #include "zbd.h"
22
23 static FLIST_HEAD(engine_list);
24
25 static bool check_engine_ops(struct ioengine_ops *ops)
26 {
27         if (ops->version != FIO_IOOPS_VERSION) {
28                 log_err("bad ioops version %d (want %d)\n", ops->version,
29                                                         FIO_IOOPS_VERSION);
30                 return true;
31         }
32
33         if (!ops->queue) {
34                 log_err("%s: no queue handler\n", ops->name);
35                 return true;
36         }
37
38         /*
39          * sync engines only need a ->queue()
40          */
41         if (ops->flags & FIO_SYNCIO)
42                 return false;
43
44         if (!ops->event || !ops->getevents) {
45                 log_err("%s: no event/getevents handler\n", ops->name);
46                 return true;
47         }
48
49         return false;
50 }
51
52 void unregister_ioengine(struct ioengine_ops *ops)
53 {
54         dprint(FD_IO, "ioengine %s unregistered\n", ops->name);
55         flist_del_init(&ops->list);
56 }
57
58 void register_ioengine(struct ioengine_ops *ops)
59 {
60         dprint(FD_IO, "ioengine %s registered\n", ops->name);
61         flist_add_tail(&ops->list, &engine_list);
62 }
63
64 static struct ioengine_ops *find_ioengine(const char *name)
65 {
66         struct ioengine_ops *ops;
67         struct flist_head *entry;
68
69         flist_for_each(entry, &engine_list) {
70                 ops = flist_entry(entry, struct ioengine_ops, list);
71                 if (!strcmp(name, ops->name))
72                         return ops;
73         }
74
75         return NULL;
76 }
77
78 static struct ioengine_ops *dlopen_ioengine(struct thread_data *td,
79                                             const char *engine_lib)
80 {
81         struct ioengine_ops *ops;
82         void *dlhandle;
83
84         dprint(FD_IO, "dload engine %s\n", engine_lib);
85
86         dlerror();
87         dlhandle = dlopen(engine_lib, RTLD_LAZY);
88         if (!dlhandle) {
89                 td_vmsg(td, -1, dlerror(), "dlopen");
90                 return NULL;
91         }
92
93         /*
94          * Unlike the included modules, external engines should have a
95          * non-static ioengine structure that we can reference.
96          */
97         ops = dlsym(dlhandle, engine_lib);
98         if (!ops)
99                 ops = dlsym(dlhandle, "ioengine");
100
101         /*
102          * For some external engines (like C++ ones) it is not that trivial
103          * to provide a non-static ionengine structure that we can reference.
104          * Instead we call a method which allocates the required ioengine
105          * structure.
106          */
107         if (!ops) {
108                 get_ioengine_t get_ioengine = dlsym(dlhandle, "get_ioengine");
109
110                 if (get_ioengine)
111                         get_ioengine(&ops);
112         }
113
114         if (!ops) {
115                 td_vmsg(td, -1, dlerror(), "dlsym");
116                 dlclose(dlhandle);
117                 return NULL;
118         }
119
120         td->io_ops_dlhandle = dlhandle;
121         return ops;
122 }
123
124 static struct ioengine_ops *__load_ioengine(const char *name)
125 {
126         char engine[64];
127
128         engine[sizeof(engine) - 1] = '\0';
129         strncpy(engine, name, sizeof(engine) - 1);
130
131         /*
132          * linux libaio has alias names, so convert to what we want
133          */
134         if (!strncmp(engine, "linuxaio", 8) || !strncmp(engine, "aio", 3)) {
135                 dprint(FD_IO, "converting ioengine name: %s -> libaio\n", name);
136                 strcpy(engine, "libaio");
137         }
138
139         dprint(FD_IO, "load ioengine %s\n", engine);
140         return find_ioengine(engine);
141 }
142
143 struct ioengine_ops *load_ioengine(struct thread_data *td)
144 {
145         struct ioengine_ops *ops = NULL;
146         const char *name;
147
148         /*
149          * Use ->ioengine_so_path if an external ioengine path is specified.
150          * In this case, ->ioengine is "external" which also means the prefix
151          * for external ioengines "external:" is properly used.
152          */
153         name = td->o.ioengine_so_path ?: td->o.ioengine;
154
155         /*
156          * Try to load ->ioengine first, and if failed try to dlopen(3) either
157          * ->ioengine or ->ioengine_so_path.  This is redundant for an external
158          * ioengine with prefix, and also leaves the possibility of unexpected
159          * behavior (e.g. if the "external" ioengine exists), but we do this
160          * so as not to break job files not using the prefix.
161          */
162         ops = __load_ioengine(td->o.ioengine);
163         if (!ops)
164                 ops = dlopen_ioengine(td, name);
165
166         /*
167          * If ops is NULL, we failed to load ->ioengine, and also failed to
168          * dlopen(3) either ->ioengine or ->ioengine_so_path as a path.
169          */
170         if (!ops) {
171                 log_err("fio: engine %s not loadable\n", name);
172                 return NULL;
173         }
174
175         /*
176          * Check that the required methods are there.
177          */
178         if (check_engine_ops(ops))
179                 return NULL;
180
181         return ops;
182 }
183
184 /*
185  * For cleaning up an ioengine which never made it to init().
186  */
187 void free_ioengine(struct thread_data *td)
188 {
189         dprint(FD_IO, "free ioengine %s\n", td->io_ops->name);
190
191         if (td->eo && td->io_ops->options) {
192                 options_free(td->io_ops->options, td->eo);
193                 free(td->eo);
194                 td->eo = NULL;
195         }
196
197         if (td->io_ops_dlhandle) {
198                 dlclose(td->io_ops_dlhandle);
199                 td->io_ops_dlhandle = NULL;
200         }
201
202         td->io_ops = NULL;
203 }
204
205 void close_ioengine(struct thread_data *td)
206 {
207         dprint(FD_IO, "close ioengine %s\n", td->io_ops->name);
208
209         if (td->io_ops->cleanup) {
210                 td->io_ops->cleanup(td);
211                 td->io_ops_data = NULL;
212         }
213
214         free_ioengine(td);
215 }
216
217 int td_io_prep(struct thread_data *td, struct io_u *io_u)
218 {
219         dprint_io_u(io_u, "prep");
220         fio_ro_check(td, io_u);
221
222         lock_file(td, io_u->file, io_u->ddir);
223
224         if (td->io_ops->prep) {
225                 int ret = td->io_ops->prep(td, io_u);
226
227                 dprint(FD_IO, "prep: io_u %p: ret=%d\n", io_u, ret);
228
229                 if (ret)
230                         unlock_file(td, io_u->file);
231                 return ret;
232         }
233
234         return 0;
235 }
236
237 int td_io_getevents(struct thread_data *td, unsigned int min, unsigned int max,
238                     const struct timespec *t)
239 {
240         int r = 0;
241
242         /*
243          * For ioengine=rdma one side operation RDMA_WRITE or RDMA_READ,
244          * server side gets a message from the client
245          * side that the task is finished, and
246          * td->done is set to 1 after td_io_commit(). In this case,
247          * there is no need to reap complete event in server side.
248          */
249         if (td->done)
250                 return 0;
251
252         if (min > 0 && td->io_ops->commit) {
253                 r = td->io_ops->commit(td);
254                 if (r < 0)
255                         goto out;
256         }
257         if (max > td->cur_depth)
258                 max = td->cur_depth;
259         if (min > max)
260                 max = min;
261
262         r = 0;
263         if (max && td->io_ops->getevents)
264                 r = td->io_ops->getevents(td, min, max, t);
265 out:
266         if (r >= 0) {
267                 /*
268                  * Reflect that our submitted requests were retrieved with
269                  * whatever OS async calls are in the underlying engine.
270                  */
271                 td->io_u_in_flight -= r;
272                 io_u_mark_complete(td, r);
273         } else
274                 td_verror(td, r, "get_events");
275
276         dprint(FD_IO, "getevents: %d\n", r);
277         return r;
278 }
279
280 enum fio_q_status td_io_queue(struct thread_data *td, struct io_u *io_u)
281 {
282         const enum fio_ddir ddir = acct_ddir(io_u);
283         unsigned long long buflen = io_u->xfer_buflen;
284         enum fio_q_status ret;
285
286         dprint_io_u(io_u, "queue");
287         fio_ro_check(td, io_u);
288
289         assert((io_u->flags & IO_U_F_FLIGHT) == 0);
290         io_u_set(td, io_u, IO_U_F_FLIGHT);
291
292         assert(fio_file_open(io_u->file));
293
294         /*
295          * If using a write iolog, store this entry.
296          */
297         log_io_u(td, io_u);
298
299         io_u->error = 0;
300         io_u->resid = 0;
301
302         if (td_ioengine_flagged(td, FIO_SYNCIO)) {
303                 if (fio_fill_issue_time(td))
304                         fio_gettime(&io_u->issue_time, NULL);
305
306                 /*
307                  * only used for iolog
308                  */
309                 if (td->o.read_iolog_file)
310                         memcpy(&td->last_issue, &io_u->issue_time,
311                                         sizeof(io_u->issue_time));
312         }
313
314         if (ddir_rw(ddir)) {
315                 if (!(io_u->flags & IO_U_F_VER_LIST)) {
316                         td->io_issues[ddir]++;
317                         td->io_issue_bytes[ddir] += buflen;
318                 }
319                 td->rate_io_issue_bytes[ddir] += buflen;
320         }
321
322         ret = td->io_ops->queue(td, io_u);
323         if (ret != FIO_Q_BUSY && io_u->post_submit) {
324                 io_u->post_submit(io_u, io_u->error == 0);
325                 io_u->post_submit = NULL;
326         }
327
328         unlock_file(td, io_u->file);
329
330         if (ret == FIO_Q_BUSY && ddir_rw(ddir)) {
331                 td->io_issues[ddir]--;
332                 td->io_issue_bytes[ddir] -= buflen;
333                 td->rate_io_issue_bytes[ddir] -= buflen;
334                 io_u_clear(td, io_u, IO_U_F_FLIGHT);
335         }
336
337         /*
338          * If an error was seen and the io engine didn't propagate it
339          * back to 'td', do so.
340          */
341         if (io_u->error && !td->error)
342                 td_verror(td, io_u->error, "td_io_queue");
343
344         /*
345          * Add warning for O_DIRECT so that users have an easier time
346          * spotting potentially bad alignment. If this triggers for the first
347          * IO, then it's likely an alignment problem or because the host fs
348          * does not support O_DIRECT
349          */
350         if (io_u->error == EINVAL && td->io_issues[io_u->ddir & 1] == 1 &&
351             td->o.odirect) {
352
353                 log_info("fio: first direct IO errored. File system may not "
354                          "support direct IO, or iomem_align= is bad, or "
355                          "invalid block size. Try setting direct=0.\n");
356         }
357
358         if (zbd_unaligned_write(io_u->error) &&
359             td->io_issues[io_u->ddir & 1] == 1 &&
360             td->o.zone_mode != ZONE_MODE_ZBD) {
361                 log_info("fio: first I/O failed. If %s is a zoned block device, consider --zonemode=zbd\n",
362                          io_u->file->file_name);
363         }
364
365         if (!td->io_ops->commit) {
366                 io_u_mark_submit(td, 1);
367                 io_u_mark_complete(td, 1);
368         }
369
370         if (ret == FIO_Q_COMPLETED) {
371                 if (ddir_rw(io_u->ddir) || ddir_sync(io_u->ddir)) {
372                         io_u_mark_depth(td, 1);
373                         td->ts.total_io_u[io_u->ddir]++;
374                 }
375         } else if (ret == FIO_Q_QUEUED) {
376                 td->io_u_queued++;
377
378                 if (ddir_rw(io_u->ddir) || ddir_sync(io_u->ddir))
379                         td->ts.total_io_u[io_u->ddir]++;
380
381                 if (td->io_u_queued >= td->o.iodepth_batch)
382                         td_io_commit(td);
383         }
384
385         if (!td_ioengine_flagged(td, FIO_SYNCIO)) {
386                 if (fio_fill_issue_time(td))
387                         fio_gettime(&io_u->issue_time, NULL);
388
389                 /*
390                  * only used for iolog
391                  */
392                 if (td->o.read_iolog_file)
393                         memcpy(&td->last_issue, &io_u->issue_time,
394                                         sizeof(io_u->issue_time));
395         }
396
397         return ret;
398 }
399
400 int td_io_init(struct thread_data *td)
401 {
402         int ret = 0;
403
404         if (td->io_ops->init) {
405                 ret = td->io_ops->init(td);
406                 if (ret)
407                         log_err("fio: io engine %s init failed.%s\n",
408                                 td->io_ops->name,
409                                 td->o.iodepth > 1 ?
410                                 " Perhaps try reducing io depth?" : "");
411                 else
412                         td->io_ops_init = 1;
413                 if (!td->error)
414                         td->error = ret;
415         }
416
417         return ret;
418 }
419
420 void td_io_commit(struct thread_data *td)
421 {
422         int ret;
423
424         dprint(FD_IO, "calling ->commit(), depth %d\n", td->cur_depth);
425
426         if (!td->cur_depth || !td->io_u_queued)
427                 return;
428
429         io_u_mark_depth(td, td->io_u_queued);
430
431         if (td->io_ops->commit) {
432                 ret = td->io_ops->commit(td);
433                 if (ret)
434                         td_verror(td, -ret, "io commit");
435         }
436
437         /*
438          * Reflect that events were submitted as async IO requests.
439          */
440         td->io_u_in_flight += td->io_u_queued;
441         td->io_u_queued = 0;
442 }
443
444 int td_io_open_file(struct thread_data *td, struct fio_file *f)
445 {
446         if (fio_file_closing(f)) {
447                 /*
448                  * Open translates to undo closing.
449                  */
450                 fio_file_clear_closing(f);
451                 get_file(f);
452                 return 0;
453         }
454         assert(!fio_file_open(f));
455         assert(f->fd == -1);
456         assert(td->io_ops->open_file);
457
458         if (td->io_ops->open_file(td, f)) {
459                 if (td->error == EINVAL && td->o.odirect)
460                         log_err("fio: destination does not support O_DIRECT\n");
461                 if (td->error == EMFILE) {
462                         log_err("fio: try reducing/setting openfiles (failed"
463                                 " at %u of %u)\n", td->nr_open_files,
464                                                         td->o.nr_files);
465                 }
466
467                 assert(f->fd == -1);
468                 assert(!fio_file_open(f));
469                 return 1;
470         }
471
472         fio_file_reset(td, f);
473         fio_file_set_open(f);
474         fio_file_clear_closing(f);
475         disk_util_inc(f->du);
476
477         td->nr_open_files++;
478         get_file(f);
479
480         if (f->filetype == FIO_TYPE_PIPE) {
481                 if (td_random(td)) {
482                         log_err("fio: can't seek on pipes (no random io)\n");
483                         goto err;
484                 }
485         }
486
487         if (td_ioengine_flagged(td, FIO_DISKLESSIO))
488                 goto done;
489
490         if (td->o.invalidate_cache && file_invalidate_cache(td, f))
491                 goto err;
492
493         if (td->o.fadvise_hint != F_ADV_NONE &&
494             (f->filetype == FIO_TYPE_BLOCK || f->filetype == FIO_TYPE_FILE)) {
495                 int flags;
496
497                 if (td->o.fadvise_hint == F_ADV_TYPE) {
498                         if (td_random(td))
499                                 flags = POSIX_FADV_RANDOM;
500                         else
501                                 flags = POSIX_FADV_SEQUENTIAL;
502                 } else if (td->o.fadvise_hint == F_ADV_RANDOM)
503                         flags = POSIX_FADV_RANDOM;
504                 else if (td->o.fadvise_hint == F_ADV_SEQUENTIAL)
505                         flags = POSIX_FADV_SEQUENTIAL;
506                 else {
507                         log_err("fio: unknown fadvise type %d\n",
508                                                         td->o.fadvise_hint);
509                         flags = POSIX_FADV_NORMAL;
510                 }
511
512                 if (posix_fadvise(f->fd, f->file_offset, f->io_size, flags) < 0) {
513                         if (!fio_did_warn(FIO_WARN_FADVISE))
514                                 log_err("fio: fadvise hint failed\n");
515                 }
516         }
517 #ifdef FIO_HAVE_WRITE_HINT
518         if (fio_option_is_set(&td->o, write_hint) &&
519             (f->filetype == FIO_TYPE_BLOCK || f->filetype == FIO_TYPE_FILE)) {
520                 uint64_t hint = td->o.write_hint;
521                 int cmd;
522
523                 /*
524                  * For direct IO, we just need/want to set the hint on
525                  * the file descriptor. For buffered IO, we need to set
526                  * it on the inode.
527                  */
528                 if (td->o.odirect)
529                         cmd = F_SET_FILE_RW_HINT;
530                 else
531                         cmd = F_SET_RW_HINT;
532
533                 if (fcntl(f->fd, cmd, &hint) < 0) {
534                         td_verror(td, errno, "fcntl write hint");
535                         goto err;
536                 }
537         }
538 #endif
539
540         if (td->o.odirect && !OS_O_DIRECT && fio_set_directio(td, f))
541                 goto err;
542
543 done:
544         log_file(td, f, FIO_LOG_OPEN_FILE);
545         return 0;
546 err:
547         disk_util_dec(f->du);
548         if (td->io_ops->close_file)
549                 td->io_ops->close_file(td, f);
550         return 1;
551 }
552
553 int td_io_close_file(struct thread_data *td, struct fio_file *f)
554 {
555         if (!fio_file_closing(f))
556                 log_file(td, f, FIO_LOG_CLOSE_FILE);
557
558         /*
559          * mark as closing, do real close when last io on it has completed
560          */
561         fio_file_set_closing(f);
562
563         return put_file(td, f);
564 }
565
566 int td_io_unlink_file(struct thread_data *td, struct fio_file *f)
567 {
568         if (td->io_ops->unlink_file)
569                 return td->io_ops->unlink_file(td, f);
570         else {
571                 int ret;
572
573                 ret = unlink(f->file_name);
574                 if (ret < 0)
575                         return errno;
576
577                 return 0;
578         }
579 }
580
581 int td_io_get_file_size(struct thread_data *td, struct fio_file *f)
582 {
583         if (!td->io_ops->get_file_size)
584                 return 0;
585
586         return td->io_ops->get_file_size(td, f);
587 }
588
589 int fio_show_ioengine_help(const char *engine)
590 {
591         struct flist_head *entry;
592         struct thread_data td;
593         struct ioengine_ops *io_ops;
594         char *sep;
595         int ret = 1;
596
597         if (!engine || !*engine) {
598                 log_info("Available IO engines:\n");
599                 flist_for_each(entry, &engine_list) {
600                         io_ops = flist_entry(entry, struct ioengine_ops, list);
601                         log_info("\t%s\n", io_ops->name);
602                 }
603                 return 0;
604         }
605         sep = strchr(engine, ',');
606         if (sep) {
607                 *sep = 0;
608                 sep++;
609         }
610
611         memset(&td, 0, sizeof(struct thread_data));
612         td.o.ioengine = (char *)engine;
613         io_ops = load_ioengine(&td);
614
615         if (!io_ops) {
616                 log_info("IO engine %s not found\n", engine);
617                 return 1;
618         }
619
620         if (io_ops->options)
621                 ret = show_cmd_help(io_ops->options, sep);
622         else
623                 log_info("IO engine %s has no options\n", io_ops->name);
624
625         free_ioengine(&td);
626         return ret;
627 }