PATCH 3/6 - direct-io: do not merge logically non-contiguous requests

I guess was hit by those "slightly less optimal I/O patters for other file-systems" while measuring performance with iozone sequential using direct I/O with 64k requests.
First I only saw increased cpu costs and a huge number of request merges, analyzing that brought me to this patch (reverting fixes the issue).

Therefore I'd like to come back to that suggested "that way it only affects btrfs" solution.

What happens on my system is that all direct I/O requests from userspace are broken up in 4k bio's and then re-merged by the ioscheduler before reaching the device driver. Eventually that means +30% cpu cost for 64k, probably much more for larger request sizes - Throughput is only affected if there is no cpu left to spare for this additional overhead.

A blktrace log is probably the best way to explain this in detail:
(sequential 64k requests using direct I/O reading a 2Gb file on a ext2 file system)

Application summary for iozone :
BAD: GOOD:
iozone (18572, ...) iozone (18482, ...)

 Reads Queued:     506,222,    2,024MiB    Reads Queued:      37,851, 2,040MiB 
 Read Dispatches:   33,110,    2,024MiB    Read Dispatches:   33,368, 2,040MiB 
 Reads Requeued:         0                 Reads Requeued:         0            
 Reads Completed:   15,072,  911,112KiB    Reads Completed:    9,814, 588,708KiB 
 Read Merges:      473,111,    1,892MiB    Read Merges:        4,483,  
17,936KiB 
 IO unplugs:        32,108                 IO unplugs:        32,364            
 Allocation wait:       32                 Allocation wait:       26            
 Dispatch wait:        338                 Dispatch wait:        216            
 Completion wait:    1,426                 Completion wait:    1,362 

As a full stream of blktrace events it looks like that:
GOOD:

  8,0    3        3     0.002964189 18400  A   R 65960 + 128 <- (8,1) 65928
  8,0    3        4     0.002964345 18400  Q   R 65960 + 128 [iozone]
  8,0    3        5     0.002964814 18400  G   R 65960 + 128 [iozone]
  8,0    3        6     0.002965533 18400  P   N [iozone]
  8,0    3        7     0.002965689 18400  I   R 65960 + 128 (     875) [iozone]
  8,0    3        8     0.002966095 18400  U   N [iozone] 1
  8,0    3        9     0.002966501 18400  D   R 65960 + 128 (     812) [iozone]
  8,0    3       11     0.003599064 18401  C   R 65960 + 128 (  632563) [0]

