The infos of the last interrupt status and its timestamp are very helpful
when debug system stability issues, e.g. IRQ starvation, so add them to
ufshcd_print_host_state. Meanwhile, UFS device infos like model name and
its FW version also come in handy during debug. In addition, this change
makes cleanup to some prints in ufshcd_print_host_regs as similar prints
are already available in ufshcd_print_host_state.
Signed-off-by: Can Guo <[email protected]>
Reviewed-by: Avri Altman <[email protected]>
---
drivers/scsi/ufs/ufshcd.c | 31 ++++++++++++++++++-------------
drivers/scsi/ufs/ufshcd.h | 5 +++++
2 files changed, 23 insertions(+), 13 deletions(-)
diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index 99bd3e4..eda4dc6 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -411,15 +411,6 @@ static void ufshcd_print_err_hist(struct ufs_hba *hba,
static void ufshcd_print_host_regs(struct ufs_hba *hba)
{
ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: ");
- dev_err(hba->dev, "hba->ufs_version = 0x%x, hba->capabilities = 0x%x\n",
- hba->ufs_version, hba->capabilities);
- dev_err(hba->dev,
- "hba->outstanding_reqs = 0x%x, hba->outstanding_tasks = 0x%x\n",
- (u32)hba->outstanding_reqs, (u32)hba->outstanding_tasks);
- dev_err(hba->dev,
- "last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt = %d\n",
- ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
- hba->ufs_stats.hibern8_exit_cnt);
ufshcd_print_err_hist(hba, &hba->ufs_stats.pa_err, "pa_err");
ufshcd_print_err_hist(hba, &hba->ufs_stats.dl_err, "dl_err");
@@ -438,8 +429,6 @@ static void ufshcd_print_host_regs(struct ufs_hba *hba)
ufshcd_print_err_hist(hba, &hba->ufs_stats.host_reset, "host_reset");
ufshcd_print_err_hist(hba, &hba->ufs_stats.task_abort, "task_abort");
- ufshcd_print_clk_freqs(hba);
-
ufshcd_vops_dbg_register_dump(hba);
}
@@ -499,6 +488,8 @@ static void ufshcd_print_tmrs(struct ufs_hba *hba, unsigned long bitmap)
static void ufshcd_print_host_state(struct ufs_hba *hba)
{
+ struct scsi_device *sdev_ufs = hba->sdev_ufs_device;
+
dev_err(hba->dev, "UFS Host state=%d\n", hba->ufshcd_state);
dev_err(hba->dev, "outstanding reqs=0x%lx tasks=0x%lx\n",
hba->outstanding_reqs, hba->outstanding_tasks);
@@ -511,12 +502,24 @@ static void ufshcd_print_host_state(struct ufs_hba *hba)
dev_err(hba->dev, "Auto BKOPS=%d, Host self-block=%d\n",
hba->auto_bkops_enabled, hba->host->host_self_blocked);
dev_err(hba->dev, "Clk gate=%d\n", hba->clk_gating.state);
+ dev_err(hba->dev,
+ "last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt=%d\n",
+ ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
+ hba->ufs_stats.hibern8_exit_cnt);
+ dev_err(hba->dev, "last intr at %lld us, last intr status=0x%x\n",
+ ktime_to_us(hba->ufs_stats.last_intr_ts),
+ hba->ufs_stats.last_intr_status);
dev_err(hba->dev, "error handling flags=0x%x, req. abort count=%d\n",
hba->eh_flags, hba->req_abort_count);
- dev_err(hba->dev, "Host capabilities=0x%x, caps=0x%x\n",
- hba->capabilities, hba->caps);
+ dev_err(hba->dev, "hba->ufs_version=0x%x, Host capabilities=0x%x, caps=0x%x\n",
+ hba->ufs_version, hba->capabilities, hba->caps);
dev_err(hba->dev, "quirks=0x%x, dev. quirks=0x%x\n", hba->quirks,
hba->dev_quirks);
+ if (sdev_ufs)
+ dev_err(hba->dev, "UFS dev info: %.8s %.16s rev %.4s\n",
+ sdev_ufs->vendor, sdev_ufs->model, sdev_ufs->rev);
+
+ ufshcd_print_clk_freqs(hba);
}
/**
@@ -5951,6 +5954,8 @@ static irqreturn_t ufshcd_intr(int irq, void *__hba)
spin_lock(hba->host->host_lock);
intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
+ hba->ufs_stats.last_intr_status = intr_status;
+ hba->ufs_stats.last_intr_ts = ktime_get();
/*
* There could be max of hba->nutrs reqs in flight and in worst case
diff --git a/drivers/scsi/ufs/ufshcd.h b/drivers/scsi/ufs/ufshcd.h
index 656c069..5b2cdaf 100644
--- a/drivers/scsi/ufs/ufshcd.h
+++ b/drivers/scsi/ufs/ufshcd.h
@@ -406,6 +406,8 @@ struct ufs_err_reg_hist {
/**
* struct ufs_stats - keeps usage/err statistics
+ * @last_intr_status: record the last interrupt status.
+ * @last_intr_ts: record the last interrupt timestamp.
* @hibern8_exit_cnt: Counter to keep track of number of exits,
* reset this after link-startup.
* @last_hibern8_exit_tstamp: Set time after the hibern8 exit.
@@ -425,6 +427,9 @@ struct ufs_err_reg_hist {
* @tsk_abort: tracks task abort events
*/
struct ufs_stats {
+ u32 last_intr_status;
+ ktime_t last_intr_ts;
+
u32 hibern8_exit_cnt;
ktime_t last_hibern8_exit_tstamp;
--
Qualcomm Innovation Center, Inc. is a member of Code Aurora Forum, a Linux Foundation Collaborative Project.
On 2020-07-28 13:00, Can Guo wrote:
> The infos of the last interrupt status and its timestamp are very
> helpful
> when debug system stability issues, e.g. IRQ starvation, so add them to
> ufshcd_print_host_state. Meanwhile, UFS device infos like model name
> and
> its FW version also come in handy during debug. In addition, this
> change
> makes cleanup to some prints in ufshcd_print_host_regs as similar
> prints
> are already available in ufshcd_print_host_state.
>
> Signed-off-by: Can Guo <[email protected]>
> Reviewed-by: Avri Altman <[email protected]>
> ---
> drivers/scsi/ufs/ufshcd.c | 31 ++++++++++++++++++-------------
> drivers/scsi/ufs/ufshcd.h | 5 +++++
> 2 files changed, 23 insertions(+), 13 deletions(-)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index 99bd3e4..eda4dc6 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -411,15 +411,6 @@ static void ufshcd_print_err_hist(struct ufs_hba
> *hba,
> static void ufshcd_print_host_regs(struct ufs_hba *hba)
> {
> ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: ");
> - dev_err(hba->dev, "hba->ufs_version = 0x%x, hba->capabilities =
> 0x%x\n",
> - hba->ufs_version, hba->capabilities);
> - dev_err(hba->dev,
> - "hba->outstanding_reqs = 0x%x, hba->outstanding_tasks = 0x%x\n",
> - (u32)hba->outstanding_reqs, (u32)hba->outstanding_tasks);
> - dev_err(hba->dev,
> - "last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt = %d\n",
> - ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
> - hba->ufs_stats.hibern8_exit_cnt);
>
> ufshcd_print_err_hist(hba, &hba->ufs_stats.pa_err, "pa_err");
> ufshcd_print_err_hist(hba, &hba->ufs_stats.dl_err, "dl_err");
> @@ -438,8 +429,6 @@ static void ufshcd_print_host_regs(struct ufs_hba
> *hba)
> ufshcd_print_err_hist(hba, &hba->ufs_stats.host_reset, "host_reset");
> ufshcd_print_err_hist(hba, &hba->ufs_stats.task_abort, "task_abort");
>
> - ufshcd_print_clk_freqs(hba);
> -
> ufshcd_vops_dbg_register_dump(hba);
> }
>
> @@ -499,6 +488,8 @@ static void ufshcd_print_tmrs(struct ufs_hba *hba,
> unsigned long bitmap)
>
> static void ufshcd_print_host_state(struct ufs_hba *hba)
> {
> + struct scsi_device *sdev_ufs = hba->sdev_ufs_device;
> +
> dev_err(hba->dev, "UFS Host state=%d\n", hba->ufshcd_state);
> dev_err(hba->dev, "outstanding reqs=0x%lx tasks=0x%lx\n",
> hba->outstanding_reqs, hba->outstanding_tasks);
> @@ -511,12 +502,24 @@ static void ufshcd_print_host_state(struct
> ufs_hba *hba)
> dev_err(hba->dev, "Auto BKOPS=%d, Host self-block=%d\n",
> hba->auto_bkops_enabled, hba->host->host_self_blocked);
> dev_err(hba->dev, "Clk gate=%d\n", hba->clk_gating.state);
> + dev_err(hba->dev,
> + "last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt=%d\n",
> + ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
> + hba->ufs_stats.hibern8_exit_cnt);
> + dev_err(hba->dev, "last intr at %lld us, last intr status=0x%x\n",
> + ktime_to_us(hba->ufs_stats.last_intr_ts),
> + hba->ufs_stats.last_intr_status);
> dev_err(hba->dev, "error handling flags=0x%x, req. abort count=%d\n",
> hba->eh_flags, hba->req_abort_count);
> - dev_err(hba->dev, "Host capabilities=0x%x, caps=0x%x\n",
> - hba->capabilities, hba->caps);
> + dev_err(hba->dev, "hba->ufs_version=0x%x, Host capabilities=0x%x,
> caps=0x%x\n",
> + hba->ufs_version, hba->capabilities, hba->caps);
> dev_err(hba->dev, "quirks=0x%x, dev. quirks=0x%x\n", hba->quirks,
> hba->dev_quirks);
> + if (sdev_ufs)
> + dev_err(hba->dev, "UFS dev info: %.8s %.16s rev %.4s\n",
> + sdev_ufs->vendor, sdev_ufs->model, sdev_ufs->rev);
> +
> + ufshcd_print_clk_freqs(hba);
> }
>
> /**
> @@ -5951,6 +5954,8 @@ static irqreturn_t ufshcd_intr(int irq, void
> *__hba)
>
> spin_lock(hba->host->host_lock);
> intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
> + hba->ufs_stats.last_intr_status = intr_status;
> + hba->ufs_stats.last_intr_ts = ktime_get();
>
> /*
> * There could be max of hba->nutrs reqs in flight and in worst case
> diff --git a/drivers/scsi/ufs/ufshcd.h b/drivers/scsi/ufs/ufshcd.h
> index 656c069..5b2cdaf 100644
> --- a/drivers/scsi/ufs/ufshcd.h
> +++ b/drivers/scsi/ufs/ufshcd.h
> @@ -406,6 +406,8 @@ struct ufs_err_reg_hist {
>
> /**
> * struct ufs_stats - keeps usage/err statistics
> + * @last_intr_status: record the last interrupt status.
> + * @last_intr_ts: record the last interrupt timestamp.
> * @hibern8_exit_cnt: Counter to keep track of number of exits,
> * reset this after link-startup.
> * @last_hibern8_exit_tstamp: Set time after the hibern8 exit.
> @@ -425,6 +427,9 @@ struct ufs_err_reg_hist {
> * @tsk_abort: tracks task abort events
> */
> struct ufs_stats {
> + u32 last_intr_status;
> + ktime_t last_intr_ts;
> +
> u32 hibern8_exit_cnt;
> ktime_t last_hibern8_exit_tstamp;
Reviewed-by: Hongwu Su <[email protected]>
On 7/27/2020 10:00 PM, Can Guo wrote:
> The infos of the last interrupt status and its timestamp are very helpful
> when debug system stability issues, e.g. IRQ starvation, so add them to
> ufshcd_print_host_state. Meanwhile, UFS device infos like model name and
> its FW version also come in handy during debug. In addition, this change
> makes cleanup to some prints in ufshcd_print_host_regs as similar prints
> are already available in ufshcd_print_host_state.
>
> Signed-off-by: Can Guo <[email protected]>
> Reviewed-by: Avri Altman <[email protected]>
Reviewed-by: Asutosh Das <[email protected]>
> ---
> drivers/scsi/ufs/ufshcd.c | 31 ++++++++++++++++++-------------
> drivers/scsi/ufs/ufshcd.h | 5 +++++
> 2 files changed, 23 insertions(+), 13 deletions(-)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index 99bd3e4..eda4dc6 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -411,15 +411,6 @@ static void ufshcd_print_err_hist(struct ufs_hba *hba,
> static void ufshcd_print_host_regs(struct ufs_hba *hba)
> {
> ufshcd_dump_regs(hba, 0, UFSHCI_REG_SPACE_SIZE, "host_regs: ");
> - dev_err(hba->dev, "hba->ufs_version = 0x%x, hba->capabilities = 0x%x\n",
> - hba->ufs_version, hba->capabilities);
> - dev_err(hba->dev,
> - "hba->outstanding_reqs = 0x%x, hba->outstanding_tasks = 0x%x\n",
> - (u32)hba->outstanding_reqs, (u32)hba->outstanding_tasks);
> - dev_err(hba->dev,
> - "last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt = %d\n",
> - ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
> - hba->ufs_stats.hibern8_exit_cnt);
>
> ufshcd_print_err_hist(hba, &hba->ufs_stats.pa_err, "pa_err");
> ufshcd_print_err_hist(hba, &hba->ufs_stats.dl_err, "dl_err");
> @@ -438,8 +429,6 @@ static void ufshcd_print_host_regs(struct ufs_hba *hba)
> ufshcd_print_err_hist(hba, &hba->ufs_stats.host_reset, "host_reset");
> ufshcd_print_err_hist(hba, &hba->ufs_stats.task_abort, "task_abort");
>
> - ufshcd_print_clk_freqs(hba);
> -
> ufshcd_vops_dbg_register_dump(hba);
> }
>
> @@ -499,6 +488,8 @@ static void ufshcd_print_tmrs(struct ufs_hba *hba, unsigned long bitmap)
>
> static void ufshcd_print_host_state(struct ufs_hba *hba)
> {
> + struct scsi_device *sdev_ufs = hba->sdev_ufs_device;
> +
> dev_err(hba->dev, "UFS Host state=%d\n", hba->ufshcd_state);
> dev_err(hba->dev, "outstanding reqs=0x%lx tasks=0x%lx\n",
> hba->outstanding_reqs, hba->outstanding_tasks);
> @@ -511,12 +502,24 @@ static void ufshcd_print_host_state(struct ufs_hba *hba)
> dev_err(hba->dev, "Auto BKOPS=%d, Host self-block=%d\n",
> hba->auto_bkops_enabled, hba->host->host_self_blocked);
> dev_err(hba->dev, "Clk gate=%d\n", hba->clk_gating.state);
> + dev_err(hba->dev,
> + "last_hibern8_exit_tstamp at %lld us, hibern8_exit_cnt=%d\n",
> + ktime_to_us(hba->ufs_stats.last_hibern8_exit_tstamp),
> + hba->ufs_stats.hibern8_exit_cnt);
> + dev_err(hba->dev, "last intr at %lld us, last intr status=0x%x\n",
> + ktime_to_us(hba->ufs_stats.last_intr_ts),
> + hba->ufs_stats.last_intr_status);
> dev_err(hba->dev, "error handling flags=0x%x, req. abort count=%d\n",
> hba->eh_flags, hba->req_abort_count);
> - dev_err(hba->dev, "Host capabilities=0x%x, caps=0x%x\n",
> - hba->capabilities, hba->caps);
> + dev_err(hba->dev, "hba->ufs_version=0x%x, Host capabilities=0x%x, caps=0x%x\n",
> + hba->ufs_version, hba->capabilities, hba->caps);
> dev_err(hba->dev, "quirks=0x%x, dev. quirks=0x%x\n", hba->quirks,
> hba->dev_quirks);
> + if (sdev_ufs)
> + dev_err(hba->dev, "UFS dev info: %.8s %.16s rev %.4s\n",
> + sdev_ufs->vendor, sdev_ufs->model, sdev_ufs->rev);
> +
> + ufshcd_print_clk_freqs(hba);
> }
>
> /**
> @@ -5951,6 +5954,8 @@ static irqreturn_t ufshcd_intr(int irq, void *__hba)
>
> spin_lock(hba->host->host_lock);
> intr_status = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
> + hba->ufs_stats.last_intr_status = intr_status;
> + hba->ufs_stats.last_intr_ts = ktime_get();
>
> /*
> * There could be max of hba->nutrs reqs in flight and in worst case
> diff --git a/drivers/scsi/ufs/ufshcd.h b/drivers/scsi/ufs/ufshcd.h
> index 656c069..5b2cdaf 100644
> --- a/drivers/scsi/ufs/ufshcd.h
> +++ b/drivers/scsi/ufs/ufshcd.h
> @@ -406,6 +406,8 @@ struct ufs_err_reg_hist {
>
> /**
> * struct ufs_stats - keeps usage/err statistics
> + * @last_intr_status: record the last interrupt status.
> + * @last_intr_ts: record the last interrupt timestamp.
> * @hibern8_exit_cnt: Counter to keep track of number of exits,
> * reset this after link-startup.
> * @last_hibern8_exit_tstamp: Set time after the hibern8 exit.
> @@ -425,6 +427,9 @@ struct ufs_err_reg_hist {
> * @tsk_abort: tracks task abort events
> */
> struct ufs_stats {
> + u32 last_intr_status;
> + ktime_t last_intr_ts;
> +
> u32 hibern8_exit_cnt;
> ktime_t last_hibern8_exit_tstamp;
>
>
--
The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum,
Linux Foundation Collaborative Project
On Tue, 2020-07-28 at 13:00 +0800, Can Guo wrote:
> The infos of the last interrupt status and its timestamp are very helpful
> when debug system stability issues, e.g. IRQ starvation, so add them to
> ufshcd_print_host_state. Meanwhile, UFS device infos like model name and
> its FW version also come in handy during debug. In addition, this change
> makes cleanup to some prints in ufshcd_print_host_regs as similar prints
> are already available in ufshcd_print_host_state.
>
> Signed-off-by: Can Guo <[email protected]>
> Reviewed-by: Avri Altman <[email protected]>
Reviewed-by: Stanley Chu <[email protected]>