Sequential Commands are essentially random when in mixed sequential/random workloads

Sequential Commands are essentially random when in mixed sequential/random workloads

[Stephen Nichols]

Hi all,

When using fio configuration below..

[global]
ioengine=libaio
direct=1
runtime=600
bs=32k
iodepth=8
rw=randrw
rwmixread=80
percentage_random=100,0

[drive1]
filename=/dev/sda


I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.


Snippet from the bus trace for reference

Command������������������������������������������ LBA
Read FPDMA Queued:����������������� 19F3F818
Read FPDMA Queued:����������������� 1CBE2740
Write FPDMA Queued: ��������������� 24E35198
Write FPDMA Queued:���������������� 24E351A0
Read FPDMA Queued:����������������� 115A9E10
Write FPDMA Queued:���������������� A3C1968
Read FPDMA Queued:����������������� 20B89488
Write FPDMA Queued:���������������� 336EE0D0
Write FPDMA Queued:���������������� 336EE0D8



Let me know what you think, this feature may be working as intended but it seemed off to me.

Thanks,
Stephen "Nick" Nichols
Western Digital
Enterprise Test Development

Re: Sequential Commands are essentially random when in mixed sequential/random workloads

[Andrey Kuzmin]

On Sat, Dec 13, 2014 at 3:23 AM, Stephen Nichols
<Stephen.Nichols@wdc.com> wrote:
>
> Hi all,
>
> When using fio configuration below..
>
> [global]
> ioengine=libaio
> direct=1
> runtime=600
> bs=32k
> iodepth=8
> rw=randrw
> rwmixread=80
> percentage_random=100,0
>
> [drive1]
> filename=/dev/sda
>
>
> I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.
>
>
> Snippet from the bus trace for reference
>
> Command                                           LBA
> Read FPDMA Queued:                  19F3F818
> Read FPDMA Queued:                  1CBE2740
> Write FPDMA Queued:                 24E35198
> Write FPDMA Queued:                 24E351A0
> Read FPDMA Queued:                  115A9E10
> Write FPDMA Queued:                 A3C1968
> Read FPDMA Queued:                  20B89488
> Write FPDMA Queued:                 336EE0D0
> Write FPDMA Queued:                 336EE0D8
>
>

The problem is that, with non-trivial percentage_random, fio generates
next sequential offset off the file's last position, but the latter is
global, not per data direction. As a result, with the workload above,
one gets the pattern where next write is sequential with respect to
the last I/O, not the last write as, I believe, the expectation goes.

I've added a debug printout for the last_pos to illustrate the point
in the debug output below. ddir=1 are writes.

Regards,
Andrey