BAD:

  8,0    1      226     0.002707250 18572  A   R 148008 + 8 <- (8,1) 147976
  8,0    1      227     0.002707406 18572  Q   R 148008 + 8 [iozone]
  8,0    1      228     0.002707875 18572  G   R 148008 + 8 [iozone]
  8,0    1      229     0.002708563 18572  P   N [iozone]
  8,0    1      230     0.002708813 18572  I   R 148008 + 8 (     938) [iozone]
  8,0    1      231     0.002709469 18572  A   R 148016 + 8 <- (8,1) 147984
  8,0    1      232     0.002709625 18572  Q   R 148016 + 8 [iozone]
  8,0    1      233     0.002709875 18572  M   R 148016 + 8 [iozone]
  8,0    1      234     0.002710594 18572  A   R 148024 + 8 <- (8,1) 147992
  8,0    1      235     0.002710750 18572  Q   R 148024 + 8 [iozone]
  8,0    1      236     0.002710969 18572  M   R 148024 + 8 [iozone]
  8,0    1      237     0.002711563 18572  A   R 148032 + 8 <- (8,1) 148000
  8,0    1      238     0.002711750 18572  Q   R 148032 + 8 [iozone]
  8,0    1      239     0.002712063 18572  M   R 148032 + 8 [iozone]
  8,0    1      240     0.002712625 18572  A   R 148040 + 8 <- (8,1) 148008
  8,0    1      241     0.002712750 18572  Q   R 148040 + 8 [iozone]
  8,0    1      242     0.002713000 18572  M   R 148040 + 8 [iozone]
  8,0    1      243     0.002713531 18572  A   R 148048 + 8 <- (8,1) 148016
  8,0    1      244     0.002713750 18572  Q   R 148048 + 8 [iozone]
  8,0    1      245     0.002713969 18572  M   R 148048 + 8 [iozone]
  8,0    1      246     0.002714531 18572  A   R 148056 + 8 <- (8,1) 148024
  8,0    1      247     0.002714656 18572  Q   R 148056 + 8 [iozone]
  8,0    1      248     0.002714938 18572  M   R 148056 + 8 [iozone]
  8,0    1      249     0.002715500 18572  A   R 148064 + 8 <- (8,1) 148032
  8,0    1      250     0.002715625 18572  Q   R 148064 + 8 [iozone]
  8,0    1      251     0.002715844 18572  M   R 148064 + 8 [iozone]
  8,0    1      252     0.002716438 18572  A   R 148072 + 8 <- (8,1) 148040
  8,0    1      253     0.002716625 18572  Q   R 148072 + 8 [iozone]
  8,0    1      254     0.002716844 18572  M   R 148072 + 8 [iozone]
  8,0    1      255     0.002717375 18572  A   R 148080 + 8 <- (8,1) 148048
  8,0    1      256     0.002717531 18572  Q   R 148080 + 8 [iozone]
  8,0    1      257     0.002717750 18572  M   R 148080 + 8 [iozone]
  8,0    1      258     0.002718344 18572  A   R 148088 + 8 <- (8,1) 148056
  8,0    1      259     0.002718500 18572  Q   R 148088 + 8 [iozone]
  8,0    1      260     0.002718719 18572  M   R 148088 + 8 [iozone]
  8,0    1      261     0.002719250 18572  A   R 148096 + 8 <- (8,1) 148064
  8,0    1      262     0.002719406 18572  Q   R 148096 + 8 [iozone]
  8,0    1      263     0.002719688 18572  M   R 148096 + 8 [iozone]
  8,0    1      264     0.002720156 18572  A   R 148104 + 8 <- (8,1) 148072
  8,0    1      265     0.002720313 18572  Q   R 148104 + 8 [iozone]
  8,0    1      266     0.002720531 18572  M   R 148104 + 8 [iozone]
  8,0    1      267     0.002721031 18572  A   R 148112 + 8 <- (8,1) 148080
  8,0    1      268     0.002721219 18572  Q   R 148112 + 8 [iozone]
  8,0    1      269     0.002721469 18572  M   R 148112 + 8 [iozone]
  8,0    1      270     0.002721938 18572  A   R 148120 + 8 <- (8,1) 148088
  8,0    1      271     0.002722063 18572  Q   R 148120 + 8 [iozone]
  8,0    1      272     0.002722344 18572  M   R 148120 + 8 [iozone]
  8,0    1      273     0.002722813 18572  A   R 148128 + 8 <- (8,1) 148096
  8,0    1      274     0.002722938 18572  Q   R 148128 + 8 [iozone]
  8,0    1      275     0.002723156 18572  M   R 148128 + 8 [iozone]
  8,0    1      276     0.002723406 18572  U   N [iozone] 1
  8,0    1      277     0.002724031 18572  D   R 148008 + 128 (   15218) [iozone]
  8,0    1      279     0.003318094     0  C   R 148008 + 128 (  594063) [0]

Grüsse / regards, Christian Ehrhardt
IBM Linux Technology Center, System z Linux Performance 

Something is deeply wrong here. Raw block device access has a 1:1 mapping between logical and physical block numbers. They really should never be non-contiguous.

ld

At least I did nothing I know about to break it :-)

As I mentioned just iozone using direct I/O (-I flag of iozone then=20 using O_DIRECT for the file) on a ext2 file-system.
The file system was coming clean out of mkfs the file was written with=20 iozone one step before the traced read run.

