scsi: ufs: add command logging infrastructure

Add the necessary infrastructure to keep timestamp history
of commands, events and other useful info for debugging
complex issues. This helps in diagnosing events leading
upto failure.

Change-Id: I34f78b0c875262fa06c16d476be6255f7ae4d92f
Signed-off-by: Subhash Jadavani <subhashj@codeaurora.org>
Signed-off-by: Sayali Lokhande <sayalil@codeaurora.org>
[cang@codeaurora.org: fixed trivial merge conflicts and
compilation errors]
Signed-off-by: Can Guo <cang@codeaurora.org>
[cang@codeaurora.org: resolved trivial merge conflicts and
fixed kernel compilation errors]
Signed-off-by: Can Guo <cang@codeaurora.org>
This commit is contained in:
Can Guo 2017-04-18 16:22:56 +08:00
parent 90ac2be1d7
commit b7352cb1d2
3 changed files with 199 additions and 20 deletions

View File

@ -123,3 +123,15 @@ config SCSI_UFS_TEST
The UFS unit-tests register as a block device test utility to
the test-iosched and will be initiated when the test-iosched will
be chosen to be the active I/O scheduler.
config SCSI_UFSHCD_CMD_LOGGING
bool "Universal Flash Storage host controller driver layer command logging support"
depends on SCSI_UFSHCD
help
This selects the UFS host controller driver layer command logging.
UFS host controller driver layer command logging records all the
command information sent from UFS host controller for debugging
purpose.
Select this if you want above mentioned debug information captured.
If unsure, say N.

View File