fio: set debug option io
io       5299  load ioengine libaio
drive1: (g=0): rw=randrw, bs=32K-32K/32K-32K/32K-32K, ioengine=libaio, iodepth=8
fio-2.1.14-45-g7003
Starting 1 process
io       5301  invalidate cache /tmp/drive1: 0/1048576
io       5301  get_next_block: last pos 0
io       5301  fill_io_u: io_u 0x121ec00: off=32768/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121ec00: off=32768/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121ec00)=0
io       5301  queue: io_u 0x121ec00: off=32768/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 1
io       5301  get_next_block: last pos 65536
io       5301  fill_io_u: io_u 0x121e900:
off=753664/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121e900: off=753664/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121e900)=0
io       5301  queue: io_u 0x121e900: off=753664/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 2
io       5301  get_next_block: last pos 786432
io       5301  fill_io_u: io_u 0x121e1c0:
off=851968/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121e1c0: off=851968/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121e1c0)=0
io       5301  queue: io_u 0x121e1c0: off=851968/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 3
================================================================
io       5301  get_next_block: last pos 884736
io       5301  fill_io_u: io_u 0x121dec0:
off=884736/len=32768/ddir=1//tmp/drive1
io       5301  prep: io_u 0x121dec0: off=884736/len=32768/ddir=1//tmp/drive1
io       5301  ->prep(0x121dec0)=0
io       5301  queue: io_u 0x121dec0: off=884736/len=32768/ddir=1//tmp/drive1
io       5301  calling ->commit(), depth 4
io       5301  get_next_block: last pos 917504
io       5301  fill_io_u: io_u 0x121dbc0:
off=491520/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121dbc0: off=491520/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121dbc0)=0
io       5301  queue: io_u 0x121dbc0: off=491520/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 5
io       5301  get_next_block: last pos 524288
io       5301  fill_io_u: io_u 0x121d8c0:
off=393216/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121d8c0: off=393216/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121d8c0)=0
io       5301  queue: io_u 0x121d8c0: off=393216/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 6
io       5301  get_next_block: last pos 425984
io       5301  fill_io_u: io_u 0x121d600: off=0/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121d600: off=0/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121d600)=0
io       5301  queue: io_u 0x121d600: off=0/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 7
io       5301  get_next_block: last pos 32768
io       5301  fill_io_u: io_u 0x121d300: off=65536/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121d300: off=65536/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121d300)=0
io       5301  queue: io_u 0x121d300: off=65536/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 8
io       5301  io_u_queued_completed: min=1
io       5301  getevents: 1
io       5301  io complete: io_u 0x121ec00:
off=32768/len=32768/ddir=0//tmp/drive1
io       5301  get_next_block: last pos 98304
io       5301  fill_io_u: io_u 0x121ec00:
off=360448/len=32768/ddir=0//tmp/drive1
io       5301  prep: io_u 0x121ec00: off=360448/len=32768/ddir=0//tmp/drive1
io       5301  ->prep(0x121ec00)=0
io       5301  queue: io_u 0x121ec00: off=360448/len=32768/ddir=0//tmp/drive1
io       5301  calling ->commit(), depth 8
io       5301  io_u_queued_completed: min=1
io       5301  getevents: 1
io       5301  io complete: io_u 0x121e900:
off=753664/len=32768/ddir=0//tmp/drive1
==================================================================
io       5301  get_next_block: last pos 393216
io       5301  fill_io_u: io_u 0x121e900:
off=393216/len=32768/ddir=1//tmp/drive1
io       5301  prep: io_u 0x121e900: off=393216/len=32768/ddir=1//tmp/drive1
io       5301  ->prep(0x121e900)=0


Regards,
Andrey

>
> Let me know what you think, this feature may be working as intended but it seemed off to me.
>
> Thanks,
> Stephen "Nick" Nichols
> Western Digital
> Enterprise Test Development
>
> --
> To unsubscribe from this list: send the line "unsubscribe fio" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: Sequential Commands are essentially random when in mixed sequential/random workloads

[Jens Axboe]