The only uncommon thing here might be the block device, which is a scsi= =20
disk on our SAN servers (I'm running on s390) - so the driver in charge= =20
is zfcp (drivers/s390/scsi/).
I could use dasd (drivers/s390/block) disks as well, but I have no=20 blktrace of them yet - what I already know is that they show a similar=20 cost increase. On monday I should be able to get machine resources to=20 verify that both disk types are affected.

Let me know if I can do anything else on my system to shed some light o= n=20
the matter.

--=20

Gr=FCsse / regards, Christian Ehrhardt
IBM Linux Technology Center, System z Linux Performance
--
To unsubscribe from this list: send the line "unsubscribe linux-fsdevel= " in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

I think Christoph missed that you were using ext2, not the block device.

Well, the problem is pretty obvious. Inside submit_page_section, you have this code:

	/*
	 * If there's a deferred page already there then send it.
	 */
	if (dio->cur_page) {
		ret = dio_send_cur_page(dio);
		page_cache_release(dio->cur_page);
		dio->cur_page = NULL;
		if (ret)
			goto out;
	}

	page_cache_get(page);/* It is in dio */
	dio->cur_page = page;
	dio->cur_page_offset = offset;
	dio->cur_page_len = len;
	dio->cur_page_block = blocknr;
	dio->cur_page_fs_offset = dio->block_in_file << dio->blkbits;

Notice that we're processing a new page, so we submit the old page for I/O.

And in dio_send_cur_page, we have this:

	if (dio->final_block_in_bio != dio->cur_page_block ||
	    cur_offset != bio_next_offset)
		dio_bio_submit(dio);

So, we are actually comparing values between two different pages, and of course, this doesn't work. We're always one page behind in the I/O.

Also, the block of code above is immediately followed by this:

	/*
	 * Submit now if the underlying fs is about to perform a
	 * metadata read
	 */
	if (dio->boundary)
		dio_bio_submit(dio);

So, it looks to me like this could result in submitting the same bio twice if you are unlucky enough. I'll see what I can do to fix this up.

Cheers,
Jeff

So above we have this

        loff_t cur_offset = dio->block_in_file << dio->blkbits;
        loff_t bio_next_offset = dio->logical_offset_in_bio +
                dio->bio->bi_size;

block_in_file is the logical offset of the current page we are working on. logical_offset_in_bio is the logical offset of the first page in the bio, plus bi_size gives us the logical offset that would come next for a contiguous page, so if cur_offset != bio_next_offset then the range in the bio and the current page we have are not right next to eachother, so it works just fine. It's a little tricky, but

dio->block_in_file - logical offset of current page dio->logical_offset_in_bio - logical offset of first page added to the bio

So say blocksize of 4k, we do dio to 12k, the first time around dio->block_in_file is 0, we set dio->cur_page, and move on to the next page, and bio->block_in_file is set to 1. We find that dio->cur_page is set, so we do dio_send_cur_page(). Since !dio->bio we create a new bio, and set dio->logical_offset_in_bio to 0, since thats the offset of dio->cur_page. Then we setup the next cur_page as the page for logical block 1, and dio->block_in_file gets bumped to 2. We map the next block and come into dio_send_cur_page() again. At this point cur_offset would be 8192...and shit I just realized what was wrong. If you change

loff_t cur_offset = dio->block_in_file << dio->blkbits;

to

loff_t cur_offset = dio->cur_page_fs_offset << dio->blkbits;

That should fix the problem. Sorry guys, I screwed that up. I'll look at this again tomorrow after I've had my 2 hours of sleep and see if this all still makes sense, but I think the above should fixe the performance thing. As for the dio->boundary thing, dio_bio_submit() sets dio->boundary to 0, so the same bio won't be submitted twice. Thanks,

Josef

Sorry, I wasn't very clear in my description, but you figured it out. ;-) Of course, cur_page_fs_offset is already in bytes, so that left shift is not necessary.

While I don't doubt that you are right, I will sleep better at night if we do an else if. (To be fair, this ambiguity was not introduced by you).

I've tested this patch, added printk's and watched blktrace to verify that we don't split up I/Os. So long as no one objects, I'll post this for inclusion in a new thread.

Thanks for looking into it, Josef.

Cheers,
Jeff

index 7600aac..445901c 100644
@@ -632,7 +632,7 @@ static int dio_send_cur_page(struct dio *dio)
 	int ret = 0;
 
 	if (dio->bio) {
-		loff_t cur_offset = dio->block_in_file << dio->blkbits;
+		loff_t cur_offset = dio->cur_page_fs_offset;
 		loff_t bio_next_offset = dio->logical_offset_in_bio +
 			dio->bio->bi_size;
 

@@ -657,7 +657,7 @@ static int dio_send_cur_page(struct dio *dio)
 		 * Submit now if the underlying fs is about to perform a
 		 * metadata read
 		 */
-		if (dio->boundary)
+		else if (dio->boundary)
 			dio_bio_submit(dio);
 	}
 

Ah right, sorry.

No problem, thanks for making me look at it again. You can add

Thanks,

Josef