* [PATCH v4 0/2] UFS bug fixes @ 2021-01-07 7:47 Jaegeuk Kim 2021-01-07 7:47 ` [PATCH v4 1/2] scsi: ufs: fix livelock of ufshcd_clear_ua_wluns Jaegeuk Kim 2021-01-07 7:47 ` [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd Jaegeuk Kim 0 siblings, 2 replies; 11+ messages in thread From: Jaegeuk Kim @ 2021-01-07 7:47 UTC (permalink / raw) To: linux-kernel, linux-scsi, kernel-team Cc: cang, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu Change log from v3: - move ufshcd_clear_ua_wluns() after ufshcd_scsi_add_wlus() - remove BLK_MQ_REQ_RESERVED for tm tag - move IO wait to cover all the non-fatal errors ^ permalink raw reply [flat|nested] 11+ messages in thread
* [PATCH v4 1/2] scsi: ufs: fix livelock of ufshcd_clear_ua_wluns 2021-01-07 7:47 [PATCH v4 0/2] UFS bug fixes Jaegeuk Kim @ 2021-01-07 7:47 ` Jaegeuk Kim 2021-01-07 7:58 ` Can Guo 2021-01-07 7:47 ` [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd Jaegeuk Kim 1 sibling, 1 reply; 11+ messages in thread From: Jaegeuk Kim @ 2021-01-07 7:47 UTC (permalink / raw) To: linux-kernel, linux-scsi, kernel-team Cc: cang, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu, Jaegeuk Kim When gate_work/ungate_work gets an error during hibern8_enter or exit, ufshcd_err_handler() ufshcd_scsi_block_requests() ufshcd_reset_and_restore() ufshcd_clear_ua_wluns() -> stuck ufshcd_scsi_unblock_requests() In order to avoid it, ufshcd_clear_ua_wluns() can be called per recovery flows such as suspend/resume, link_recovery, and error_handler. Fixes: 1918651f2d7e ("scsi: ufs: Clear UAC for RPMB after ufshcd resets") Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> --- drivers/scsi/ufs/ufshcd.c | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c index bedb822a40a3..e6e7bdf99cd7 100644 --- a/drivers/scsi/ufs/ufshcd.c +++ b/drivers/scsi/ufs/ufshcd.c @@ -3996,6 +3996,8 @@ int ufshcd_link_recovery(struct ufs_hba *hba) if (ret) dev_err(hba->dev, "%s: link recovery failed, err %d", __func__, ret); + else + ufshcd_clear_ua_wluns(hba); return ret; } @@ -6003,6 +6005,9 @@ static void ufshcd_err_handler(struct work_struct *work) ufshcd_scsi_unblock_requests(hba); ufshcd_err_handling_unprepare(hba); up(&hba->eh_sem); + + if (!err && needs_reset) + ufshcd_clear_ua_wluns(hba); } /** @@ -6940,14 +6945,11 @@ static int ufshcd_host_reset_and_restore(struct ufs_hba *hba) ufshcd_set_clk_freq(hba, true); err = ufshcd_hba_enable(hba); - if (err) - goto out; /* Establish the link again and restore the device */ - err = ufshcd_probe_hba(hba, false); if (!err) - ufshcd_clear_ua_wluns(hba); -out: + err = ufshcd_probe_hba(hba, false); + if (err) dev_err(hba->dev, "%s: Host init failed %d\n", __func__, err); ufshcd_update_evt_hist(hba, UFS_EVT_HOST_RESET, (u32)err); @@ -7718,6 +7720,8 @@ static int ufshcd_add_lus(struct ufs_hba *hba) if (ret) goto out; + ufshcd_clear_ua_wluns(hba); + /* Initialize devfreq after UFS device is detected */ if (ufshcd_is_clkscaling_supported(hba)) { memcpy(&hba->clk_scaling.saved_pwr_info.info, @@ -7919,8 +7923,6 @@ static void ufshcd_async_scan(void *data, async_cookie_t cookie) pm_runtime_put_sync(hba->dev); ufshcd_exit_clk_scaling(hba); ufshcd_hba_exit(hba); - } else { - ufshcd_clear_ua_wluns(hba); } } @@ -8777,6 +8779,7 @@ static int ufshcd_suspend(struct ufs_hba *hba, enum ufs_pm_op pm_op) ufshcd_resume_clkscaling(hba); hba->clk_gating.is_suspended = false; hba->dev_info.b_rpm_dev_flush_capable = false; + ufshcd_clear_ua_wluns(hba); ufshcd_release(hba); out: if (hba->dev_info.b_rpm_dev_flush_capable) { @@ -8887,6 +8890,8 @@ static int ufshcd_resume(struct ufs_hba *hba, enum ufs_pm_op pm_op) cancel_delayed_work(&hba->rpm_dev_flush_recheck_work); } + ufshcd_clear_ua_wluns(hba); + /* Schedule clock gating in case of no access to UFS device yet */ ufshcd_release(hba); -- 2.29.2.729.g45daf8777d-goog ^ permalink raw reply related [flat|nested] 11+ messages in thread
* Re: [PATCH v4 1/2] scsi: ufs: fix livelock of ufshcd_clear_ua_wluns 2021-01-07 7:47 ` [PATCH v4 1/2] scsi: ufs: fix livelock of ufshcd_clear_ua_wluns Jaegeuk Kim @ 2021-01-07 7:58 ` Can Guo 0 siblings, 0 replies; 11+ messages in thread From: Can Guo @ 2021-01-07 7:58 UTC (permalink / raw) To: Jaegeuk Kim Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu On 2021-01-07 15:47, Jaegeuk Kim wrote: > When gate_work/ungate_work gets an error during hibern8_enter or exit, > ufshcd_err_handler() > ufshcd_scsi_block_requests() > ufshcd_reset_and_restore() > ufshcd_clear_ua_wluns() -> stuck > ufshcd_scsi_unblock_requests() > > In order to avoid it, ufshcd_clear_ua_wluns() can be called per > recovery flows > such as suspend/resume, link_recovery, and error_handler. > > Fixes: 1918651f2d7e ("scsi: ufs: Clear UAC for RPMB after ufshcd > resets") > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> > --- > drivers/scsi/ufs/ufshcd.c | 19 ++++++++++++------- > 1 file changed, 12 insertions(+), 7 deletions(-) > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c > index bedb822a40a3..e6e7bdf99cd7 100644 > --- a/drivers/scsi/ufs/ufshcd.c > +++ b/drivers/scsi/ufs/ufshcd.c > @@ -3996,6 +3996,8 @@ int ufshcd_link_recovery(struct ufs_hba *hba) > if (ret) > dev_err(hba->dev, "%s: link recovery failed, err %d", > __func__, ret); > + else > + ufshcd_clear_ua_wluns(hba); > > return ret; > } > @@ -6003,6 +6005,9 @@ static void ufshcd_err_handler(struct work_struct > *work) > ufshcd_scsi_unblock_requests(hba); > ufshcd_err_handling_unprepare(hba); > up(&hba->eh_sem); > + > + if (!err && needs_reset) > + ufshcd_clear_ua_wluns(hba); > } > > /** > @@ -6940,14 +6945,11 @@ static int > ufshcd_host_reset_and_restore(struct ufs_hba *hba) > ufshcd_set_clk_freq(hba, true); > > err = ufshcd_hba_enable(hba); > - if (err) > - goto out; > > /* Establish the link again and restore the device */ > - err = ufshcd_probe_hba(hba, false); > if (!err) > - ufshcd_clear_ua_wluns(hba); > -out: > + err = ufshcd_probe_hba(hba, false); > + > if (err) > dev_err(hba->dev, "%s: Host init failed %d\n", __func__, err); > ufshcd_update_evt_hist(hba, UFS_EVT_HOST_RESET, (u32)err); > @@ -7718,6 +7720,8 @@ static int ufshcd_add_lus(struct ufs_hba *hba) > if (ret) > goto out; > > + ufshcd_clear_ua_wluns(hba); > + > /* Initialize devfreq after UFS device is detected */ > if (ufshcd_is_clkscaling_supported(hba)) { > memcpy(&hba->clk_scaling.saved_pwr_info.info, > @@ -7919,8 +7923,6 @@ static void ufshcd_async_scan(void *data, > async_cookie_t cookie) > pm_runtime_put_sync(hba->dev); > ufshcd_exit_clk_scaling(hba); > ufshcd_hba_exit(hba); > - } else { > - ufshcd_clear_ua_wluns(hba); > } > } > > @@ -8777,6 +8779,7 @@ static int ufshcd_suspend(struct ufs_hba *hba, > enum ufs_pm_op pm_op) > ufshcd_resume_clkscaling(hba); > hba->clk_gating.is_suspended = false; > hba->dev_info.b_rpm_dev_flush_capable = false; > + ufshcd_clear_ua_wluns(hba); > ufshcd_release(hba); > out: > if (hba->dev_info.b_rpm_dev_flush_capable) { > @@ -8887,6 +8890,8 @@ static int ufshcd_resume(struct ufs_hba *hba, > enum ufs_pm_op pm_op) > cancel_delayed_work(&hba->rpm_dev_flush_recheck_work); > } > > + ufshcd_clear_ua_wluns(hba); > + > /* Schedule clock gating in case of no access to UFS device yet */ > ufshcd_release(hba); Reviewed-by: Can Guo <cang@codeaurora.org> ^ permalink raw reply [flat|nested] 11+ messages in thread
* [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 7:47 [PATCH v4 0/2] UFS bug fixes Jaegeuk Kim 2021-01-07 7:47 ` [PATCH v4 1/2] scsi: ufs: fix livelock of ufshcd_clear_ua_wluns Jaegeuk Kim @ 2021-01-07 7:47 ` Jaegeuk Kim 2021-01-07 8:02 ` Can Guo 1 sibling, 1 reply; 11+ messages in thread From: Jaegeuk Kim @ 2021-01-07 7:47 UTC (permalink / raw) To: linux-kernel, linux-scsi, kernel-team Cc: cang, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu, Jaegeuk Kim, Jaegeuk Kim From: Jaegeuk Kim <jaegeuk@google.com> This fixes a warning caused by wrong reserve tag usage in __ufshcd_issue_tm_cmd. WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 blk_mq_get_tag+0x438/0x46c And, in ufshcd_err_handler(), we can avoid to send tm_cmd before aborting outstanding commands by waiting a bit for IO completion like this. __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to allocate and free TMFs") Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err handler") Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> --- drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- 1 file changed, 31 insertions(+), 4 deletions(-) diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c index e6e7bdf99cd7..340dd5e515dd 100644 --- a/drivers/scsi/ufs/ufshcd.c +++ b/drivers/scsi/ufs/ufshcd.c @@ -44,6 +44,9 @@ /* Query request timeout */ #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ +/* LINERESET TIME OUT */ +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ + /* Task management command timeout */ #define TM_CMD_TIMEOUT 100 /* msecs */ @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct *work) int err = 0, pmc_err; int tag; bool needs_reset = false, needs_restore = false; + ktime_t start; hba = container_of(work, struct ufs_hba, eh_work); @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct *work) } hba->silence_err_logs = true; + + /* Wait for IO completion for non-fatal errors to avoid aborting IOs */ + start = ktime_get(); + while (hba->outstanding_reqs) { + ufshcd_complete_requests(hba); + spin_unlock_irqrestore(hba->host->host_lock, flags); + schedule(); + spin_lock_irqsave(hba->host->host_lock, flags); + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > + LINERESET_IO_TIMEOUT_MS) { + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", + __func__, hba->outstanding_reqs); + break; + } + } + /* release lock as clear command might sleep */ spin_unlock_irqrestore(hba->host->host_lock, flags); /* Clear pending transfer requests */ @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void *__hba) intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); } - if (enabled_intr_status && retval == IRQ_NONE) { - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", - __func__, intr_status); + if (enabled_intr_status && retval == IRQ_NONE && + !ufshcd_eh_in_progress(hba)) { + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, 0x%08x)\n", + __func__, + intr_status, + hba->ufs_stats.last_intr_status, + enabled_intr_status); ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); } @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba *hba, * Even though we use wait_event() which sleeps indefinitely, * the maximum wait time is bounded by %TM_CMD_TIMEOUT. */ - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); + if (IS_ERR(req)) + return PTR_ERR(req); + req->end_io_data = &wait; free_slot = req->tag; WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); -- 2.29.2.729.g45daf8777d-goog ^ permalink raw reply related [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 7:47 ` [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd Jaegeuk Kim @ 2021-01-07 8:02 ` Can Guo 2021-01-07 8:07 ` Jaegeuk Kim 0 siblings, 1 reply; 11+ messages in thread From: Can Guo @ 2021-01-07 8:02 UTC (permalink / raw) To: Jaegeuk Kim Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu, Jaegeuk Kim On 2021-01-07 15:47, Jaegeuk Kim wrote: > From: Jaegeuk Kim <jaegeuk@google.com> > > This fixes a warning caused by wrong reserve tag usage in > __ufshcd_issue_tm_cmd. > > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 > blk_get_request+0x68/0x70 > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 > blk_mq_get_tag+0x438/0x46c > > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before > aborting > outstanding commands by waiting a bit for IO completion like this. > > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out > > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to > allocate and free TMFs") > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err > handler") Hi Jaegeuk, Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O reqs is a general procedure for handling all non-fatal errors. Thanks, Can Guo. > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> > --- > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- > 1 file changed, 31 insertions(+), 4 deletions(-) > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c > index e6e7bdf99cd7..340dd5e515dd 100644 > --- a/drivers/scsi/ufs/ufshcd.c > +++ b/drivers/scsi/ufs/ufshcd.c > @@ -44,6 +44,9 @@ > /* Query request timeout */ > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ > > +/* LINERESET TIME OUT */ > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ > + > /* Task management command timeout */ > #define TM_CMD_TIMEOUT 100 /* msecs */ > > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct > *work) > int err = 0, pmc_err; > int tag; > bool needs_reset = false, needs_restore = false; > + ktime_t start; > > hba = container_of(work, struct ufs_hba, eh_work); > > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct > work_struct *work) > } > > hba->silence_err_logs = true; > + > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs > */ > + start = ktime_get(); > + while (hba->outstanding_reqs) { > + ufshcd_complete_requests(hba); > + spin_unlock_irqrestore(hba->host->host_lock, flags); > + schedule(); > + spin_lock_irqsave(hba->host->host_lock, flags); > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > > + LINERESET_IO_TIMEOUT_MS) { > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", > + __func__, hba->outstanding_reqs); > + break; > + } > + } > + > /* release lock as clear command might sleep */ > spin_unlock_irqrestore(hba->host->host_lock, flags); > /* Clear pending transfer requests */ > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void > *__hba) > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); > } > > - if (enabled_intr_status && retval == IRQ_NONE) { > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", > - __func__, intr_status); > + if (enabled_intr_status && retval == IRQ_NONE && > + !ufshcd_eh_in_progress(hba)) { > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, > 0x%08x)\n", > + __func__, > + intr_status, > + hba->ufs_stats.last_intr_status, > + enabled_intr_status); > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); > } > > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba > *hba, > * Even though we use wait_event() which sleeps indefinitely, > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. > */ > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); > + if (IS_ERR(req)) > + return PTR_ERR(req); > + > req->end_io_data = &wait; > free_slot = req->tag; > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 8:02 ` Can Guo @ 2021-01-07 8:07 ` Jaegeuk Kim 2021-01-07 8:17 ` Can Guo 0 siblings, 1 reply; 11+ messages in thread From: Jaegeuk Kim @ 2021-01-07 8:07 UTC (permalink / raw) To: Can Guo Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu On 01/07, Can Guo wrote: > On 2021-01-07 15:47, Jaegeuk Kim wrote: > > From: Jaegeuk Kim <jaegeuk@google.com> > > > > This fixes a warning caused by wrong reserve tag usage in > > __ufshcd_issue_tm_cmd. > > > > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 > > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 > > blk_mq_get_tag+0x438/0x46c > > > > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before > > aborting > > outstanding commands by waiting a bit for IO completion like this. > > > > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out > > > > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to > > allocate and free TMFs") > > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err > > handler") > > Hi Jaegeuk, > > Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O > reqs is a general procedure for handling all non-fatal errors. Without waiting IOs, I hit the below timeout all the time from LINERESET, which causes UFS stuck permanently, as mentioned in the description. "__ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out" > > Thanks, > Can Guo. > > > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> > > --- > > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- > > 1 file changed, 31 insertions(+), 4 deletions(-) > > > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c > > index e6e7bdf99cd7..340dd5e515dd 100644 > > --- a/drivers/scsi/ufs/ufshcd.c > > +++ b/drivers/scsi/ufs/ufshcd.c > > @@ -44,6 +44,9 @@ > > /* Query request timeout */ > > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ > > > > +/* LINERESET TIME OUT */ > > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ > > + > > /* Task management command timeout */ > > #define TM_CMD_TIMEOUT 100 /* msecs */ > > > > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct > > *work) > > int err = 0, pmc_err; > > int tag; > > bool needs_reset = false, needs_restore = false; > > + ktime_t start; > > > > hba = container_of(work, struct ufs_hba, eh_work); > > > > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct > > *work) > > } > > > > hba->silence_err_logs = true; > > + > > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs > > */ > > + start = ktime_get(); > > + while (hba->outstanding_reqs) { > > + ufshcd_complete_requests(hba); > > + spin_unlock_irqrestore(hba->host->host_lock, flags); > > + schedule(); > > + spin_lock_irqsave(hba->host->host_lock, flags); > > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > > > + LINERESET_IO_TIMEOUT_MS) { > > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", > > + __func__, hba->outstanding_reqs); > > + break; > > + } > > + } > > + > > /* release lock as clear command might sleep */ > > spin_unlock_irqrestore(hba->host->host_lock, flags); > > /* Clear pending transfer requests */ > > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void > > *__hba) > > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); > > } > > > > - if (enabled_intr_status && retval == IRQ_NONE) { > > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", > > - __func__, intr_status); > > + if (enabled_intr_status && retval == IRQ_NONE && > > + !ufshcd_eh_in_progress(hba)) { > > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, > > 0x%08x)\n", > > + __func__, > > + intr_status, > > + hba->ufs_stats.last_intr_status, > > + enabled_intr_status); > > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); > > } > > > > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba > > *hba, > > * Even though we use wait_event() which sleeps indefinitely, > > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. > > */ > > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); > > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); > > + if (IS_ERR(req)) > > + return PTR_ERR(req); > > + > > req->end_io_data = &wait; > > free_slot = req->tag; > > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 8:07 ` Jaegeuk Kim @ 2021-01-07 8:17 ` Can Guo 2021-01-07 8:46 ` Jaegeuk Kim 0 siblings, 1 reply; 11+ messages in thread From: Can Guo @ 2021-01-07 8:17 UTC (permalink / raw) To: Jaegeuk Kim Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu On 2021-01-07 16:07, Jaegeuk Kim wrote: > On 01/07, Can Guo wrote: >> On 2021-01-07 15:47, Jaegeuk Kim wrote: >> > From: Jaegeuk Kim <jaegeuk@google.com> >> > >> > This fixes a warning caused by wrong reserve tag usage in >> > __ufshcd_issue_tm_cmd. >> > >> > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 >> > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 >> > blk_mq_get_tag+0x438/0x46c >> > >> > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before >> > aborting >> > outstanding commands by waiting a bit for IO completion like this. >> > >> > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out >> > >> > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to >> > allocate and free TMFs") >> > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err >> > handler") >> >> Hi Jaegeuk, >> >> Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O >> reqs is a general procedure for handling all non-fatal errors. > > Without waiting IOs, I hit the below timeout all the time from > LINERESET, which > causes UFS stuck permanently, as mentioned in the description. > > "__ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out" In that case, ufshcd_try_to_abort_task(), the caller of __ufshcd_issue_tm_cmd(), should return -ETIMEOUT, then err_handler would jump to do a full reset, then bail. I am not sure what gets UFS stuck permanently. Could you please share the callstack if possible? I really want to know what is happening. Thanks. Regards, Can Guo. > >> >> Thanks, >> Can Guo. >> >> > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> >> > --- >> > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- >> > 1 file changed, 31 insertions(+), 4 deletions(-) >> > >> > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c >> > index e6e7bdf99cd7..340dd5e515dd 100644 >> > --- a/drivers/scsi/ufs/ufshcd.c >> > +++ b/drivers/scsi/ufs/ufshcd.c >> > @@ -44,6 +44,9 @@ >> > /* Query request timeout */ >> > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ >> > >> > +/* LINERESET TIME OUT */ >> > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ >> > + >> > /* Task management command timeout */ >> > #define TM_CMD_TIMEOUT 100 /* msecs */ >> > >> > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct >> > *work) >> > int err = 0, pmc_err; >> > int tag; >> > bool needs_reset = false, needs_restore = false; >> > + ktime_t start; >> > >> > hba = container_of(work, struct ufs_hba, eh_work); >> > >> > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct >> > *work) >> > } >> > >> > hba->silence_err_logs = true; >> > + >> > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs >> > */ >> > + start = ktime_get(); >> > + while (hba->outstanding_reqs) { >> > + ufshcd_complete_requests(hba); >> > + spin_unlock_irqrestore(hba->host->host_lock, flags); >> > + schedule(); >> > + spin_lock_irqsave(hba->host->host_lock, flags); >> > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > >> > + LINERESET_IO_TIMEOUT_MS) { >> > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", >> > + __func__, hba->outstanding_reqs); >> > + break; >> > + } >> > + } >> > + >> > /* release lock as clear command might sleep */ >> > spin_unlock_irqrestore(hba->host->host_lock, flags); >> > /* Clear pending transfer requests */ >> > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void >> > *__hba) >> > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); >> > } >> > >> > - if (enabled_intr_status && retval == IRQ_NONE) { >> > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", >> > - __func__, intr_status); >> > + if (enabled_intr_status && retval == IRQ_NONE && >> > + !ufshcd_eh_in_progress(hba)) { >> > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, >> > 0x%08x)\n", >> > + __func__, >> > + intr_status, >> > + hba->ufs_stats.last_intr_status, >> > + enabled_intr_status); >> > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); >> > } >> > >> > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba >> > *hba, >> > * Even though we use wait_event() which sleeps indefinitely, >> > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. >> > */ >> > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); >> > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); >> > + if (IS_ERR(req)) >> > + return PTR_ERR(req); >> > + >> > req->end_io_data = &wait; >> > free_slot = req->tag; >> > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 8:17 ` Can Guo @ 2021-01-07 8:46 ` Jaegeuk Kim 2021-01-07 8:58 ` Can Guo 0 siblings, 1 reply; 11+ messages in thread From: Jaegeuk Kim @ 2021-01-07 8:46 UTC (permalink / raw) To: Can Guo Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu On 01/07, Can Guo wrote: > On 2021-01-07 16:07, Jaegeuk Kim wrote: > > On 01/07, Can Guo wrote: > > > On 2021-01-07 15:47, Jaegeuk Kim wrote: > > > > From: Jaegeuk Kim <jaegeuk@google.com> > > > > > > > > This fixes a warning caused by wrong reserve tag usage in > > > > __ufshcd_issue_tm_cmd. > > > > > > > > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 > > > > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 > > > > blk_mq_get_tag+0x438/0x46c > > > > > > > > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before > > > > aborting > > > > outstanding commands by waiting a bit for IO completion like this. > > > > > > > > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out > > > > > > > > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to > > > > allocate and free TMFs") > > > > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err > > > > handler") > > > > > > Hi Jaegeuk, > > > > > > Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O > > > reqs is a general procedure for handling all non-fatal errors. > > > > Without waiting IOs, I hit the below timeout all the time from > > LINERESET, which > > causes UFS stuck permanently, as mentioned in the description. > > > > "__ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out" > > In that case, ufshcd_try_to_abort_task(), the caller of > __ufshcd_issue_tm_cmd(), > should return -ETIMEOUT, then err_handler would jump to do a full reset, > then bail. > I am not sure what gets UFS stuck permanently. Could you please share the > callstack > if possible? I really want to know what is happening. Thanks. I can't share all the log tho, it entered full reset. While printing out whole registers, the device was hard reset. Thanks, > > Regards, > Can Guo. > > > > > > > > > Thanks, > > > Can Guo. > > > > > > > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> > > > > --- > > > > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- > > > > 1 file changed, 31 insertions(+), 4 deletions(-) > > > > > > > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c > > > > index e6e7bdf99cd7..340dd5e515dd 100644 > > > > --- a/drivers/scsi/ufs/ufshcd.c > > > > +++ b/drivers/scsi/ufs/ufshcd.c > > > > @@ -44,6 +44,9 @@ > > > > /* Query request timeout */ > > > > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ > > > > > > > > +/* LINERESET TIME OUT */ > > > > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ > > > > + > > > > /* Task management command timeout */ > > > > #define TM_CMD_TIMEOUT 100 /* msecs */ > > > > > > > > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct > > > > *work) > > > > int err = 0, pmc_err; > > > > int tag; > > > > bool needs_reset = false, needs_restore = false; > > > > + ktime_t start; > > > > > > > > hba = container_of(work, struct ufs_hba, eh_work); > > > > > > > > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct > > > > *work) > > > > } > > > > > > > > hba->silence_err_logs = true; > > > > + > > > > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs > > > > */ > > > > + start = ktime_get(); > > > > + while (hba->outstanding_reqs) { > > > > + ufshcd_complete_requests(hba); > > > > + spin_unlock_irqrestore(hba->host->host_lock, flags); > > > > + schedule(); > > > > + spin_lock_irqsave(hba->host->host_lock, flags); > > > > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > > > > > + LINERESET_IO_TIMEOUT_MS) { > > > > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", > > > > + __func__, hba->outstanding_reqs); > > > > + break; > > > > + } > > > > + } > > > > + > > > > /* release lock as clear command might sleep */ > > > > spin_unlock_irqrestore(hba->host->host_lock, flags); > > > > /* Clear pending transfer requests */ > > > > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void > > > > *__hba) > > > > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); > > > > } > > > > > > > > - if (enabled_intr_status && retval == IRQ_NONE) { > > > > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", > > > > - __func__, intr_status); > > > > + if (enabled_intr_status && retval == IRQ_NONE && > > > > + !ufshcd_eh_in_progress(hba)) { > > > > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, > > > > 0x%08x)\n", > > > > + __func__, > > > > + intr_status, > > > > + hba->ufs_stats.last_intr_status, > > > > + enabled_intr_status); > > > > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); > > > > } > > > > > > > > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba > > > > *hba, > > > > * Even though we use wait_event() which sleeps indefinitely, > > > > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. > > > > */ > > > > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); > > > > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); > > > > + if (IS_ERR(req)) > > > > + return PTR_ERR(req); > > > > + > > > > req->end_io_data = &wait; > > > > free_slot = req->tag; > > > > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 8:46 ` Jaegeuk Kim @ 2021-01-07 8:58 ` Can Guo 2021-01-07 9:13 ` Can Guo 2021-01-07 18:55 ` Jaegeuk Kim 0 siblings, 2 replies; 11+ messages in thread From: Can Guo @ 2021-01-07 8:58 UTC (permalink / raw) To: Jaegeuk Kim Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu On 2021-01-07 16:46, Jaegeuk Kim wrote: > On 01/07, Can Guo wrote: >> On 2021-01-07 16:07, Jaegeuk Kim wrote: >> > On 01/07, Can Guo wrote: >> > > On 2021-01-07 15:47, Jaegeuk Kim wrote: >> > > > From: Jaegeuk Kim <jaegeuk@google.com> >> > > > >> > > > This fixes a warning caused by wrong reserve tag usage in >> > > > __ufshcd_issue_tm_cmd. >> > > > >> > > > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 >> > > > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 >> > > > blk_mq_get_tag+0x438/0x46c >> > > > >> > > > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before >> > > > aborting >> > > > outstanding commands by waiting a bit for IO completion like this. >> > > > >> > > > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out >> > > > >> > > > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to >> > > > allocate and free TMFs") >> > > > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err >> > > > handler") >> > > >> > > Hi Jaegeuk, >> > > >> > > Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O >> > > reqs is a general procedure for handling all non-fatal errors. >> > >> > Without waiting IOs, I hit the below timeout all the time from >> > LINERESET, which >> > causes UFS stuck permanently, as mentioned in the description. >> > >> > "__ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out" >> >> In that case, ufshcd_try_to_abort_task(), the caller of >> __ufshcd_issue_tm_cmd(), >> should return -ETIMEOUT, then err_handler would jump to do a full >> reset, >> then bail. >> I am not sure what gets UFS stuck permanently. Could you please share >> the >> callstack >> if possible? I really want to know what is happening. Thanks. > > I can't share all the log tho, it entered full reset. While printing > out > whole registers, the device was hard reset. Thanks, Hi Jaegeuk, Entering full reset is expected in this case, which is why I am saying line-reset handling logic should not be penalized. I think we need to find out what caused the hard reset but not just adding a delay before clearing pending reqs, because let's say 3 sec expires and you hit the same tm req timeout (maybe with a lower possibility), you may still end up same at the hard reset. You don't need to share all the log, just the last call stacks before hard reset. Is it a QCOM's platform used in your case? Can you check the log/dump if NoC error happened? Thanks. Can Guo. > >> >> Regards, >> Can Guo. >> >> > >> > > >> > > Thanks, >> > > Can Guo. >> > > >> > > > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> >> > > > --- >> > > > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- >> > > > 1 file changed, 31 insertions(+), 4 deletions(-) >> > > > >> > > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c >> > > > index e6e7bdf99cd7..340dd5e515dd 100644 >> > > > --- a/drivers/scsi/ufs/ufshcd.c >> > > > +++ b/drivers/scsi/ufs/ufshcd.c >> > > > @@ -44,6 +44,9 @@ >> > > > /* Query request timeout */ >> > > > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ >> > > > >> > > > +/* LINERESET TIME OUT */ >> > > > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ >> > > > + >> > > > /* Task management command timeout */ >> > > > #define TM_CMD_TIMEOUT 100 /* msecs */ >> > > > >> > > > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct >> > > > *work) >> > > > int err = 0, pmc_err; >> > > > int tag; >> > > > bool needs_reset = false, needs_restore = false; >> > > > + ktime_t start; >> > > > >> > > > hba = container_of(work, struct ufs_hba, eh_work); >> > > > >> > > > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct >> > > > *work) >> > > > } >> > > > >> > > > hba->silence_err_logs = true; >> > > > + >> > > > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs >> > > > */ >> > > > + start = ktime_get(); >> > > > + while (hba->outstanding_reqs) { >> > > > + ufshcd_complete_requests(hba); >> > > > + spin_unlock_irqrestore(hba->host->host_lock, flags); >> > > > + schedule(); >> > > > + spin_lock_irqsave(hba->host->host_lock, flags); >> > > > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > >> > > > + LINERESET_IO_TIMEOUT_MS) { >> > > > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", >> > > > + __func__, hba->outstanding_reqs); >> > > > + break; >> > > > + } >> > > > + } >> > > > + >> > > > /* release lock as clear command might sleep */ >> > > > spin_unlock_irqrestore(hba->host->host_lock, flags); >> > > > /* Clear pending transfer requests */ >> > > > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void >> > > > *__hba) >> > > > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); >> > > > } >> > > > >> > > > - if (enabled_intr_status && retval == IRQ_NONE) { >> > > > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", >> > > > - __func__, intr_status); >> > > > + if (enabled_intr_status && retval == IRQ_NONE && >> > > > + !ufshcd_eh_in_progress(hba)) { >> > > > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, >> > > > 0x%08x)\n", >> > > > + __func__, >> > > > + intr_status, >> > > > + hba->ufs_stats.last_intr_status, >> > > > + enabled_intr_status); >> > > > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); >> > > > } >> > > > >> > > > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba >> > > > *hba, >> > > > * Even though we use wait_event() which sleeps indefinitely, >> > > > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. >> > > > */ >> > > > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); >> > > > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); >> > > > + if (IS_ERR(req)) >> > > > + return PTR_ERR(req); >> > > > + >> > > > req->end_io_data = &wait; >> > > > free_slot = req->tag; >> > > > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); ^ permalink raw reply [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 8:58 ` Can Guo @ 2021-01-07 9:13 ` Can Guo 2021-01-07 18:55 ` Jaegeuk Kim 1 sibling, 0 replies; 11+ messages in thread From: Can Guo @ 2021-01-07 9:13 UTC (permalink / raw) To: Jaegeuk Kim Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu [-- Attachment #1: Type: text/plain, Size: 6415 bytes --] On 2021-01-07 16:58, Can Guo wrote: > On 2021-01-07 16:46, Jaegeuk Kim wrote: >> On 01/07, Can Guo wrote: >>> On 2021-01-07 16:07, Jaegeuk Kim wrote: >>> > On 01/07, Can Guo wrote: >>> > > On 2021-01-07 15:47, Jaegeuk Kim wrote: >>> > > > From: Jaegeuk Kim <jaegeuk@google.com> >>> > > > >>> > > > This fixes a warning caused by wrong reserve tag usage in >>> > > > __ufshcd_issue_tm_cmd. >>> > > > >>> > > > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 >>> > > > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 >>> > > > blk_mq_get_tag+0x438/0x46c >>> > > > >>> > > > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before >>> > > > aborting >>> > > > outstanding commands by waiting a bit for IO completion like this. >>> > > > >>> > > > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out >>> > > > >>> > > > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to >>> > > > allocate and free TMFs") >>> > > > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err >>> > > > handler") >>> > > >>> > > Hi Jaegeuk, >>> > > >>> > > Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O >>> > > reqs is a general procedure for handling all non-fatal errors. >>> > >>> > Without waiting IOs, I hit the below timeout all the time from >>> > LINERESET, which >>> > causes UFS stuck permanently, as mentioned in the description. >>> > >>> > "__ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out" >>> >>> In that case, ufshcd_try_to_abort_task(), the caller of >>> __ufshcd_issue_tm_cmd(), >>> should return -ETIMEOUT, then err_handler would jump to do a full >>> reset, >>> then bail. >>> I am not sure what gets UFS stuck permanently. Could you please share >>> the >>> callstack >>> if possible? I really want to know what is happening. Thanks. >> >> I can't share all the log tho, it entered full reset. While printing >> out >> whole registers, the device was hard reset. Thanks, > > Hi Jaegeuk, > > Entering full reset is expected in this case, which is why I am saying > line-reset handling logic should not be penalized. I think we need to > find out what caused the hard reset but not just adding a delay before > clearing pending reqs, because let's say 3 sec expires and you hit the > same tm req timeout (maybe with a lower possibility), you may still end > up same at the hard reset. You don't need to share all the log, just > the > last call stacks before hard reset. Is it a QCOM's platform used in > your > case? Can you check the log/dump if NoC error happened? > > Thanks. > Can Guo. > Hi Jaegeuk, If it is QCOM's platform, what you described looks like a known issue which we have already fixed in downstream. Please try attached patch. If not, please ignore it. Thanks, Can Guo. >> >>> >>> Regards, >>> Can Guo. >>> >>> > >>> > > >>> > > Thanks, >>> > > Can Guo. >>> > > >>> > > > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> >>> > > > --- >>> > > > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- >>> > > > 1 file changed, 31 insertions(+), 4 deletions(-) >>> > > > >>> > > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c >>> > > > index e6e7bdf99cd7..340dd5e515dd 100644 >>> > > > --- a/drivers/scsi/ufs/ufshcd.c >>> > > > +++ b/drivers/scsi/ufs/ufshcd.c >>> > > > @@ -44,6 +44,9 @@ >>> > > > /* Query request timeout */ >>> > > > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ >>> > > > >>> > > > +/* LINERESET TIME OUT */ >>> > > > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ >>> > > > + >>> > > > /* Task management command timeout */ >>> > > > #define TM_CMD_TIMEOUT 100 /* msecs */ >>> > > > >>> > > > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct >>> > > > *work) >>> > > > int err = 0, pmc_err; >>> > > > int tag; >>> > > > bool needs_reset = false, needs_restore = false; >>> > > > + ktime_t start; >>> > > > >>> > > > hba = container_of(work, struct ufs_hba, eh_work); >>> > > > >>> > > > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct >>> > > > *work) >>> > > > } >>> > > > >>> > > > hba->silence_err_logs = true; >>> > > > + >>> > > > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs >>> > > > */ >>> > > > + start = ktime_get(); >>> > > > + while (hba->outstanding_reqs) { >>> > > > + ufshcd_complete_requests(hba); >>> > > > + spin_unlock_irqrestore(hba->host->host_lock, flags); >>> > > > + schedule(); >>> > > > + spin_lock_irqsave(hba->host->host_lock, flags); >>> > > > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > >>> > > > + LINERESET_IO_TIMEOUT_MS) { >>> > > > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", >>> > > > + __func__, hba->outstanding_reqs); >>> > > > + break; >>> > > > + } >>> > > > + } >>> > > > + >>> > > > /* release lock as clear command might sleep */ >>> > > > spin_unlock_irqrestore(hba->host->host_lock, flags); >>> > > > /* Clear pending transfer requests */ >>> > > > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void >>> > > > *__hba) >>> > > > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); >>> > > > } >>> > > > >>> > > > - if (enabled_intr_status && retval == IRQ_NONE) { >>> > > > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", >>> > > > - __func__, intr_status); >>> > > > + if (enabled_intr_status && retval == IRQ_NONE && >>> > > > + !ufshcd_eh_in_progress(hba)) { >>> > > > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, >>> > > > 0x%08x)\n", >>> > > > + __func__, >>> > > > + intr_status, >>> > > > + hba->ufs_stats.last_intr_status, >>> > > > + enabled_intr_status); >>> > > > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); >>> > > > } >>> > > > >>> > > > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba >>> > > > *hba, >>> > > > * Even though we use wait_event() which sleeps indefinitely, >>> > > > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. >>> > > > */ >>> > > > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); >>> > > > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); >>> > > > + if (IS_ERR(req)) >>> > > > + return PTR_ERR(req); >>> > > > + >>> > > > req->end_io_data = &wait; >>> > > > free_slot = req->tag; >>> > > > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: 0001-scsi-ufs-qcom-Disable-interrupt-in-reset-path.patch --] [-- Type: text/x-diff; name=0001-scsi-ufs-qcom-Disable-interrupt-in-reset-path.patch, Size: 1298 bytes --] From b50e595a80e9e31c2f9744439b3bdd986e9433ea Mon Sep 17 00:00:00 2001 From: Can Guo <cang@codeaurora.org> Date: Thu, 7 Jan 2021 01:07:12 -0800 Subject: [PATCH] scsi: ufs-qcom: Disable interrupt in reset path Disable interrupt in reset path Signed-off-by: Can Guo <cang@codeaurora.org> diff --git a/drivers/scsi/ufs/ufs-qcom.c b/drivers/scsi/ufs/ufs-qcom.c index 2206b1e..e55201f 100644 --- a/drivers/scsi/ufs/ufs-qcom.c +++ b/drivers/scsi/ufs/ufs-qcom.c @@ -253,12 +253,17 @@ static int ufs_qcom_host_reset(struct ufs_hba *hba) { int ret = 0; struct ufs_qcom_host *host = ufshcd_get_variant(hba); + bool reenable_intr = false; if (!host->core_reset) { dev_warn(hba->dev, "%s: reset control not set\n", __func__); goto out; } + reenable_intr = hba->is_irq_enabled; + disable_irq(hba->irq); + hba->is_irq_enabled = false; + ret = reset_control_assert(host->core_reset); if (ret) { dev_err(hba->dev, "%s: core_reset assert failed, err = %d\n", @@ -280,6 +285,11 @@ static int ufs_qcom_host_reset(struct ufs_hba *hba) usleep_range(1000, 1100); + if (reenable_intr) { + enable_irq(hba->irq); + hba->is_irq_enabled = true; + } + out: return ret; } -- Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum, a Linux Foundation Collaborative Project. ^ permalink raw reply related [flat|nested] 11+ messages in thread
* Re: [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd 2021-01-07 8:58 ` Can Guo 2021-01-07 9:13 ` Can Guo @ 2021-01-07 18:55 ` Jaegeuk Kim 1 sibling, 0 replies; 11+ messages in thread From: Jaegeuk Kim @ 2021-01-07 18:55 UTC (permalink / raw) To: Can Guo Cc: linux-kernel, linux-scsi, kernel-team, alim.akhtar, avri.altman, bvanassche, martin.petersen, stanley.chu On 01/07, Can Guo wrote: > On 2021-01-07 16:46, Jaegeuk Kim wrote: > > On 01/07, Can Guo wrote: > > > On 2021-01-07 16:07, Jaegeuk Kim wrote: > > > > On 01/07, Can Guo wrote: > > > > > On 2021-01-07 15:47, Jaegeuk Kim wrote: > > > > > > From: Jaegeuk Kim <jaegeuk@google.com> > > > > > > > > > > > > This fixes a warning caused by wrong reserve tag usage in > > > > > > __ufshcd_issue_tm_cmd. > > > > > > > > > > > > WARNING: CPU: 7 PID: 7 at block/blk-core.c:630 blk_get_request+0x68/0x70 > > > > > > WARNING: CPU: 4 PID: 157 at block/blk-mq-tag.c:82 > > > > > > blk_mq_get_tag+0x438/0x46c > > > > > > > > > > > > And, in ufshcd_err_handler(), we can avoid to send tm_cmd before > > > > > > aborting > > > > > > outstanding commands by waiting a bit for IO completion like this. > > > > > > > > > > > > __ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out > > > > > > > > > > > > Fixes: 69a6c269c097 ("scsi: ufs: Use blk_{get,put}_request() to > > > > > > allocate and free TMFs") > > > > > > Fixes: 2355b66ed20c ("scsi: ufs: Handle LINERESET indication in err > > > > > > handler") > > > > > > > > > > Hi Jaegeuk, > > > > > > > > > > Sorry, what is wrong with commit 2355b66ed20c? Clearing pending I/O > > > > > reqs is a general procedure for handling all non-fatal errors. > > > > > > > > Without waiting IOs, I hit the below timeout all the time from > > > > LINERESET, which > > > > causes UFS stuck permanently, as mentioned in the description. > > > > > > > > "__ufshcd_issue_tm_cmd: task management cmd 0x80 timed-out" > > > > > > In that case, ufshcd_try_to_abort_task(), the caller of > > > __ufshcd_issue_tm_cmd(), > > > should return -ETIMEOUT, then err_handler would jump to do a full > > > reset, > > > then bail. > > > I am not sure what gets UFS stuck permanently. Could you please > > > share the > > > callstack > > > if possible? I really want to know what is happening. Thanks. > > > > I can't share all the log tho, it entered full reset. While printing out > > whole registers, the device was hard reset. Thanks, > > Hi Jaegeuk, > > Entering full reset is expected in this case, which is why I am saying > line-reset handling logic should not be penalized. I think we need to > find out what caused the hard reset but not just adding a delay before > clearing pending reqs, because let's say 3 sec expires and you hit the > same tm req timeout (maybe with a lower possibility), you may still end > up same at the hard reset. You don't need to share all the log, just the > last call stacks before hard reset. Is it a QCOM's platform used in your > case? Can you check the log/dump if NoC error happened? Hi Can, I figured out it is caused by verbose kernel logs printed in terminal. I posted v5, so could you please review it? Thanks, > > Thanks. > Can Guo. > > > > > > > > > Regards, > > > Can Guo. > > > > > > > > > > > > > > > > > Thanks, > > > > > Can Guo. > > > > > > > > > > > Signed-off-by: Jaegeuk Kim <jaegeuk@kernel.org> > > > > > > --- > > > > > > drivers/scsi/ufs/ufshcd.c | 35 +++++++++++++++++++++++++++++++---- > > > > > > 1 file changed, 31 insertions(+), 4 deletions(-) > > > > > > > > > > > > diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c > > > > > > index e6e7bdf99cd7..340dd5e515dd 100644 > > > > > > --- a/drivers/scsi/ufs/ufshcd.c > > > > > > +++ b/drivers/scsi/ufs/ufshcd.c > > > > > > @@ -44,6 +44,9 @@ > > > > > > /* Query request timeout */ > > > > > > #define QUERY_REQ_TIMEOUT 1500 /* 1.5 seconds */ > > > > > > > > > > > > +/* LINERESET TIME OUT */ > > > > > > +#define LINERESET_IO_TIMEOUT_MS (30000) /* 30 sec */ > > > > > > + > > > > > > /* Task management command timeout */ > > > > > > #define TM_CMD_TIMEOUT 100 /* msecs */ > > > > > > > > > > > > @@ -5826,6 +5829,7 @@ static void ufshcd_err_handler(struct work_struct > > > > > > *work) > > > > > > int err = 0, pmc_err; > > > > > > int tag; > > > > > > bool needs_reset = false, needs_restore = false; > > > > > > + ktime_t start; > > > > > > > > > > > > hba = container_of(work, struct ufs_hba, eh_work); > > > > > > > > > > > > @@ -5911,6 +5915,22 @@ static void ufshcd_err_handler(struct work_struct > > > > > > *work) > > > > > > } > > > > > > > > > > > > hba->silence_err_logs = true; > > > > > > + > > > > > > + /* Wait for IO completion for non-fatal errors to avoid aborting IOs > > > > > > */ > > > > > > + start = ktime_get(); > > > > > > + while (hba->outstanding_reqs) { > > > > > > + ufshcd_complete_requests(hba); > > > > > > + spin_unlock_irqrestore(hba->host->host_lock, flags); > > > > > > + schedule(); > > > > > > + spin_lock_irqsave(hba->host->host_lock, flags); > > > > > > + if (ktime_to_ms(ktime_sub(ktime_get(), start)) > > > > > > > + LINERESET_IO_TIMEOUT_MS) { > > > > > > + dev_err(hba->dev, "%s: timeout, outstanding=0x%lx\n", > > > > > > + __func__, hba->outstanding_reqs); > > > > > > + break; > > > > > > + } > > > > > > + } > > > > > > + > > > > > > /* release lock as clear command might sleep */ > > > > > > spin_unlock_irqrestore(hba->host->host_lock, flags); > > > > > > /* Clear pending transfer requests */ > > > > > > @@ -6302,9 +6322,13 @@ static irqreturn_t ufshcd_intr(int irq, void > > > > > > *__hba) > > > > > > intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS); > > > > > > } > > > > > > > > > > > > - if (enabled_intr_status && retval == IRQ_NONE) { > > > > > > - dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x\n", > > > > > > - __func__, intr_status); > > > > > > + if (enabled_intr_status && retval == IRQ_NONE && > > > > > > + !ufshcd_eh_in_progress(hba)) { > > > > > > + dev_err(hba->dev, "%s: Unhandled interrupt 0x%08x (0x%08x, > > > > > > 0x%08x)\n", > > > > > > + __func__, > > > > > > + intr_status, > > > > > > + hba->ufs_stats.last_intr_status, > > > > > > + enabled_intr_status); > > > > > > ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: "); > > > > > > } > > > > > > > > > > > > @@ -6348,7 +6372,10 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba > > > > > > *hba, > > > > > > * Even though we use wait_event() which sleeps indefinitely, > > > > > > * the maximum wait time is bounded by %TM_CMD_TIMEOUT. > > > > > > */ > > > > > > - req = blk_get_request(q, REQ_OP_DRV_OUT, BLK_MQ_REQ_RESERVED); > > > > > > + req = blk_get_request(q, REQ_OP_DRV_OUT, 0); > > > > > > + if (IS_ERR(req)) > > > > > > + return PTR_ERR(req); > > > > > > + > > > > > > req->end_io_data = &wait; > > > > > > free_slot = req->tag; > > > > > > WARN_ON_ONCE(free_slot < 0 || free_slot >= hba->nutmrs); ^ permalink raw reply [flat|nested] 11+ messages in thread
end of thread, other threads:[~2021-01-07 18:56 UTC | newest] Thread overview: 11+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2021-01-07 7:47 [PATCH v4 0/2] UFS bug fixes Jaegeuk Kim 2021-01-07 7:47 ` [PATCH v4 1/2] scsi: ufs: fix livelock of ufshcd_clear_ua_wluns Jaegeuk Kim 2021-01-07 7:58 ` Can Guo 2021-01-07 7:47 ` [PATCH v4 2/2] scsi: ufs: handle LINERESET with correct tm_cmd Jaegeuk Kim 2021-01-07 8:02 ` Can Guo 2021-01-07 8:07 ` Jaegeuk Kim 2021-01-07 8:17 ` Can Guo 2021-01-07 8:46 ` Jaegeuk Kim 2021-01-07 8:58 ` Can Guo 2021-01-07 9:13 ` Can Guo 2021-01-07 18:55 ` Jaegeuk Kim
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).