[-- Attachment #1: Type: text/plain, Size: 1847 bytes --]

On 12/12/2014 05:23 PM, Stephen Nichols wrote:
> Hi all,
> 
> When using fio configuration below..
> 
> [global]
> ioengine=libaio
> direct=1
> runtime=600
> bs=32k
> iodepth=8
> rw=randrw
> rwmixread=80
> percentage_random=100,0
> 
> [drive1]
> filename=/dev/sda
> 
> 
> I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.
> 
> 
> Snippet from the bus trace for reference
> 
> Command                                           LBA
> Read FPDMA Queued:                  19F3F818
> Read FPDMA Queued:                  1CBE2740
> Write FPDMA Queued:                 24E35198
> Write FPDMA Queued:                 24E351A0
> Read FPDMA Queued:                  115A9E10
> Write FPDMA Queued:                 A3C1968
> Read FPDMA Queued:                  20B89488
> Write FPDMA Queued:                 336EE0D0
> Write FPDMA Queued:                 336EE0D8
> 
> 
> 
> Let me know what you think, this feature may be working as intended but it seemed off to me.

Would be easy enough to fix, we just need to track last offset per data
direction. Does the attached work for you? Totally untested, will test
on Monday.

-- 
Jens Axboe


[-- Attachment #2: last-rwdir-pos.patch --]
[-- Type: text/x-patch, Size: 3193 bytes --]

diff --git a/file.h b/file.h
index add77730fdb4..70e4c48c2093 100644
--- a/file.h
+++ b/file.h
@@ -88,8 +88,8 @@ struct fio_file {
 	uint64_t file_offset;
 	uint64_t io_size;
 
-	uint64_t last_pos;
-	uint64_t last_start;
+	uint64_t last_pos[DDIR_RWDIR_CNT];
+	uint64_t last_start[DDIR_RWDIR_CNT];
 
 	uint64_t first_write;
 	uint64_t last_write;
diff --git a/filesetup.c b/filesetup.c
index cc6d44091736..a918234fb77f 100644
--- a/filesetup.c
+++ b/filesetup.c
@@ -1536,8 +1536,13 @@ void free_release_files(struct thread_data *td)
 
 void fio_file_reset(struct thread_data *td, struct fio_file *f)
 {
-	f->last_pos = f->file_offset;
-	f->last_start = -1ULL;
+	int i;
+
+	for (i = 0; i < DDIR_RWDIR_CNT; i++) {
+		f->last_pos[i] = f->file_offset;
+		f->last_start[i] = -1ULL;
+	}
+
 	if (f->io_axmap)
 		axmap_reset(f->io_axmap);
 	if (td->o.random_generator == FIO_RAND_GEN_LFSR)
diff --git a/io_u.c b/io_u.c
index f13590835286..efbcea9eb15b 100644
--- a/io_u.c
+++ b/io_u.c
@@ -249,7 +249,7 @@ static int get_next_rand_block(struct thread_data *td, struct fio_file *f,
 	}
 
 	dprint(FD_IO, "%s: rand offset failed, last=%llu, size=%llu\n",
-			f->file_name, (unsigned long long) f->last_pos,
+			f->file_name, (unsigned long long) f->last_pos[ddir],
 			(unsigned long long) f->real_file_size);
 	return 1;
 }
@@ -261,17 +261,17 @@ static int get_next_seq_offset(struct thread_data *td, struct fio_file *f,
 
 	assert(ddir_rw(ddir));
 
-	if (f->last_pos >= f->io_size + get_start_offset(td, f) &&
+	if (f->last_pos[ddir] >= f->io_size + get_start_offset(td, f) &&
 	    o->time_based)
-		f->last_pos = f->last_pos - f->io_size;
+		f->last_pos[ddir] = f->last_pos[ddir] - f->io_size;
 
-	if (f->last_pos < f->real_file_size) {
+	if (f->last_pos[ddir] < f->real_file_size) {
 		uint64_t pos;
 
-		if (f->last_pos == f->file_offset && o->ddir_seq_add < 0)
-			f->last_pos = f->real_file_size;
+		if (f->last_pos[ddir] == f->file_offset && o->ddir_seq_add < 0)
+			f->last_pos[ddir] = f->real_file_size;
 
-		pos = f->last_pos - f->file_offset;
+		pos = f->last_pos[ddir] - f->file_offset;
 		if (pos && o->ddir_seq_add) {
 			pos += o->ddir_seq_add;
 
@@ -330,8 +330,8 @@ static int get_next_block(struct thread_data *td, struct io_u *io_u,
 				*is_random = 0;
 			}
 		} else if (td->o.rw_seq == RW_SEQ_IDENT) {
-			if (f->last_start != -1ULL)
-				offset = f->last_start - f->file_offset;
+			if (f->last_start[ddir] != -1ULL)
+				offset = f->last_start[ddir] - f->file_offset;
 			else
 				offset = 0;
 			ret = 0;
@@ -743,7 +743,7 @@ static int fill_io_u(struct thread_data *td, struct io_u *io_u)
 		 */
 		if (f->file_offset >= f->real_file_size)
 			f->file_offset = f->real_file_size - f->file_offset;
-		f->last_pos = f->file_offset;
+		f->last_pos[io_u->ddir] = f->file_offset;
 		td->io_skip_bytes += td->o.zone_skip;
 	}
 
@@ -1471,8 +1471,8 @@ struct io_u *get_io_u(struct thread_data *td)
 			goto err_put;
 		}
 
-		f->last_start = io_u->offset;
-		f->last_pos = io_u->offset + io_u->buflen;
+		f->last_start[io_u->ddir] = io_u->offset;
+		f->last_pos[io_u->ddir] = io_u->offset + io_u->buflen;
 
 		if (io_u->ddir == DDIR_WRITE) {
 			if (td->flags & TD_F_REFILL_BUFFERS) {

Re: Sequential Commands are essentially random when in mixed sequential/random workloads

[Jens Axboe]

On 12/13/2014 01:31 PM, Andrey Kuzmin wrote:
> On Sat, Dec 13, 2014 at 3:23 AM, Stephen Nichols
> <Stephen.Nichols@wdc.com> wrote:
>>
>> Hi all,
>>
>> When using fio configuration below..
>>
>> [global]
>> ioengine=libaio
>> direct=1
>> runtime=600
>> bs=32k
>> iodepth=8
>> rw=randrw
>> rwmixread=80
>> percentage_random=100,0
>>
>> [drive1]
>> filename=/dev/sda
>>
>>
>> I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.
>>
>>
>> Snippet from the bus trace for reference
>>
>> Command                                           LBA
>> Read FPDMA Queued:                  19F3F818
>> Read FPDMA Queued:                  1CBE2740
>> Write FPDMA Queued:                 24E35198
>> Write FPDMA Queued:                 24E351A0
>> Read FPDMA Queued:                  115A9E10
>> Write FPDMA Queued:                 A3C1968
>> Read FPDMA Queued:                  20B89488
>> Write FPDMA Queued:                 336EE0D0
>> Write FPDMA Queued:                 336EE0D8
>>
>>
> 
> The problem is that, with non-trivial percentage_random, fio generates
> next sequential offset off the file's last position, but the latter is
> global, not per data direction. As a result, with the workload above,
> one gets the pattern where next write is sequential with respect to
> the last I/O, not the last write as, I believe, the expectation goes.

Yup, that is exactly the problem.

-- 
Jens Axboe

Re: Sequential Commands are essentially random when in mixed sequential/random workloads

[Andrey Kuzmin]

On Sun, Dec 14, 2014 at 1:53 AM, Jens Axboe <axboe@kernel.dk> wrote:
> On 12/12/2014 05:23 PM, Stephen Nichols wrote:
>> Hi all,
>>
>> When using fio configuration below..
>>
>> [global]
>> ioengine=libaio
>> direct=1
>> runtime=600
>> bs=32k
>> iodepth=8
>> rw=randrw
>> rwmixread=80
>> percentage_random=100,0
>>
>> [drive1]
>> filename=/dev/sda
>>
>>
>> I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.
>>
>>
>> Snippet from the bus trace for reference
>>
>> Command                                           LBA
>> Read FPDMA Queued:                  19F3F818
>> Read FPDMA Queued:                  1CBE2740
>> Write FPDMA Queued:                 24E35198
>> Write FPDMA Queued:                 24E351A0
>> Read FPDMA Queued:                  115A9E10
>> Write FPDMA Queued:                 A3C1968
>> Read FPDMA Queued:                  20B89488
>> Write FPDMA Queued:                 336EE0D0
>> Write FPDMA Queued:                 336EE0D8
>>
>>
>>
>> Let me know what you think, this feature may be working as intended but it seemed off to me.
>
> Would be easy enough to fix, we just need to track last offset per data
> direction. Does the attached work for you? Totally untested, will test
> on Monday.

Looks like fixed.

Regards,
Andrey

io       8568  load ioengine libaio
drive1: (g=0): rw=randrw, bs=32K-32K/32K-32K/32K-32K, ioengine=libaio, iodepth=8
fio-2.1.14-45-g7003
Starting 1 process
io       8570  invalidate cache /tmp/drive1: 0/1048576
io       8570  get_next_block: last read pos 0
io       8570  fill_io_u: io_u 0x176be40: off=32768/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176be40: off=32768/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176be40)=0
io       8570  queue: io_u 0x176be40: off=32768/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 1
io       8570  get_next_block: last read pos 65536
io       8570  fill_io_u: io_u 0x176bb40:
off=753664/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176bb40: off=753664/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176bb40)=0
io       8570  queue: io_u 0x176bb40: off=753664/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 2
io       8570  get_next_block: last read pos 786432
io       8570  fill_io_u: io_u 0x176b400:
off=851968/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176b400: off=851968/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176b400)=0
io       8570  queue: io_u 0x176b400: off=851968/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 3
===
io       8570  get_next_block: last write pos 0
io       8570  fill_io_u: io_u 0x176b100: off=0/len=32768/ddir=1//tmp/drive1
io       8570  prep: io_u 0x176b100: off=0/len=32768/ddir=1//tmp/drive1
io       8570  ->prep(0x176b100)=0
io       8570  queue: io_u 0x176b100: off=0/len=32768/ddir=1//tmp/drive1
io       8570  calling ->commit(), depth 4
io       8570  get_next_block: last read pos 884736
io       8570  fill_io_u: io_u 0x176ae00:
off=491520/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176ae00: off=491520/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176ae00)=0
io       8570  queue: io_u 0x176ae00: off=491520/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 5
io       8570  get_next_block: last read pos 524288
io       8570  fill_io_u: io_u 0x176ab00:
off=393216/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176ab00: off=393216/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176ab00)=0
io       8570  queue: io_u 0x176ab00: off=393216/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 6
io       8570  get_next_block: last read pos 425984
io       8570  fill_io_u: io_u 0x176a840: off=0/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176a840: off=0/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176a840)=0
io       8570  queue: io_u 0x176a840: off=0/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 7
io       8570  get_next_block: last read pos 32768
io       8570  fill_io_u: io_u 0x176a540: off=65536/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176a540: off=65536/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176a540)=0
io       8570  queue: io_u 0x176a540: off=65536/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176b100: off=0/len=32768/ddir=1//tmp/drive1
io       8570  get_next_block: last read pos 98304
io       8570  fill_io_u: io_u 0x176b100:
off=360448/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176b100: off=360448/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176b100)=0
io       8570  queue: io_u 0x176b100: off=360448/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176a840: off=0/len=32768/ddir=0//tmp/drive1
===
io       8570  get_next_block: last write pos 32768
io       8570  fill_io_u: io_u 0x176a840: off=32768/len=32768/ddir=1//tmp/drive1
io       8570  prep: io_u 0x176a840: off=32768/len=32768/ddir=1//tmp/drive1
io       8570  ->prep(0x176a840)=0
io       8570  queue: io_u 0x176a840: off=32768/len=32768/ddir=1//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176a840:
off=32768/len=32768/ddir=1//tmp/drive1
io       8570  get_next_block: last read pos 393216
io       8570  fill_io_u: io_u 0x176a840:
off=950272/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176a840: off=950272/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176a840)=0
io       8570  queue: io_u 0x176a840: off=950272/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176be40:
off=32768/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 983040
io       8570  fill_io_u: io_u 0x176be40: off=98304/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176be40: off=98304/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176be40)=0
io       8570  queue: io_u 0x176be40: off=98304/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176bb40:
off=753664/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 131072
io       8570  fill_io_u: io_u 0x176bb40:
off=884736/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176bb40: off=884736/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176bb40)=0
io       8570  queue: io_u 0x176bb40: off=884736/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176b400:
off=851968/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 917504
io       8570  fill_io_u: io_u 0x176b400:
off=655360/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176b400: off=655360/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176b400)=0
io       8570  queue: io_u 0x176b400: off=655360/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176ae00:
off=491520/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 688128
io       8570  fill_io_u: io_u 0x176ae00:
off=131072/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176ae00: off=131072/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176ae00)=0
io       8570  queue: io_u 0x176ae00: off=131072/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176ab00:
off=393216/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 163840
io       8570  fill_io_u: io_u 0x176ab00:
off=229376/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176ab00: off=229376/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176ab00)=0
io       8570  queue: io_u 0x176ab00: off=229376/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176a540:
off=65536/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 262144
io       8570  fill_io_u: io_u 0x176a540:
off=163840/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176a540: off=163840/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176a540)=0
io       8570  queue: io_u 0x176a540: off=163840/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176b100:
off=360448/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 196608
io       8570  fill_io_u: io_u 0x176b100:
off=557056/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176b100: off=557056/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176b100)=0
io       8570  queue: io_u 0x176b100: off=557056/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176a840:
off=950272/len=32768/ddir=0//tmp/drive1
io       8570  get_next_block: last read pos 589824
io       8570  fill_io_u: io_u 0x176a840:
off=458752/len=32768/ddir=0//tmp/drive1
io       8570  prep: io_u 0x176a840: off=458752/len=32768/ddir=0//tmp/drive1
io       8570  ->prep(0x176a840)=0
io       8570  queue: io_u 0x176a840: off=458752/len=32768/ddir=0//tmp/drive1
io       8570  calling ->commit(), depth 8
io       8570  io_u_queued_completed: min=1
io       8570  getevents: 1
io       8570  io complete: io_u 0x176be40:
off=98304/len=32768/ddir=0//tmp/drive1
===
io       8570  get_next_block: last write pos 65536
io       8570  fill_io_u: io_u 0x176be40: off=65536/len=32768/ddir=1//tmp/drive1
io       8570  prep: io_u 0x176be40: off=65536/len=32768/ddir=1//tmp/drive1
io       8570  ->prep(0x176be40)=0
io       8570  queue: io_u 0x176be40: off=65536/len=32768/ddir=1//tmp/drive1

