Question about Request Sense case in scsi_lib.c

I'm having some odd behavior with my multipath fibre channel system. I'm running 2.6.9-rc3, and have a Qlogic 2300 dual ported controller, routed through two brocade switches to two IBM FastT200 disk arrays.

The FastT200 are configured as JBOD. Each array has 10 disks. Each FastT200 is dual ported, configured in "active-active" mode. So, I have four paths to each physical disk, 80 paths total.

Doing just simple IO (dd if=/dev/zero of=/dev/sdX bs=1M) on all 20 at once drives gives me occasional messages of the form:

Incorrect number of segments after building list
counted 31, received 30
req nr_sec 1024, cur_nr_sec 8

this is from the code in scsi_init_io() function in scsi_lib.c

I traced this to scsi_io_completion(), to the scsi_requeue_command() at the bottom of this code.

			if ((cmd->sense_buffer[2] & 0xf) == UNIT_ATTENTION) {
                                if (cmd->device->removable) {
                                        /* detected disc change.  set a bit
                                         * and quietly refuse further access.
                                         */
                                        cmd->device->changed = 1;
                                        cmd = scsi_end_request(cmd, 0,
                                                        this_count, 1);
                                        return;
                                } else {
                                        /*
                                        * Must have been a power glitch, or a
                                        * bus reset.  Could not have been a
                                        * media change, so we just retry the
                                        * request and see what happens.
                                        */
                                        scsi_requeue_command(q, cmd);
                                        return;
                                }
			}

My system hits this scsi_requeue_command() case a lot (maybe 1 in 1000 writes), and of these I occasionally get the error messages in the requeue.

Can anyone explain why I might be getting the "bus reset" in my request sense data? I'll later look into the requeued commands that fail, to understand what's going on there.

Thanks!
Dave Olien

I thought on FAStT's while there are dual-active controllers, for a given lun they weren't active-active, but rather active-passive with either manual or automatic volume transfer. Assuming automatic volume transfer is on and you send IOs to both controllers simultaneously you would ping-pong the cache, drive IO rates lower and possibly see that manifest itself in interesting behaviour in the linux scsi stack. With manual volume transfer you should get IO errors from the controller which is not active or preferred for the given lun. Maybe somebody involved with their RDAC multipathing driver follows this list and can comment on their intentions for the 2.6 kernel and dm multipathing.

Tim,

Thanks for the feedback. Yes, Automatic volume transfer is on, and I was expecting there'd be poor performance as a result. I just didn't expect to get IO errors. The odd thing is that the "bus reset" leads to the SCSI request being requeued. But every once in a while, the requeue fails with errors and the request is failed. I'll look at these cases a little more closely, try to understand why the requeues fail.

I think the dm multipathing software will soon have hooks to support manual volume transfer in these situations.

Dave

Hang on a minute ... if you're ping pong'ing the drives using AVT, those transfers take time to achieve. The device is probably returning UNIT ATTENTION, NOT_READY while the transfer is in progress. This is probably the source of the requeue.

As for the error, I still don't understand that, but it looks like something went wrong in setting up or tearing down the dma mapping, so that it was incorrectly described when this happened a second time.

James

James,

OK, This probably makes sense. I'm going to see if I can get a theory of operations for this device somewhere. I'd like to have a better understanding of how the device works and how long it takes to do these transfers.

I'll dump out some more information about these cases, and see if we can analyze what's going on.

Thanks!
Dave

I ran that way (use both controllers for one LUN while in AVT mode) a long time ago, I don't know the timing, but performance was horrid. I can't think of any reason to run that way, other than trying to duplicate this bug ;-)

AFAIR the "transfer" is moving cached data from one controller of the disk array to the other, but it must have some sort of synchronization method.

But try running with the scsi command completion logging on, it should dump the full sense data.

You can run at this log level without generating extra IO (won't log the logging), make sure you have CONFIG_SCSI_LOGGING on, and then use:

	sysctl -w dev.scsi.logging_level=0x1200

Or just use /proc/sys/dev/scsi/logging_level ...

Set back to zero to turn off logging:

sysctl -w dev.scsi.logging_level=0

And you should get logging for non-zero scmd->result IO completions (scmd->result is 2 meaning check condition in the below output) like this:

Oct 12 13:00:54 elm3b79 kernel: scsi <0:0:0:0> done SUCCESS        2 scsi0 : destination target 0, lun 0
Oct 12 13:00:54 elm3b79 kernel:         command = Inquiry 01 83 00 fe 00
Oct 12 13:00:54 elm3b79 kernel: Current sda: sense key Illegal Request
Oct 12 13:00:54 elm3b79 kernel: Additional sense: Invalid field in cdb

HTH ...

-- Patrick Mansfield

Patrick,

Thanks for the pointer. I'll see what SCSI logging reveals.

Yup, I'm definately not doing this hoping to measure performance. I'm trying to understand better how my hardware is working, and making sure it's working correctly.

A couple weeks ago, I had IO failures because of two flakey gbic's on my fibre channel switches. It took some effort to track those down and replace them. So now, I want to understand this new behavior before moving on.

If there's a software bug triggered by these scsi command requeue's, it's probably worth understanding that and fixing it.

Thanks!
Dave Olien

UNIT ATTENTION and NOT READY are both sense keys so a device can't yield both on one command. However you may be on the right track as there is an ever increasing number of reasons a device could issue a UNIT ATTENTION. [See SPC-3 rev 21 and I believe these ASC codes (and all their associated ASCQ codes) occur with a sense key of UNIT ATTENTION:
0x28, 0x29, 0x2a, 0x3f, 0x5b/0x1 and 0x5d.]

Unlikely in this case but a sense key of UNIT ATTENTION (or perhaps RECOVERED ERROR) with an additional sense of "Hardware impending failure, seek error rate too high" may slip by without even a log entry.

I hope to address the code in the scsi_io_completion() error/warning processing paths with the descriptor_sense cleanup. There seems to be a missing scsi_print_sense() call on the UNIT ATTENTION path.

Dave, does your log show a bus error (ASC/ASCQ=0x29/0x2) has occurred?

Doug Gilbert

Here's what seeing out of the SCSI log:

        command = Write (10) 00 00 00 84 00 00 04 00 00
Current sdx: sense key Unit Attention
ASC=8b ASCQ= 2
P<6>scsi <2:0:2:3> done SUCCESS        2 scsi2 : destination target 2, lun 3
        command = Write (10) 00 00 00 88 00 00 04 00 00
Current sdx: sense key Unit Attention
ASC=8b ASCQ= 2
P<6>scsi <2:0:2:0> done SUCCESS        2 scsi2 : destination target 2, lun 0
        command = Write (10) 00 00 00 00 48 00 04 00 00

Current sdu: sense key Unit Attention
ASC=8b ASCQ= 2
P<3>Incorrect number of segments after building list counted 11, received 5
req nr_sec 1024, cur_nr_sec 8