* All I/O patterns are replayed to one file with fio 2.0.13
@ 2013-02-14 19:37 Nikolaus Jeremic
2013-02-18 13:57 ` Jens Axboe
0 siblings, 1 reply; 4+ messages in thread
From: Nikolaus Jeremic @ 2013-02-14 19:37 UTC (permalink / raw)
To: fio
Hi,
I've tried to replay I/Os from a textual iolog file to a couple of files
using fio 2.0.13 on Linux. However, all I/Os were performed to the last
opened file, which is '/mnt/ssd5/rand-write.1.0_1_2' in this example .
My jobfile and iolog files contain the following:
############### job file #########
[global]
name=replay_filetraces
description=Replay file traces
ioengine=libaio
iodepth=6
direct=1
continue_on_error=1
[replay]
numjobs=1
read_iolog=file_io_patterns
unlink=0
############## EOF #########
############## iolog file #########
fio version 2 iolog
/mnt/ssd0/rand-write.1.0_0_0 add
/mnt/ssd1/rand-write.1.0_0_1 add
/mnt/ssd2/rand-write.1.0_0_2 add
/mnt/ssd3/rand-write.1.0_1_0 add
/mnt/ssd4/rand-write.1.0_1_1 add
/mnt/ssd5/rand-write.1.0_1_2 add
/mnt/ssd0/rand-write.1.0_0_0 open
/mnt/ssd1/rand-write.1.0_0_1 open
/mnt/ssd2/rand-write.1.0_0_2 open
/mnt/ssd3/rand-write.1.0_1_0 open
/mnt/ssd4/rand-write.1.0_1_1 open
/mnt/ssd5/rand-write.1.0_1_2 open
/mnt/ssd0/rand-write.1.0_0_0 write 0 65536
/mnt/ssd1/rand-write.1.0_0_1 write 0 65536
/mnt/ssd2/rand-write.1.0_0_2 write 0 65536
/mnt/ssd3/rand-write.1.0_1_0 write 0 65536
/mnt/ssd4/rand-write.1.0_1_1 write 0 65536
/mnt/ssd5/rand-write.1.0_1_2 write 0 65536
/mnt/ssd0/rand-write.1.0_0_0 write 65536 65536
/mnt/ssd1/rand-write.1.0_0_1 write 65536 65536
/mnt/ssd2/rand-write.1.0_0_2 write 65536 65536
/mnt/ssd3/rand-write.1.0_1_0 write 65536 65536
/mnt/ssd4/rand-write.1.0_1_1 write 65536 65536
/mnt/ssd5/rand-write.1.0_1_2 write 65536 65536
/mnt/ssd0/rand-write.1.0_0_0 close
/mnt/ssd1/rand-write.1.0_0_1 close
/mnt/ssd2/rand-write.1.0_0_2 close
/mnt/ssd3/rand-write.1.0_1_0 close
/mnt/ssd4/rand-write.1.0_1_1 close
/mnt/ssd5/rand-write.1.0_1_2 close
############## EOF #########
I've turned on debugging and added some extra printf in read_iolog2()
within iolog.c.
############## begin of debug excerpt ########
file 24594 add file /mnt/ssd0/rand-write.1.0_0_0
file 24594 resize file array to 2 files
file 24594 file 0x7fbe03f53090 "/mnt/ssd0/rand-write.1.0_0_0" added at 0
file 24594 add file /mnt/ssd1/rand-write.1.0_0_1
file 24594 file 0x7fbe03f53230 "/mnt/ssd1/rand-write.1.0_0_1" added at 1
file 24594 add file /mnt/ssd2/rand-write.1.0_0_2
file 24594 resize file array to 4 files
file 24594 file 0x7fbe03f533d0 "/mnt/ssd2/rand-write.1.0_0_2" added at 2
file 24594 add file /mnt/ssd3/rand-write.1.0_1_0
file 24594 file 0x7fbe03f53570 "/mnt/ssd3/rand-write.1.0_1_0" added at 3
file 24594 add file /mnt/ssd4/rand-write.1.0_1_1
file 24594 resize file array to 6 files
file 24594 file 0x7fbe03f53710 "/mnt/ssd4/rand-write.1.0_1_1" added at 4
file 24594 add file /mnt/ssd5/rand-write.1.0_1_2
file 24594 file 0x7fbe03f538b0 "/mnt/ssd5/rand-write.1.0_1_2" added at 5
io 24594 read_iolog2: Making note of file.
offset=7310584035475809390 bytes=811544671 fileno=0 file_action=1
fname=/mnt/ssd0/rand-write.1.0_0_0 act=open
io 24594 read_iolog2: Making note of file.
offset=7310584035475809390 bytes=811544671 fileno=1 file_action=1
fname=/mnt/ssd1/rand-write.1.0_0_1 act=open
io 24594 read_iolog2: Making note of file.
offset=7310584035475809390 bytes=811544671 fileno=2 file_action=1
fname=/mnt/ssd2/rand-write.1.0_0_2 act=open
io 24594 read_iolog2: Making note of file.
offset=7310584035475809390 bytes=811544671 fileno=3 file_action=1
fname=/mnt/ssd3/rand-write.1.0_1_0 act=open
io 24594 read_iolog2: Making note of file.
offset=7310584035475809390 bytes=811544671 fileno=4 file_action=1
fname=/mnt/ssd4/rand-write.1.0_1_1 act=open
io 24594 read_iolog2: Making note of file.
offset=7310584035475809390 bytes=811544671 fileno=5 file_action=1
fname=/mnt/ssd5/rand-write.1.0_1_2 act=open
io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
fileno=5 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0 act=write
io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
fileno=5 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1 act=write
io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
fileno=5 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2 act=write
io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
fileno=5 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0 act=write
io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
fileno=5 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1 act=write
io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2 act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0
act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1
act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2
act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0
act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1
act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2
act=write
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=0 file_action=2 fname=/mnt/ssd0/rand-write.1.0_0_0
act=close
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=1 file_action=2 fname=/mnt/ssd1/rand-write.1.0_0_1
act=close
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=2 file_action=2 fname=/mnt/ssd2/rand-write.1.0_0_2
act=close
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=3 file_action=2 fname=/mnt/ssd3/rand-write.1.0_1_0
act=close
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=4 file_action=2 fname=/mnt/ssd4/rand-write.1.0_1_1
act=close
io 24594 read_iolog2: Making note of file. offset=65536
bytes=65536 fileno=5 file_action=2 fname=/mnt/ssd5/rand-write.1.0_1_2
act=close
############## end of debug excerpt ########
Taking a look to the debugging output shows that on write action the
'fileno' variable is always set to 5 regardless of the file that should
be written. However, for open and close we have a different fileno value
for each file. Taking a look into the source code of read_iolog2()
reveals why: In case of actions 'open' or 'close', 'fileno' is looked up
through 'get_fileno(td, fname)', but for 'write', 'read' and the other 4
argument actions 'fileno' is not looked up. When I add a 'fileno =
get_fileno(td, fname);' at the end of the '(r == 4)' branch, I/Os are
replayed to the designated files.
########## excerpt from read_iolog2() within iolog.c ######
if (r == 4) {
/*
* Check action first
*/
if (!strcmp(act, "wait"))
rw = DDIR_WAIT;
else if (!strcmp(act, "read"))
rw = DDIR_READ;
else if (!strcmp(act, "write"))
rw = DDIR_WRITE;
else if (!strcmp(act, "sync"))
rw = DDIR_SYNC;
else if (!strcmp(act, "datasync"))
rw = DDIR_DATASYNC;
else if (!strcmp(act, "trim"))
rw = DDIR_TRIM;
else {
log_err("fio: bad iolog file action: %s\n",
act);
continue;
}
} else if (r == 2) {
rw = DDIR_INVAL;
if (!strcmp(act, "add")) {
td->o.nr_files++;
fileno = add_file(td, fname);
file_action = FIO_LOG_ADD_FILE;
continue;
} else if (!strcmp(act, "open")) {
fileno = get_fileno(td, fname);
file_action = FIO_LOG_OPEN_FILE;
} else if (!strcmp(act, "close")) {
fileno = get_fileno(td, fname);
file_action = FIO_LOG_CLOSE_FILE;
} else {
log_err("fio: bad iolog file action: %s\n",
act);
continue;
}
} else {
log_err("bad iolog2: %s", p);
continue;
}
########## end ######
Best regards,
Nikolaus
--
Dipl.-Inf. Nikolaus Jeremic nikolaus.jeremic@uni-rostock.de
Universitaet Rostock Tel: (+49) 381 / 498 - 7635
Albert-Einstein-Str. 22 Fax: (+49) 381 / 498 - 7482
18059 Rostock, Germany wwwava.informatik.uni-rostock.de
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: All I/O patterns are replayed to one file with fio 2.0.13
2013-02-14 19:37 All I/O patterns are replayed to one file with fio 2.0.13 Nikolaus Jeremic
@ 2013-02-18 13:57 ` Jens Axboe
2013-02-18 15:48 ` Nikolaus Jeremic
0 siblings, 1 reply; 4+ messages in thread
From: Jens Axboe @ 2013-02-18 13:57 UTC (permalink / raw)
To: Nikolaus Jeremic; +Cc: fio
On Thu, Feb 14 2013, Nikolaus Jeremic wrote:
> Hi,
>
> I've tried to replay I/Os from a textual iolog file to a couple of files
> using fio 2.0.13 on Linux. However, all I/Os were performed to the last
> opened file, which is '/mnt/ssd5/rand-write.1.0_1_2' in this example . My
> jobfile and iolog files contain the following:
>
> ############### job file #########
> [global]
> name=replay_filetraces
> description=Replay file traces
> ioengine=libaio
> iodepth=6
> direct=1
> continue_on_error=1
>
> [replay]
> numjobs=1
> read_iolog=file_io_patterns
> unlink=0
> ############## EOF #########
>
>
> ############## iolog file #########
> fio version 2 iolog
> /mnt/ssd0/rand-write.1.0_0_0 add
> /mnt/ssd1/rand-write.1.0_0_1 add
> /mnt/ssd2/rand-write.1.0_0_2 add
> /mnt/ssd3/rand-write.1.0_1_0 add
> /mnt/ssd4/rand-write.1.0_1_1 add
> /mnt/ssd5/rand-write.1.0_1_2 add
> /mnt/ssd0/rand-write.1.0_0_0 open
> /mnt/ssd1/rand-write.1.0_0_1 open
> /mnt/ssd2/rand-write.1.0_0_2 open
> /mnt/ssd3/rand-write.1.0_1_0 open
> /mnt/ssd4/rand-write.1.0_1_1 open
> /mnt/ssd5/rand-write.1.0_1_2 open
> /mnt/ssd0/rand-write.1.0_0_0 write 0 65536
> /mnt/ssd1/rand-write.1.0_0_1 write 0 65536
> /mnt/ssd2/rand-write.1.0_0_2 write 0 65536
> /mnt/ssd3/rand-write.1.0_1_0 write 0 65536
> /mnt/ssd4/rand-write.1.0_1_1 write 0 65536
> /mnt/ssd5/rand-write.1.0_1_2 write 0 65536
> /mnt/ssd0/rand-write.1.0_0_0 write 65536 65536
> /mnt/ssd1/rand-write.1.0_0_1 write 65536 65536
> /mnt/ssd2/rand-write.1.0_0_2 write 65536 65536
> /mnt/ssd3/rand-write.1.0_1_0 write 65536 65536
> /mnt/ssd4/rand-write.1.0_1_1 write 65536 65536
> /mnt/ssd5/rand-write.1.0_1_2 write 65536 65536
> /mnt/ssd0/rand-write.1.0_0_0 close
> /mnt/ssd1/rand-write.1.0_0_1 close
> /mnt/ssd2/rand-write.1.0_0_2 close
> /mnt/ssd3/rand-write.1.0_1_0 close
> /mnt/ssd4/rand-write.1.0_1_1 close
> /mnt/ssd5/rand-write.1.0_1_2 close
> ############## EOF #########
>
> I've turned on debugging and added some extra printf in read_iolog2() within
> iolog.c.
>
> ############## begin of debug excerpt ########
> file 24594 add file /mnt/ssd0/rand-write.1.0_0_0
> file 24594 resize file array to 2 files
> file 24594 file 0x7fbe03f53090 "/mnt/ssd0/rand-write.1.0_0_0" added at 0
> file 24594 add file /mnt/ssd1/rand-write.1.0_0_1
> file 24594 file 0x7fbe03f53230 "/mnt/ssd1/rand-write.1.0_0_1" added at 1
> file 24594 add file /mnt/ssd2/rand-write.1.0_0_2
> file 24594 resize file array to 4 files
> file 24594 file 0x7fbe03f533d0 "/mnt/ssd2/rand-write.1.0_0_2" added at 2
> file 24594 add file /mnt/ssd3/rand-write.1.0_1_0
> file 24594 file 0x7fbe03f53570 "/mnt/ssd3/rand-write.1.0_1_0" added at 3
> file 24594 add file /mnt/ssd4/rand-write.1.0_1_1
> file 24594 resize file array to 6 files
> file 24594 file 0x7fbe03f53710 "/mnt/ssd4/rand-write.1.0_1_1" added at 4
> file 24594 add file /mnt/ssd5/rand-write.1.0_1_2
> file 24594 file 0x7fbe03f538b0 "/mnt/ssd5/rand-write.1.0_1_2" added at 5
> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
> bytes=811544671 fileno=0 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0
> act=open
> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
> bytes=811544671 fileno=1 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1
> act=open
> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
> bytes=811544671 fileno=2 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2
> act=open
> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
> bytes=811544671 fileno=3 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0
> act=open
> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
> bytes=811544671 fileno=4 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1
> act=open
> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
> bytes=811544671 fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2
> act=open
> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0 act=write
> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1 act=write
> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2 act=write
> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0 act=write
> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1 act=write
> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2 act=write
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=0 file_action=2 fname=/mnt/ssd0/rand-write.1.0_0_0 act=close
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=1 file_action=2 fname=/mnt/ssd1/rand-write.1.0_0_1 act=close
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=2 file_action=2 fname=/mnt/ssd2/rand-write.1.0_0_2 act=close
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=3 file_action=2 fname=/mnt/ssd3/rand-write.1.0_1_0 act=close
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=4 file_action=2 fname=/mnt/ssd4/rand-write.1.0_1_1 act=close
> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
> fileno=5 file_action=2 fname=/mnt/ssd5/rand-write.1.0_1_2 act=close
> ############## end of debug excerpt ########
>
> Taking a look to the debugging output shows that on write action the
> 'fileno' variable is always set to 5 regardless of the file that should be
> written. However, for open and close we have a different fileno value for
> each file. Taking a look into the source code of read_iolog2() reveals why:
> In case of actions 'open' or 'close', 'fileno' is looked up through
> 'get_fileno(td, fname)', but for 'write', 'read' and the other 4 argument
> actions 'fileno' is not looked up. When I add a 'fileno = get_fileno(td,
> fname);' at the end of the '(r == 4)' branch, I/Os are replayed to the
> designated files.
>
> ########## excerpt from read_iolog2() within iolog.c ######
> if (r == 4) {
> /*
> * Check action first
> */
> if (!strcmp(act, "wait"))
> rw = DDIR_WAIT;
> else if (!strcmp(act, "read"))
> rw = DDIR_READ;
> else if (!strcmp(act, "write"))
> rw = DDIR_WRITE;
> else if (!strcmp(act, "sync"))
> rw = DDIR_SYNC;
> else if (!strcmp(act, "datasync"))
> rw = DDIR_DATASYNC;
> else if (!strcmp(act, "trim"))
> rw = DDIR_TRIM;
> else {
> log_err("fio: bad iolog file action: %s\n",
> act);
> continue;
> }
> } else if (r == 2) {
> rw = DDIR_INVAL;
> if (!strcmp(act, "add")) {
> td->o.nr_files++;
> fileno = add_file(td, fname);
> file_action = FIO_LOG_ADD_FILE;
> continue;
> } else if (!strcmp(act, "open")) {
> fileno = get_fileno(td, fname);
> file_action = FIO_LOG_OPEN_FILE;
> } else if (!strcmp(act, "close")) {
> fileno = get_fileno(td, fname);
> file_action = FIO_LOG_CLOSE_FILE;
> } else {
> log_err("fio: bad iolog file action: %s\n",
> act);
> continue;
> }
> } else {
> log_err("bad iolog2: %s", p);
> continue;
> }
> ########## end ######
Thanks for the detailed and thorough analysis. Care to resend this is a
"proper" patch, and I'll get it tested and added too?
--
Jens Axboe
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: All I/O patterns are replayed to one file with fio 2.0.13
2013-02-18 13:57 ` Jens Axboe
@ 2013-02-18 15:48 ` Nikolaus Jeremic
2013-02-18 18:45 ` Jens Axboe
0 siblings, 1 reply; 4+ messages in thread
From: Nikolaus Jeremic @ 2013-02-18 15:48 UTC (permalink / raw)
To: Jens Axboe; +Cc: fio
Am 18.02.2013 14:57, schrieb Jens Axboe:
> On Thu, Feb 14 2013, Nikolaus Jeremic wrote:
>> Hi,
>>
>> I've tried to replay I/Os from a textual iolog file to a couple of files
>> using fio 2.0.13 on Linux. However, all I/Os were performed to the last
>> opened file, which is '/mnt/ssd5/rand-write.1.0_1_2' in this example . My
>> jobfile and iolog files contain the following:
>>
>> ############### job file #########
>> [global]
>> name=replay_filetraces
>> description=Replay file traces
>> ioengine=libaio
>> iodepth=6
>> direct=1
>> continue_on_error=1
>>
>> [replay]
>> numjobs=1
>> read_iolog=file_io_patterns
>> unlink=0
>> ############## EOF #########
>>
>>
>> ############## iolog file #########
>> fio version 2 iolog
>> /mnt/ssd0/rand-write.1.0_0_0 add
>> /mnt/ssd1/rand-write.1.0_0_1 add
>> /mnt/ssd2/rand-write.1.0_0_2 add
>> /mnt/ssd3/rand-write.1.0_1_0 add
>> /mnt/ssd4/rand-write.1.0_1_1 add
>> /mnt/ssd5/rand-write.1.0_1_2 add
>> /mnt/ssd0/rand-write.1.0_0_0 open
>> /mnt/ssd1/rand-write.1.0_0_1 open
>> /mnt/ssd2/rand-write.1.0_0_2 open
>> /mnt/ssd3/rand-write.1.0_1_0 open
>> /mnt/ssd4/rand-write.1.0_1_1 open
>> /mnt/ssd5/rand-write.1.0_1_2 open
>> /mnt/ssd0/rand-write.1.0_0_0 write 0 65536
>> /mnt/ssd1/rand-write.1.0_0_1 write 0 65536
>> /mnt/ssd2/rand-write.1.0_0_2 write 0 65536
>> /mnt/ssd3/rand-write.1.0_1_0 write 0 65536
>> /mnt/ssd4/rand-write.1.0_1_1 write 0 65536
>> /mnt/ssd5/rand-write.1.0_1_2 write 0 65536
>> /mnt/ssd0/rand-write.1.0_0_0 write 65536 65536
>> /mnt/ssd1/rand-write.1.0_0_1 write 65536 65536
>> /mnt/ssd2/rand-write.1.0_0_2 write 65536 65536
>> /mnt/ssd3/rand-write.1.0_1_0 write 65536 65536
>> /mnt/ssd4/rand-write.1.0_1_1 write 65536 65536
>> /mnt/ssd5/rand-write.1.0_1_2 write 65536 65536
>> /mnt/ssd0/rand-write.1.0_0_0 close
>> /mnt/ssd1/rand-write.1.0_0_1 close
>> /mnt/ssd2/rand-write.1.0_0_2 close
>> /mnt/ssd3/rand-write.1.0_1_0 close
>> /mnt/ssd4/rand-write.1.0_1_1 close
>> /mnt/ssd5/rand-write.1.0_1_2 close
>> ############## EOF #########
>>
>> I've turned on debugging and added some extra printf in read_iolog2() within
>> iolog.c.
>>
>> ############## begin of debug excerpt ########
>> file 24594 add file /mnt/ssd0/rand-write.1.0_0_0
>> file 24594 resize file array to 2 files
>> file 24594 file 0x7fbe03f53090 "/mnt/ssd0/rand-write.1.0_0_0" added at 0
>> file 24594 add file /mnt/ssd1/rand-write.1.0_0_1
>> file 24594 file 0x7fbe03f53230 "/mnt/ssd1/rand-write.1.0_0_1" added at 1
>> file 24594 add file /mnt/ssd2/rand-write.1.0_0_2
>> file 24594 resize file array to 4 files
>> file 24594 file 0x7fbe03f533d0 "/mnt/ssd2/rand-write.1.0_0_2" added at 2
>> file 24594 add file /mnt/ssd3/rand-write.1.0_1_0
>> file 24594 file 0x7fbe03f53570 "/mnt/ssd3/rand-write.1.0_1_0" added at 3
>> file 24594 add file /mnt/ssd4/rand-write.1.0_1_1
>> file 24594 resize file array to 6 files
>> file 24594 file 0x7fbe03f53710 "/mnt/ssd4/rand-write.1.0_1_1" added at 4
>> file 24594 add file /mnt/ssd5/rand-write.1.0_1_2
>> file 24594 file 0x7fbe03f538b0 "/mnt/ssd5/rand-write.1.0_1_2" added at 5
>> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
>> bytes=811544671 fileno=0 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0
>> act=open
>> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
>> bytes=811544671 fileno=1 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1
>> act=open
>> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
>> bytes=811544671 fileno=2 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2
>> act=open
>> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
>> bytes=811544671 fileno=3 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0
>> act=open
>> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
>> bytes=811544671 fileno=4 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1
>> act=open
>> io 24594 read_iolog2: Making note of file. offset=7310584035475809390
>> bytes=811544671 fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2
>> act=open
>> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0 act=write
>> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1 act=write
>> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2 act=write
>> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0 act=write
>> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1 act=write
>> io 24594 read_iolog2: Making note of file. offset=0 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd0/rand-write.1.0_0_0 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd1/rand-write.1.0_0_1 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd2/rand-write.1.0_0_2 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd3/rand-write.1.0_1_0 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd4/rand-write.1.0_1_1 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=1 fname=/mnt/ssd5/rand-write.1.0_1_2 act=write
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=0 file_action=2 fname=/mnt/ssd0/rand-write.1.0_0_0 act=close
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=1 file_action=2 fname=/mnt/ssd1/rand-write.1.0_0_1 act=close
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=2 file_action=2 fname=/mnt/ssd2/rand-write.1.0_0_2 act=close
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=3 file_action=2 fname=/mnt/ssd3/rand-write.1.0_1_0 act=close
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=4 file_action=2 fname=/mnt/ssd4/rand-write.1.0_1_1 act=close
>> io 24594 read_iolog2: Making note of file. offset=65536 bytes=65536
>> fileno=5 file_action=2 fname=/mnt/ssd5/rand-write.1.0_1_2 act=close
>> ############## end of debug excerpt ########
>>
>> Taking a look to the debugging output shows that on write action the
>> 'fileno' variable is always set to 5 regardless of the file that should be
>> written. However, for open and close we have a different fileno value for
>> each file. Taking a look into the source code of read_iolog2() reveals why:
>> In case of actions 'open' or 'close', 'fileno' is looked up through
>> 'get_fileno(td, fname)', but for 'write', 'read' and the other 4 argument
>> actions 'fileno' is not looked up. When I add a 'fileno = get_fileno(td,
>> fname);' at the end of the '(r == 4)' branch, I/Os are replayed to the
>> designated files.
>>
>> ########## excerpt from read_iolog2() within iolog.c ######
>> if (r == 4) {
>> /*
>> * Check action first
>> */
>> if (!strcmp(act, "wait"))
>> rw = DDIR_WAIT;
>> else if (!strcmp(act, "read"))
>> rw = DDIR_READ;
>> else if (!strcmp(act, "write"))
>> rw = DDIR_WRITE;
>> else if (!strcmp(act, "sync"))
>> rw = DDIR_SYNC;
>> else if (!strcmp(act, "datasync"))
>> rw = DDIR_DATASYNC;
>> else if (!strcmp(act, "trim"))
>> rw = DDIR_TRIM;
>> else {
>> log_err("fio: bad iolog file action: %s\n",
>> act);
>> continue;
>> }
>> } else if (r == 2) {
>> rw = DDIR_INVAL;
>> if (!strcmp(act, "add")) {
>> td->o.nr_files++;
>> fileno = add_file(td, fname);
>> file_action = FIO_LOG_ADD_FILE;
>> continue;
>> } else if (!strcmp(act, "open")) {
>> fileno = get_fileno(td, fname);
>> file_action = FIO_LOG_OPEN_FILE;
>> } else if (!strcmp(act, "close")) {
>> fileno = get_fileno(td, fname);
>> file_action = FIO_LOG_CLOSE_FILE;
>> } else {
>> log_err("fio: bad iolog file action: %s\n",
>> act);
>> continue;
>> }
>> } else {
>> log_err("bad iolog2: %s", p);
>> continue;
>> }
>> ########## end ######
> Thanks for the detailed and thorough analysis. Care to resend this is a
> "proper" patch, and I'll get it tested and added too?
>
Index: fio-2.0.13/iolog.c
===================================================================
--- fio-2.0.13/iolog.c (revision 807)
+++ fio-2.0.13/iolog.c (revision 863)
@@ -316,6 +316,7 @@
act);
continue;
}
+ fileno = get_fileno(td, fname);
} else if (r == 2) {
rw = DDIR_INVAL;
if (!strcmp(act, "add")) {
--
Dipl.-Inf. Nikolaus Jeremic nikolaus.jeremic@uni-rostock.de
Universitaet Rostock Tel: (+49) 381 / 498 - 7635
Albert-Einstein-Str. 22 Fax: (+49) 381 / 498 - 7482
18059 Rostock, Germany wwwava.informatik.uni-rostock.de
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: All I/O patterns are replayed to one file with fio 2.0.13
2013-02-18 15:48 ` Nikolaus Jeremic
@ 2013-02-18 18:45 ` Jens Axboe
0 siblings, 0 replies; 4+ messages in thread
From: Jens Axboe @ 2013-02-18 18:45 UTC (permalink / raw)
To: Nikolaus Jeremic; +Cc: fio
On Mon, Feb 18 2013, Nikolaus Jeremic wrote:
> Index: fio-2.0.13/iolog.c
> ===================================================================
> --- fio-2.0.13/iolog.c (revision 807)
> +++ fio-2.0.13/iolog.c (revision 863)
> @@ -316,6 +316,7 @@
> act);
> continue;
> }
> + fileno = get_fileno(td, fname);
> } else if (r == 2) {
> rw = DDIR_INVAL;
> if (!strcmp(act, "add")) {
Thanks, applied!
--
Jens Axboe
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2013-02-18 18:46 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-02-14 19:37 All I/O patterns are replayed to one file with fio 2.0.13 Nikolaus Jeremic
2013-02-18 13:57 ` Jens Axboe
2013-02-18 15:48 ` Nikolaus Jeremic
2013-02-18 18:45 ` Jens Axboe
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.