Make gfio build with --build-static
[fio.git] / iolog.c
CommitLineData
ac9b9101
JA
1/*
2 * Code related to writing an iolog of what a thread is doing, and to
3 * later read that back and replay
4 */
5#include <stdio.h>
6#include <stdlib.h>
7#include <libgen.h>
8#include <assert.h>
b26317c9
JA
9#include <sys/types.h>
10#include <sys/stat.h>
11#include <unistd.h>
aee2ab67
JA
12#ifdef CONFIG_ZLIB
13#include <zlib.h>
14#endif
15
ac9b9101
JA
16#include "flist.h"
17#include "fio.h"
18#include "verify.h"
19#include "trim.h"
243bfe19 20#include "filelock.h"
78d55e72 21#include "lib/tp.h"
ac9b9101
JA
22
23static const char iolog_ver2[] = "fio version 2 iolog";
24
25void queue_io_piece(struct thread_data *td, struct io_piece *ipo)
26{
27 flist_add_tail(&ipo->list, &td->io_log_list);
28 td->total_io_size += ipo->len;
29}
30
1f440ece 31void log_io_u(const struct thread_data *td, const struct io_u *io_u)
ac9b9101 32{
ac9b9101
JA
33 if (!td->o.write_iolog_file)
34 return;
35
36 fprintf(td->iolog_f, "%s %s %llu %lu\n", io_u->file->file_name,
173375c2
JA
37 io_ddir_name(io_u->ddir),
38 io_u->offset, io_u->buflen);
ac9b9101
JA
39}
40
41void log_file(struct thread_data *td, struct fio_file *f,
42 enum file_log_act what)
43{
44 const char *act[] = { "add", "open", "close" };
45
46 assert(what < 3);
47
48 if (!td->o.write_iolog_file)
49 return;
50
51
52 /*
53 * this happens on the pre-open/close done before the job starts
54 */
55 if (!td->iolog_f)
56 return;
57
58 fprintf(td->iolog_f, "%s %s\n", f->file_name, act[what]);
59}
60
61static void iolog_delay(struct thread_data *td, unsigned long delay)
62{
df8fb609
JA
63 uint64_t usec = utime_since_now(&td->last_issue);
64 uint64_t this_delay;
65 struct timeval tv;
ac9b9101 66
df8fb609
JA
67 if (delay < td->time_offset) {
68 td->time_offset = 0;
69 return;
70 }
71
72 delay -= td->time_offset;
ac9b9101
JA
73 if (delay < usec)
74 return;
75
76 delay -= usec;
77
df8fb609 78 fio_gettime(&tv, NULL);
30b18672
JA
79 while (delay && !td->terminate) {
80 this_delay = delay;
81 if (this_delay > 500000)
82 this_delay = 500000;
83
84 usec_sleep(td, this_delay);
85 delay -= this_delay;
86 }
df8fb609
JA
87
88 usec = utime_since_now(&tv);
89 if (usec > delay)
90 td->time_offset = usec - delay;
91 else
92 td->time_offset = 0;
ac9b9101
JA
93}
94
95static int ipo_special(struct thread_data *td, struct io_piece *ipo)
96{
97 struct fio_file *f;
98 int ret;
99
100 /*
101 * Not a special ipo
102 */
103 if (ipo->ddir != DDIR_INVAL)
104 return 0;
105
106 f = td->files[ipo->fileno];
107
108 switch (ipo->file_action) {
109 case FIO_LOG_OPEN_FILE:
110 ret = td_io_open_file(td, f);
111 if (!ret)
112 break;
113 td_verror(td, ret, "iolog open file");
114 return -1;
115 case FIO_LOG_CLOSE_FILE:
116 td_io_close_file(td, f);
117 break;
118 case FIO_LOG_UNLINK_FILE:
38ef9c90 119 td_io_unlink_file(td, f);
ac9b9101
JA
120 break;
121 default:
122 log_err("fio: bad file action %d\n", ipo->file_action);
123 break;
124 }
125
126 return 1;
127}
128
129int read_iolog_get(struct thread_data *td, struct io_u *io_u)
130{
131 struct io_piece *ipo;
132 unsigned long elapsed;
3c3ed070 133
ac9b9101
JA
134 while (!flist_empty(&td->io_log_list)) {
135 int ret;
136
9342d5f8 137 ipo = flist_first_entry(&td->io_log_list, struct io_piece, list);
ac9b9101
JA
138 flist_del(&ipo->list);
139 remove_trim_entry(td, ipo);
140
141 ret = ipo_special(td, ipo);
142 if (ret < 0) {
143 free(ipo);
144 break;
145 } else if (ret > 0) {
146 free(ipo);
147 continue;
148 }
149
150 io_u->ddir = ipo->ddir;
151 if (ipo->ddir != DDIR_WAIT) {
152 io_u->offset = ipo->offset;
153 io_u->buflen = ipo->len;
154 io_u->file = td->files[ipo->fileno];
155 get_file(io_u->file);
156 dprint(FD_IO, "iolog: get %llu/%lu/%s\n", io_u->offset,
157 io_u->buflen, io_u->file->file_name);
158 if (ipo->delay)
159 iolog_delay(td, ipo->delay);
160 } else {
161 elapsed = mtime_since_genesis();
162 if (ipo->delay > elapsed)
163 usec_sleep(td, (ipo->delay - elapsed) * 1000);
ac9b9101
JA
164 }
165
166 free(ipo);
3c3ed070 167
ac9b9101
JA
168 if (io_u->ddir != DDIR_WAIT)
169 return 0;
170 }
171
172 td->done = 1;
173 return 1;
174}
175
176void prune_io_piece_log(struct thread_data *td)
177{
178 struct io_piece *ipo;
179 struct rb_node *n;
180
181 while ((n = rb_first(&td->io_hist_tree)) != NULL) {
182 ipo = rb_entry(n, struct io_piece, rb_node);
183 rb_erase(n, &td->io_hist_tree);
184 remove_trim_entry(td, ipo);
185 td->io_hist_len--;
186 free(ipo);
187 }
188
189 while (!flist_empty(&td->io_hist_list)) {
4e1020f8 190 ipo = flist_first_entry(&td->io_hist_list, struct io_piece, list);
ac9b9101
JA
191 flist_del(&ipo->list);
192 remove_trim_entry(td, ipo);
193 td->io_hist_len--;
194 free(ipo);
195 }
196}
197
198/*
199 * log a successful write, so we can unwind the log for verify
200 */
201void log_io_piece(struct thread_data *td, struct io_u *io_u)
202{
203 struct rb_node **p, *parent;
204 struct io_piece *ipo, *__ipo;
205
206 ipo = malloc(sizeof(struct io_piece));
207 init_ipo(ipo);
208 ipo->file = io_u->file;
209 ipo->offset = io_u->offset;
210 ipo->len = io_u->buflen;
da0a7bd2 211 ipo->numberio = io_u->numberio;
f9401285
JA
212 ipo->flags = IP_F_IN_FLIGHT;
213
214 io_u->ipo = ipo;
ac9b9101
JA
215
216 if (io_u_should_trim(td, io_u)) {
217 flist_add_tail(&ipo->trim_list, &td->trim_list);
218 td->trim_entries++;
219 }
220
221 /*
222 * We don't need to sort the entries, if:
223 *
224 * Sequential writes, or
225 * Random writes that lay out the file as it goes along
226 *
227 * For both these cases, just reading back data in the order we
228 * wrote it out is the fastest.
229 *
230 * One exception is if we don't have a random map AND we are doing
231 * verifies, in that case we need to check for duplicate blocks and
232 * drop the old one, which we rely on the rb insert/lookup for
233 * handling.
234 */
c4b6117b 235 if (((!td->o.verifysort) || !td_random(td) || !td->o.overwrite) &&
ac9b9101
JA
236 (file_randommap(td, ipo->file) || td->o.verify == VERIFY_NONE)) {
237 INIT_FLIST_HEAD(&ipo->list);
238 flist_add_tail(&ipo->list, &td->io_hist_list);
239 ipo->flags |= IP_F_ONLIST;
240 td->io_hist_len++;
241 return;
242 }
243
244 RB_CLEAR_NODE(&ipo->rb_node);
245
246 /*
247 * Sort the entry into the verification list
248 */
249restart:
250 p = &td->io_hist_tree.rb_node;
251 parent = NULL;
252 while (*p) {
253 parent = *p;
254
255 __ipo = rb_entry(parent, struct io_piece, rb_node);
256 if (ipo->file < __ipo->file)
257 p = &(*p)->rb_left;
258 else if (ipo->file > __ipo->file)
259 p = &(*p)->rb_right;
260 else if (ipo->offset < __ipo->offset)
261 p = &(*p)->rb_left;
262 else if (ipo->offset > __ipo->offset)
263 p = &(*p)->rb_right;
264 else {
885ac623
JA
265 dprint(FD_IO, "iolog: overlap %llu/%lu, %llu/%lu",
266 __ipo->offset, __ipo->len,
267 ipo->offset, ipo->len);
ac9b9101
JA
268 td->io_hist_len--;
269 rb_erase(parent, &td->io_hist_tree);
270 remove_trim_entry(td, __ipo);
271 free(__ipo);
272 goto restart;
273 }
274 }
275
276 rb_link_node(&ipo->rb_node, parent, p);
277 rb_insert_color(&ipo->rb_node, &td->io_hist_tree);
278 ipo->flags |= IP_F_ONRB;
279 td->io_hist_len++;
280}
281
890b6656
JA
282void unlog_io_piece(struct thread_data *td, struct io_u *io_u)
283{
284 struct io_piece *ipo = io_u->ipo;
285
286 if (!ipo)
287 return;
288
289 if (ipo->flags & IP_F_ONRB)
290 rb_erase(&ipo->rb_node, &td->io_hist_tree);
291 else if (ipo->flags & IP_F_ONLIST)
292 flist_del(&ipo->list);
293
294 free(ipo);
295 io_u->ipo = NULL;
296 td->io_hist_len--;
297}
298
1f440ece 299void trim_io_piece(struct thread_data *td, const struct io_u *io_u)
890b6656
JA
300{
301 struct io_piece *ipo = io_u->ipo;
302
303 if (!ipo)
304 return;
305
306 ipo->len = io_u->xfer_buflen - io_u->resid;
307}
308
ac9b9101
JA
309void write_iolog_close(struct thread_data *td)
310{
311 fflush(td->iolog_f);
312 fclose(td->iolog_f);
313 free(td->iolog_buf);
314 td->iolog_f = NULL;
315 td->iolog_buf = NULL;
316}
317
318/*
319 * Read version 2 iolog data. It is enhanced to include per-file logging,
320 * syncs, etc.
321 */
322static int read_iolog2(struct thread_data *td, FILE *f)
323{
324 unsigned long long offset;
325 unsigned int bytes;
326 int reads, writes, waits, fileno = 0, file_action = 0; /* stupid gcc */
327 char *fname, *act;
328 char *str, *p;
329 enum fio_ddir rw;
330
331 free_release_files(td);
332
333 /*
334 * Read in the read iolog and store it, reuse the infrastructure
335 * for doing verifications.
336 */
337 str = malloc(4096);
338 fname = malloc(256+16);
339 act = malloc(256+16);
340
341 reads = writes = waits = 0;
342 while ((p = fgets(str, 4096, f)) != NULL) {
343 struct io_piece *ipo;
344 int r;
345
346 r = sscanf(p, "%256s %256s %llu %u", fname, act, &offset,
347 &bytes);
348 if (r == 4) {
349 /*
350 * Check action first
351 */
352 if (!strcmp(act, "wait"))
353 rw = DDIR_WAIT;
354 else if (!strcmp(act, "read"))
355 rw = DDIR_READ;
356 else if (!strcmp(act, "write"))
357 rw = DDIR_WRITE;
358 else if (!strcmp(act, "sync"))
359 rw = DDIR_SYNC;
360 else if (!strcmp(act, "datasync"))
361 rw = DDIR_DATASYNC;
362 else if (!strcmp(act, "trim"))
363 rw = DDIR_TRIM;
364 else {
365 log_err("fio: bad iolog file action: %s\n",
366 act);
367 continue;
368 }
033ace1e 369 fileno = get_fileno(td, fname);
ac9b9101
JA
370 } else if (r == 2) {
371 rw = DDIR_INVAL;
372 if (!strcmp(act, "add")) {
5903e7b7 373 fileno = add_file(td, fname, 0, 1);
ac9b9101
JA
374 file_action = FIO_LOG_ADD_FILE;
375 continue;
376 } else if (!strcmp(act, "open")) {
377 fileno = get_fileno(td, fname);
378 file_action = FIO_LOG_OPEN_FILE;
379 } else if (!strcmp(act, "close")) {
380 fileno = get_fileno(td, fname);
381 file_action = FIO_LOG_CLOSE_FILE;
382 } else {
383 log_err("fio: bad iolog file action: %s\n",
384 act);
385 continue;
386 }
387 } else {
388 log_err("bad iolog2: %s", p);
389 continue;
390 }
391
392 if (rw == DDIR_READ)
393 reads++;
394 else if (rw == DDIR_WRITE) {
395 /*
396 * Don't add a write for ro mode
397 */
398 if (read_only)
399 continue;
400 writes++;
401 } else if (rw == DDIR_WAIT) {
402 waits++;
403 } else if (rw == DDIR_INVAL) {
404 } else if (!ddir_sync(rw)) {
405 log_err("bad ddir: %d\n", rw);
406 continue;
407 }
408
409 /*
410 * Make note of file
411 */
412 ipo = malloc(sizeof(*ipo));
413 init_ipo(ipo);
414 ipo->ddir = rw;
415 if (rw == DDIR_WAIT) {
416 ipo->delay = offset;
417 } else {
418 ipo->offset = offset;
419 ipo->len = bytes;
42793d94 420 if (rw != DDIR_INVAL && bytes > td->o.max_bs[rw])
ac9b9101
JA
421 td->o.max_bs[rw] = bytes;
422 ipo->fileno = fileno;
423 ipo->file_action = file_action;
70afff59 424 td->o.size += bytes;
ac9b9101 425 }
3c3ed070 426
ac9b9101
JA
427 queue_io_piece(td, ipo);
428 }
429
430 free(str);
431 free(act);
432 free(fname);
433
434 if (writes && read_only) {
435 log_err("fio: <%s> skips replay of %d writes due to"
436 " read-only\n", td->o.name, writes);
437 writes = 0;
438 }
439
440 if (!reads && !writes && !waits)
441 return 1;
442 else if (reads && !writes)
443 td->o.td_ddir = TD_DDIR_READ;
444 else if (!reads && writes)
445 td->o.td_ddir = TD_DDIR_WRITE;
446 else
447 td->o.td_ddir = TD_DDIR_RW;
448
449 return 0;
450}
451
452/*
453 * open iolog, check version, and call appropriate parser
454 */
455static int init_iolog_read(struct thread_data *td)
456{
457 char buffer[256], *p;
458 FILE *f;
459 int ret;
460
461 f = fopen(td->o.read_iolog_file, "r");
462 if (!f) {
463 perror("fopen read iolog");
464 return 1;
465 }
466
467 p = fgets(buffer, sizeof(buffer), f);
468 if (!p) {
469 td_verror(td, errno, "iolog read");
470 log_err("fio: unable to read iolog\n");
471 fclose(f);
472 return 1;
473 }
474
475 /*
476 * version 2 of the iolog stores a specific string as the
477 * first line, check for that
478 */
479 if (!strncmp(iolog_ver2, buffer, strlen(iolog_ver2)))
480 ret = read_iolog2(td, f);
481 else {
482 log_err("fio: iolog version 1 is no longer supported\n");
483 ret = 1;
484 }
485
486 fclose(f);
487 return ret;
488}
489
490/*
491 * Set up a log for storing io patterns.
492 */
493static int init_iolog_write(struct thread_data *td)
494{
495 struct fio_file *ff;
496 FILE *f;
497 unsigned int i;
498
499 f = fopen(td->o.write_iolog_file, "a");
500 if (!f) {
501 perror("fopen write iolog");
502 return 1;
503 }
504
505 /*
506 * That's it for writing, setup a log buffer and we're done.
507 */
508 td->iolog_f = f;
509 td->iolog_buf = malloc(8192);
510 setvbuf(f, td->iolog_buf, _IOFBF, 8192);
511
512 /*
513 * write our version line
514 */
515 if (fprintf(f, "%s\n", iolog_ver2) < 0) {
516 perror("iolog init\n");
517 return 1;
518 }
519
520 /*
521 * add all known files
522 */
523 for_each_file(td, ff, i)
524 log_file(td, ff, FIO_LOG_ADD_FILE);
525
526 return 0;
527}
528
529int init_iolog(struct thread_data *td)
530{
531 int ret = 0;
532
533 if (td->o.read_iolog_file) {
d95b34a6
JA
534 int need_swap;
535
ac9b9101
JA
536 /*
537 * Check if it's a blktrace file and load that if possible.
538 * Otherwise assume it's a normal log file and load that.
539 */
d95b34a6
JA
540 if (is_blktrace(td->o.read_iolog_file, &need_swap))
541 ret = load_blktrace(td, td->o.read_iolog_file, need_swap);
ac9b9101
JA
542 else
543 ret = init_iolog_read(td);
544 } else if (td->o.write_iolog_file)
545 ret = init_iolog_write(td);
546
f01b34ae
JA
547 if (ret)
548 td_verror(td, EINVAL, "failed initializing iolog");
549
ac9b9101
JA
550 return ret;
551}
552
aee2ab67
JA
553void setup_log(struct io_log **log, struct log_params *p,
554 const char *filename)
ac9b9101 555{
e75cc8f3 556 struct io_log *l;
ac9b9101 557
e75cc8f3 558 l = calloc(1, sizeof(*l));
ac9b9101
JA
559 l->nr_samples = 0;
560 l->max_samples = 1024;
aee2ab67
JA
561 l->log_type = p->log_type;
562 l->log_offset = p->log_offset;
563 l->log_gz = p->log_gz;
b26317c9 564 l->log_gz_store = p->log_gz_store;
ae588852 565 l->log = malloc(l->max_samples * log_entry_sz(l));
aee2ab67 566 l->avg_msec = p->avg_msec;
cb7e0ace 567 l->filename = strdup(filename);
aee2ab67
JA
568 l->td = p->td;
569
b26317c9 570 if (l->log_offset)
49e98daa 571 l->log_ddir_mask = LOG_OFFSET_SAMPLE_BIT;
b26317c9 572
aee2ab67
JA
573 INIT_FLIST_HEAD(&l->chunk_list);
574
575 if (l->log_gz && !p->td)
576 l->log_gz = 0;
577 else if (l->log_gz) {
578 pthread_mutex_init(&l->chunk_lock, NULL);
579 p->td->flags |= TD_F_COMPRESS_LOG;
580 }
581
ac9b9101
JA
582 *log = l;
583}
584
2e802282
JA
585#ifdef CONFIG_SETVBUF
586static void *set_file_buffer(FILE *f)
587{
588 size_t size = 1048576;
589 void *buf;
590
591 buf = malloc(size);
592 setvbuf(f, buf, _IOFBF, size);
593 return buf;
594}
595
596static void clear_file_buffer(void *buf)
597{
598 free(buf);
599}
600#else
601static void *set_file_buffer(FILE *f)
602{
603 return NULL;
604}
605
606static void clear_file_buffer(void *buf)
607{
608}
609#endif
610
518dac09 611void free_log(struct io_log *log)
cb7e0ace
JA
612{
613 free(log->log);
614 free(log->filename);
615 free(log);
616}
617
b26317c9 618static void flush_samples(FILE *f, void *samples, uint64_t sample_size)
ac9b9101 619{
b26317c9
JA
620 struct io_sample *s;
621 int log_offset;
622 uint64_t i, nr_samples;
623
624 if (!sample_size)
625 return;
626
627 s = __get_sample(samples, 0, 0);
49e98daa 628 log_offset = (s->__ddir & LOG_OFFSET_SAMPLE_BIT) != 0;
b26317c9
JA
629
630 nr_samples = sample_size / __log_entry_sz(log_offset);
ac9b9101 631
aee2ab67 632 for (i = 0; i < nr_samples; i++) {
b26317c9 633 s = __get_sample(samples, log_offset, i);
ac9b9101 634
aee2ab67 635 if (!log_offset) {
ae588852
JA
636 fprintf(f, "%lu, %lu, %u, %u\n",
637 (unsigned long) s->time,
638 (unsigned long) s->val,
b26317c9 639 io_sample_ddir(s), s->bs);
ae588852
JA
640 } else {
641 struct io_sample_offset *so = (void *) s;
642
643 fprintf(f, "%lu, %lu, %u, %u, %llu\n",
644 (unsigned long) s->time,
645 (unsigned long) s->val,
b26317c9 646 io_sample_ddir(s), s->bs,
ae588852
JA
647 (unsigned long long) so->offset);
648 }
ac9b9101 649 }
aee2ab67
JA
650}
651
652#ifdef CONFIG_ZLIB
97eabb2a
JA
653
654struct iolog_flush_data {
655 struct tp_work work;
656 struct io_log *log;
657 void *samples;
658 uint64_t nr_samples;
659};
660
661struct iolog_compress {
662 struct flist_head list;
663 void *buf;
664 size_t len;
665 unsigned int seq;
97eabb2a
JA
666};
667
668#define GZ_CHUNK 131072
669
670static struct iolog_compress *get_new_chunk(unsigned int seq)
671{
672 struct iolog_compress *c;
673
674 c = malloc(sizeof(*c));
675 INIT_FLIST_HEAD(&c->list);
676 c->buf = malloc(GZ_CHUNK);
677 c->len = 0;
678 c->seq = seq;
97eabb2a
JA
679 return c;
680}
681
682static void free_chunk(struct iolog_compress *ic)
683{
c07826cd
JA
684 free(ic->buf);
685 free(ic);
97eabb2a
JA
686}
687
b26317c9 688static int z_stream_init(z_stream *stream, int gz_hdr)
aee2ab67 689{
b26317c9
JA
690 int wbits = 15;
691
aee2ab67
JA
692 stream->zalloc = Z_NULL;
693 stream->zfree = Z_NULL;
694 stream->opaque = Z_NULL;
695 stream->next_in = Z_NULL;
696
1a8e7458
JA
697 /*
698 * zlib magic - add 32 for auto-detection of gz header or not,
699 * if we decide to store files in a gzip friendly format.
700 */
b26317c9
JA
701 if (gz_hdr)
702 wbits += 32;
703
704 if (inflateInit2(stream, wbits) != Z_OK)
aee2ab67
JA
705 return 1;
706
707 return 0;
708}
709
1a8e7458 710struct inflate_chunk_iter {
aee2ab67 711 unsigned int seq;
dad95da1 712 int err;
aee2ab67
JA
713 void *buf;
714 size_t buf_size;
715 size_t buf_used;
716 size_t chunk_sz;
717};
718
b26317c9 719static void finish_chunk(z_stream *stream, FILE *f,
1a8e7458 720 struct inflate_chunk_iter *iter)
aee2ab67 721{
aee2ab67
JA
722 int ret;
723
724 ret = inflateEnd(stream);
725 if (ret != Z_OK)
726 log_err("fio: failed to end log inflation (%d)\n", ret);
727
b26317c9 728 flush_samples(f, iter->buf, iter->buf_used);
aee2ab67
JA
729 free(iter->buf);
730 iter->buf = NULL;
731 iter->buf_size = iter->buf_used = 0;
732}
733
1a8e7458
JA
734/*
735 * Iterative chunk inflation. Handles cases where we cross into a new
736 * sequence, doing flush finish of previous chunk if needed.
737 */
738static size_t inflate_chunk(struct iolog_compress *ic, int gz_hdr, FILE *f,
739 z_stream *stream, struct inflate_chunk_iter *iter)
aee2ab67 740{
0c56718d
JA
741 size_t ret;
742
743 dprint(FD_COMPRESS, "inflate chunk size=%lu, seq=%u",
744 (unsigned long) ic->len, ic->seq);
745
aee2ab67
JA
746 if (ic->seq != iter->seq) {
747 if (iter->seq)
b26317c9 748 finish_chunk(stream, f, iter);
aee2ab67 749
b26317c9 750 z_stream_init(stream, gz_hdr);
aee2ab67
JA
751 iter->seq = ic->seq;
752 }
753
754 stream->avail_in = ic->len;
755 stream->next_in = ic->buf;
756
757 if (!iter->buf_size) {
758 iter->buf_size = iter->chunk_sz;
759 iter->buf = malloc(iter->buf_size);
760 }
761
762 while (stream->avail_in) {
b26317c9 763 size_t this_out = iter->buf_size - iter->buf_used;
aee2ab67
JA
764 int err;
765
b26317c9 766 stream->avail_out = this_out;
aee2ab67
JA
767 stream->next_out = iter->buf + iter->buf_used;
768
769 err = inflate(stream, Z_NO_FLUSH);
770 if (err < 0) {
771 log_err("fio: failed inflating log: %d\n", err);
dad95da1 772 iter->err = err;
aee2ab67
JA
773 break;
774 }
775
b26317c9
JA
776 iter->buf_used += this_out - stream->avail_out;
777
778 if (!stream->avail_out) {
779 iter->buf_size += iter->chunk_sz;
780 iter->buf = realloc(iter->buf, iter->buf_size);
781 continue;
782 }
783
784 if (err == Z_STREAM_END)
785 break;
aee2ab67
JA
786 }
787
0c56718d
JA
788 ret = (void *) stream->next_in - ic->buf;
789
790 dprint(FD_COMPRESS, "inflated to size=%lu\n", (unsigned long) ret);
791
792 return ret;
aee2ab67
JA
793}
794
1a8e7458
JA
795/*
796 * Inflate stored compressed chunks, or write them directly to the log
797 * file if so instructed.
798 */
dad95da1 799static int inflate_gz_chunks(struct io_log *log, FILE *f)
aee2ab67 800{
1a8e7458 801 struct inflate_chunk_iter iter = { .chunk_sz = log->log_gz, };
aee2ab67
JA
802 z_stream stream;
803
804 while (!flist_empty(&log->chunk_list)) {
805 struct iolog_compress *ic;
806
9342d5f8 807 ic = flist_first_entry(&log->chunk_list, struct iolog_compress, list);
aee2ab67 808 flist_del(&ic->list);
b26317c9 809
1a8e7458
JA
810 if (log->log_gz_store) {
811 size_t ret;
812
0c56718d
JA
813 dprint(FD_COMPRESS, "log write chunk size=%lu, "
814 "seq=%u\n", (unsigned long) ic->len, ic->seq);
815
1a8e7458 816 ret = fwrite(ic->buf, ic->len, 1, f);
dad95da1
JA
817 if (ret != 1 || ferror(f)) {
818 iter.err = errno;
1a8e7458 819 log_err("fio: error writing compressed log\n");
dad95da1 820 }
1a8e7458
JA
821 } else
822 inflate_chunk(ic, log->log_gz_store, f, &stream, &iter);
c07826cd
JA
823
824 free_chunk(ic);
aee2ab67
JA
825 }
826
827 if (iter.seq) {
b26317c9 828 finish_chunk(&stream, f, &iter);
aee2ab67
JA
829 free(iter.buf);
830 }
dad95da1
JA
831
832 return iter.err;
aee2ab67
JA
833}
834
1a8e7458
JA
835/*
836 * Open compressed log file and decompress the stored chunks and
837 * write them to stdout. The chunks are stored sequentially in the
838 * file, so we iterate over them and do them one-by-one.
839 */
b26317c9
JA
840int iolog_file_inflate(const char *file)
841{
1a8e7458 842 struct inflate_chunk_iter iter = { .chunk_sz = 64 * 1024 * 1024, };
b26317c9
JA
843 struct iolog_compress ic;
844 z_stream stream;
845 struct stat sb;
fd771971 846 ssize_t ret;
f302710c
JA
847 size_t total;
848 void *buf;
b26317c9
JA
849 FILE *f;
850
b26317c9
JA
851 f = fopen(file, "r");
852 if (!f) {
853 perror("fopen");
854 return 1;
855 }
856
fd771971
JA
857 if (stat(file, &sb) < 0) {
858 fclose(f);
859 perror("stat");
860 return 1;
861 }
862
f302710c 863 ic.buf = buf = malloc(sb.st_size);
b26317c9 864 ic.len = sb.st_size;
b26317c9
JA
865 ic.seq = 1;
866
867 ret = fread(ic.buf, ic.len, 1, f);
868 if (ret < 0) {
869 perror("fread");
870 fclose(f);
871 return 1;
872 } else if (ret != 1) {
873 log_err("fio: short read on reading log\n");
874 fclose(f);
875 return 1;
876 }
877
878 fclose(f);
879
1a8e7458
JA
880 /*
881 * Each chunk will return Z_STREAM_END. We don't know how many
882 * chunks are in the file, so we just keep looping and incrementing
883 * the sequence number until we have consumed the whole compressed
884 * file.
885 */
f302710c
JA
886 total = ic.len;
887 do {
8a1db9a1 888 size_t iret;
f302710c 889
8a1db9a1
JA
890 iret = inflate_chunk(&ic, 1, stdout, &stream, &iter);
891 total -= iret;
f302710c
JA
892 if (!total)
893 break;
dad95da1
JA
894 if (iter.err)
895 break;
f302710c
JA
896
897 ic.seq++;
8a1db9a1
JA
898 ic.len -= iret;
899 ic.buf += iret;
f302710c 900 } while (1);
b26317c9
JA
901
902 if (iter.seq) {
903 finish_chunk(&stream, stdout, &iter);
904 free(iter.buf);
905 }
906
f302710c 907 free(buf);
dad95da1 908 return iter.err;
b26317c9
JA
909}
910
aee2ab67
JA
911#else
912
dad95da1 913static int inflate_gz_chunks(struct io_log *log, FILE *f)
aee2ab67 914{
b7364e21 915 return 0;
aee2ab67
JA
916}
917
a68c66b2
JA
918int iolog_file_inflate(const char *file)
919{
920 log_err("fio: log inflation not possible without zlib\n");
921 return 1;
922}
923
aee2ab67
JA
924#endif
925
926void flush_log(struct io_log *log)
927{
928 void *buf;
929 FILE *f;
930
931 f = fopen(log->filename, "w");
932 if (!f) {
933 perror("fopen log");
934 return;
935 }
936
937 buf = set_file_buffer(f);
938
1a8e7458 939 inflate_gz_chunks(log, f);
aee2ab67 940
b26317c9 941 flush_samples(f, log->log, log->nr_samples * log_entry_sz(log));
ac9b9101
JA
942
943 fclose(f);
2e802282 944 clear_file_buffer(buf);
ac9b9101
JA
945}
946
cb7e0ace 947static int finish_log(struct thread_data *td, struct io_log *log, int trylock)
ac9b9101 948{
aee2ab67
JA
949 if (td->tp_data)
950 iolog_flush(log, 1);
951
243bfe19 952 if (trylock) {
cb7e0ace 953 if (fio_trylock_file(log->filename))
243bfe19
JA
954 return 1;
955 } else
cb7e0ace 956 fio_lock_file(log->filename);
243bfe19 957
aee2ab67 958 if (td->client_type == FIO_CLIENT_TYPE_GUI)
cb7e0ace 959 fio_send_iolog(td, log, log->filename);
aee2ab67
JA
960 else
961 flush_log(log);
243bfe19 962
cb7e0ace 963 fio_unlock_file(log->filename);
518dac09 964 free_log(log);
243bfe19 965 return 0;
ac9b9101
JA
966}
967
aee2ab67
JA
968#ifdef CONFIG_ZLIB
969
1a8e7458
JA
970/*
971 * Invoked from our compress helper thread, when logging would have exceeded
972 * the specified memory limitation. Compresses the previously stored
973 * entries.
974 */
aee2ab67
JA
975static int gz_work(struct tp_work *work)
976{
977 struct iolog_flush_data *data;
978 struct iolog_compress *c;
979 struct flist_head list;
980 unsigned int seq;
981 z_stream stream;
982 size_t total = 0;
d73ac887 983 int ret;
aee2ab67
JA
984
985 INIT_FLIST_HEAD(&list);
986
987 data = container_of(work, struct iolog_flush_data, work);
988
989 stream.zalloc = Z_NULL;
990 stream.zfree = Z_NULL;
991 stream.opaque = Z_NULL;
992
b26317c9 993 ret = deflateInit(&stream, Z_DEFAULT_COMPRESSION);
b26317c9 994 if (ret != Z_OK) {
aee2ab67
JA
995 log_err("fio: failed to init gz stream\n");
996 return 0;
997 }
998
999 seq = ++data->log->chunk_seq;
b26317c9 1000
aee2ab67
JA
1001 stream.next_in = (void *) data->samples;
1002 stream.avail_in = data->nr_samples * log_entry_sz(data->log);
1003
0c56718d
JA
1004 dprint(FD_COMPRESS, "deflate input size=%lu, seq=%u\n",
1005 (unsigned long) stream.avail_in, seq);
aee2ab67
JA
1006 do {
1007 c = get_new_chunk(seq);
1008 stream.avail_out = GZ_CHUNK;
1009 stream.next_out = c->buf;
1010 ret = deflate(&stream, Z_NO_FLUSH);
1011 if (ret < 0) {
1012 log_err("fio: deflate log (%d)\n", ret);
dad95da1
JA
1013 free_chunk(c);
1014 goto err;
aee2ab67
JA
1015 }
1016
1017 c->len = GZ_CHUNK - stream.avail_out;
1018 flist_add_tail(&c->list, &list);
1019 total += c->len;
1020 } while (stream.avail_in);
1021
1022 stream.next_out = c->buf + c->len;
1023 stream.avail_out = GZ_CHUNK - c->len;
1024
1025 ret = deflate(&stream, Z_FINISH);
1026 if (ret == Z_STREAM_END)
1027 c->len = GZ_CHUNK - stream.avail_out;
1028 else {
1029 do {
1030 c = get_new_chunk(seq);
1031 stream.avail_out = GZ_CHUNK;
1032 stream.next_out = c->buf;
1033 ret = deflate(&stream, Z_FINISH);
1034 c->len = GZ_CHUNK - stream.avail_out;
0c56718d 1035 total += c->len;
aee2ab67
JA
1036 flist_add_tail(&c->list, &list);
1037 } while (ret != Z_STREAM_END);
1038 }
1039
0c56718d
JA
1040 dprint(FD_COMPRESS, "deflated to size=%lu\n", (unsigned long) total);
1041
aee2ab67
JA
1042 ret = deflateEnd(&stream);
1043 if (ret != Z_OK)
1044 log_err("fio: deflateEnd %d\n", ret);
1045
1046 free(data->samples);
1047
1048 if (!flist_empty(&list)) {
1049 pthread_mutex_lock(&data->log->chunk_lock);
1050 flist_splice_tail(&list, &data->log->chunk_list);
1051 pthread_mutex_unlock(&data->log->chunk_lock);
1052 }
1053
dad95da1
JA
1054 ret = 0;
1055done:
aee2ab67
JA
1056 if (work->wait) {
1057 work->done = 1;
1058 pthread_cond_signal(&work->cv);
1059 } else
1060 free(data);
1061
dad95da1
JA
1062 return ret;
1063err:
1064 while (!flist_empty(&list)) {
1065 c = flist_first_entry(list.next, struct iolog_compress, list);
1066 flist_del(&c->list);
1067 free_chunk(c);
1068 }
1069 ret = 1;
1070 goto done;
aee2ab67
JA
1071}
1072
1a8e7458
JA
1073/*
1074 * Queue work item to compress the existing log entries. We copy the
1075 * samples, and reset the log sample count to 0 (so the logging will
1076 * continue to use the memory associated with the log). If called with
1077 * wait == 1, will not return until the log compression has completed.
1078 */
aee2ab67
JA
1079int iolog_flush(struct io_log *log, int wait)
1080{
b26317c9 1081 struct tp_data *tdat = log->td->tp_data;
aee2ab67
JA
1082 struct iolog_flush_data *data;
1083 size_t sample_size;
1084
1085 data = malloc(sizeof(*data));
1086 if (!data)
1087 return 1;
1088
1089 data->log = log;
1090
1091 sample_size = log->nr_samples * log_entry_sz(log);
1092 data->samples = malloc(sample_size);
1093 if (!data->samples) {
1094 free(data);
1095 return 1;
1096 }
1097
1098 memcpy(data->samples, log->log, sample_size);
1099 data->nr_samples = log->nr_samples;
1100 data->work.fn = gz_work;
1101 log->nr_samples = 0;
1102
1103 if (wait) {
1104 pthread_mutex_init(&data->work.lock, NULL);
1105 pthread_cond_init(&data->work.cv, NULL);
1106 data->work.wait = 1;
1107 } else
1108 data->work.wait = 0;
1109
5930db2c 1110 data->work.prio = 1;
b26317c9 1111 tp_queue_work(tdat, &data->work);
aee2ab67
JA
1112
1113 if (wait) {
1114 pthread_mutex_lock(&data->work.lock);
1115 while (!data->work.done)
1116 pthread_cond_wait(&data->work.cv, &data->work.lock);
1117 pthread_mutex_unlock(&data->work.lock);
1118 free(data);
1119 }
1120
1121 return 0;
1122}
1123
1124#else
1125
1126int iolog_flush(struct io_log *log, int wait)
1127{
1128 return 1;
1129}
1130
1131#endif
1132
cb7e0ace 1133static int write_iops_log(struct thread_data *td, int try)
905e3d4f 1134{
cb7e0ace 1135 struct io_log *log = td->iops_log;
905e3d4f
JA
1136
1137 if (!log)
1138 return 0;
1139
cb7e0ace 1140 return finish_log(td, log, try);
905e3d4f
JA
1141}
1142
1143static int write_slat_log(struct thread_data *td, int try)
1144{
cb7e0ace 1145 struct io_log *log = td->slat_log;
905e3d4f 1146
cb7e0ace
JA
1147 if (!log)
1148 return 0;
1149
1150 return finish_log(td, log, try);
905e3d4f
JA
1151}
1152
1153static int write_clat_log(struct thread_data *td, int try)
1154{
cb7e0ace 1155 struct io_log *log = td->clat_log;
905e3d4f 1156
cb7e0ace
JA
1157 if (!log)
1158 return 0;
1159
1160 return finish_log(td, log, try);
905e3d4f
JA
1161}
1162
1163static int write_lat_log(struct thread_data *td, int try)
1164{
cb7e0ace
JA
1165 struct io_log *log = td->lat_log;
1166
1167 if (!log)
1168 return 0;
905e3d4f 1169
cb7e0ace 1170 return finish_log(td, log, try);
905e3d4f
JA
1171}
1172
1173static int write_bandw_log(struct thread_data *td, int try)
1174{
cb7e0ace
JA
1175 struct io_log *log = td->bw_log;
1176
1177 if (!log)
1178 return 0;
905e3d4f 1179
cb7e0ace 1180 return finish_log(td, log, try);
905e3d4f
JA
1181}
1182
1183enum {
1184 BW_LOG_MASK = 1,
1185 LAT_LOG_MASK = 2,
1186 SLAT_LOG_MASK = 4,
1187 CLAT_LOG_MASK = 8,
1188 IOPS_LOG_MASK = 16,
1189
905e3d4f
JA
1190 ALL_LOG_NR = 5,
1191};
1192
1193struct log_type {
1194 unsigned int mask;
1195 int (*fn)(struct thread_data *, int);
1196};
1197
1198static struct log_type log_types[] = {
1199 {
1200 .mask = BW_LOG_MASK,
1201 .fn = write_bandw_log,
1202 },
1203 {
1204 .mask = LAT_LOG_MASK,
1205 .fn = write_lat_log,
1206 },
1207 {
1208 .mask = SLAT_LOG_MASK,
1209 .fn = write_slat_log,
1210 },
1211 {
1212 .mask = CLAT_LOG_MASK,
1213 .fn = write_clat_log,
1214 },
1215 {
1216 .mask = IOPS_LOG_MASK,
1217 .fn = write_iops_log,
1218 },
1219};
1220
1221void fio_writeout_logs(struct thread_data *td)
1222{
ea5409f9 1223 unsigned int log_mask = 0;
905e3d4f
JA
1224 unsigned int log_left = ALL_LOG_NR;
1225 int old_state, i;
1226
1227 old_state = td_bump_runstate(td, TD_FINISHING);
1228
1229 finalize_logs(td);
1230
1231 while (log_left) {
1232 int prev_log_left = log_left;
1233
1234 for (i = 0; i < ALL_LOG_NR && log_left; i++) {
1235 struct log_type *lt = &log_types[i];
1236 int ret;
1237
ea5409f9 1238 if (!(log_mask & lt->mask)) {
905e3d4f
JA
1239 ret = lt->fn(td, log_left != 1);
1240 if (!ret) {
1241 log_left--;
ea5409f9 1242 log_mask |= lt->mask;
905e3d4f
JA
1243 }
1244 }
1245 }
1246
1247 if (prev_log_left == log_left)
1248 usleep(5000);
1249 }
1250
1251 td_restore_runstate(td, old_state);
1252}