[PATCH v2 0/4] scsi_dh_alua: fix stuck I/O after unavailable/standby states

[PATCH v2 0/4] scsi_dh_alua: fix stuck I/O after unavailable/standby states

[Mauricio Faria de Oliveira]

Currently, scsi_dh_alua fails I/O requests early on once ALUA state
unavailable/standby occur, which prevents path checkers to actually
check if I/O still fails or now works.

Then I/O requests are blocked indefinitely due to queue_if_no_path
but the underlying individual paths are fully operational, and can
be verified as such otherways (e.g., SG_IO).

This patchset addresses that problem, and adds a few improvements
to the logging of PG state changes.

Patch 1 fixes the problem.
Patch 2 makes sure that state changes for all PGs are logged.
Patch 3 makes sure that state no-changes for PGs in unavailable/standby
        are not logged - only changes are.
Patch 4 adds few sdev_dbg() calls to track the path to alua_rtpg_work()

Tested on v4.12+ (commit b4b8cbf679c4).

Mauricio Faria de Oliveira (4):
  scsi: scsi_dh_alua: allow I/O in target port unavailable and standby
    states
  scsi: scsi_dh_alua: print changes to RTPG state of all PGs
  scsi: scsi_dh_alua: do not print RTPG state if it remains
    unavailable/standby
  scsi: scsi_dh_alua: add sdev_dbg() to track alua_rtpg_work()

 drivers/scsi/device_handler/scsi_dh_alua.c | 129 +++++++++++++++++++++++++----
 1 file changed, 113 insertions(+), 16 deletions(-)

-- 
1.8.3.1

[PATCH v2 1/4] scsi: scsi_dh_alua: allow I/O in target port unavailable and standby states

[Mauricio Faria de Oliveira]

According to SPC-4 (5.15.2.4.5 Unavailable state), the unavailable
state may (or may not) transition to other states (e.g., microcode
downloading or hardware error, which may be temporary or permanent).

But, scsi_dh_alua currently fails I/O requests early on once that
state occurs (in alua_prep_fn()) preventing path checkers in such
function path to actually check if I/O still fails or now works.

And that prevents a path activation (alua_activate()) which could
update the PG state if it eventually recovered to an active state,
thus resume I/O. (This is also the case with the standby state.)

This might cause device-mapper multipath to fail all paths to some
storage system that moves the controllers to the unavailable state
for firmware upgrades, and never recover regardless of the storage
system doing upgrades one controller at a time and get them online.

