[PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Hannes Reinecke]

The abort handler might be racing with command completion, so the
task might already be NULL by the time the abort handler is called.

Signed-off-by: Hannes Reinecke <hare@suse.com>
---
 drivers/scsi/libsas/sas_scsi_host.c | 22 +++++++++++++++++++---
 1 file changed, 19 insertions(+), 3 deletions(-)

diff --git a/drivers/scsi/libsas/sas_scsi_host.c b/drivers/scsi/libsas/sas_scsi_host.c
index 58476b7..08203fb 100644
--- a/drivers/scsi/libsas/sas_scsi_host.c
+++ b/drivers/scsi/libsas/sas_scsi_host.c
@@ -486,18 +486,34 @@ static int sas_queue_reset(struct domain_device *dev, int reset_type,
 
 int sas_eh_abort_handler(struct scsi_cmnd *cmd)
 {
-	int res;
-	struct sas_task *task = TO_SAS_TASK(cmd);
+	int res = TMF_RESP_FUNC_COMPLETE;
+	struct sas_task *task;
 	struct Scsi_Host *host = cmd->device->host;
 	struct sas_internal *i = to_sas_internal(host->transportt);
+	struct domain_device *dev = cmd_to_domain_dev(cmd);
+	struct sas_ha_struct *ha = dev->port->ha;
+	unsigned long flags;
 
 	if (!i->dft->lldd_abort_task)
 		return FAILED;
 
-	res = i->dft->lldd_abort_task(task);
+	/* Avoid sas_scsi_task_done() interfering */
+	spin_lock_irqsave(&dev->done_lock, flags);
+	task = TO_SAS_TASK(cmd);
+	if (test_bit(SAS_HA_FROZEN, &ha->state)) {
+		res = TMF_RESP_FUNC_FAILED;
+		task = NULL;
+	} else
+		ASSIGN_SAS_TASK(cmd, NULL);
+	spin_unlock_irqrestore(&dev->done_lock, flags);
+	if (task)
+		res = i->dft->lldd_abort_task(task);
 	if (res == TMF_RESP_FUNC_SUCC || res == TMF_RESP_FUNC_COMPLETE)
 		return SUCCESS;
 
+	spin_lock_irqsave(&dev->done_lock, flags);
+	ASSIGN_SAS_TASK(cmd, task);
+	spin_unlock_irqrestore(&dev->done_lock, flags);
 	return FAILED;
 }
 EXPORT_SYMBOL_GPL(sas_eh_abort_handler);
-- 
1.8.5.6

Re: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Yves-Alexis Perez]

[-- Attachment #1: Type: text/plain, Size: 477 bytes --]

On Mon, 2018-01-08 at 13:04 +0100, Hannes Reinecke wrote:
> The abort handler might be racing with command completion, so the
> task might already be NULL by the time the abort handler is called.

Hi,

I tried the patch on top of 4.15-rc7 (and without the revert of 90965761). I
don't have the NULL pointer deref anymore, but the box timeouts after SCSI
init. It's not completely dead, but I don't have any meaningful log from the
kernel.

Regards,
-- 
Yves-Alexis

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Jason Yan]

Hannes,

On 2018/1/8 20:04, Hannes Reinecke wrote:
> The abort handler might be racing with command completion, so the
> task might already be NULL by the time the abort handler is called.
>
> Signed-off-by: Hannes Reinecke <hare@suse.com>
> ---
>   drivers/scsi/libsas/sas_scsi_host.c | 22 +++++++++++++++++++---
>   1 file changed, 19 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/scsi/libsas/sas_scsi_host.c b/drivers/scsi/libsas/sas_scsi_host.c
> index 58476b7..08203fb 100644
> --- a/drivers/scsi/libsas/sas_scsi_host.c
> +++ b/drivers/scsi/libsas/sas_scsi_host.c
> @@ -486,18 +486,34 @@ static int sas_queue_reset(struct domain_device *dev, int reset_type,
>
>   int sas_eh_abort_handler(struct scsi_cmnd *cmd)
>   {
> -	int res;
> -	struct sas_task *task = TO_SAS_TASK(cmd);
> +	int res = TMF_RESP_FUNC_COMPLETE;
> +	struct sas_task *task;
>   	struct Scsi_Host *host = cmd->device->host;
>   	struct sas_internal *i = to_sas_internal(host->transportt);
> +	struct domain_device *dev = cmd_to_domain_dev(cmd);
> +	struct sas_ha_struct *ha = dev->port->ha;
> +	unsigned long flags;
>
>   	if (!i->dft->lldd_abort_task)
>   		return FAILED;
>
> -	res = i->dft->lldd_abort_task(task);
> +	/* Avoid sas_scsi_task_done() interfering */
> +	spin_lock_irqsave(&dev->done_lock, flags);
> +	task = TO_SAS_TASK(cmd);
> +	if (test_bit(SAS_HA_FROZEN, &ha->state)) {
> +		res = TMF_RESP_FUNC_FAILED;
> +		task = NULL;
> +	} else
> +		ASSIGN_SAS_TASK(cmd, NULL);
> +	spin_unlock_irqrestore(&dev->done_lock, flags);
> +	if (task)
> +		res = i->dft->lldd_abort_task(task);
>   	if (res == TMF_RESP_FUNC_SUCC || res == TMF_RESP_FUNC_COMPLETE)
>   		return SUCCESS;
>
> +	spin_lock_irqsave(&dev->done_lock, flags);
> +	ASSIGN_SAS_TASK(cmd, task);
> +	spin_unlock_irqrestore(&dev->done_lock, flags);

Why do you assign task back? As I remember, when this cmd dispatch
again, we will create a new task and assign to it again. So should we
end this task here?


>   	return FAILED;
>   }
>   EXPORT_SYMBOL_GPL(sas_eh_abort_handler);
>

Re: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Hannes Reinecke]

