Buffered I/O to block device very slow and other SCSI issues...

Buffered I/O to block device very slow and other SCSI issues...

[David Chinner]

4p ia64, 24GB RAM, 2.6.25-rc3, qla1280, 15krpm scsi disk.

Direct I/O:

dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=1024 oflag=direct
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB) copied, 27.8974 s, 38.5 MB/s

Doing approximately 80 512k I/os per second (disk bandwidth).

Buffered I/O:

dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=4096
4096+0 records in
4096+0 records out
4294967296 bytes (4.3 GB) copied, 427.872 s, 10.0 MB/s

Which was doing about 200 64k I/Os per second for the entire write.
Interactivity goes to hell, cpu usage is pretty much zero. I can
barely run anything, I can't ctrl-c out of running programs, etc.

It would appear that the block device is being flushed one sector at
a time:

  8,22   3     8757    26.699052800 12143  Q   W 9770471 + 1 [sync]
  8,22   3     8760    26.699058050 12143  Q   W 9770472 + 1 [sync]
  8,22   3     8763    26.699063300 12143  Q   W 9770473 + 1 [sync]
  8,22   3     8766    26.699068900 12143  Q   W 9770474 + 1 [sync]
  8,22   3     8769    26.699074150 12143  Q   W 9770475 + 1 [sync]
  8,22   3     8772    26.699079400 12143  Q   W 9770476 + 1 [sync]
  8,22   3     8775    26.699084650 12143  Q   W 9770477 + 1 [sync]
  8,22   3     8778    26.699090200 12143  Q   W 9770478 + 1 [sync]
  8,22   3     8781    26.699095600 12143  Q   W 9770479 + 1 [sync]
  8,22   3     8784    26.699100800 12143  Q   W 9770480 + 1 [sync]
  8,22   3     8787    26.699106100 12143  Q   W 9770481 + 1 [sync]
  8,22   3     8790    26.699111700 12143  Q   W 9770482 + 1 [sync]
  8,22   3     8793    26.699117000 12143  Q   W 9770483 + 1 [sync]
  8,22   3     8796    26.699122250 12143  Q   W 9770484 + 1 [sync]
  8,22   3     8799    26.699127500 12143  Q   W 9770485 + 1 [sync]
  8,22   3     8802    26.699133100 12143  Q   W 9770486 + 1 [sync]
  8,22   3     8805    26.699138450 12143  Q   W 9770487 + 1 [sync]

And it's only combining into 128 sector I/Os. Something wrong
with bio merging limiting the I/os to 128 elements? I'm using BSG
here, so maybe that's a factor.....

I also suspect that CTQ has not been set up correctly on this
kernel, because:

$ cat /sys/block/sdb/device/queue_depth
3
$ ls -l /sys/block/sdb/device/queue_depth
-r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
$

It appears to be hard coded to 3 and can't be changed....

Hmmm:

$ sudo sdparm -s WCE=1 /dev/sdb
SCSI INQUIRY command failed on /dev/sdb
$

Did I miss some new config option, or are things just generally broken?

Cheers,

Dave.

-- 
Dave Chinner
Principal Engineer
SGI Australian Software Group

Re: Buffered I/O to block device very slow and other SCSI issues...

[Jeremy Higdon]

On Thu, Mar 20, 2008 at 10:16:54AM +1100, David Chinner wrote:
> 4p ia64, 24GB RAM, 2.6.25-rc3, qla1280, 15krpm scsi disk.
> 
> Direct I/O:
> 
> dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=1024 oflag=direct
> 1024+0 records in
> 1024+0 records out
> 1073741824 bytes (1.1 GB) copied, 27.8974 s, 38.5 MB/s
> 
> Doing approximately 80 512k I/os per second (disk bandwidth).
> 
> Buffered I/O:
> 
> dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=4096
> 4096+0 records in
> 4096+0 records out
> 4294967296 bytes (4.3 GB) copied, 427.872 s, 10.0 MB/s

