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

PATCH In review David Chinner 5 participants 10 messages Mar 20, 2008 – May 13, 2008

Subsystems (2)

SCSI QLogic QLA1280 SCSI driver

lore

Share & tools

lore

David Chinner

author

2008-03-20 00:08 UTC #0 lore raw

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.

Signature · 3 lines

Dave Chinner
Principal Engineer
SGI Australian Software Group

Jeremy Higdon

2008-03-20 01:08 UTC #1 lore raw

Quoted 9 lines · 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

Quoted 8 lines

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

Quoted 10 lines

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

Andrew Morton

2008-03-20 10:20 UTC #2 lore raw

Quoted 1 line · On Wed, 19 Mar 2008 18:08:07 -0700 Jeremy Higdon <[email protected]> wrote:

(cc's added. It matters)

Quoted 14 lines · David Chinner

Quoted 13 lines
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:

Quoted 8 lines

Quoted 4 lines
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...

Quoted 9 lines

Quoted 9 lines
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
$

Quoted 5 lines

Quoted 1 line
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?

Mike Snitzer

2008-03-20 11:59 UTC #3 lore raw

Quoted 27 lines · Andrew Morton

Quoted 1 line · On Wed, 19 Mar 2008 18:08:07 -0700 Jeremy Higdon <[email protected]> wrote:
(cc's added. It matters)
Quoted 21 lines · David Chinner
Quoted 9 lines
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
Quoted 8 lines
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

Quoted 7 lines

Quoted 1 line
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

Jeremy Higdon

2008-03-23 23:11 UTC #4 lore raw

In reply to Andrew Morton

Quoted 10 lines · Andrew Morton

Quoted 9 lines · On Wed, 19 Mar 2008 18:08:07 -0700 Jeremy Higdon <[email protected]> wrote:
Quoted 9 lines
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
$

Quoted 7 lines

Quoted 5 lines
Quoted 1 line
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

Jeremy Higdon

2008-05-12 06:17 UTC #5 lore raw

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

In reply to Andrew Morton

Quoted 9 lines · Andrew Morton

Quoted 9 lines
Quoted 9 lines
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
$

Quoted 6 lines

Quoted 4 lines
Quoted 1 line
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 <[email protected]>

---

drivers/scsi/qla1280.c +2 -2

@@ -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;

David Chinner

author Tested-by on v1 1/1

2008-05-12 11:43 UTC #6 lore raw

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

Quoted 18 lines · Jeremy Higdon

Quoted 9 lines · Andrew Morton
Quoted 9 lines
Quoted 9 lines
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
$
Quoted 6 lines
Quoted 4 lines
Quoted 1 line
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...

....

Quoted 8 lines

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).

Quoted 4 lines

I tested with a Seagate ST336753LC, and results look good, so I'm satisfied with this patch.
Signed-off-by Jeremy Higdon <[email protected]>

Works fine here.

Tested-by Dave Chinner <[email protected]>

Cheers,

Dave.

Signature · 3 lines

Dave Chinner
Principal Engineer
SGI Australian Software Group

Andrew Morton

2008-05-13 00:19 UTC #7 lore raw

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

In reply to Jeremy Higdon

Quoted 71 lines · On Sun, 11 May 2008 23:17:03 -0700 Jeremy Higdon <[email protected]> wrote:

Quoted 9 lines · Andrew Morton
Quoted 9 lines
Quoted 9 lines
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
$
Quoted 6 lines
Quoted 4 lines
Quoted 1 line
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 <[email protected]>
---
drivers/scsi/qla1280.c +1 -1
@@ -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;

drivers/scsi/qla1280.c qla1280_config_target(struct scsi_qla_ho · line 2056

Quoted 7 lines

drivers/scsi/qla1280.c +1 -1

@@ -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?)

Jes Sorensen

Acked-by

2008-05-13 07:15 UTC #8 lore raw

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

Quoted 14 lines · Andrew Morton

Quoted 14 lines

drivers/scsi/qla1280.c +1 -1

@@ -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);

Quoted 9 lines

drivers/scsi/qla1280.c qla1280_config_target(struct scsi_qla_ho · line 2056
Quoted 5 lines
drivers/scsi/qla1280.c +1 -1
 	/* 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 <[email protected]>

Cheers,
Jes

Jeremy Higdon

2008-05-13 08:58 UTC #9 lore raw

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

Quoted 25 lines · Jes Sorensen

Quoted 14 lines · Andrew Morton

Quoted 14 lines

drivers/scsi/qla1280.c +1 -1

@@ -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);

Quoted 9 lines

drivers/scsi/qla1280.c qla1280_config_target(struct scsi_qla_ho · line 2056
Quoted 5 lines
drivers/scsi/qla1280.c +1 -1
 	/* 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?)

Quoted 2 lines

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

I agree.

Quoted 1 line

Acked-by Jes Sorensen <[email protected]>

jeremy