[PATCH v2 1/1] scsi: ufs: core: fix device management cmd timeout flow

[PATCH v2 1/1] scsi: ufs: core: fix device management cmd timeout flow

[Mason Zhang]

From: Mason Zhang <Mason.Zhang@mediatek.com>

In ufs error handler flow, host will send device management cmd(NOP OUT)
to device for recovery link. If cmd response timeout, and clear doorbell
fail, ufshcd_wait_for_dev_cmd will do nothing and return,
hba->dev_cmd.complete struct not set to null.

In this time, if cmd has been responsed by device, then it will
call complete() in __ufshcd_transfer_req_compl, because of complete
struct is alloced in stack, then the KE will occur.

Fix the following crash:
  ipanic_die+0x24/0x38 [mrdump]
  die+0x344/0x748
  arm64_notify_die+0x44/0x104
  do_debug_exception+0x104/0x1e0
  el1_dbg+0x38/0x54
  el1_sync_handler+0x40/0x88
  el1_sync+0x8c/0x140
  queued_spin_lock_slowpath+0x2e4/0x3c0
  __ufshcd_transfer_req_compl+0x3b0/0x1164
  ufshcd_trc_handler+0x15c/0x308
  ufshcd_host_reset_and_restore+0x54/0x260
  ufshcd_reset_and_restore+0x28c/0x57c
  ufshcd_err_handler+0xeb8/0x1b6c
  process_one_work+0x288/0x964
  worker_thread+0x4bc/0xc7c
  kthread+0x15c/0x264
  ret_from_fork+0x10/0x30

Signed-off-by: Mason Zhang <Mason.Zhang@mediatek.com>
---
 drivers/ufs/core/ufshcd.c | 46 ++++++++++++++++++---------------------
 1 file changed, 21 insertions(+), 25 deletions(-)

diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c
index b1f59a5fe632..2b4934a562a6 100644
--- a/drivers/ufs/core/ufshcd.c
+++ b/drivers/ufs/core/ufshcd.c
@@ -2979,35 +2979,31 @@ static int ufshcd_wait_for_dev_cmd(struct ufs_hba *hba,
 		err = -ETIMEDOUT;
 		dev_dbg(hba->dev, "%s: dev_cmd request timedout, tag %d\n",
 			__func__, lrbp->task_tag);
-		if (ufshcd_clear_cmds(hba, 1U << lrbp->task_tag) == 0) {
+		if (ufshcd_clear_cmds(hba, 1U << lrbp->task_tag) == 0)
 			/* successfully cleared the command, retry if needed */
 			err = -EAGAIN;
+		/*
+		 * Since clearing the command succeeded we also need to
+		 * clear the task tag bit from the outstanding_reqs
+		 * variable.
+		 */
+		spin_lock_irqsave(&hba->outstanding_lock, flags);
+		pending = test_bit(lrbp->task_tag,
+				   &hba->outstanding_reqs);
+		if (pending) {
+			hba->dev_cmd.complete = NULL;
+			__clear_bit(lrbp->task_tag,
+				    &hba->outstanding_reqs);
+		}
+		spin_unlock_irqrestore(&hba->outstanding_lock, flags);
+
+		if (!pending) {
 			/*
-			 * Since clearing the command succeeded we also need to
-			 * clear the task tag bit from the outstanding_reqs
-			 * variable.
+			 * The completion handler ran while we tried to
+			 * clear the command.
 			 */
-			spin_lock_irqsave(&hba->outstanding_lock, flags);
-			pending = test_bit(lrbp->task_tag,
-					   &hba->outstanding_reqs);
-			if (pending) {
-				hba->dev_cmd.complete = NULL;
-				__clear_bit(lrbp->task_tag,
-					    &hba->outstanding_reqs);
-			}
-			spin_unlock_irqrestore(&hba->outstanding_lock, flags);
-
-			if (!pending) {
-				/*
-				 * The completion handler ran while we tried to
-				 * clear the command.
-				 */
-				time_left = 1;
-				goto retry;
-			}
-		} else {
-			dev_err(hba->dev, "%s: failed to clear tag %d\n",
-				__func__, lrbp->task_tag);
+			time_left = 1;
+			goto retry;
 		}
 	}
 
-- 
2.18.0

Re: [PATCH v2 1/1] scsi: ufs: core: fix device management cmd timeout flow

[Asutosh Das]

On Mon, Dec 05 2022 at 17:53 -0800, Mason Zhang wrote:
>From: Mason Zhang <Mason.Zhang@mediatek.com>
>
>In ufs error handler flow, host will send device management cmd(NOP OUT)
>to device for recovery link. If cmd response timeout, and clear doorbell
>fail, ufshcd_wait_for_dev_cmd will do nothing and return,
>hba->dev_cmd.complete struct not set to null.
>
>In this time, if cmd has been responsed by device, then it will
>call complete() in __ufshcd_transfer_req_compl, because of complete
>struct is alloced in stack, then the KE will occur.
>
What is KE?

>Fix the following crash:
>  ipanic_die+0x24/0x38 [mrdump]
>  die+0x344/0x748
>  arm64_notify_die+0x44/0x104
>  do_debug_exception+0x104/0x1e0
>  el1_dbg+0x38/0x54
>  el1_sync_handler+0x40/0x88
>  el1_sync+0x8c/0x140
>  queued_spin_lock_slowpath+0x2e4/0x3c0
>  __ufshcd_transfer_req_compl+0x3b0/0x1164
>  ufshcd_trc_handler+0x15c/0x308
>  ufshcd_host_reset_and_restore+0x54/0x260
>  ufshcd_reset_and_restore+0x28c/0x57c
>  ufshcd_err_handler+0xeb8/0x1b6c
>  process_one_work+0x288/0x964
>  worker_thread+0x4bc/0xc7c
>  kthread+0x15c/0x264
>  ret_from_fork+0x10/0x30
>
>Signed-off-by: Mason Zhang <Mason.Zhang@mediatek.com>
>---
> drivers/ufs/core/ufshcd.c | 46 ++++++++++++++++++---------------------
> 1 file changed, 21 insertions(+), 25 deletions(-)
>
>diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c
>index b1f59a5fe632..2b4934a562a6 100644
>--- a/drivers/ufs/core/ufshcd.c
>+++ b/drivers/ufs/core/ufshcd.c
>@@ -2979,35 +2979,31 @@ static int ufshcd_wait_for_dev_cmd(struct ufs_hba *hba,
> 		err = -ETIMEDOUT;
> 		dev_dbg(hba->dev, "%s: dev_cmd request timedout, tag %d\n",
> 			__func__, lrbp->task_tag);
>-		if (ufshcd_clear_cmds(hba, 1U << lrbp->task_tag) == 0) {
>+		if (ufshcd_clear_cmds(hba, 1U << lrbp->task_tag) == 0)
> 			/* successfully cleared the command, retry if needed */
> 			err = -EAGAIN;
>+		/*
>+		 * Since clearing the command succeeded we also need to
>+		 * clear the task tag bit from the outstanding_reqs
>+		 * variable.
>+		 */
Does this comment still hold true? Perhaps this needs to be updated?
Also, perhaps you missed Bart's comments in v1.
Also, please can you add a section for changes from v1 -> v2?

-asd

>+		spin_lock_irqsave(&hba->outstanding_lock, flags);
>+		pending = test_bit(lrbp->task_tag,
>+				   &hba->outstanding_reqs);
>+		if (pending) {
>+			hba->dev_cmd.complete = NULL;
>+			__clear_bit(lrbp->task_tag,
>+				    &hba->outstanding_reqs);
>+		}
>+		spin_unlock_irqrestore(&hba->outstanding_lock, flags);
>+
>+		if (!pending) {
> 			/*
>-			 * Since clearing the command succeeded we also need to
>-			 * clear the task tag bit from the outstanding_reqs
>-			 * variable.
>+			 * The completion handler ran while we tried to
>+			 * clear the command.
> 			 */
>-			spin_lock_irqsave(&hba->outstanding_lock, flags);
>-			pending = test_bit(lrbp->task_tag,
>-					   &hba->outstanding_reqs);
>-			if (pending) {
>-				hba->dev_cmd.complete = NULL;
>-				__clear_bit(lrbp->task_tag,
>-					    &hba->outstanding_reqs);
>-			}
>-			spin_unlock_irqrestore(&hba->outstanding_lock, flags);
>-
>-			if (!pending) {
>-				/*
>-				 * The completion handler ran while we tried to
>-				 * clear the command.
>-				 */
>-				time_left = 1;
>-				goto retry;
>-			}
>-		} else {
>-			dev_err(hba->dev, "%s: failed to clear tag %d\n",
>-				__func__, lrbp->task_tag);
>+			time_left = 1;
>+			goto retry;
> 		}
> 	}
>
>-- 
>2.18.0
>

Re: [PATCH v2 1/1] scsi: ufs: core: fix device management cmd timeout flow

[Mason Zhang (章辉)]

On Mon, 2022-12-05 at 11:50 -0800, Asutosh Das wrote:
> On Mon, Dec 05 2022 at 17:53 -0800, Mason Zhang wrote:
> > From: Mason Zhang <Mason.Zhang@mediatek.com>
> > 
> > In ufs error handler flow, host will send device management cmd(NOP
> > OUT)
> > to device for recovery link. If cmd response timeout, and clear
> > doorbell
> > fail, ufshcd_wait_for_dev_cmd will do nothing and return,
> > hba->dev_cmd.complete struct not set to null.
> > 
> > In this time, if cmd has been responsed by device, then it will
> > call complete() in __ufshcd_transfer_req_compl, because of complete
> > struct is alloced in stack, then the KE will occur.
> > 
> 
> What is KE?
> 
> > Fix the following crash:
> >  ipanic_die+0x24/0x38 [mrdump]
> >  die+0x344/0x748
> >  arm64_notify_die+0x44/0x104
> >  do_debug_exception+0x104/0x1e0
> >  el1_dbg+0x38/0x54
> >  el1_sync_handler+0x40/0x88
> >  el1_sync+0x8c/0x140
> >  queued_spin_lock_slowpath+0x2e4/0x3c0
> >  __ufshcd_transfer_req_compl+0x3b0/0x1164
> >  ufshcd_trc_handler+0x15c/0x308
> >  ufshcd_host_reset_and_restore+0x54/0x260
> >  ufshcd_reset_and_restore+0x28c/0x57c
> >  ufshcd_err_handler+0xeb8/0x1b6c
> >  process_one_work+0x288/0x964
> >  worker_thread+0x4bc/0xc7c
> >  kthread+0x15c/0x264
> >  ret_from_fork+0x10/0x30
> > 
> > Signed-off-by: Mason Zhang <Mason.Zhang@mediatek.com>
> > ---
> > drivers/ufs/core/ufshcd.c | 46 ++++++++++++++++++----------------
> > -----
> > 1 file changed, 21 insertions(+), 25 deletions(-)
> > 
> > diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c
> > index b1f59a5fe632..2b4934a562a6 100644
> > --- a/drivers/ufs/core/ufshcd.c
> > +++ b/drivers/ufs/core/ufshcd.c
> > @@ -2979,35 +2979,31 @@ static int ufshcd_wait_for_dev_cmd(struct
> > ufs_hba *hba,
> > 		err = -ETIMEDOUT;
> > 		dev_dbg(hba->dev, "%s: dev_cmd request timedout, tag
> > %d\n",
> > 			__func__, lrbp->task_tag);
> > -		if (ufshcd_clear_cmds(hba, 1U << lrbp->task_tag) == 0)
> > {
> > +		if (ufshcd_clear_cmds(hba, 1U << lrbp->task_tag) == 0)
> > 			/* successfully cleared the command, retry if
> > needed */
> > 			err = -EAGAIN;
> > +		/*
> > +		 * Since clearing the command succeeded we also need to
> > +		 * clear the task tag bit from the outstanding_reqs
> > +		 * variable.
> > +		 */
> 
> Does this comment still hold true? Perhaps this needs to be updated?
> Also, perhaps you missed Bart's comments in v1.
> Also, please can you add a section for changes from v1 -> v2?
> 
> -asd
> 
> > +		spin_lock_irqsave(&hba->outstanding_lock, flags);
> > +		pending = test_bit(lrbp->task_tag,
> > +				   &hba->outstanding_reqs);
> > +		if (pending) {
> > +			hba->dev_cmd.complete = NULL;
> > +			__clear_bit(lrbp->task_tag,
> > +				    &hba->outstanding_reqs);
> > +		}
> > +		spin_unlock_irqrestore(&hba->outstanding_lock, flags);
> > +
> > +		if (!pending) {
> > 			/*
> > -			 * Since clearing the command succeeded we also
> > need to
> > -			 * clear the task tag bit from the
> > outstanding_reqs
> > -			 * variable.
> > +			 * The completion handler ran while we tried to
> > +			 * clear the command.
> > 			 */
> > -			spin_lock_irqsave(&hba->outstanding_lock,
> > flags);
> > -			pending = test_bit(lrbp->task_tag,
> > -					   &hba->outstanding_reqs);
> > -			if (pending) {
> > -				hba->dev_cmd.complete = NULL;
> > -				__clear_bit(lrbp->task_tag,
> > -					    &hba->outstanding_reqs);
> > -			}
> > -			spin_unlock_irqrestore(&hba->outstanding_lock,
> > flags);
> > -
> > -			if (!pending) {
> > -				/*
> > -				 * The completion handler ran while we
> > tried to
> > -				 * clear the command.
> > -				 */
> > -				time_left = 1;
> > -				goto retry;
> > -			}
> > -		} else {
> > -			dev_err(hba->dev, "%s: failed to clear tag
> > %d\n",
> > -				__func__, lrbp->task_tag);
> > +			time_left = 1;
> > +			goto retry;
> > 		}
> > 	}
> > 
> > -- 
> > 2.18.0
> > 
Dear Asutosh and Bart:
	
	Thanks for yours comments~

	I think if clear db fail and then clear outstanding_reqs is not
a problem, because it means cmd is send to device but device not
responed, so host should do device reset and clear all outstanding_reqs
or return error and retry, it also will clear this outstanding_reqs.
	And because of we have do test_bit outstanding_reqs first in
spin_lock, so it also will not have race condition between cmd complete
flow.

	And about KE, KE means 'kernel exception', because of complete
stuct has been released in stack. 
	And I wil remove this comment in patchv3.

	Thank you again~

Thanks
Mason