>
> --
> Jens Axboe
>

Re: Sequential Commands are essentially random when in mixed sequential/random workloads

[Jens Axboe]

On 12/14/2014 08:20 AM, Andrey Kuzmin wrote:
> On Sun, Dec 14, 2014 at 1:53 AM, Jens Axboe <axboe@kernel.dk> wrote:
>> On 12/12/2014 05:23 PM, Stephen Nichols wrote:
>>> Hi all,
>>>
>>> When using fio configuration below..
>>>
>>> [global]
>>> ioengine=libaio
>>> direct=1
>>> runtime=600
>>> bs=32k
>>> iodepth=8
>>> rw=randrw
>>> rwmixread=80
>>> percentage_random=100,0
>>>
>>> [drive1]
>>> filename=/dev/sda
>>>
>>>
>>> I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.
>>>
>>>
>>> Snippet from the bus trace for reference
>>>
>>> Command                                           LBA
>>> Read FPDMA Queued:                  19F3F818
>>> Read FPDMA Queued:                  1CBE2740
>>> Write FPDMA Queued:                 24E35198
>>> Write FPDMA Queued:                 24E351A0
>>> Read FPDMA Queued:                  115A9E10
>>> Write FPDMA Queued:                 A3C1968
>>> Read FPDMA Queued:                  20B89488
>>> Write FPDMA Queued:                 336EE0D0
>>> Write FPDMA Queued:                 336EE0D8
>>>
>>>
>>>
>>> Let me know what you think, this feature may be working as intended but it seemed off to me.
>>
>> Would be easy enough to fix, we just need to track last offset per data
>> direction. Does the attached work for you? Totally untested, will test
>> on Monday.
>
> Looks like fixed.

