scsi: ufs: core: Log error handler activity

Kernel logs are hard to comprehend without information about what the UFS
error handler is doing. Hence this patch that logs information about error
handler activity.

Link: https://lore.kernel.org/r/20211020214024.2007615-5-bvanassche@acm.org
Acked-by: Avri Altman <Avri.Altman@wdc.com>
Signed-off-by: Bart Van Assche <bvanassche@acm.org>
Signed-off-by: Martin K. Petersen <martin.petersen@oracle.com>

diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index 610be6746f740bed23083174c5d541e188e77e90..49623bf3e87628760c5f1e173f691e82015a587e 100644 (file)
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -132,6 +132,14 @@ enum {
        UFSHCD_CAN_QUEUE        = 32,
 };
 
+static const char *const ufshcd_state_name[] = {
+       [UFSHCD_STATE_RESET]                    = "reset",
+       [UFSHCD_STATE_OPERATIONAL]              = "operational",
+       [UFSHCD_STATE_ERROR]                    = "error",
+       [UFSHCD_STATE_EH_SCHEDULED_FATAL]       = "eh_fatal",
+       [UFSHCD_STATE_EH_SCHEDULED_NON_FATAL]   = "eh_non_fatal",
+};
+
 /* UFSHCD error handling flags */
 enum {
        UFSHCD_EH_IN_PROGRESS = (1 << 0),
@@ -6069,6 +6077,13 @@ static void ufshcd_err_handler(struct work_struct *work)
 
        hba = container_of(work, struct ufs_hba, eh_work);
 
+       dev_info(hba->dev,
+                "%s started; HBA state %s; powered %d; shutting down %d; saved_err = %d; saved_uic_err = %d; force_reset = %d%s\n",
+                __func__, ufshcd_state_name[hba->ufshcd_state],
+                hba->is_powered, hba->shutting_down, hba->saved_err,
+                hba->saved_uic_err, hba->force_reset,
+                ufshcd_is_link_broken(hba) ? "; link is broken" : "");
+
        down(&hba->host_sem);
        spin_lock_irqsave(hba->host->host_lock, flags);
        if (ufshcd_err_handling_should_stop(hba)) {
@@ -6163,6 +6178,8 @@ again:
                        err_xfer = true;
                        goto lock_skip_pending_xfer_clear;
                }
+               dev_err(hba->dev, "Aborted tag %d / CDB %#02x\n", tag,
+                       hba->lrb[tag].cmd ? hba->lrb[tag].cmd->cmnd[0] : -1);
        }
 
        /* Clear pending task management requests */
@@ -6243,6 +6260,9 @@ skip_err_handling:
        spin_unlock_irqrestore(hba->host->host_lock, flags);
        ufshcd_err_handling_unprepare(hba);
        up(&hba->host_sem);
+
+       dev_info(hba->dev, "%s finished; HBA state %s\n", __func__,
+                ufshcd_state_name[hba->ufshcd_state]);
 }
 
 /**
@@ -6539,6 +6559,10 @@ static int ufshcd_clear_tm_cmd(struct ufs_hba *hba, int tag)
        err = ufshcd_wait_for_register(hba,
                        REG_UTP_TASK_REQ_DOOR_BELL,
                        mask, 0, 1000, 1000);
+
+       dev_err(hba->dev, "Clearing task management function with tag %d %s\n",
+               tag, err ? "succeeded" : "failed");
+
 out:
        return err;
 }