On 01/09/2018 05:09 AM, Jason Yan wrote:
> Hannes,
> 
> On 2018/1/8 20:04, Hannes Reinecke wrote:
>> The abort handler might be racing with command completion, so the
>> task might already be NULL by the time the abort handler is called.
>>
>> Signed-off-by: Hannes Reinecke <hare@suse.com>
>> ---
>>   drivers/scsi/libsas/sas_scsi_host.c | 22 +++++++++++++++++++---
>>   1 file changed, 19 insertions(+), 3 deletions(-)
>>
>> diff --git a/drivers/scsi/libsas/sas_scsi_host.c
>> b/drivers/scsi/libsas/sas_scsi_host.c
>> index 58476b7..08203fb 100644
>> --- a/drivers/scsi/libsas/sas_scsi_host.c
>> +++ b/drivers/scsi/libsas/sas_scsi_host.c
>> @@ -486,18 +486,34 @@ static int sas_queue_reset(struct domain_device
>> *dev, int reset_type,
>>
>>   int sas_eh_abort_handler(struct scsi_cmnd *cmd)
>>   {
>> -    int res;
>> -    struct sas_task *task = TO_SAS_TASK(cmd);
>> +    int res = TMF_RESP_FUNC_COMPLETE;
>> +    struct sas_task *task;
>>       struct Scsi_Host *host = cmd->device->host;
>>       struct sas_internal *i = to_sas_internal(host->transportt);
>> +    struct domain_device *dev = cmd_to_domain_dev(cmd);
>> +    struct sas_ha_struct *ha = dev->port->ha;
>> +    unsigned long flags;
>>
>>       if (!i->dft->lldd_abort_task)
>>           return FAILED;
>>
>> -    res = i->dft->lldd_abort_task(task);
>> +    /* Avoid sas_scsi_task_done() interfering */
>> +    spin_lock_irqsave(&dev->done_lock, flags);
>> +    task = TO_SAS_TASK(cmd);
>> +    if (test_bit(SAS_HA_FROZEN, &ha->state)) {
>> +        res = TMF_RESP_FUNC_FAILED;
>> +        task = NULL;
>> +    } else
>> +        ASSIGN_SAS_TASK(cmd, NULL);
>> +    spin_unlock_irqrestore(&dev->done_lock, flags);
>> +    if (task)
>> +        res = i->dft->lldd_abort_task(task);
>>       if (res == TMF_RESP_FUNC_SUCC || res == TMF_RESP_FUNC_COMPLETE)
>>           return SUCCESS;
>>
>> +    spin_lock_irqsave(&dev->done_lock, flags);
>> +    ASSIGN_SAS_TASK(cmd, task);
>> +    spin_unlock_irqrestore(&dev->done_lock, flags);
> 
> Why do you assign task back? As I remember, when this cmd dispatch
> again, we will create a new task and assign to it again. So should we
> end this task here?
> 
We only will create a new task if we decide to retry the command.
But if we return FAILED here the command is not retried but rather the
SCSI EH is invoked.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		   Teamlead Storage & Networking
hare@suse.com			               +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: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Jason Yan]

On 2018/1/9 15:34, Hannes Reinecke wrote:
> On 01/09/2018 05:09 AM, Jason Yan wrote:
>> Hannes,
>>
>> On 2018/1/8 20:04, Hannes Reinecke wrote:
>>> The abort handler might be racing with command completion, so the
>>> task might already be NULL by the time the abort handler is called.
>>>
>>> Signed-off-by: Hannes Reinecke <hare@suse.com>
>>> ---
>>>    drivers/scsi/libsas/sas_scsi_host.c | 22 +++++++++++++++++++---
>>>    1 file changed, 19 insertions(+), 3 deletions(-)
>>>
>>> diff --git a/drivers/scsi/libsas/sas_scsi_host.c
>>> b/drivers/scsi/libsas/sas_scsi_host.c
>>> index 58476b7..08203fb 100644
>>> --- a/drivers/scsi/libsas/sas_scsi_host.c
>>> +++ b/drivers/scsi/libsas/sas_scsi_host.c
>>> @@ -486,18 +486,34 @@ static int sas_queue_reset(struct domain_device
>>> *dev, int reset_type,
>>>
>>>    int sas_eh_abort_handler(struct scsi_cmnd *cmd)
>>>    {
>>> -    int res;
>>> -    struct sas_task *task = TO_SAS_TASK(cmd);
>>> +    int res = TMF_RESP_FUNC_COMPLETE;
>>> +    struct sas_task *task;
>>>        struct Scsi_Host *host = cmd->device->host;
>>>        struct sas_internal *i = to_sas_internal(host->transportt);
>>> +    struct domain_device *dev = cmd_to_domain_dev(cmd);
>>> +    struct sas_ha_struct *ha = dev->port->ha;
>>> +    unsigned long flags;
>>>
>>>        if (!i->dft->lldd_abort_task)
>>>            return FAILED;
>>>
>>> -    res = i->dft->lldd_abort_task(task);
>>> +    /* Avoid sas_scsi_task_done() interfering */
>>> +    spin_lock_irqsave(&dev->done_lock, flags);
>>> +    task = TO_SAS_TASK(cmd);
>>> +    if (test_bit(SAS_HA_FROZEN, &ha->state)) {
>>> +        res = TMF_RESP_FUNC_FAILED;
>>> +        task = NULL;
>>> +    } else
>>> +        ASSIGN_SAS_TASK(cmd, NULL);
>>> +    spin_unlock_irqrestore(&dev->done_lock, flags);
>>> +    if (task)
>>> +        res = i->dft->lldd_abort_task(task);
>>>        if (res == TMF_RESP_FUNC_SUCC || res == TMF_RESP_FUNC_COMPLETE)
>>>            return SUCCESS;
>>>
>>> +    spin_lock_irqsave(&dev->done_lock, flags);
>>> +    ASSIGN_SAS_TASK(cmd, task);
>>> +    spin_unlock_irqrestore(&dev->done_lock, flags);
>>
>> Why do you assign task back? As I remember, when this cmd dispatch
>> again, we will create a new task and assign to it again. So should we
>> end this task here?
>>
> We only will create a new task if we decide to retry the command.
> But if we return FAILED here the command is not retried but rather the
> SCSI EH is invoked.
>

I got it. The SCSI EH will handle this.

But when we return SUCCESS above, shall we free the task? I don't see
that LLDDs free it.

Jason

> Cheers,
>
> Hannes
>

Re: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Hannes Reinecke]

On 01/09/2018 10:04 AM, Jason Yan wrote:
> 
> On 2018/1/9 15:34, Hannes Reinecke wrote:
>> On 01/09/2018 05:09 AM, Jason Yan wrote:
>>> Hannes,
>>>
>>> On 2018/1/8 20:04, Hannes Reinecke wrote:
>>>> The abort handler might be racing with command completion, so the
>>>> task might already be NULL by the time the abort handler is called.
>>>>
>>>> Signed-off-by: Hannes Reinecke <hare@suse.com>
>>>> ---
>>>>    drivers/scsi/libsas/sas_scsi_host.c | 22 +++++++++++++++++++---
>>>>    1 file changed, 19 insertions(+), 3 deletions(-)
>>>>
>>>> diff --git a/drivers/scsi/libsas/sas_scsi_host.c
>>>> b/drivers/scsi/libsas/sas_scsi_host.c
>>>> index 58476b7..08203fb 100644
>>>> --- a/drivers/scsi/libsas/sas_scsi_host.c
>>>> +++ b/drivers/scsi/libsas/sas_scsi_host.c
>>>> @@ -486,18 +486,34 @@ static int sas_queue_reset(struct domain_device
>>>> *dev, int reset_type,
>>>>
>>>>    int sas_eh_abort_handler(struct scsi_cmnd *cmd)
>>>>    {
>>>> -    int res;
>>>> -    struct sas_task *task = TO_SAS_TASK(cmd);
>>>> +    int res = TMF_RESP_FUNC_COMPLETE;
>>>> +    struct sas_task *task;
>>>>        struct Scsi_Host *host = cmd->device->host;
>>>>        struct sas_internal *i = to_sas_internal(host->transportt);
>>>> +    struct domain_device *dev = cmd_to_domain_dev(cmd);
>>>> +    struct sas_ha_struct *ha = dev->port->ha;
>>>> +    unsigned long flags;
>>>>
>>>>        if (!i->dft->lldd_abort_task)
>>>>            return FAILED;
>>>>
>>>> -    res = i->dft->lldd_abort_task(task);
>>>> +    /* Avoid sas_scsi_task_done() interfering */
>>>> +    spin_lock_irqsave(&dev->done_lock, flags);
>>>> +    task = TO_SAS_TASK(cmd);
>>>> +    if (test_bit(SAS_HA_FROZEN, &ha->state)) {
>>>> +        res = TMF_RESP_FUNC_FAILED;
>>>> +        task = NULL;
>>>> +    } else
>>>> +        ASSIGN_SAS_TASK(cmd, NULL);
>>>> +    spin_unlock_irqrestore(&dev->done_lock, flags);
>>>> +    if (task)
>>>> +        res = i->dft->lldd_abort_task(task);
>>>>        if (res == TMF_RESP_FUNC_SUCC || res == TMF_RESP_FUNC_COMPLETE)
>>>>            return SUCCESS;
>>>>
>>>> +    spin_lock_irqsave(&dev->done_lock, flags);
>>>> +    ASSIGN_SAS_TASK(cmd, task);
>>>> +    spin_unlock_irqrestore(&dev->done_lock, flags);
>>>
>>> Why do you assign task back? As I remember, when this cmd dispatch
>>> again, we will create a new task and assign to it again. So should we
>>> end this task here?
>>>
>> We only will create a new task if we decide to retry the command.
>> But if we return FAILED here the command is not retried but rather the
>> SCSI EH is invoked.
>>
> 
> I got it. The SCSI EH will handle this.
> 
> But when we return SUCCESS above, shall we free the task? I don't see
> that LLDDs free it.
> 
Hmm. Possibly.
I'll check.

Cheers,

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

Re: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Hannes Reinecke]

On 01/08/2018 06:11 PM, Yves-Alexis Perez wrote:
> On Mon, 2018-01-08 at 13:04 +0100, Hannes Reinecke wrote:
>> The abort handler might be racing with command completion, so the
>> task might already be NULL by the time the abort handler is called.
> 
> Hi,
> 
> I tried the patch on top of 4.15-rc7 (and without the revert of 90965761). I
> don't have the NULL pointer deref anymore, but the box timeouts after SCSI
> init. It's not completely dead, but I don't have any meaningful log from the
> kernel.
> 
Can you try to boot the stock 4.15 kernel (without any patches) with
scsi_mod.scsi_logging_level=9411
on the kernel commandline and send me tha output?
I really would like to see which command fails.
THX.

Cheers,

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

Re: [PATCHv2] libsas: Check for completed commands before calling lldd_abort_task()

[Yves-Alexis Perez]

[-- Attachment #1: Type: text/plain, Size: 4350 bytes --]

On Tue, 2018-01-09 at 10:30 +0100, Hannes Reinecke wrote:
> Can you try to boot the stock 4.15 kernel (without any patches) with
> scsi_mod.scsi_logging_level=9411
> on the kernel commandline and send me tha output?
> I really would like to see which command fails.
> THX.

Here it is:

[  204.960508] sd 0:0:1:0: [sdb] tag#0 Send: scmd 0x000000006f2d047e
[  204.960510] sd 0:0:0:0: [sda] tag#1 Send: scmd 0x000000009840a325
[  204.960511] sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 05 00 fe 00 00 00 00 00 00 40 ef 00
[  204.960512] sd 0:0:0:0: [sda] tag#1 CDB: ATA command pass through(16) 85 06 20 00 05 00 fe 00 00 00 00 00 00 40 ef 00
[  204.960583] sd 0:0:1:0: [sdb] tag#0 Done: TIMEOUT_ERROR Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  204.960586] sd 0:0:1:0: [sdb] tag#0 CDB: ATA command pass through(16) 85 06 20 00 05 00 fe 00 00 00 00 00 00 40 ef 00
[  204.983681] BUG: unable to handle kernel NULL pointer dereference at           (null)
[  204.983690] IP: isci_task_abort_task+0x30/0x4b0 [isci]
[  204.983691] PGD 0 P4D 0 
[  204.983693] Oops: 0000 [#1] SMP PTI
[  204.983695] Modules linked in: snd_hwdep(+) snd_hda_core snd_pcm_oss snd_mixer_oss iTCO_wdt snd_pcm iTCO_vendor_support mei_me snd_timer snd lpc_ich shpchp sg mei joydev evdev mfd_core soundcore dcdbas serio_raw intel_rapl_perf(+) iptable_filter(+) nls_cp437 nls_utf8 vfat fat coretemp dell_smm_hwmon parport_pc ppdev lp parport ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto algif_skcipher af_alg dm_crypt dm_mod tpm_rng rng_core uhci_hcd pcrypt sr_mod cdrom sd_mod hid_lenovo usbhid hid nouveau crct10dif_pclmul crc32_pclmul video isci crc32c_intel mxm_wmi ahci xhci_pci libsas ehci_pci ghash_clmulni_intel wmi libahci scsi_transport_sas xhci_hcd ehci_hcd i2c_algo_bit pcbc drm_kms_helper libata e1000e ttm aesni_intel aes_x86_64 crypto_simd cryptd psmouse ptp glue_helper i2c_i801 usbcore scsi_mod
[  204.983738]  pps_core drm button
[  204.983741] CPU: 11 PID: 262 Comm: kworker/u64:5 Not tainted 4.15.0-rc7 #2
[  204.983742] Hardware name: Dell Inc. Precision T5600/0Y56T3, BIOS A09 05/03/2013
[  204.983750] Workqueue: scsi_tmf_0 scmd_eh_abort_handler [scsi_mod]
[  204.983755] RIP: 0010:isci_task_abort_task+0x30/0x4b0 [isci]
[  204.983756] RSP: 0018:ffffb0504152fcd8 EFLAGS: 00010246
[  204.983757] RAX: 0000000000000000 RBX: ffff8a8f842d79a8 RCX: 00000000ffffffff
[  204.983758] RDX: ffff8a8f80f7f800 RSI: 0000000000000000 RDI: 0000000000000000
[  204.983759] RBP: ffff8a8f842d7948 R08: ffff8a8f870e1f60 R09: 0000000000000000
[  204.983759] R10: 0000000000000000 R11: 0000000000000f27 R12: 0000000000000008
[  204.983760] R13: 0000000000000000 R14: ffff8a8f80b51540 R15: 0000000000000000
[  204.983761] FS:  0000000000000000(0000) GS:ffff8a8f870c0000(0000) knlGS:0000000000000000
[  204.983774] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  204.983775] CR2: 0000000000000000 CR3: 0000000200a0a005 CR4: 00000000000606e0
[  204.983775] Call Trace:
[  204.983781]  ? sched_clock+0x5/0x10
[  204.983784]  ? sched_clock_cpu+0xc/0xb0
[  204.983787]  ? sched_clock+0x5/0x10
[  204.983788]  ? sched_clock+0x5/0x10
[  204.983790]  ? sched_clock_cpu+0xc/0xb0
[  204.983791]  ? pick_next_task_fair+0x4de/0x5f0
[  204.983794]  ? __switch_to+0xa2/0x450
[  204.983795]  ? put_prev_entity+0x1e/0xe0
[  204.983799]  sas_eh_abort_handler+0x2f/0x50 [libsas]
[  204.983805]  scmd_eh_abort_handler+0x56/0x210 [scsi_mod]
[  204.983809]  process_one_work+0x188/0x380
[  204.983811]  worker_thread+0x2e/0x390
[  204.983812]  ? process_one_work+0x380/0x380
[  204.983814]  kthread+0x111/0x130
[  204.983815]  ? kthread_create_worker_on_cpu+0x70/0x70
[  204.983819]  ret_from_fork+0x1f/0x30
[  204.983820] Code: 41 57 41 56 49 89 ff 41 55 41 54 4d 8d 67 08 55 53 48 81 ec 68 01 00 00 65 48 8b 04 25 28 00 00 00 48 89 84 24 60 01 00 00 31 c0 <48> 8b 07 c7 44 24 08 00 00 00 00 c7 44 24 10 00 00 00 00 48 8b 
[  204.983843] RIP: isci_task_abort_task+0x30/0x4b0 [isci] RSP: ffffb0504152fcd8
[  204.983843] CR2: 0000000000000000
[  204.983845] ---[ end trace c55806a9bed49dc4 ]---

I have the full log from boot (2.2M) but I'm unsure how much private data
appears in it so I'd rather not send it to a mailing list. If you need it I'll
send it privately.

Regards,
-- 
Yves-Alexis

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 488 bytes --]