Thanks for verifying, Andrey. After taking a second look, looks sane to 
me after all. Lucky punch!

Stephen, the fix has been committed, so if you just update to the latest 
git, it should hopefully work for you as well. Please report back when 
you have tested it.

-- 
Jens Axboe

RE: Sequential Commands are essentially random when in mixed sequential/random workloads

[Stephen Nichols]

>> Would be easy enough to fix, we just need to track last offset per 
>> data direction. Does the attached work for you? Totally untested, 
>> will test on Monday.
>
> Looks like fixed.

Thanks for verifying, Andrey. After taking a second look, looks sane to me after all. Lucky punch!

Stephen, the fix has been committed, so if you just update to the latest git, it should hopefully work for you as well. Please report back when you have tested it.

--

Thanks for the quick turnaround. I will test and review a bus trace as soon as an analyzer becomes available to me. Should be today sometime.
-Stephen Nichols

RE: Sequential Commands are essentially random when in mixed sequential/random workloads

[Stephen Nichols]

On 12/16/2014 10:40 AM, Stephen Nichols wrote:
 Hi Jens and Andrey,
 
 The fix worked great. Confirmed in bus trace.
  I adjusted the BS of the original workload to 4K to make it easier to 
 track sequential LBA's and here is a snippet from the trace
 
 Command			LBA
 Read FPDMA Queued:		42DD8338
 Read FPDMA Queued:		3861F5D7
 Write FPDMA Queued:		EC
 Read FPDMA Queued:		3DAD77C5
 Write FPDMA Queued:		ED
 Write FPDMA Queued:		EE
 Read FPDMA Queued:		3CFB77D2
 Read FPDMA Queued:		33304BF3
 Read FPDMA Queued:		350491D5
 Read FPDMA Queued:		2D428D0D
 Write FPDMA Queued:		EF
 Read FPDMA Queued:		15C76871
 Write FPDMA Queued:		F0
 Read FPDMA Queued:		12C6A679
 
 Thanks,
 Stephen Nichols