@ -552,14 +552,145 @@ static inline void ufshcd_remove_non_printable(char *val)
*val = ' ';
}
#define UFSHCD_MAX_CMD_LOGGING 100
#ifdef CONFIG_TRACEPOINTS
static void ufshcd_add_command_trace(struct ufs_hba *hba,
unsigned int tag, const char *str)
static inline void ufshcd_add_command_trace(struct ufs_hba *hba,
struct ufshcd_cmd_log_entry *entry, u8 opcode)
{
if (trace_ufshcd_command_enabled()) {
u32 intr = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
trace_ufshcd_command(dev_name(hba->dev), entry->str, entry->tag,
entry->doorbell, entry->transfer_len, intr,
entry->lba, opcode);
}
}
#else
static inline void ufshcd_add_command_trace(struct ufs_hba *hba,
struct ufshcd_cmd_log_entry *entry, u8 opcode)
{
}
#endif
#ifdef CONFIG_SCSI_UFSHCD_CMD_LOGGING
static void ufshcd_cmd_log_init(struct ufs_hba *hba)
{
/* Allocate log entries */
if (!hba->cmd_log.entries) {
hba->cmd_log.entries = kzalloc(UFSHCD_MAX_CMD_LOGGING *
sizeof(struct ufshcd_cmd_log_entry), GFP_KERNEL);
if (!hba->cmd_log.entries)
return;
dev_dbg(hba->dev, "%s: cmd_log.entries initialized\n",
__func__);
}
}
static void __ufshcd_cmd_log(struct ufs_hba *hba, char *str, char *cmd_type,
unsigned int tag, u8 cmd_id, u8 idn, u8 lun,
sector_t lba, int transfer_len, u8 opcode)
{
struct ufshcd_cmd_log_entry *entry;
if (!hba->cmd_log.entries)
return;
entry = &hba->cmd_log.entries[hba->cmd_log.pos];
entry->lun = lun;
entry->str = str;
entry->cmd_type = cmd_type;
entry->cmd_id = cmd_id;
entry->lba = lba;
entry->transfer_len = transfer_len;
entry->idn = idn;
entry->doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
entry->tag = tag;
entry->tstamp = ktime_get();
entry->outstanding_reqs = hba->outstanding_reqs;
entry->seq_num = hba->cmd_log.seq_num;
hba->cmd_log.seq_num++;
hba->cmd_log.pos =
(hba->cmd_log.pos + 1) % UFSHCD_MAX_CMD_LOGGING;
ufshcd_add_command_trace(hba, entry, opcode);
}
static void ufshcd_cmd_log(struct ufs_hba *hba, char *str, char *cmd_type,
unsigned int tag, u8 cmd_id, u8 idn)
{
__ufshcd_cmd_log(hba, str, cmd_type, tag, cmd_id, idn,
0xff, (sector_t)-1, -1, -1);
}
static void ufshcd_dme_cmd_log(struct ufs_hba *hba, char *str, u8 cmd_id)
{
ufshcd_cmd_log(hba, str, "dme", 0xff, cmd_id, 0xff);
}
static void ufshcd_cmd_log_print(struct ufs_hba *hba)
{
int i;
int pos;
struct ufshcd_cmd_log_entry *p;
if (!hba->cmd_log.entries)
return;
pos = hba->cmd_log.pos;
for (i = 0; i < UFSHCD_MAX_CMD_LOGGING; i++) {
p = &hba->cmd_log.entries[pos];
pos = (pos + 1) % UFSHCD_MAX_CMD_LOGGING;
if (ktime_to_us(p->tstamp)) {
pr_err("%s: %s: seq_no=%u lun=0x%x cmd_id=0x%02x lba=0x%llx txfer_len=%d tag=%u, doorbell=0x%x outstanding=0x%x idn=%d time=%lld us\n",
p->cmd_type, p->str, p->seq_num,
p->lun, p->cmd_id, (unsigned long long)p->lba,
p->transfer_len, p->tag, p->doorbell,
p->outstanding_reqs, p->idn,
ktime_to_us(p->tstamp));
usleep_range(1000, 1100);
}
}
}
#else
static void ufshcd_cmd_log_init(struct ufs_hba *hba)
{
}
static void __ufshcd_cmd_log(struct ufs_hba *hba, char *str, char *cmd_type,
unsigned int tag, u8 cmd_id, u8 idn, u8 lun,
sector_t lba, int transfer_len, u8 opcode)
{
struct ufshcd_cmd_log_entry entry;
entry.str = str;
entry.lba = lba;
entry.transfer_len = transfer_len;
entry.doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
entry.tag = tag;
ufshcd_add_command_trace(hba, &entry, opcode);
}
static void ufshcd_dme_cmd_log(struct ufs_hba *hba, char *str, u8 cmd_id)
{
}
static void ufshcd_cmd_log_print(struct ufs_hba *hba)
{
}
#endif
#ifdef CONFIG_TRACEPOINTS
static inline void ufshcd_cond_add_cmd_trace(struct ufs_hba *hba,
unsigned int tag, const char *str)
{
sector_t lba = -1;
u8 opcode = 0;
u32 intr, doorbell;
struct ufshcd_lrb *lrbp;
char *cmd_type = NULL;
u8 opcode = 0;
u8 cmd_id = 0, idn = 0;
sector_t lba = -1;
int transfer_len = -1;
if (!trace_ufshcd_command_enabled())
@ -576,23 +707,28 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba,
*/
if (lrbp->cmd->request && lrbp->cmd->request->bio)
lba =
lrbp->cmd->request->bio->bi_iter.bi_sector;
lrbp->cmd->request->bio->bi_iter.bi_sector;
transfer_len = be32_to_cpu(
lrbp->ucd_req_ptr->sc.exp_data_transfer_len);
}
}
intr = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
trace_ufshcd_command(dev_name(hba->dev), str, tag,
doorbell, transfer_len, intr, lba, opcode);
}
if (lrbp->cmd && (lrbp->command_type == UTP_CMD_TYPE_SCSI)) {
cmd_type = "scsi";
cmd_id = (u8)(*lrbp->cmd->cmnd);
} else if (lrbp->command_type == UTP_CMD_TYPE_DEV_MANAGE) {
if (hba->dev_cmd.type == DEV_CMD_TYPE_NOP) {
cmd_type = "nop";
cmd_id = 0;
} else if (hba->dev_cmd.type == DEV_CMD_TYPE_QUERY) {
cmd_type = "query";
cmd_id = hba->dev_cmd.query.request.upiu_req.opcode;
idn = hba->dev_cmd.query.request.upiu_req.idn;
}
}
static inline void ufshcd_cond_add_cmd_trace(struct ufs_hba *hba,
unsigned int tag, const char *str)
{
if (trace_ufshcd_command_enabled())
ufshcd_add_command_trace(hba, tag, str);
__ufshcd_cmd_log(hba, (char *) str, cmd_type, tag, cmd_id, idn,
lrbp->lun, lba, transfer_len, opcode);
}
#else
static inline void ufshcd_cond_add_cmd_trace(struct ufs_hba *hba,
@ -2814,6 +2950,7 @@ ufshcd_dispatch_uic_cmd(struct ufs_hba *hba, struct uic_command *uic_cmd)
hba->active_uic_cmd = uic_cmd;
ufshcd_dme_cmd_log(hba, "send", hba->active_uic_cmd->command);
/* Write Args */
ufshcd_writel(hba, uic_cmd->argument1, REG_UIC_COMMAND_ARG_1);
ufshcd_writel(hba, uic_cmd->argument2, REG_UIC_COMMAND_ARG_2);
@ -2847,6 +2984,8 @@ ufshcd_wait_for_uic_cmd(struct ufs_hba *hba, struct uic_command *uic_cmd)
if (ret)
ufsdbg_set_err_state(hba);
ufshcd_dme_cmd_log(hba, "cmp1", hba->active_uic_cmd->command);
spin_lock_irqsave(hba->host->host_lock, flags);
hba->active_uic_cmd = NULL;
spin_unlock_irqrestore(hba->host->host_lock, flags);
@ -4778,6 +4917,8 @@ static int ufshcd_uic_pwr_ctrl(struct ufs_hba *hba, struct uic_command *cmd)
cmd->command, status);
ret = (status != PWR_OK) ? status : -1;
}
ufshcd_dme_cmd_log(hba, "cmp2", hba->active_uic_cmd->command);
out:
if (ret) {
ufsdbg_set_err_state(hba);
@ -5991,7 +6132,7 @@ static void __ufshcd_transfer_req_compl(struct ufs_hba *hba,
lrbp->command_type == UTP_CMD_TYPE_UFS_STORAGE) {
if (hba->dev_cmd.complete) {
ufshcd_cond_add_cmd_trace(hba, index,
"dev_complete");
"dcmp");
complete(hba->dev_cmd.complete);
}
}
@ -6026,7 +6167,7 @@ void ufshcd_abort_outstanding_transfer_requests(struct ufs_hba *hba, int result)
lrbp = &hba->lrb[index];
cmd = lrbp->cmd;
if (cmd) {
ufshcd_add_command_trace(hba, index, "failed");
ufshcd_cond_add_cmd_trace(hba, index, "failed");
ufshcd_update_error_stats(hba,
UFS_ERR_INT_FATAL_ERRORS);
scsi_dma_unmap(cmd);
@ -6048,7 +6189,7 @@ void ufshcd_abort_outstanding_transfer_requests(struct ufs_hba *hba, int result)
cmd->scsi_done(cmd);
} else if (lrbp->command_type == UTP_CMD_TYPE_DEV_MANAGE) {
if (hba->dev_cmd.complete) {
ufshcd_add_command_trace(hba, index,
ufshcd_cond_add_cmd_trace(hba, index,
"dev_failed");
ufshcd_outstanding_req_clear(hba, index);
complete(hba->dev_cmd.complete);
@ -6529,6 +6670,7 @@ static void ufshcd_err_handler(struct work_struct *work)
ufshcd_print_host_state(hba);
ufshcd_print_pwr_info(hba);
ufshcd_print_tmrs(hba, hba->outstanding_tasks);
ufshcd_cmd_log_print(hba);
spin_lock_irqsave(hba->host->host_lock, flags);
}
}
@ -7048,6 +7190,7 @@ static int ufshcd_eh_device_reset_handler(struct scsi_cmnd *cmd)
hba = shost_priv(host);
tag = cmd->request->tag;
ufshcd_cmd_log_print(hba);
lrbp = &hba->lrb[tag];
err = ufshcd_issue_tm_cmd(hba, lrbp->lun, 0, UFS_LOGICAL_RESET, &resp);
if (err || resp != UPIU_TASK_MANAGEMENT_FUNC_COMPL) {
@ -10194,6 +10337,8 @@ int ufshcd_init(struct ufs_hba *hba, void __iomem *mmio_base, unsigned int irq)
*/
ufshcd_set_ufs_dev_active(hba);
ufshcd_cmd_log_init(hba);
async_schedule(ufshcd_async_scan, hba);
ufsdbg_add_debugfs(hba);

View File

@ -519,7 +519,7 @@ struct ufs_clk_scaling {
bool is_scaled_up;
};
#define UIC_ERR_REG_HIST_LENGTH 8
#define UIC_ERR_REG_HIST_LENGTH 20
/**
* struct ufs_uic_err_reg_hist - keeps history of uic errors
* @pos: index to indicate cyclic buffer position
@ -640,6 +640,27 @@ struct ufs_stats {
UFSHCD_DBG_PRINT_TMRS_EN | UFSHCD_DBG_PRINT_PWR_EN | \
UFSHCD_DBG_PRINT_HOST_STATE_EN)
struct ufshcd_cmd_log_entry {
char *str; /* context like "send", "complete" */
char *cmd_type; /* "scsi", "query", "nop", "dme" */
u8 lun;
u8 cmd_id;
sector_t lba;
int transfer_len;
u8 idn; /* used only for query idn */
u32 doorbell;
u32 outstanding_reqs;
u32 seq_num;
unsigned int tag;
ktime_t tstamp;
};
struct ufshcd_cmd_log {
struct ufshcd_cmd_log_entry *entries;
int pos;
u32 seq_num;
};
/**
* struct ufs_hba - per adapter private structure
* @mmio_base: UFSHCI base register address
@ -898,6 +919,7 @@ struct ufs_hba {
struct ufs_clk_gating clk_gating;
struct ufs_hibern8_on_idle hibern8_on_idle;
struct ufshcd_cmd_log cmd_log;
/* Control to enable/disable host capabilities */
u32 caps;