Then I/O requests are blocked indefinitely due to queue_if_no_path
but the underlying individual paths are fully operational, and can
be verified as such through other function paths (e.g., SG_IO):

    # multipath -l
    mpatha (360050764008100dac000000000000100) dm-0 IBM,2145
    size=40G features='2 queue_if_no_path retain_attached_hw_handler'
    hwhandler='1 alua' wp=rw
    |-+- policy='service-time 0' prio=0 status=enabled
    | |- 1:0:1:0 sdf 8:80  failed undef running
    | `- 2:0:1:0 sdn 8:208 failed undef running
    `-+- policy='service-time 0' prio=0 status=enabled
      |- 1:0:0:0 sdb 8:16  failed undef running
      `- 2:0:0:0 sdj 8:144 failed undef running

    # strace -e read \
        sg_dd blk_sgio=0 \
        if=/dev/sdj of=/dev/null bs=512 count=1 iflag=direct \
        2>&1 | grep 512
    read(3, 0x3fff7ba80000, 512) = -1 EIO (Input/output error)

    # strace -e ioctl \
        sg_dd blk_sgio=1 \
        if=/dev/sdj of=/dev/null bs=512 count=1 iflag=direct \
        2>&1 | grep 512
    ioctl(3, SG_IO, {'S', SG_DXFER_FROM_DEV, cmd[10]=[28, 00, 00, 00,
    00, 00, 00, 00, 01, 00], <...>) = 0

So, allow I/O to paths of PGs in unavailable/standby state, so path
checkers can actually check them.

Also, schedule a recheck when unavailable/standby state is detected
(in alua_check_sense()) to update pg->state, and quiet further SCSI
error messages (in alua_prep_fn()).

Once a path checker eventually detects a working/active state again,
the PG state is normally updated on path activation (alua_activate(),
as it schedules a recheck), thus I/O requests are no longer failed.

Signed-off-by: Mauricio Faria de Oliveira <mauricfo@linux.vnet.ibm.com>
Reported-by: Naresh Bannoth <nbannoth@in.ibm.com>

---
v2:
- also add support for standby state to alua_check_sense(), alua_prep_fn()
  (Bart Van Assche <Bart.VanAssche@sandisk.com>)

 drivers/scsi/device_handler/scsi_dh_alua.c | 25 +++++++++++++++++++++++++
 1 file changed, 25 insertions(+)

diff --git a/drivers/scsi/device_handler/scsi_dh_alua.c b/drivers/scsi/device_handler/scsi_dh_alua.c
index c01b47e5b55a..a1cf3d6aa853 100644
--- a/drivers/scsi/device_handler/scsi_dh_alua.c
+++ b/drivers/scsi/device_handler/scsi_dh_alua.c
@@ -431,6 +431,26 @@ static int alua_check_sense(struct scsi_device *sdev,
 			alua_check(sdev, false);
 			return NEEDS_RETRY;
 		}
+		if (sense_hdr->asc == 0x04 && sense_hdr->ascq == 0x0b) {
+			/*
+			 * LUN Not Accessible - target port in standby state.
+			 *
+			 * Do not retry, so failover to another target port occur.
+			 * Schedule a recheck to update state for other functions.
+			 */
+			alua_check(sdev, true);
+			return SUCCESS;
+		}
+		if (sense_hdr->asc == 0x04 && sense_hdr->ascq == 0x0c) {
+			/*
+			 * LUN Not Accessible - target port in unavailable state.
+			 *
+			 * Do not retry, so failover to another target port occur.
+			 * Schedule a recheck to update state for other functions.
+			 */
+			alua_check(sdev, true);
+			return SUCCESS;
+		}
 		break;
 	case UNIT_ATTENTION:
 		if (sense_hdr->asc == 0x29 && sense_hdr->ascq == 0x00) {
@@ -1057,6 +1077,8 @@ static void alua_check(struct scsi_device *sdev, bool force)
  *
  * Fail I/O to all paths not in state
  * active/optimized or active/non-optimized.
+ * Allow I/O to paths in state unavailable/standby
+ * so path checkers can actually check them.
  */
 static int alua_prep_fn(struct scsi_device *sdev, struct request *req)
 {
@@ -1072,6 +1094,9 @@ static int alua_prep_fn(struct scsi_device *sdev, struct request *req)
 	rcu_read_unlock();
 	if (state == SCSI_ACCESS_STATE_TRANSITIONING)
 		ret = BLKPREP_DEFER;
+	else if (state == SCSI_ACCESS_STATE_UNAVAILABLE ||
+		 state == SCSI_ACCESS_STATE_STANDBY)
+		req->rq_flags |= RQF_QUIET;
 	else if (state != SCSI_ACCESS_STATE_OPTIMAL &&
 		 state != SCSI_ACCESS_STATE_ACTIVE &&
 		 state != SCSI_ACCESS_STATE_LBA) {
-- 
1.8.3.1

Re: [PATCH v2 1/4] scsi: scsi_dh_alua: allow I/O in target port unavailable and standby states

[Hannes Reinecke]

On 07/11/2017 12:47 AM, Mauricio Faria de Oliveira wrote:
> According to SPC-4 (5.15.2.4.5 Unavailable state), the unavailable
> state may (or may not) transition to other states (e.g., microcode
> downloading or hardware error, which may be temporary or permanent).
> 
> But, scsi_dh_alua currently fails I/O requests early on once that
> state occurs (in alua_prep_fn()) preventing path checkers in such
> function path to actually check if I/O still fails or now works.
> 
> And that prevents a path activation (alua_activate()) which could
> update the PG state if it eventually recovered to an active state,
> thus resume I/O. (This is also the case with the standby state.)
> 
> This might cause device-mapper multipath to fail all paths to some
> storage system that moves the controllers to the unavailable state
> for firmware upgrades, and never recover regardless of the storage
> system doing upgrades one controller at a time and get them online.
> 
> Then I/O requests are blocked indefinitely due to queue_if_no_path
> but the underlying individual paths are fully operational, and can
> be verified as such through other function paths (e.g., SG_IO):
> 
>     # multipath -l
>     mpatha (360050764008100dac000000000000100) dm-0 IBM,2145
>     size=40G features='2 queue_if_no_path retain_attached_hw_handler'
>     hwhandler='1 alua' wp=rw
>     |-+- policy='service-time 0' prio=0 status=enabled
>     | |- 1:0:1:0 sdf 8:80  failed undef running
>     | `- 2:0:1:0 sdn 8:208 failed undef running
>     `-+- policy='service-time 0' prio=0 status=enabled
>       |- 1:0:0:0 sdb 8:16  failed undef running
>       `- 2:0:0:0 sdj 8:144 failed undef running
> 
>     # strace -e read \
>         sg_dd blk_sgio=0 \
>         if=/dev/sdj of=/dev/null bs=512 count=1 iflag=direct \
>         2>&1 | grep 512
>     read(3, 0x3fff7ba80000, 512) = -1 EIO (Input/output error)
> 
>     # strace -e ioctl \
>         sg_dd blk_sgio=1 \
>         if=/dev/sdj of=/dev/null bs=512 count=1 iflag=direct \
>         2>&1 | grep 512
>     ioctl(3, SG_IO, {'S', SG_DXFER_FROM_DEV, cmd[10]=[28, 00, 00, 00,
>     00, 00, 00, 00, 01, 00], <...>) = 0
> 
> So, allow I/O to paths of PGs in unavailable/standby state, so path
> checkers can actually check them.
> 
> Also, schedule a recheck when unavailable/standby state is detected
> (in alua_check_sense()) to update pg->state, and quiet further SCSI
> error messages (in alua_prep_fn()).
> 
> Once a path checker eventually detects a working/active state again,
> the PG state is normally updated on path activation (alua_activate(),
> as it schedules a recheck), thus I/O requests are no longer failed.
> 
> Signed-off-by: Mauricio Faria de Oliveira <mauricfo@linux.vnet.ibm.com>
> Reported-by: Naresh Bannoth <nbannoth@in.ibm.com>
> 
> ---
> v2:
> - also add support for standby state to alua_check_sense(), alua_prep_fn()
>   (Bart Van Assche <Bart.VanAssche@sandisk.com>)
> 
>  drivers/scsi/device_handler/scsi_dh_alua.c | 25 +++++++++++++++++++++++++
>  1 file changed, 25 insertions(+)
> 
> diff --git a/drivers/scsi/device_handler/scsi_dh_alua.c b/drivers/scsi/device_handler/scsi_dh_alua.c
> index c01b47e5b55a..a1cf3d6aa853 100644
> --- a/drivers/scsi/device_handler/scsi_dh_alua.c
> +++ b/drivers/scsi/device_handler/scsi_dh_alua.c
> @@ -431,6 +431,26 @@ static int alua_check_sense(struct scsi_device *sdev,
>  			alua_check(sdev, false);
>  			return NEEDS_RETRY;
>  		}
> +		if (sense_hdr->asc == 0x04 && sense_hdr->ascq == 0x0b) {
> +			/*
> +			 * LUN Not Accessible - target port in standby state.
> +			 *
> +			 * Do not retry, so failover to another target port occur.
> +			 * Schedule a recheck to update state for other functions.
> +			 */
> +			alua_check(sdev, true);
> +			return SUCCESS;
> +		}
> +		if (sense_hdr->asc == 0x04 && sense_hdr->ascq == 0x0c) {
> +			/*
> +			 * LUN Not Accessible - target port in unavailable state.
> +			 *
> +			 * Do not retry, so failover to another target port occur.
> +			 * Schedule a recheck to update state for other functions.
> +			 */
> +			alua_check(sdev, true);
> +			return SUCCESS;
> +		}
>  		break;
>  	case UNIT_ATTENTION:
>  		if (sense_hdr->asc == 0x29 && sense_hdr->ascq == 0x00) {
> @@ -1057,6 +1077,8 @@ static void alua_check(struct scsi_device *sdev, bool force)
>   *
>   * Fail I/O to all paths not in state
>   * active/optimized or active/non-optimized.
> + * Allow I/O to paths in state unavailable/standby
> + * so path checkers can actually check them.
>   */
>  static int alua_prep_fn(struct scsi_device *sdev, struct request *req)
>  {
> @@ -1072,6 +1094,9 @@ static int alua_prep_fn(struct scsi_device *sdev, struct request *req)
>  	rcu_read_unlock();
>  	if (state == SCSI_ACCESS_STATE_TRANSITIONING)
>  		ret = BLKPREP_DEFER;
> +	else if (state == SCSI_ACCESS_STATE_UNAVAILABLE ||
> +		 state == SCSI_ACCESS_STATE_STANDBY)
> +		req->rq_flags |= RQF_QUIET;
>  	else if (state != SCSI_ACCESS_STATE_OPTIMAL &&
>  		 state != SCSI_ACCESS_STATE_ACTIVE &&
>  		 state != SCSI_ACCESS_STATE_LBA) {
> 
NACK.

The whole _point_ of having device handlers is to _avoid_ I/O errors
during booting.

And the ALUA checker is prepared to handle this situation properly.
The directio checker of course doesn't know about this, but then no-one
expected the directio checker to work with ALUA.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		   Teamlead Storage & Networking
hare@suse.de			               +49 911 74053 688
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: F. Imendörffer, J. Smithard, J. Guild, D. Upmanyu, G. Norton
HRB 21284 (AG Nürnberg)

Re: [PATCH v2 1/4] scsi: scsi_dh_alua: allow I/O in target port unavailable and standby states

[Mauricio Faria de Oliveira]

On 07/11/2017 06:18 AM, Hannes Reinecke wrote:
> NACK.
> 
> The whole_point_  of having device handlers is to_avoid_  I/O errors
> during booting.
> 
> And the ALUA checker is prepared to handle this situation properly.
> The directio checker of course doesn't know about this, but then no-one
> expected the directio checker to work with ALUA.

I lacked that more holistic understanding. Thanks for explaining.

Now, for the sake of logging/debugging...

Any problem with patches 2 and 4?

Also, it seems the Unavailable/Standby states would not be logged
without a recheck from alua_check_sense(), since the only callers
of alua_rtpg_queue() are alua_activate() and alua_check[_sense]()
[the call from alua_check_vpd() is only in the initialization path].

Isn't there a point in scheduling a recheck once those conditions
are found in alua_check_sense() to get them logged? - since valid
path checkers won't go through that function.

(and it occurred to me that the state-change check of patch 3 can
be done there, simpler.)

cheers,

-- 
Mauricio Faria de Oliveira
IBM Linux Technology Center

Re: [PATCH v2 1/4] scsi: scsi_dh_alua: allow I/O in target port unavailable and standby states

[Mauricio Faria de Oliveira]

On 07/11/2017 12:32 PM, Mauricio Faria de Oliveira wrote:
> Also, it seems the Unavailable/Standby states would not be logged
> without a recheck from alua_check_sense(), since the only callers
> of alua_rtpg_queue() are alua_activate() and alua_check[_sense]()

Well, actually it does get logged if when activating/switching path
groups but shouldn't be the case with only a single path group.


-- 
Mauricio Faria de Oliveira
IBM Linux Technology Center

[PATCH v2 2/4] scsi: scsi_dh_alua: print changes to RTPG state of all PGs

[Mauricio Faria de Oliveira]

Currently, alua_rtpg() can change the 'state' and 'preferred'
values for the current port group _and_ of other port groups.

However, it reports that _only_ for the current port group.

This might cause uncertainty and confusion when going through
the kernel logs for analyzing/debugging scsi_dh_alua behavior,
which is not helpful during support and development scenarios.

So, print of such changes for all port groups, when it occurs.

It's possible to distinguish between the messages printed for
the current and other PGs by the 'supports' (supported states)
part, which is only printed for the current PG.

Signed-off-by: Mauricio Faria de Oliveira <mauricfo@linux.vnet.ibm.com>

---
v2:
- use lockdep_assert_held() instead of documenting locking conventions
  (Bart Van Assche <Bart.VanAssche@sandisk.com>)
- define two functions (with/without supported states information)
  (Bart Van Assche <Bart.VanAssche@sandisk.com>)
- simplify which device is used for printing the messages
  (use the evaluated scsi device and tell which PG the info is for)
- call the print functions from nearby places
  (right after modifying the PG data)

 drivers/scsi/device_handler/scsi_dh_alua.c | 63 +++++++++++++++++++++++-------
 1 file changed, 49 insertions(+), 14 deletions(-)

diff --git a/drivers/scsi/device_handler/scsi_dh_alua.c b/drivers/scsi/device_handler/scsi_dh_alua.c
index a1cf3d6aa853..937341ddb767 100644
--- a/drivers/scsi/device_handler/scsi_dh_alua.c
+++ b/drivers/scsi/device_handler/scsi_dh_alua.c
@@ -529,6 +529,49 @@ static int alua_tur(struct scsi_device *sdev)
 }
 
 /*
+ * alua_rtpg_print - Print REPORT TARGET GROUP STATES information
+ * 		     (without supported states)
+ * @sdev: the device evaluated (source of information).
+ * @pg: the port group associated with the information.
+ */
+static void alua_rtpg_print(struct scsi_device *sdev,
+			    struct alua_port_group *pg)
+{
+	lockdep_assert_held(&pg->lock);
+
+	sdev_printk(KERN_INFO, sdev,
+		    "%s: port group %02x state %c %s\n",
+		    ALUA_DH_NAME, pg->group_id, print_alua_state(pg->state),
+		    pg->pref ? "preferred" : "non-preferred");
+}
+
+/*
+ * alua_rtpg_print_supported - Print REPORT TARGET GROUP STATES information
+ * 			       (with supported states)
+ * @sdev: the device evaluated (source of information).
+ * @pg: the port group associated with the information.
+ * @supported_states: the supported states information.
+ */
+static void alua_rtpg_print_supported(struct scsi_device *sdev,
+				      struct alua_port_group *pg,
+				      int supported_states)
+{
+	lockdep_assert_held(&pg->lock);
+
+	sdev_printk(KERN_INFO, sdev,
+		    "%s: port group %02x state %c %s supports %c%c%c%c%c%c%c\n",
+		    ALUA_DH_NAME, pg->group_id, print_alua_state(pg->state),
+		    pg->pref ? "preferred" : "non-preferred",
+		    supported_states & TPGS_SUPPORT_TRANSITION    ? 'T' : 't',
+		    supported_states & TPGS_SUPPORT_OFFLINE       ? 'O' : 'o',
+		    supported_states & TPGS_SUPPORT_LBA_DEPENDENT ? 'L' : 'l',
+		    supported_states & TPGS_SUPPORT_UNAVAILABLE   ? 'U' : 'u',
+		    supported_states & TPGS_SUPPORT_STANDBY       ? 'S' : 's',
+		    supported_states & TPGS_SUPPORT_NONOPTIMIZED  ? 'N' : 'n',
+		    supported_states & TPGS_SUPPORT_OPTIMIZED     ? 'A' : 'a');
+}
+
+/*
  * alua_rtpg - Evaluate REPORT TARGET GROUP STATES
  * @sdev: the device to be evaluated.
  *
@@ -540,7 +583,7 @@ static int alua_rtpg(struct scsi_device *sdev, struct alua_port_group *pg)
 {
 	struct scsi_sense_hdr sense_hdr;
 	struct alua_port_group *tmp_pg;
-	int len, k, off, valid_states = 0, bufflen = ALUA_RTPG_SIZE;
+	int len, k, off, bufflen = ALUA_RTPG_SIZE;
 	unsigned char *desc, *buff;
 	unsigned err, retval;
 	unsigned int tpg_desc_tbl_off;
@@ -674,9 +717,12 @@ static int alua_rtpg(struct scsi_device *sdev, struct alua_port_group *pg)
 						h->sdev->access_state = desc[0];
 					}
 					rcu_read_unlock();
+
+					if (tmp_pg == pg)
+						alua_rtpg_print_supported(sdev, tmp_pg, desc[1]);
+					else
+						alua_rtpg_print(sdev, tmp_pg);
 				}
-				if (tmp_pg == pg)
-					valid_states = desc[1];
 				spin_unlock_irqrestore(&tmp_pg->lock, flags);
 			}
 			kref_put(&tmp_pg->kref, release_port_group);
@@ -685,17 +731,6 @@ static int alua_rtpg(struct scsi_device *sdev, struct alua_port_group *pg)
 	}
 
 	spin_lock_irqsave(&pg->lock, flags);
-	sdev_printk(KERN_INFO, sdev,
-		    "%s: port group %02x state %c %s supports %c%c%c%c%c%c%c\n",
-		    ALUA_DH_NAME, pg->group_id, print_alua_state(pg->state),
-		    pg->pref ? "preferred" : "non-preferred",
-		    valid_states&TPGS_SUPPORT_TRANSITION?'T':'t',
-		    valid_states&TPGS_SUPPORT_OFFLINE?'O':'o',
-		    valid_states&TPGS_SUPPORT_LBA_DEPENDENT?'L':'l',
-		    valid_states&TPGS_SUPPORT_UNAVAILABLE?'U':'u',
-		    valid_states&TPGS_SUPPORT_STANDBY?'S':'s',
-		    valid_states&TPGS_SUPPORT_NONOPTIMIZED?'N':'n',
-		    valid_states&TPGS_SUPPORT_OPTIMIZED?'A':'a');
 
 	switch (pg->state) {
 	case SCSI_ACCESS_STATE_TRANSITIONING:
-- 
1.8.3.1

[PATCH v2 3/4] scsi: scsi_dh_alua: do not print RTPG state if it remains unavailable/standby

[Mauricio Faria de Oliveira]

Path checkers will check paths of a port group in unavailable/standby
state more frequently (as they are 'failed') - possibly for a long or
indefinite period of time, and/or for a large number of paths.

That might flood the kernel log with scsi_dh_alua RTPG state messages,
due to the recheck scheduled in alua_check_sense() to update PG state.

So, do not to print such message if unavailable/standby state remains
(i.e., the PG did not transition to/from such states). All other cases
continue to be printed.

Signed-off-by: Mauricio Faria de Oliveira <mauricfo@linux.vnet.ibm.com>

---
v2:
- changed v1's alua_state_remains() into alua_rtpg_print_check(),
  which includes in the states (not) to print for (deduplicates code).
- added support for Standby state too (requested in patch 1 of this set)
  (Bart Van Assche <Bart.VanAssche@sandisk.com>)
- remove superfluous parentheses in return statement.
  (Bart Van Assche <Bart.VanAssche@sandisk.com>)
- remove likely() hint
  (Bart Van Assche <Bart.VanAssche@sandisk.com>)

 drivers/scsi/device_handler/scsi_dh_alua.c | 35 ++++++++++++++++++++++++++----
 1 file changed, 31 insertions(+), 4 deletions(-)

diff --git a/drivers/scsi/device_handler/scsi_dh_alua.c b/drivers/scsi/device_handler/scsi_dh_alua.c
index 937341ddb767..e0bf0827a980 100644
--- a/drivers/scsi/device_handler/scsi_dh_alua.c
+++ b/drivers/scsi/device_handler/scsi_dh_alua.c
@@ -572,6 +572,30 @@ static void alua_rtpg_print_supported(struct scsi_device *sdev,
 }
 
 /*
+ * alua_rtpg_print_check - Whether to print RTPG state information
+ * 			   on particular state transitions.
+ * @old_state: the old state value.
+ * @new_state: the new state value.
+ */
+static bool alua_rtpg_print_check(int old_state, int new_state)
+{
+	/*
+	 * Do not print RTPG state information in case
+	 * state remains either unavailable or standby.
+	 *
+	 * Print it for everything else.
+	 */
+
+	switch (old_state) {
+	case SCSI_ACCESS_STATE_UNAVAILABLE:
+	case SCSI_ACCESS_STATE_STANDBY:
+		return old_state != new_state;
+	default:
+		return 1;
+	}
+}
+
+/*
  * alua_rtpg - Evaluate REPORT TARGET GROUP STATES
  * @sdev: the device to be evaluated.
  *
@@ -706,6 +730,7 @@ static int alua_rtpg(struct scsi_device *sdev, struct alua_port_group *pg)
 				if ((tmp_pg == pg) ||
 				    !(tmp_pg->flags & ALUA_PG_RUNNING)) {
 					struct alua_dh_data *h;
+					int tmp_pg_state_orig = tmp_pg->state;
 
 					tmp_pg->state = desc[0] & 0x0f;
 					tmp_pg->pref = desc[0] >> 7;
@@ -718,10 +743,12 @@ static int alua_rtpg(struct scsi_device *sdev, struct alua_port_group *pg)
 					}
 					rcu_read_unlock();
 
-					if (tmp_pg == pg)
-						alua_rtpg_print_supported(sdev, tmp_pg, desc[1]);
-					else
-						alua_rtpg_print(sdev, tmp_pg);
+					if (alua_rtpg_print_check(tmp_pg_state_orig, tmp_pg->state)) {
+						if (tmp_pg == pg)
+							alua_rtpg_print_supported(sdev, tmp_pg, desc[1]);
+						else
+							alua_rtpg_print(sdev, tmp_pg);
+					}
 				}
 				spin_unlock_irqrestore(&tmp_pg->lock, flags);
 			}
-- 
1.8.3.1

Re: [PATCH v2 3/4] scsi: scsi_dh_alua: do not print RTPG state if it remains unavailable/standby

[kbuild test robot]

Hi Mauricio,

[auto build test WARNING on bvanassche/for-next]
[also build test WARNING on v4.12 next-20170711]
[cannot apply to mkp-scsi/for-next scsi/for-next]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Mauricio-Faria-de-Oliveira/scsi_dh_alua-fix-stuck-I-O-after-unavailable-standby-states/20170711-141350
base:   https://github.com/bvanassche/linux for-next


coccinelle warnings: (new ones prefixed by >>)

>> drivers/scsi/device_handler/scsi_dh_alua.c:594:9-10: WARNING: return of 0/1 in function 'alua_rtpg_print_check' with return type bool

Please review and possibly fold the followup patch.

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation

[PATCH] scsi: scsi_dh_alua: fix boolreturn.cocci warnings

[kbuild test robot]

drivers/scsi/device_handler/scsi_dh_alua.c:594:9-10: WARNING: return of 0/1 in function 'alua_rtpg_print_check' with return type bool

 Return statements in functions returning bool should use
 true/false instead of 1/0.
Generated by: scripts/coccinelle/misc/boolreturn.cocci

Fixes: cb809ba2fcbf ("scsi: scsi_dh_alua: do not print RTPG state if it remains unavailable/standby")
CC: Mauricio Faria de Oliveira <mauricfo@linux.vnet.ibm.com>
Signed-off-by: Fengguang Wu <fengguang.wu@intel.com>
---

 scsi_dh_alua.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

--- a/drivers/scsi/device_handler/scsi_dh_alua.c
+++ b/drivers/scsi/device_handler/scsi_dh_alua.c
@@ -591,7 +591,7 @@ static bool alua_rtpg_print_check(int ol
 	case SCSI_ACCESS_STATE_STANDBY:
 		return old_state != new_state;
 	default:
-		return 1;
+		return true;
 	}
 }
 

[PATCH v2 4/4] scsi: scsi_dh_alua: add sdev_dbg() to track alua_rtpg_work()

[Mauricio Faria de Oliveira]

Insert sdev_dbg() calls in the function path which may queue
alua_rtpg_work() past initialization, for debugging purposes:
- alua_activate()
- alua_check_sense()
- alua_rtpg_queue()

Signed-off-by: Mauricio Faria de Oliveira <mauricfo@linux.vnet.ibm.com>
---
 drivers/scsi/device_handler/scsi_dh_alua.c | 14 ++++++++++++--
 1 file changed, 12 insertions(+), 2 deletions(-)

diff --git a/drivers/scsi/device_handler/scsi_dh_alua.c b/drivers/scsi/device_handler/scsi_dh_alua.c
index e0bf0827a980..5bf0d55f6eb1 100644
--- a/drivers/scsi/device_handler/scsi_dh_alua.c
+++ b/drivers/scsi/device_handler/scsi_dh_alua.c
@@ -422,6 +422,10 @@ static char print_alua_state(unsigned char state)
 static int alua_check_sense(struct scsi_device *sdev,
 			    struct scsi_sense_hdr *sense_hdr)
 {
+	sdev_dbg(sdev, "%s: %s(): Sense Key: 0x%x, ASC: 0x%x, ASCQ: 0x%x\n",
+		 ALUA_DH_NAME, __func__, sense_hdr->sense_key,
+		 sense_hdr->asc, sense_hdr->ascq);
+
 	switch (sense_hdr->sense_key) {
 	case NOT_READY:
 		if (sense_hdr->asc == 0x04 && sense_hdr->ascq == 0x0a) {
@@ -987,10 +991,13 @@ static bool alua_rtpg_queue(struct alua_port_group *pg,
 	spin_unlock_irqrestore(&pg->lock, flags);
 
 	if (start_queue) {
+
 		if (queue_delayed_work(alua_wq, &pg->rtpg_work,
-				msecs_to_jiffies(ALUA_RTPG_DELAY_MSECS)))
+				msecs_to_jiffies(ALUA_RTPG_DELAY_MSECS))) {
+			sdev_dbg(sdev, "%s: %s(): port group %02x\n",
+				 ALUA_DH_NAME, __func__, pg->group_id);
 			sdev = NULL;
-		else
+		} else
 			kref_put(&pg->kref, release_port_group);
 	}
 	if (sdev)
@@ -1100,6 +1107,9 @@ static int alua_activate(struct scsi_device *sdev,
 	rcu_read_unlock();
 	mutex_unlock(&h->init_mutex);
 
+	sdev_dbg(sdev, "%s: %s(): port group %02x, fn: %pf()\n",
+		 ALUA_DH_NAME, __func__, pg->group_id, fn);
+
 	if (alua_rtpg_queue(pg, sdev, qdata, true))
 		fn = NULL;
 	else
-- 
1.8.3.1

Re: [PATCH v2 0/4] scsi_dh_alua: fix stuck I/O after unavailable/standby states

[Mauricio Faria de Oliveira]

On 07/10/2017 07:47 PM, Mauricio Faria de Oliveira wrote:
> This patchset addresses that problem, and adds a few improvements
> to the logging of PG state changes.

Here are some kernel log snippets with the patchset, if that helps.

The 2 port groups temporarily gone into unavailable state, and
recovered to active states later on, when I/O has been restored.

The devices, port groups, and relative port IDs:
2 LUNs, 2 targets per LUN, 2 hosts (8 paths total).

[  294.482107] scsi 4:0:0:0: alua: device 
naa.60050764008100dac000000000000104 port group 1 rel port 881
[  294.642063] scsi 4:0:0:1: alua: device 
naa.60050764008100dac000000000000105 port group 0 rel port 881
[  294.812140] scsi 4:0:1:0: alua: device 
naa.60050764008100dac000000000000104 port group 0 rel port 81
[  295.002027] scsi 4:0:1:1: alua: device 
naa.60050764008100dac000000000000105 port group 1 rel port 81
[  296.952092] scsi 5:0:0:0: alua: device 
naa.60050764008100dac000000000000104 port group 1 rel port 881
[  297.162043] scsi 5:0:0:1: alua: device 
naa.60050764008100dac000000000000105 port group 0 rel port 881
[  297.312130] scsi 5:0:1:0: alua: device 
naa.60050764008100dac000000000000104 port group 0 rel port 81
[  297.512006] scsi 5:0:1:1: alua: device 
naa.60050764008100dac000000000000105 port group 1 rel port 81

First, mpatha goes down:

mpatha (360050764008100dac000000000000104) dm-6 IBM     ,2145
size=40G features='1 queue_if_no_path' hwhandler='1 alua' wp=rw
|-+- policy='round-robin 0' prio=0 status=active
| |- 4:0:1:0 sde 8:64  active undef unknown
| `- 5:0:1:0 sdi 8:128 active undef unknown
`-+- policy='round-robin 0' prio=0 status=enabled
   |- 4:0:0:0 sdc 8:32  active undef unknown
   `- 5:0:0:0 sdg 8:96  active undef unknown

[258929.940734] device-mapper: multipath: Failing path 8:64.
[258929.940751] device-mapper: multipath: Failing path 8:128.

[258929.940777] sd 4:0:0:0: alua: alua_activate(): port group 01, fn: 
pg_init_done [dm_multipath]()
[258929.940784] sd 5:0:0:0: alua: alua_activate(): port group 01, fn: 
pg_init_done [dm_multipath]()

[258929.941575] sd 5:0:1:0: alua: alua_check_sense(): Sense Key: 0x2, 
ASC: 0x4, ASCQ: 0xc
[258929.941578] sd 5:0:1:0: [sdi] tag#1 FAILED Result: hostbyte=DID_OK 
driverbyte=DRIVER_SENSE
[258929.941874] sd 5:0:1:0: [sdi] tag#1 Sense Key : Not Ready [current]
[258929.941928] sd 5:0:1:0: [sdi] tag#1 Add. Sense: Logical unit not 
accessible, target port in unavailable state

[258929.942096] sd 4:0:1:0: alua: alua_check_sense(): Sense Key: 0x2, 
ASC: 0x4, ASCQ: 0xc
[258929.942104] sd 4:0:1:0: [sde] tag#2 FAILED Result: hostbyte=DID_OK 
driverbyte=DRIVER_SENSE
[258929.942300] sd 4:0:1:0: [sde] tag#2 Sense Key : Not Ready [current]
[258929.942354] sd 4:0:1:0: [sde] tag#2 Add. Sense: Logical unit not 
accessible, target port in unavailable state

[258929.956347] sd 4:0:1:0: alua: port group 00 state U non-preferred 
supports tolusna
[258929.956389] sd 4:0:1:0: alua: port group 01 state U non-preferred

[258930.036355] sd 5:0:0:0: alua: alua_check_sense(): Sense Key: 0x2, 
ASC: 0x4, ASCQ: 0xc
[258930.036360] sd 5:0:0:0: alua: alua_rtpg_queue(): port group 01
[258930.036365] device-mapper: multipath: Failing path 8:96.

[258930.036444] sd 4:0:0:0: alua: alua_check_sense(): Sense Key: 0x2, 
ASC: 0x4, ASCQ: 0xc
[258930.036506] device-mapper: multipath: Failing path 8:32.

Then, mpathb goes down:

mpathb (360050764008100dac000000000000105) dm-7 IBM     ,2145
size=40G features='1 queue_if_no_path' hwhandler='1 alua' wp=rw
|-+- policy='round-robin 0' prio=0 status=active
| |- 4:0:0:1 sdd 8:48  active undef unknown
| `- 5:0:0:1 sdh 8:112 active undef unknown
`-+- policy='round-robin 0' prio=0 status=enabled
   |- 4:0:1:1 sdf 8:80  active undef unknown
   `- 5:0:1:1 sdj 8:144 active undef unknown


[258930.162558] sd 4:0:0:1: alua: alua_check_sense(): Sense Key: 0x2, 
ASC: 0x4, ASCQ: 0xc
[258930.162568] sd 4:0:0:1: alua: alua_rtpg_queue(): port group 00

[258930.162572] sd 4:0:0:1: [sdd] tag#9 FAILED Result: hostbyte=DID_OK 
driverbyte=DRIVER_SENSE
[258930.162731] sd 4:0:0:1: [sdd] tag#9 Sense Key : Not Ready [current]
[258930.162762] sd 4:0:0:1: [sdd] tag#9 Add. Sense: Logical unit not 
accessible, target port in unavailable state
[258930.162860] device-mapper: multipath: Failing path 8:48.

[258930.162979] sd 5:0:0:1: [sdh] tag#1 FAILED Result: hostbyte=DID_OK 
driverbyte=DRIVER_SENSE
[258930.162980] sd 5:0:0:1: [sdh] tag#1 Sense Key : Not Ready [current]
[258930.162982] sd 5:0:0:1: [sdh] tag#1 Add. Sense: Logical unit not 
accessible, target port in unavailable state
[258930.162992] device-mapper: multipath: Failing path 8:112.

[258930.163025] sd 4:0:1:1: alua: alua_activate(): port group 01, fn: 
pg_init_done [dm_multipath]()
[258930.163029] sd 4:0:1:1: alua: alua_rtpg_queue(): port group 01
[258930.163048] sd 5:0:1:1: alua: alua_activate(): port group 01, fn: 
pg_init_done [dm_multipath]()

[258930.176323] sd 4:0:0:1: alua: port group 00 state U non-preferred 
supports tolusna
[258930.176325] sd 4:0:1:1: alua: port group 01 state U non-preferred 
supports tolusna

[258930.186390] device-mapper: multipath: Failing path 8:144.
[258930.186417] device-mapper: multipath: Failing path 8:80.


Later, mpathb comes back up.

[259299.514519] device-mapper: multipath: Reinstating path 8:48.
[259299.514776] sd 4:0:0:1: alua: alua_activate(): port group 00, fn: 
pg_init_done [dm_multipath]()
[259299.514781] sd 4:0:0:1: alua: alua_rtpg_queue(): port group 00

[259299.536115] sd 4:0:0:1: alua: port group 01 state N non-preferred
[259299.536243] sd 4:0:0:1: alua: port group 00 state A non-preferred 
supports tolusna

[259300.516079] device-mapper: multipath: Reinstating path 8:112.
[259300.516225] sd 5:0:0:1: alua: alua_activate(): port group 00, fn: 
pg_init_done [dm_multipath]()
[259300.516228] sd 5:0:0:1: alua: alua_rtpg_queue(): port group 00
[259300.536119] sd 5:0:0:1: alua: port group 01 state N non-preferred
[259300.536245] sd 5:0:0:1: alua: port group 00 state A non-preferred 
supports tolusna

[259301.516823] device-mapper: multipath: Reinstating path 8:80.
[259301.517727] device-mapper: multipath: Reinstating path 8:144.

And, mpatha comes back up:

[262860.847102] device-mapper: multipath: Reinstating path 8:32.
[262860.847357] sd 4:0:0:0: alua: alua_activate(): port group 01, fn: 
pg_init_done [dm_multipath]()
[262860.847363] sd 4:0:0:0: alua: alua_rtpg_queue(): port group 01

[262860.847717] device-mapper: multipath: Reinstating path 8:96.
[262860.864217] sd 4:0:0:0: alua: port group 00 state A non-preferred
[262860.864335] sd 4:0:0:0: alua: port group 01 state N non-preferred 
supports tolusna

[262860.864563] sd 5:0:0:0: alua: alua_activate(): port group 01, fn: 
pg_init_done [dm_multipath]()
[262860.884215] sd 4:0:0:0: alua: port group 00 state A non-preferred
[262860.884328] sd 4:0:0:0: alua: port group 01 state N non-preferred 
supports tolusna

[262861.848315] device-mapper: multipath: Reinstating path 8:64.
[262861.849003] device-mapper: multipath: Reinstating path 8:128.
[262862.270417] sd 4:0:1:0: alua: alua_activate(): port group 00, fn: 
pg_init_done [dm_multipath]()
[262862.270419] sd 4:0:1:0: alua: alua_rtpg_queue(): port group 00
[262862.270422] sd 5:0:1:0: alua: alua_activate(): port group 00, fn: 
pg_init_done [dm_multipath]()
[262862.284250] sd 4:0:1:0: alua: port group 00 state A non-preferred 
supports tolusna
[262862.284401] sd 4:0:1:0: alua: port group 01 state N non-preferred

cheers,

-- 
Mauricio Faria de Oliveira
IBM Linux Technology Center