> 
> 
> -----Original Message-----
> From: Jens Axboe [mailto:axboe@kernel.dk]
> Sent: Sunday, December 14, 2014 6:39 PM
> To: Andrey Kuzmin
> Cc: Stephen Nichols; fio@vger.kernel.org
> Subject: Re: Sequential Commands are essentially random when in mixed 
> sequential/random workloads
> 
> On 12/14/2014 08:20 AM, Andrey Kuzmin wrote:
>> On Sun, Dec 14, 2014 at 1:53 AM, Jens Axboe <axboe@kernel.dk> wrote:
>>> On 12/12/2014 05:23 PM, Stephen Nichols wrote:
>>>> Hi all,
>>>>
>>>> When using fio configuration below..
>>>>
>>>> [global]
>>>> ioengine=libaio
>>>> direct=1
>>>> runtime=600
>>>> bs=32k
>>>> iodepth=8
>>>> rw=randrw
>>>> rwmixread=80
>>>> percentage_random=100,0
>>>>
>>>> [drive1]
>>>> filename=/dev/sda
>>>>
>>>>
>>>> I am expecting to see 80% reads, 20% writes where all reads are random and all writes are sequential. I captured a bus trace of traffic to the disk and the bus trace reflected as much with one issue. The write commands are essentially random. Each write begins at a new random LBA. If 2 or more writes occur in a row, the LBA's are sequential based on the block size BUT I feel the heart of this feature would be to emulate a large file write during random access. With that in mind would it be possible for sequential reads or writes within mixed sequential/random workload to remember the last LBA accessed? In this scenario the writes would still only take up 20% of the workload but when a write did occur it should be the next sequential step from the last write.
>>>>
>>>>
>>>> Snippet from the bus trace for reference
>>>>
>>>> Command                                           LBA
>>>> Read FPDMA Queued:                  19F3F818
>>>> Read FPDMA Queued:                  1CBE2740
>>>> Write FPDMA Queued:                 24E35198
>>>> Write FPDMA Queued:                 24E351A0
>>>> Read FPDMA Queued:                  115A9E10
>>>> Write FPDMA Queued:                 A3C1968
>>>> Read FPDMA Queued:                  20B89488
>>>> Write FPDMA Queued:                 336EE0D0
>>>> Write FPDMA Queued:                 336EE0D8
>>>>
>>>>
>>>>
>>>> Let me know what you think, this feature may be working as intended but it seemed off to me.
>>>
>>> Would be easy enough to fix, we just need to track last offset per 
>>> data direction. Does the attached work for you? Totally untested, 
>>> will test on Monday.
>>
>> Looks like fixed.
> 
> Thanks for verifying, Andrey. After taking a second look, looks sane to me after all. Lucky punch!
> 
> Stephen, the fix has been committed, so if you just update to the latest git, it should hopefully work for you as well. Please report back when you have tested it.
> 
> --
> Jens Axboe
>