diff --git a/drivers/scsi/ufs/ufs-debugfs.c b/drivers/scsi/ufs/ufs-debugfs.c index 6d6b82126d6a..9aaf7e5eaf92 100644 --- a/drivers/scsi/ufs/ufs-debugfs.c +++ b/drivers/scsi/ufs/ufs-debugfs.c @@ -960,6 +960,70 @@ DEFINE_SIMPLE_ATTRIBUTE(ufsdbg_dbg_print_en_ops, ufsdbg_dbg_print_en_set, "%llu\n"); +static ssize_t ufsdbg_req_stats_write(struct file *filp, + const char __user *ubuf, size_t cnt, loff_t *ppos) +{ + struct ufs_hba *hba = filp->f_mapping->host->i_private; + int val; + int ret; + unsigned long flags; + + ret = kstrtoint_from_user(ubuf, cnt, 0, &val); + if (ret) { + dev_err(hba->dev, "%s: Invalid argument\n", __func__); + return ret; + } + + spin_lock_irqsave(hba->host->host_lock, flags); + ufshcd_init_req_stats(hba); + spin_unlock_irqrestore(hba->host->host_lock, flags); + + return cnt; +} + +static int ufsdbg_req_stats_show(struct seq_file *file, void *data) +{ + struct ufs_hba *hba = (struct ufs_hba *)file->private; + int i; + unsigned long flags; + + /* Header */ + seq_printf(file, "\t%-10s %-10s %-10s %-10s %-10s %-10s", + "All", "Write", "Read", "Read(urg)", "Write(urg)", "Flush"); + + spin_lock_irqsave(hba->host->host_lock, flags); + + seq_printf(file, "\n%s:\t", "Min"); + for (i = 0; i < TS_NUM_STATS; i++) + seq_printf(file, "%-10llu ", hba->ufs_stats.req_stats[i].min); + seq_printf(file, "\n%s:\t", "Max"); + for (i = 0; i < TS_NUM_STATS; i++) + seq_printf(file, "%-10llu ", hba->ufs_stats.req_stats[i].max); + seq_printf(file, "\n%s:\t", "Avg."); + for (i = 0; i < TS_NUM_STATS; i++) + seq_printf(file, "%-10llu ", + div64_u64(hba->ufs_stats.req_stats[i].sum, + hba->ufs_stats.req_stats[i].count)); + seq_printf(file, "\n%s:\t", "Count"); + for (i = 0; i < TS_NUM_STATS; i++) + seq_printf(file, "%-10llu ", hba->ufs_stats.req_stats[i].count); + seq_puts(file, "\n"); + spin_unlock_irqrestore(hba->host->host_lock, flags); + + return 0; +} + +static int ufsdbg_req_stats_open(struct inode *inode, struct file *file) +{ + return single_open(file, ufsdbg_req_stats_show, inode->i_private); +} + +static const struct file_operations ufsdbg_req_stats_desc = { + .open = ufsdbg_req_stats_open, + .read = seq_read, + .write = ufsdbg_req_stats_write, +}; + void ufsdbg_add_debugfs(struct ufs_hba *hba) { if (!hba) { @@ -1076,6 +1140,17 @@ void ufsdbg_add_debugfs(struct ufs_hba *hba) goto err; } + hba->debugfs_files.req_stats = + debugfs_create_file("req_stats", S_IRUSR | S_IWUSR, + hba->debugfs_files.debugfs_root, hba, + &ufsdbg_req_stats_desc); + if (!hba->debugfs_files.req_stats) { + dev_err(hba->dev, + "%s: failed create req_stats debugfs entry\n", + __func__); + goto err; + } + ufsdbg_setup_fault_injection(hba); if (hba->vops && hba->vops->add_debugfs) diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c index 7d0902b58d90..a6812007aacb 100644 --- a/drivers/scsi/ufs/ufshcd.c +++ b/drivers/scsi/ufs/ufshcd.c @@ -52,6 +52,23 @@ #ifdef CONFIG_DEBUG_FS +static int ufshcd_tag_req_type(struct request *rq) +{ + int rq_type = TS_WRITE; + + if (!rq || !(rq->cmd_type & REQ_TYPE_FS)) + rq_type = TS_NOT_SUPPORTED; + else if (rq->cmd_flags & REQ_FLUSH) + rq_type = TS_FLUSH; + else if (rq_data_dir(rq) == READ) + rq_type = (rq->cmd_flags & REQ_URGENT) ? + TS_URGENT_READ : TS_READ; + else if (rq->cmd_flags & REQ_URGENT) + rq_type = TS_URGENT_WRITE; + + return rq_type; +} + #define UFSHCD_UPDATE_ERROR_STATS(hba, type) \ do { \ if (type < UFS_ERR_MAX) \ @@ -63,20 +80,14 @@ struct request *rq = hba->lrb[task_tag].cmd ? \ hba->lrb[task_tag].cmd->request : NULL; \ u64 **tag_stats = hba->ufs_stats.tag_stats; \ - int rq_type = TS_WRITE; \ + int rq_type; \ if (!hba->ufs_stats.enabled) \ break; \ tag_stats[tag][TS_TAG]++; \ if (!rq || !(rq->cmd_type & REQ_TYPE_FS)) \ break; \ WARN_ON(hba->ufs_stats.q_depth > hba->nutrs); \ - if (rq->cmd_flags & REQ_FLUSH) \ - rq_type = TS_FLUSH; \ - else if (rq_data_dir(rq) == READ) \ - rq_type = (rq->cmd_flags & REQ_URGENT) ?\ - TS_URGENT_READ : TS_READ; \ - else if (rq->cmd_flags & REQ_URGENT) \ - rq_type = TS_URGENT_WRITE; \ + rq_type = ufshcd_tag_req_type(rq); \ tag_stats[hba->ufs_stats.q_depth++][rq_type]++; \ } while (0) @@ -91,12 +102,47 @@ #define UFSDBG_REMOVE_DEBUGFS(hba) ufsdbg_remove_debugfs(hba); +static void update_req_stats(struct ufs_hba *hba, struct ufshcd_lrb *lrbp) +{ + int rq_type; + struct request *rq = lrbp->cmd ? lrbp->cmd->request : NULL; + s64 delta = ktime_us_delta(lrbp->complete_time_stamp, + lrbp->issue_time_stamp); + + /* update general request statistics */ + if (hba->ufs_stats.req_stats[TS_TAG].count == 0) + hba->ufs_stats.req_stats[TS_TAG].min = delta; + hba->ufs_stats.req_stats[TS_TAG].count++; + hba->ufs_stats.req_stats[TS_TAG].sum += delta; + if (delta > hba->ufs_stats.req_stats[TS_TAG].max) + hba->ufs_stats.req_stats[TS_TAG].max = delta; + if (delta < hba->ufs_stats.req_stats[TS_TAG].min) + hba->ufs_stats.req_stats[TS_TAG].min = delta; + + rq_type = ufshcd_tag_req_type(rq); + if (rq_type == TS_NOT_SUPPORTED) + return; + + /* update request type specific statistics */ + if (hba->ufs_stats.req_stats[rq_type].count == 0) + hba->ufs_stats.req_stats[rq_type].min = delta; + hba->ufs_stats.req_stats[rq_type].count++; + hba->ufs_stats.req_stats[rq_type].sum += delta; + if (delta > hba->ufs_stats.req_stats[rq_type].max) + hba->ufs_stats.req_stats[rq_type].max = delta; + if (delta < hba->ufs_stats.req_stats[rq_type].min) + hba->ufs_stats.req_stats[rq_type].min = delta; +} + #else #define UFSHCD_UPDATE_TAG_STATS(hba, tag) #define UFSHCD_UPDATE_TAG_STATS_COMPLETION(hba, cmd) #define UFSDBG_ADD_DEBUGFS(hba) #define UFSDBG_REMOVE_DEBUGFS(hba) #define UFSHCD_UPDATE_ERROR_STATS(hba, type) +static inline +void update_req_stats(struct ufs_hba *hba, struct ufshcd_lrb *lrbp) +{} #endif @@ -1941,10 +1987,11 @@ int ufshcd_send_command(struct ufs_hba *hba, unsigned int task_tag) } hba->lrb[task_tag].issue_time_stamp = ktime_get(); + hba->lrb[task_tag].complete_time_stamp = ktime_set(0, 0); ufshcd_clk_scaling_start_busy(hba); __set_bit(task_tag, &hba->outstanding_reqs); ufshcd_writel(hba, 1 << task_tag, REG_UTP_TRANSFER_REQ_DOOR_BELL); - /* Make sure that doorbell is commited immediately */ + /* Make sure that doorbell is committed immediately */ wmb(); ufshcd_cond_add_cmd_trace(hba, task_tag, "send"); UFSHCD_UPDATE_TAG_STATS(hba, task_tag); @@ -4785,12 +4832,14 @@ void ufshcd_abort_outstanding_transfer_requests(struct ufs_hba *hba, int result) UFS_ERR_INT_FATAL_ERRORS); scsi_dma_unmap(cmd); cmd->result = result; - /* Mark completed command as NULL in LRB */ - lrbp->cmd = NULL; /* Clear pending transfer requests */ ufshcd_clear_cmd(hba, index); ufshcd_outstanding_req_clear(hba, index); clear_bit_unlock(index, &hba->lrb_in_use); + lrbp->complete_time_stamp = ktime_get(); + update_req_stats(hba, lrbp); + /* Mark completed command as NULL in LRB */ + lrbp->cmd = NULL; /* Do not touch lrbp after scsi done */ cmd->scsi_done(cmd); ufshcd_release_all(hba); @@ -4827,9 +4876,11 @@ static void __ufshcd_transfer_req_compl(struct ufs_hba *hba, result = ufshcd_transfer_rsp_status(hba, lrbp); scsi_dma_unmap(cmd); cmd->result = result; + clear_bit_unlock(index, &hba->lrb_in_use); + lrbp->complete_time_stamp = ktime_get(); + update_req_stats(hba, lrbp); /* Mark completed command as NULL in LRB */ lrbp->cmd = NULL; - clear_bit_unlock(index, &hba->lrb_in_use); /* Do not touch lrbp after scsi done */ cmd->scsi_done(cmd); __ufshcd_release(hba, false); diff --git a/drivers/scsi/ufs/ufshcd.h b/drivers/scsi/ufs/ufshcd.h index a0d27d99cd08..f1f80de78556 100644 --- a/drivers/scsi/ufs/ufshcd.h +++ b/drivers/scsi/ufs/ufshcd.h @@ -187,6 +187,7 @@ struct ufs_pm_lvl_states { * @lun: LUN of the command * @intr_cmd: Interrupt command (doesn't participate in interrupt aggregation) * @issue_time_stamp: time stamp for debug purposes + * @complete_time_stamp: time stamp for statistics * @req_abort_skip: skip request abort task flag */ struct ufshcd_lrb { @@ -210,6 +211,7 @@ struct ufshcd_lrb { u8 lun; /* UPIU LUN id field is only 8-bit wide */ bool intr_cmd; ktime_t issue_time_stamp; + ktime_t complete_time_stamp; bool req_abort_skip; }; @@ -456,38 +458,6 @@ struct ufs_uic_err_reg_hist { ktime_t tstamp[UIC_ERR_REG_HIST_LENGTH]; }; -/** - * struct ufs_stats - keeps usage/err statistics - * @enabled: enable tagstats for debugfs - * @tag_stats: pointer to tag statistic counters - * @q_depth: current amount of busy slots - * @err_stats: counters to keep track of various errors - * @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. - * Clear after the first successful command completion. - * @pa_err: tracks pa-uic errors - * @dl_err: tracks dl-uic errors - * @nl_err: tracks nl-uic errors - * @tl_err: tracks tl-uic errors - * @dme_err: tracks dme errors - */ -struct ufs_stats { -#ifdef CONFIG_DEBUG_FS - bool enabled; - u64 **tag_stats; - int q_depth; - int err_stats[UFS_ERR_MAX]; -#endif - u32 hibern8_exit_cnt; - ktime_t last_hibern8_exit_tstamp; - struct ufs_uic_err_reg_hist pa_err; - struct ufs_uic_err_reg_hist dl_err; - struct ufs_uic_err_reg_hist nl_err; - struct ufs_uic_err_reg_hist tl_err; - struct ufs_uic_err_reg_hist dme_err; -}; - #ifdef CONFIG_DEBUG_FS struct debugfs_files { struct dentry *debugfs_root; @@ -500,6 +470,7 @@ struct debugfs_files { struct dentry *dme_local_read; struct dentry *dme_peer_read; struct dentry *dbg_print_en; + struct dentry *req_stats; u32 dme_local_attr_id; u32 dme_peer_attr_id; #ifdef CONFIG_UFS_FAULT_INJECTION @@ -519,8 +490,56 @@ enum ts_types { TS_FLUSH = 5, TS_NUM_STATS = 6, }; + +/** + * struct ufshcd_req_stat - statistics for request handling times (in usec) + * @min: shortest time measured + * @max: longest time measured + * @sum: sum of all the handling times measured (used for average calculation) + * @count: number of measurements taken + */ +struct ufshcd_req_stat { + u64 min; + u64 max; + u64 sum; + u64 count; +}; #endif +/** + * struct ufs_stats - keeps usage/err statistics + * @enabled: enable tag stats for debugfs + * @tag_stats: pointer to tag statistic counters + * @q_depth: current amount of busy slots + * @err_stats: counters to keep track of various errors + * @req_stat: request handling time statistics per request type + * @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. + * Clear after the first successful command completion. + * @pa_err: tracks pa-uic errors + * @dl_err: tracks dl-uic errors + * @nl_err: tracks nl-uic errors + * @tl_err: tracks tl-uic errors + * @dme_err: tracks dme errors + */ +struct ufs_stats { +#ifdef CONFIG_DEBUG_FS + bool enabled; + u64 **tag_stats; + int q_depth; + int err_stats[UFS_ERR_MAX]; + struct ufshcd_req_stat req_stats[TS_NUM_STATS]; +#endif + u32 hibern8_exit_cnt; + ktime_t last_hibern8_exit_tstamp; + struct ufs_uic_err_reg_hist pa_err; + struct ufs_uic_err_reg_hist dl_err; + struct ufs_uic_err_reg_hist nl_err; + struct ufs_uic_err_reg_hist tl_err; + struct ufs_uic_err_reg_hist dme_err; +}; + /* PM QoS voting state */ enum ufshcd_pm_qos_state { PM_QOS_UNVOTED, @@ -974,6 +993,11 @@ static inline bool ufshcd_is_hs_mode(struct ufs_pa_layer_attr *pwr_info) pwr_info->pwr_tx == FASTAUTO_MODE); } +static inline void ufshcd_init_req_stats(struct ufs_hba *hba) +{ + memset(hba->ufs_stats.req_stats, 0, sizeof(hba->ufs_stats.req_stats)); +} + #define ASCII_STD true #define UTF16_STD false int ufshcd_read_string_desc(struct ufs_hba *hba, int desc_index, u8 *buf,