* Re: [PATCH] Log offsets of I/O operations
2014-06-30 22:09 ` Abutalib Aghayev
@ 2014-06-30 22:19 ` Jens Axboe
2014-07-01 3:00 ` Jens Axboe
0 siblings, 1 reply; 6+ messages in thread
From: Jens Axboe @ 2014-06-30 22:19 UTC (permalink / raw)
To: Abutalib Aghayev; +Cc: fio
[-- Attachment #1: Type: text/plain, Size: 1514 bytes --]
On 2014-06-30 16:09, Abutalib Aghayev wrote:
>
> On Mon, Jun 30 2014 at 17:50 PM, Jens Axboe <axboe@kernel.dk> wrote:
>> On 2014-06-29 11:43, Abutalib Aghayev wrote:
>>>
>>> This is a quick and dirty patch to log offsets of I/O operations as
>>> well. It is useful if you would like to make offset vs latency plot for
>>> random I/O, which may not be interesting to many people, so feel free to
>>> ignore it.
>>
>> I can definitely see this being useful. But adding 8 bytes to every log
>> entry complicates things, as fio is already memory intensive there when
>> logging longer runs.
>>
>> I'd suggest having two logging types:
>>
>> struct io_sample {
>> uint64_t time;
>> uint64_t val;
>> uint32_t ddir;
>> uint32_t bs;
>> uint64_t offset;
>
> I assume you didn't mean offset being here as well.
Ah no, of course not.
>> struct io_sample_offset {
>> struct io_sample s;
>> uint64_t offset;
>> };
>>
>> and using the right type for what you are logging. This means you'd need
>> an option to switch on the offset logging, and that you'd need to store
>> this in the iolog struct (whether to log offset or not) and use the
>> appropriate size for allocating and extending the log entries when needed.
>>
>> Make sense?
>
> Yes, let me rework the patch.
Thanks! Note that you also need to handle the client/server part.
Half-assed attempt attached, not tested at all. Still needs the client
part update.
--
Jens Axboe
[-- Attachment #2: iolog-offset.patch --]
[-- Type: text/x-patch, Size: 16522 bytes --]
diff --git a/backend.c b/backend.c
index ee75566af84c..ac6ed3e45fc2 100644
--- a/backend.c
+++ b/backend.c
@@ -2020,9 +2020,9 @@ int fio_backend(void)
return 0;
if (write_bw_log) {
- setup_log(&agg_io_log[DDIR_READ], 0, IO_LOG_TYPE_BW);
- setup_log(&agg_io_log[DDIR_WRITE], 0, IO_LOG_TYPE_BW);
- setup_log(&agg_io_log[DDIR_TRIM], 0, IO_LOG_TYPE_BW);
+ setup_log(&agg_io_log[DDIR_READ], 0, IO_LOG_TYPE_BW, 0);
+ setup_log(&agg_io_log[DDIR_WRITE], 0, IO_LOG_TYPE_BW, 0);
+ setup_log(&agg_io_log[DDIR_TRIM], 0, IO_LOG_TYPE_BW, 0);
}
startup_mutex = fio_mutex_init(FIO_MUTEX_LOCKED);
diff --git a/client.c b/client.c
index 828dd97b0b35..9ab7e70df8ca 100644
--- a/client.c
+++ b/client.c
@@ -1156,7 +1156,11 @@ static struct cmd_iolog_pdu *convert_iolog_gz(struct fio_net_cmd *cmd,
*/
nr_samples = le32_to_cpu(pdu->nr_samples);
- total = nr_samples * sizeof(struct io_sample);
+ if (pdu->log_offset)
+ total = nr_samples * sizeof(struct io_sample);
+ else
+ total = nr_samples * sizeof(struct io_sample_offset);
+
ret = malloc(total + sizeof(*pdu));
ret->nr_samples = nr_samples;
@@ -1225,10 +1229,11 @@ static struct cmd_iolog_pdu *convert_iolog(struct fio_net_cmd *cmd)
} else
ret = pdu;
+ ret->nr_samples = le64_to_cpu(ret->nr_samples);
ret->thread_number = le32_to_cpu(ret->thread_number);
- ret->nr_samples = le32_to_cpu(ret->nr_samples);
ret->log_type = le32_to_cpu(ret->log_type);
ret->compressed = le32_to_cpu(ret->compressed);
+ ret->log_offset = le32_to_cpu(ret->log_offset);
for (i = 0; i < ret->nr_samples; i++) {
struct io_sample *s = &ret->samples[i];
diff --git a/init.c b/init.c
index 6b29aa702407..4f8b38d6e632 100644
--- a/init.c
+++ b/init.c
@@ -1146,14 +1146,19 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num,
goto err;
if (o->lat_log_file || write_lat_log) {
- setup_log(&td->lat_log, o->log_avg_msec, IO_LOG_TYPE_LAT);
- setup_log(&td->slat_log, o->log_avg_msec, IO_LOG_TYPE_SLAT);
- setup_log(&td->clat_log, o->log_avg_msec, IO_LOG_TYPE_CLAT);
+ setup_log(&td->lat_log, o->log_avg_msec, IO_LOG_TYPE_LAT,
+ o->log_offset);
+ setup_log(&td->slat_log, o->log_avg_msec, IO_LOG_TYPE_SLAT,
+ o->log_offset);
+ setup_log(&td->clat_log, o->log_avg_msec, IO_LOG_TYPE_CLAT,
+ o->log_offset);
}
if (o->bw_log_file || write_bw_log)
- setup_log(&td->bw_log, o->log_avg_msec, IO_LOG_TYPE_BW);
+ setup_log(&td->bw_log, o->log_avg_msec, IO_LOG_TYPE_BW,
+ o->log_offset);
if (o->iops_log_file)
- setup_log(&td->iops_log, o->log_avg_msec, IO_LOG_TYPE_IOPS);
+ setup_log(&td->iops_log, o->log_avg_msec, IO_LOG_TYPE_IOPS,
+ o->log_offset);
if (!o->name)
o->name = strdup(jobname);
diff --git a/io_u.c b/io_u.c
index 997e1137ab90..5b9d483dcd33 100644
--- a/io_u.c
+++ b/io_u.c
@@ -1567,7 +1567,7 @@ static void account_io_completion(struct thread_data *td, struct io_u *io_u,
unsigned long tusec;
tusec = utime_since(&io_u->start_time, &icd->time);
- add_lat_sample(td, idx, tusec, bytes);
+ add_lat_sample(td, idx, tusec, bytes, io_u->offset);
if (td->flags & TD_F_PROFILE_OPS) {
struct prof_io_ops *ops = &td->prof_io_ops;
@@ -1585,7 +1585,7 @@ static void account_io_completion(struct thread_data *td, struct io_u *io_u,
}
if (!td->o.disable_clat) {
- add_clat_sample(td, idx, lusec, bytes);
+ add_clat_sample(td, idx, lusec, bytes, io_u->offset);
io_u_mark_latency(td, lusec);
}
@@ -1823,7 +1823,8 @@ void io_u_queued(struct thread_data *td, struct io_u *io_u)
unsigned long slat_time;
slat_time = utime_since(&io_u->start_time, &io_u->issue_time);
- add_slat_sample(td, io_u->ddir, slat_time, io_u->xfer_buflen);
+ add_slat_sample(td, io_u->ddir, slat_time, io_u->xfer_buflen,
+ io_u->offset);
}
}
diff --git a/iolog.c b/iolog.c
index fd1e9e49dd18..ad3cf9cd9151 100644
--- a/iolog.c
+++ b/iolog.c
@@ -539,7 +539,8 @@ int init_iolog(struct thread_data *td)
return ret;
}
-void setup_log(struct io_log **log, unsigned long avg_msec, int log_type)
+void setup_log(struct io_log **log, unsigned long avg_msec, int log_type,
+ int log_offset)
{
struct io_log *l = malloc(sizeof(*l));
@@ -547,7 +548,8 @@ void setup_log(struct io_log **log, unsigned long avg_msec, int log_type)
l->nr_samples = 0;
l->max_samples = 1024;
l->log_type = log_type;
- l->log = malloc(l->max_samples * sizeof(struct io_sample));
+ l->log_offset = log_offset;
+ l->log = malloc(l->max_samples * log_entry_sz(l));
l->avg_msec = avg_msec;
*log = l;
}
@@ -593,10 +595,22 @@ void __finish_log(struct io_log *log, const char *name)
buf = set_file_buffer(f);
for (i = 0; i < log->nr_samples; i++) {
- fprintf(f, "%lu, %lu, %u, %u\n",
- (unsigned long) log->log[i].time,
- (unsigned long) log->log[i].val,
- log->log[i].ddir, log->log[i].bs);
+ struct io_sample *s = get_sample(log, i);
+
+ if (!log->log_offset) {
+ fprintf(f, "%lu, %lu, %u, %u\n",
+ (unsigned long) s->time,
+ (unsigned long) s->val,
+ s->ddir, s->bs);
+ } else {
+ struct io_sample_offset *so = (void *) s;
+
+ fprintf(f, "%lu, %lu, %u, %u, %llu\n",
+ (unsigned long) s->time,
+ (unsigned long) s->val,
+ s->ddir, s->bs,
+ (unsigned long long) so->offset);
+ }
}
fclose(f);
diff --git a/iolog.h b/iolog.h
index 3af56682c64e..42095b2379ff 100644
--- a/iolog.h
+++ b/iolog.h
@@ -28,6 +28,11 @@ struct io_sample {
uint32_t bs;
};
+struct io_sample_offset {
+ struct io_sample s;
+ uint64_t offset;
+};
+
enum {
IO_LOG_TYPE_LAT = 1,
IO_LOG_TYPE_CLAT,
@@ -45,7 +50,7 @@ struct io_log {
*/
unsigned long nr_samples;
unsigned long max_samples;
- struct io_sample *log;
+ void *log;
unsigned int log_type;
@@ -55,6 +60,11 @@ struct io_log {
unsigned int disabled;
/*
+ * Log offsets
+ */
+ unsigned int log_offset;
+
+ /*
* Windowed average, for logging single entries average over some
* period of time.
*/
@@ -63,6 +73,20 @@ struct io_log {
unsigned long avg_last;
};
+static inline size_t log_entry_sz(struct io_log *log)
+{
+ if (log->log_offset)
+ return sizeof(struct io_sample_offset);
+ else
+ return sizeof(struct io_sample);
+}
+
+static inline struct io_sample *get_sample(struct io_log *iolog,
+ uint64_t sample)
+{
+ return iolog->log + sample * log_entry_sz(iolog);
+}
+
enum {
IP_F_ONRB = 1,
IP_F_ONLIST = 2,
@@ -121,18 +145,18 @@ extern void write_iolog_close(struct thread_data *);
*/
extern void finalize_logs(struct thread_data *td);
extern void add_lat_sample(struct thread_data *, enum fio_ddir, unsigned long,
- unsigned int);
+ unsigned int, unsigned long long);
extern void add_clat_sample(struct thread_data *, enum fio_ddir, unsigned long,
- unsigned int);
+ unsigned int, unsigned long long);
extern void add_slat_sample(struct thread_data *, enum fio_ddir, unsigned long,
- unsigned int);
+ unsigned int, unsigned long long);
extern void add_bw_sample(struct thread_data *, enum fio_ddir, unsigned int,
struct timeval *);
extern void add_iops_sample(struct thread_data *, enum fio_ddir, unsigned int,
struct timeval *);
extern void init_disk_util(struct thread_data *);
extern void update_rusage_stat(struct thread_data *);
-extern void setup_log(struct io_log **, unsigned long, int);
+extern void setup_log(struct io_log **, unsigned long, int, int);
extern void __finish_log(struct io_log *, const char *);
extern struct io_log *agg_io_log[DDIR_RWDIR_CNT];
extern int write_bw_log;
diff --git a/options.c b/options.c
index 74347f3554e0..da70087d2fd7 100644
--- a/options.c
+++ b/options.c
@@ -3095,6 +3095,16 @@ struct fio_option fio_options[FIO_MAX_OPTS] = {
.group = FIO_OPT_G_INVALID,
},
{
+ .name = "log_offset",
+ .lname = "Log offset of IO",
+ .type = FIO_OPT_INT,
+ .off1 = td_var_offset(log_offset),
+ .help = "Include offset of IO for each log entry",
+ .def = "0",
+ .category = FIO_OPT_C_LOG,
+ .group = FIO_OPT_G_INVALID,
+ },
+ {
.name = "bwavgtime",
.lname = "Bandwidth average time",
.type = FIO_OPT_INT,
diff --git a/server.c b/server.c
index 76b6b54d369b..cd00cc65f852 100644
--- a/server.c
+++ b/server.c
@@ -1177,7 +1177,7 @@ static int fio_send_iolog_gz(struct cmd_iolog_pdu *pdu, struct io_log *log)
}
stream.next_in = (void *) log->log;
- stream.avail_in = log->nr_samples * sizeof(struct io_sample);
+ stream.avail_in = log->nr_samples * log_entry_sz(log);
do {
unsigned int this_len, flags = 0;
@@ -1214,8 +1214,8 @@ int fio_send_iolog(struct thread_data *td, struct io_log *log, const char *name)
struct cmd_iolog_pdu pdu;
int i, ret = 0;
+ pdu.nr_samples = cpu_to_le64(log->nr_samples);
pdu.thread_number = cpu_to_le32(td->thread_number);
- pdu.nr_samples = __cpu_to_le32(log->nr_samples);
pdu.log_type = cpu_to_le32(log->log_type);
pdu.compressed = cpu_to_le32(use_zlib);
@@ -1223,12 +1223,18 @@ int fio_send_iolog(struct thread_data *td, struct io_log *log, const char *name)
pdu.name[FIO_NET_NAME_MAX - 1] = '\0';
for (i = 0; i < log->nr_samples; i++) {
- struct io_sample *s = &log->log[i];
+ struct io_sample *s = get_sample(log, i);
s->time = cpu_to_le64(s->time);
s->val = cpu_to_le64(s->val);
s->ddir = cpu_to_le32(s->ddir);
s->bs = cpu_to_le32(s->bs);
+
+ if (log->log_offset) {
+ struct io_sample_offset *so = (void *) s;
+
+ so->offset = cpu_to_le64(so->offset);
+ }
}
/*
@@ -1246,7 +1252,7 @@ int fio_send_iolog(struct thread_data *td, struct io_log *log, const char *name)
return fio_send_iolog_gz(&pdu, log);
return fio_send_cmd_ext_pdu(server_fd, FIO_NET_CMD_IOLOG, log->log,
- log->nr_samples * sizeof(struct io_sample), 0, 0);
+ log->nr_samples * log_entry_sz(log), 0, 0);
}
void fio_server_send_add_job(struct thread_data *td)
diff --git a/server.h b/server.h
index 52ad4a1518fb..cc4c5b435a2f 100644
--- a/server.h
+++ b/server.h
@@ -143,10 +143,11 @@ struct cmd_text_pdu {
};
struct cmd_iolog_pdu {
+ uint64_t nr_samples;
uint32_t thread_number;
- uint32_t nr_samples;
uint32_t log_type;
uint32_t compressed;
+ uint32_t log_offset;
uint8_t name[FIO_NET_NAME_MAX];
struct io_sample samples[0];
};
diff --git a/stat.c b/stat.c
index 3adb46eab808..bac637592f94 100644
--- a/stat.c
+++ b/stat.c
@@ -1563,9 +1563,10 @@ static inline void add_stat_sample(struct io_stat *is, unsigned long data)
static void __add_log_sample(struct io_log *iolog, unsigned long val,
enum fio_ddir ddir, unsigned int bs,
- unsigned long t)
+ unsigned long t, unsigned long long offset)
{
const int nr_samples = iolog->nr_samples;
+ struct io_sample *s;
if (iolog->disabled)
return;
@@ -1574,9 +1575,10 @@ static void __add_log_sample(struct io_log *iolog, unsigned long val,
iolog->avg_last = t;
if (iolog->nr_samples == iolog->max_samples) {
- int new_size = sizeof(struct io_sample) * iolog->max_samples*2;
+ size_t new_size;
void *new_log;
+ new_size = 2 * iolog->max_samples * log_entry_sz(iolog);
new_log = realloc(iolog->log, new_size);
if (!new_log) {
log_err("fio: failed extending iolog! Will stop logging.\n");
@@ -1587,10 +1589,19 @@ static void __add_log_sample(struct io_log *iolog, unsigned long val,
iolog->max_samples <<= 1;
}
- iolog->log[nr_samples].val = val;
- iolog->log[nr_samples].time = t;
- iolog->log[nr_samples].ddir = ddir;
- iolog->log[nr_samples].bs = bs;
+ s = get_sample(iolog, nr_samples);
+
+ s->val = val;
+ s->time = t;
+ s->ddir = ddir;
+ s->bs = bs;
+
+ if (iolog->log_offset) {
+ struct io_sample_offset *so = (void *) s;
+
+ so->offset = offset;
+ }
+
iolog->nr_samples++;
}
@@ -1646,19 +1657,19 @@ static void _add_stat_to_log(struct io_log *iolog, unsigned long elapsed)
unsigned long mr;
mr = iolog->avg_window[DDIR_READ].mean.u.f + 0.50;
- __add_log_sample(iolog, mr, DDIR_READ, 0, elapsed);
+ __add_log_sample(iolog, mr, DDIR_READ, 0, elapsed, 0);
}
if (iolog->avg_window[DDIR_WRITE].samples) {
unsigned long mw;
mw = iolog->avg_window[DDIR_WRITE].mean.u.f + 0.50;
- __add_log_sample(iolog, mw, DDIR_WRITE, 0, elapsed);
+ __add_log_sample(iolog, mw, DDIR_WRITE, 0, elapsed, 0);
}
if (iolog->avg_window[DDIR_TRIM].samples) {
unsigned long mw;
mw = iolog->avg_window[DDIR_TRIM].mean.u.f + 0.50;
- __add_log_sample(iolog, mw, DDIR_TRIM, 0, elapsed);
+ __add_log_sample(iolog, mw, DDIR_TRIM, 0, elapsed, 0);
}
reset_io_stat(&iolog->avg_window[DDIR_READ]);
@@ -1668,7 +1679,7 @@ static void _add_stat_to_log(struct io_log *iolog, unsigned long elapsed)
static void add_log_sample(struct thread_data *td, struct io_log *iolog,
unsigned long val, enum fio_ddir ddir,
- unsigned int bs)
+ unsigned int bs, unsigned long long offset)
{
unsigned long elapsed, this_window;
@@ -1681,7 +1692,7 @@ static void add_log_sample(struct thread_data *td, struct io_log *iolog,
* If no time averaging, just add the log sample.
*/
if (!iolog->avg_msec) {
- __add_log_sample(iolog, val, ddir, bs, elapsed);
+ __add_log_sample(iolog, val, ddir, bs, elapsed, offset);
return;
}
@@ -1730,7 +1741,7 @@ void add_agg_sample(unsigned long val, enum fio_ddir ddir, unsigned int bs)
return;
iolog = agg_io_log[ddir];
- __add_log_sample(iolog, val, ddir, bs, mtime_since_genesis());
+ __add_log_sample(iolog, val, ddir, bs, mtime_since_genesis(), 0);
}
static void add_clat_percentile_sample(struct thread_stat *ts,
@@ -1743,7 +1754,8 @@ static void add_clat_percentile_sample(struct thread_stat *ts,
}
void add_clat_sample(struct thread_data *td, enum fio_ddir ddir,
- unsigned long usec, unsigned int bs)
+ unsigned long usec, unsigned int bs,
+ unsigned long long offset)
{
struct thread_stat *ts = &td->ts;
@@ -1753,14 +1765,15 @@ void add_clat_sample(struct thread_data *td, enum fio_ddir ddir,
add_stat_sample(&ts->clat_stat[ddir], usec);
if (td->clat_log)
- add_log_sample(td, td->clat_log, usec, ddir, bs);
+ add_log_sample(td, td->clat_log, usec, ddir, bs, offset);
if (ts->clat_percentiles)
add_clat_percentile_sample(ts, usec, ddir);
}
void add_slat_sample(struct thread_data *td, enum fio_ddir ddir,
- unsigned long usec, unsigned int bs)
+ unsigned long usec, unsigned int bs,
+ unsigned long long offset)
{
struct thread_stat *ts = &td->ts;
@@ -1770,11 +1783,12 @@ void add_slat_sample(struct thread_data *td, enum fio_ddir ddir,
add_stat_sample(&ts->slat_stat[ddir], usec);
if (td->slat_log)
- add_log_sample(td, td->slat_log, usec, ddir, bs);
+ add_log_sample(td, td->slat_log, usec, ddir, bs, offset);
}
void add_lat_sample(struct thread_data *td, enum fio_ddir ddir,
- unsigned long usec, unsigned int bs)
+ unsigned long usec, unsigned int bs,
+ unsigned long long offset)
{
struct thread_stat *ts = &td->ts;
@@ -1784,7 +1798,7 @@ void add_lat_sample(struct thread_data *td, enum fio_ddir ddir,
add_stat_sample(&ts->lat_stat[ddir], usec);
if (td->lat_log)
- add_log_sample(td, td->lat_log, usec, ddir, bs);
+ add_log_sample(td, td->lat_log, usec, ddir, bs, offset);
}
void add_bw_sample(struct thread_data *td, enum fio_ddir ddir, unsigned int bs,
@@ -1818,7 +1832,7 @@ void add_bw_sample(struct thread_data *td, enum fio_ddir ddir, unsigned int bs,
add_stat_sample(&ts->bw_stat[ddir], rate);
if (td->bw_log)
- add_log_sample(td, td->bw_log, rate, ddir, bs);
+ add_log_sample(td, td->bw_log, rate, ddir, bs, 0);
td->stat_io_bytes[ddir] = td->this_io_bytes[ddir];
}
@@ -1857,7 +1871,7 @@ void add_iops_sample(struct thread_data *td, enum fio_ddir ddir, unsigned int bs
add_stat_sample(&ts->iops_stat[ddir], iops);
if (td->iops_log)
- add_log_sample(td, td->iops_log, iops, ddir, bs);
+ add_log_sample(td, td->iops_log, iops, ddir, bs, 0);
td->stat_io_blocks[ddir] = td->this_io_blocks[ddir];
}
diff --git a/thread_options.h b/thread_options.h
index 57d84dbba3de..e53000ab248b 100644
--- a/thread_options.h
+++ b/thread_options.h
@@ -108,6 +108,7 @@ struct thread_options {
unsigned long long rand_seed;
unsigned int use_os_rand;
unsigned int log_avg_msec;
+ unsigned int log_offset;
unsigned int norandommap;
unsigned int softrandommap;
unsigned int bs_unaligned;
@@ -335,6 +336,7 @@ struct thread_options_pack {
uint64_t rand_seed;
uint32_t use_os_rand;
uint32_t log_avg_msec;
+ uint32_t log_offset;
uint32_t norandommap;
uint32_t softrandommap;
uint32_t bs_unaligned;
^ permalink raw reply related [flat|nested] 6+ messages in thread