How big is sdb6?  How many '2's do you see in

	factor `cat /sys/block/sdb/sdb6/size`

> I also suspect that CTQ has not been set up correctly on this
> kernel, because:
> 
> $ cat /sys/block/sdb/device/queue_depth
> 3
> $ ls -l /sys/block/sdb/device/queue_depth
> -r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
> $
> 
> It appears to be hard coded to 3 and can't be changed....

That's a bug in the qla1280 driver.  I thought that had gotten fixed.
It's looking at the wrong mailbox register after setting device parameters.

jeremy

Re: Buffered I/O to block device very slow and other SCSI issues...

[Andrew Morton]

On Wed, 19 Mar 2008 18:08:07 -0700 Jeremy Higdon <jeremy@sgi.com> wrote:
>

(cc's added.  It matters)

> On Thu, Mar 20, 2008 at 10:16:54AM +1100, David Chinner wrote:
> > 4p ia64, 24GB RAM, 2.6.25-rc3, qla1280, 15krpm scsi disk.
> > 
> > Direct I/O:
> > 
> > dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=1024 oflag=direct
> > 1024+0 records in
> > 1024+0 records out
> > 1073741824 bytes (1.1 GB) copied, 27.8974 s, 38.5 MB/s
> > 
> > Doing approximately 80 512k I/os per second (disk bandwidth).
> > 
> > Buffered I/O:
> > 
> > dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=4096
> > 4096+0 records in
> > 4096+0 records out
> > 4294967296 bytes (4.3 GB) copied, 427.872 s, 10.0 MB/s
> 
> How big is sdb6?  How many '2's do you see in
> 
> 	factor `cat /sys/block/sdb/sdb6/size`

There have always been problems with thsi and I'm not sure that anyone
cared enough about buffered writes to blockdevs to get to the bottom of
them.

I assume you aren't running i386 highmem...


> > I also suspect that CTQ has not been set up correctly on this
> > kernel, because:
> > 
> > $ cat /sys/block/sdb/device/queue_depth
> > 3
> > $ ls -l /sys/block/sdb/device/queue_depth
> > -r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
> > $
> > 
> > It appears to be hard coded to 3 and can't be changed....
> 
> That's a bug in the qla1280 driver.  I thought that had gotten fixed.
> It's looking at the wrong mailbox register after setting device parameters.
> 

Was there a patch anywhere?

Re: Buffered I/O to block device very slow and other SCSI issues...

[Mike Snitzer]

On Thu, Mar 20, 2008 at 6:20 AM, Andrew Morton
<akpm@linux-foundation.org> wrote:
> On Wed, 19 Mar 2008 18:08:07 -0700 Jeremy Higdon <jeremy@sgi.com> wrote:
>  >
>
>  (cc's added.  It matters)
>
>
>  > On Thu, Mar 20, 2008 at 10:16:54AM +1100, David Chinner wrote:
>  > > 4p ia64, 24GB RAM, 2.6.25-rc3, qla1280, 15krpm scsi disk.
>  > >
>  > > Direct I/O:
>  > >
>  > > dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=1024 oflag=direct
>  > > 1024+0 records in
>  > > 1024+0 records out
>  > > 1073741824 bytes (1.1 GB) copied, 27.8974 s, 38.5 MB/s
>  > >
>  > > Doing approximately 80 512k I/os per second (disk bandwidth).
>  > >
>  > > Buffered I/O:
>  > >
>  > > dgc@budgie:~/xfstests$ sudo dd if=/dev/zero of=/dev/sdb6 bs=1024k count=4096
>  > > 4096+0 records in
>  > > 4096+0 records out
>  > > 4294967296 bytes (4.3 GB) copied, 427.872 s, 10.0 MB/s
>  >
>  > How big is sdb6?  How many '2's do you see in
>  >
>  >       factor `cat /sys/block/sdb/sdb6/size`
>
>  There have always been problems with thsi and I'm not sure that anyone
>  cared enough about buffered writes to blockdevs to get to the bottom of
>  them.
>
>  I assume you aren't running i386 highmem...

I've experienced the same kind of degradation with buffered IO vs
direct specifically when using Linux partitions.  Using the full block
device doesn't create such fragmented IOs.

The problem was reported to the blktrace list some weeks ago by my
coworker (cc'ing Ming):
http://marc.info/?l=linux-btrace&m=120296070516776&w=2
(fyi, Ming forgot to use oflag=sync, this explains the weird results
when doing buffered writes while blktrace'ing)

To summarize a little more (without messing round with partition
alignment), the test system is x86_64 with 4GB, storage is directly
connected via aacraid, 7200 rpm SATA disk.

Using:
dd if=/dev/zero of=/dev/sdhX bs=1M oflag=sync count=4 seek=2
and
dd if=/dev/zero of=/dev/sdhX bs=1M oflag=direct count=4 seek=2

full disk case (sdh):
buffered writes are +8 and being merged to 3 512k requests, 1 8k and 1
504k (27MB/s)
odirect writes are all +512 (35MB/s)

partitioned case: a 3GB sdh1 and ~720GB sdh2.
buffered writes to partition1 are +1 and are merged to 65k requests  (10.3MB/s)
buffered writes to partition2 are +2 and are merged to 130k requests (15.2MB/s)
odirect writes to either partition are all +512 (27MB/s)

So it appears partition size matters (at least in this case)?

As you can see performing buffered writes to a partition resulted in
very small requests, much like David reported in his original post (+1
or +2 via blktrace).

This happens with every kernel tried; 2.6.22, 2.6.24, RHEL5U1, etc.
cfq vs deadline doesn't change anything.  For partitions, changing
partition alignment to a power of 2 actually hurt!?

Mike

Re: Buffered I/O to block device very slow and other SCSI issues...

[Jeremy Higdon]

On Thu, Mar 20, 2008 at 03:20:10AM -0700, Andrew Morton wrote:
> On Wed, 19 Mar 2008 18:08:07 -0700 Jeremy Higdon <jeremy@sgi.com> wrote:
> > > I also suspect that CTQ has not been set up correctly on this
> > > kernel, because:
> > > 
> > > $ cat /sys/block/sdb/device/queue_depth
> > > 3
> > > $ ls -l /sys/block/sdb/device/queue_depth
> > > -r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
> > > $
> > > 
> > > It appears to be hard coded to 3 and can't be changed....
> > 
> > That's a bug in the qla1280 driver.  I thought that had gotten fixed.
> > It's looking at the wrong mailbox register after setting device parameters.
> > 
> 
> Was there a patch anywhere?

I thought so, but maybe not.  I'll go looking for what happened and then
forward one, but it'll take a couple of weeks, unless I can get Jes to
do it, as I'm going on vacation/holiday for a week.

jeremy

[PATCH] drivers/scsi/qla1280.c; was Re: Buffered I/O to block device very slow and other SCSI issues...

[Jeremy Higdon]

On Thu, Mar 20, 2008 at 03:20:10AM -0700, Andrew Morton wrote:
> > > I also suspect that CTQ has not been set up correctly on this
> > > kernel, because:
> > > 
> > > $ cat /sys/block/sdb/device/queue_depth
> > > 3
> > > $ ls -l /sys/block/sdb/device/queue_depth
> > > -r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
> > > $
> > > 
> > > It appears to be hard coded to 3 and can't be changed....
> > 
> > That's a bug in the qla1280 driver.  I thought that had gotten fixed.
> > It's looking at the wrong mailbox register after setting device parameters.
> 
> Was there a patch anywhere?

Promised patch...

The qla1280 driver was ANDing the output value of mailbox register
0 with (1 << target-number) to determine whether to enable queueing
on the target in question.

But mailbox register 0 has the status code for the mailbox command
(in this case, Set Target Parameters).  Potential values are:
/*      
 * ISP mailbox command complete status codes
 */
#define MBS_CMD_CMP             0x4000  /* Command Complete. */
#define MBS_INV_CMD             0x4001  /* Invalid Command. */
#define MBS_HOST_INF_ERR        0x4002  /* Host Interface Error. */
#define MBS_TEST_FAILED         0x4003  /* Test Failed. */
#define MBS_CMD_ERR             0x4005  /* Command Error. */
#define MBS_CMD_PARAM_ERR       0x4006  /* Command Parameter Error. */

So clearly that is in error.  I can't think what the author of that
line was looking for in a mailbox register, so I just eliminated the
AND.  flag is used later in the function, and I think that the later
usage was also wrong, though it was used to set values that aren't
used.  Oh well, an overhaul of this driver is not what I want to do
now -- just a bugfix. 

After the fix, I found that my disks were getting a queue depth of
255, which is far too many.  Most SCSI disks are limited to 32 or
64.  In any case, there's no point, queueing up a bunch of commands
to the adapter that will just result in queue full or starve other
targets from being issued commands due to running out of internal
memory.  So I dropped default queue depth to 32 (from which 1 is
subtracted elsewhere, giving net of 31).

I tested with a Seagate ST336753LC, and results look good, so
I'm satisfied with this patch.

Signed-off-by: Jeremy Higdon <jeremy@sgi.com>


---


--- a/drivers/scsi/qla1280.c	2008-05-03 11:59:44.000000000 -0700
+++ b/drivers/scsi/qla1280.c	2008-05-10 21:32:23.451341969 -0700
@@ -2007,7 +2007,7 @@ qla1280_set_defaults(struct scsi_qla_hos
 		nv->bus[bus].config_2.req_ack_active_negation = 1;
 		nv->bus[bus].config_2.data_line_active_negation = 1;
 		nv->bus[bus].selection_timeout = 250;
-		nv->bus[bus].max_queue_depth = 256;
+		nv->bus[bus].max_queue_depth = 32;
 
 		if (IS_ISP1040(ha)) {
 			nv->bus[bus].bus_reset_delay = 3;
@@ -2051,7 +2051,7 @@ qla1280_config_target(struct scsi_qla_ho
 	status = qla1280_mailbox_command(ha, 0x0f, mb);
 
 	/* Save Tag queuing enable flag. */
-	flag = (BIT_0 << target) & mb[0];
+	flag = (BIT_0 << target);
 	if (nv->bus[bus].target[target].parameter.tag_queuing)
 		ha->bus_settings[bus].qtag_enables |= flag;
 

Re: [PATCH] drivers/scsi/qla1280.c; was Re: Buffered I/O to block device very slow and other SCSI issues...

[David Chinner]

On Sun, May 11, 2008 at 11:17:03PM -0700, Jeremy Higdon wrote:
> On Thu, Mar 20, 2008 at 03:20:10AM -0700, Andrew Morton wrote:
> > > > I also suspect that CTQ has not been set up correctly on this
> > > > kernel, because:
> > > > 
> > > > $ cat /sys/block/sdb/device/queue_depth
> > > > 3
> > > > $ ls -l /sys/block/sdb/device/queue_depth
> > > > -r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
> > > > $
> > > > 
> > > > It appears to be hard coded to 3 and can't be changed....
> > > 
> > > That's a bug in the qla1280 driver.  I thought that had gotten fixed.
> > > It's looking at the wrong mailbox register after setting device parameters.
> > 
> > Was there a patch anywhere?
> 
> Promised patch...
....
> After the fix, I found that my disks were getting a queue depth of
> 255, which is far too many.  Most SCSI disks are limited to 32 or
> 64.  In any case, there's no point, queueing up a bunch of commands
> to the adapter that will just result in queue full or starve other
> targets from being issued commands due to running out of internal
> memory.  So I dropped default queue depth to 32 (from which 1 is
> subtracted elsewhere, giving net of 31).
> 
> I tested with a Seagate ST336753LC, and results look good, so
> I'm satisfied with this patch.
> 
> Signed-off-by: Jeremy Higdon <jeremy@sgi.com>

Works fine here.

Tested-by: Dave Chinner <dgc@sgi.com>

Cheers,

Dave.
-- 
Dave Chinner
Principal Engineer
SGI Australian Software Group

Re: [PATCH] drivers/scsi/qla1280.c; was Re: Buffered I/O to block device very slow and other SCSI issues...

[Andrew Morton]

On Sun, 11 May 2008 23:17:03 -0700
Jeremy Higdon <jeremy@sgi.com> wrote:

> On Thu, Mar 20, 2008 at 03:20:10AM -0700, Andrew Morton wrote:
> > > > I also suspect that CTQ has not been set up correctly on this
> > > > kernel, because:
> > > > 
> > > > $ cat /sys/block/sdb/device/queue_depth
> > > > 3
> > > > $ ls -l /sys/block/sdb/device/queue_depth
> > > > -r--r--r-- 1 root root 0 Mar 20 09:59 /sys/block/sdb/device/queue_depth
> > > > $
> > > > 
> > > > It appears to be hard coded to 3 and can't be changed....
> > > 
> > > That's a bug in the qla1280 driver.  I thought that had gotten fixed.
> > > It's looking at the wrong mailbox register after setting device parameters.
> > 
> > Was there a patch anywhere?
> 
> Promised patch...
> 
> The qla1280 driver was ANDing the output value of mailbox register
> 0 with (1 << target-number) to determine whether to enable queueing
> on the target in question.
> 
> But mailbox register 0 has the status code for the mailbox command
> (in this case, Set Target Parameters).  Potential values are:
> /*      
>  * ISP mailbox command complete status codes
>  */
> #define MBS_CMD_CMP             0x4000  /* Command Complete. */
> #define MBS_INV_CMD             0x4001  /* Invalid Command. */
> #define MBS_HOST_INF_ERR        0x4002  /* Host Interface Error. */
> #define MBS_TEST_FAILED         0x4003  /* Test Failed. */
> #define MBS_CMD_ERR             0x4005  /* Command Error. */
> #define MBS_CMD_PARAM_ERR       0x4006  /* Command Parameter Error. */
> 
> So clearly that is in error.  I can't think what the author of that
> line was looking for in a mailbox register, so I just eliminated the
> AND.  flag is used later in the function, and I think that the later
> usage was also wrong, though it was used to set values that aren't
> used.  Oh well, an overhaul of this driver is not what I want to do
> now -- just a bugfix. 
> 
> After the fix, I found that my disks were getting a queue depth of
> 255, which is far too many.  Most SCSI disks are limited to 32 or
> 64.  In any case, there's no point, queueing up a bunch of commands
> to the adapter that will just result in queue full or starve other
> targets from being issued commands due to running out of internal
> memory.  So I dropped default queue depth to 32 (from which 1 is
> subtracted elsewhere, giving net of 31).
> 
> I tested with a Seagate ST336753LC, and results look good, so
> I'm satisfied with this patch.
> 
> Signed-off-by: Jeremy Higdon <jeremy@sgi.com>
> 
> 
> ---
> 
> 
> --- a/drivers/scsi/qla1280.c	2008-05-03 11:59:44.000000000 -0700
> +++ b/drivers/scsi/qla1280.c	2008-05-10 21:32:23.451341969 -0700
> @@ -2007,7 +2007,7 @@ qla1280_set_defaults(struct scsi_qla_hos
>  		nv->bus[bus].config_2.req_ack_active_negation = 1;
>  		nv->bus[bus].config_2.data_line_active_negation = 1;
>  		nv->bus[bus].selection_timeout = 250;
> -		nv->bus[bus].max_queue_depth = 256;
> +		nv->bus[bus].max_queue_depth = 32;
>  
>  		if (IS_ISP1040(ha)) {
>  			nv->bus[bus].bus_reset_delay = 3;
> @@ -2051,7 +2051,7 @@ qla1280_config_target(struct scsi_qla_ho
>  	status = qla1280_mailbox_command(ha, 0x0f, mb);
>  
>  	/* Save Tag queuing enable flag. */
> -	flag = (BIT_0 << target) & mb[0];
> +	flag = (BIT_0 << target);
>  	if (nv->bus[bus].target[target].parameter.tag_queuing)
>  		ha->bus_settings[bus].qtag_enables |= flag;

Thanks.  I tagged this for a -stable backport (assuming that is
appropriate?)

Re: [PATCH] drivers/scsi/qla1280.c; was Re: Buffered I/O to block device very slow and other SCSI issues...

[Jes Sorensen]

Andrew Morton wrote:
>> --- a/drivers/scsi/qla1280.c	2008-05-03 11:59:44.000000000 -0700
>> +++ b/drivers/scsi/qla1280.c	2008-05-10 21:32:23.451341969 -0700
>> @@ -2007,7 +2007,7 @@ qla1280_set_defaults(struct scsi_qla_hos
>>  		nv->bus[bus].config_2.req_ack_active_negation = 1;
>>  		nv->bus[bus].config_2.data_line_active_negation = 1;
>>  		nv->bus[bus].selection_timeout = 250;
>> -		nv->bus[bus].max_queue_depth = 256;
>> +		nv->bus[bus].max_queue_depth = 32;
>>  
>>  		if (IS_ISP1040(ha)) {
>>  			nv->bus[bus].bus_reset_delay = 3;
>> @@ -2051,7 +2051,7 @@ qla1280_config_target(struct scsi_qla_ho
>>  	status = qla1280_mailbox_command(ha, 0x0f, mb);
>>  
>>  	/* Save Tag queuing enable flag. */
>> -	flag = (BIT_0 << target) & mb[0];
>> +	flag = (BIT_0 << target);
>>  	if (nv->bus[bus].target[target].parameter.tag_queuing)
>>  		ha->bus_settings[bus].qtag_enables |= flag;
> 
> Thanks.  I tagged this for a -stable backport (assuming that is
> appropriate?)
> 

Sounds good, given the nature of this it should go into stable as well
as current.

Acked-by: Jes Sorensen <jes@sgi.com>

Cheers,
Jes

Re: [PATCH] drivers/scsi/qla1280.c; was Re: Buffered I/O to block device very slow and other SCSI issues...

[Jeremy Higdon]

On Tue, May 13, 2008 at 09:15:46AM +0200, Jes Sorensen wrote:
> Andrew Morton wrote:
> >>--- a/drivers/scsi/qla1280.c	2008-05-03 11:59:44.000000000 -0700
> >>+++ b/drivers/scsi/qla1280.c	2008-05-10 21:32:23.451341969 -0700
> >>@@ -2007,7 +2007,7 @@ qla1280_set_defaults(struct scsi_qla_hos
> >> 		nv->bus[bus].config_2.req_ack_active_negation = 1;
> >> 		nv->bus[bus].config_2.data_line_active_negation = 1;
> >> 		nv->bus[bus].selection_timeout = 250;
> >>-		nv->bus[bus].max_queue_depth = 256;
> >>+		nv->bus[bus].max_queue_depth = 32;
> >> 
> >> 		if (IS_ISP1040(ha)) {
> >> 			nv->bus[bus].bus_reset_delay = 3;
> >>@@ -2051,7 +2051,7 @@ qla1280_config_target(struct scsi_qla_ho
> >> 	status = qla1280_mailbox_command(ha, 0x0f, mb);
> >> 
> >> 	/* Save Tag queuing enable flag. */
> >>-	flag = (BIT_0 << target) & mb[0];
> >>+	flag = (BIT_0 << target);
> >> 	if (nv->bus[bus].target[target].parameter.tag_queuing)
> >> 		ha->bus_settings[bus].qtag_enables |= flag;
> >
> >Thanks.  I tagged this for a -stable backport (assuming that is
> >appropriate?)
> >
> 
> Sounds good, given the nature of this it should go into stable as well
> as current.

I agree.

> Acked-by: Jes Sorensen <jes@sgi.com>


jeremy