From: Bean Huo Date: Tue, 5 Jan 2021 11:34:42 +0000 (+0100) Subject: scsi: ufs: Use __print_symbolic() for UFS trace string print X-Git-Tag: v5.15~1607^2~221 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=28fa68fc557a7eba02615aa7d97a7cbcfa94559d;p=platform%2Fkernel%2Flinux-starfive.git scsi: ufs: Use __print_symbolic() for UFS trace string print __print_symbolic() is designed for exporting the print formatting table to userspace and allows parsing tool, such as trace-cmd and perf, to analyze trace log according to this print formatting table, meanwhile, by using __print_symbolic()s, save space in the trace ring buffer. original print format: print fmt: "%s: %s: HDR:%s, CDB:%s", __get_str(str), __get_str(dev_name), __print_hex(REC->hdr, sizeof(REC->hdr)), __print_hex(REC->tsf, sizeof(REC->tsf)) after this change: print fmt: "%s: %s: HDR:%s, CDB:%s", print_symbolic(REC->str_t, {0, "send"}, {1, "complete"}, {2, "dev_complete"}, {3, "query_send"}, {4, "query_complete"}, {5, "query_complete_err"}, {6, "tm_send"}, {7, "tm_complete"}, {8, "tm_complete_err"}), __get_str(dev_name), __print_hex(REC->hdr, sizeof(REC->hdr)), __print_hex(REC->tsf, sizeof(REC->tsf)) Note: This patch just converts current __get_str(str) to __print_symbolic(), the original tracing log will not be affected by this change, so it doesn't break what current parsers expect. Link: https://lore.kernel.org/r/20210105113446.16027-3-huobean@gmail.com Acked-by: Steven Rostedt (VMware) Signed-off-by: Bean Huo Signed-off-by: Martin K. Petersen --- diff --git a/drivers/scsi/ufs/ufs.h b/drivers/scsi/ufs/ufs.h index 14dfda7..ba24b50 100644 --- a/drivers/scsi/ufs/ufs.h +++ b/drivers/scsi/ufs/ufs.h @@ -545,6 +545,16 @@ struct ufs_dev_info { u8 b_presrv_uspc_en; }; +/* + * This enum is used in string mapping in include/trace/events/ufs.h. + */ +enum ufs_trace_str_t { + UFS_CMD_SEND, UFS_CMD_COMP, UFS_DEV_COMP, + UFS_QUERY_SEND, UFS_QUERY_COMP, UFS_QUERY_ERR, + UFS_TM_SEND, UFS_TM_COMP, UFS_TM_ERR +}; + + /** * ufs_is_valid_unit_desc_lun - checks if the given LUN has a unit descriptor * @dev_info: pointer of instance of struct ufs_dev_info diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c index ab65783..238db7d 100644 --- a/drivers/scsi/ufs/ufshcd.c +++ b/drivers/scsi/ufs/ufshcd.c @@ -305,53 +305,53 @@ static void ufshcd_scsi_block_requests(struct ufs_hba *hba) } static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag, - const char *str) + enum ufs_trace_str_t str_t) { struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr; - trace_ufshcd_upiu(dev_name(hba->dev), str, &rq->header, &rq->sc.cdb); + trace_ufshcd_upiu(dev_name(hba->dev), str_t, &rq->header, &rq->sc.cdb); } static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba, unsigned int tag, - const char *str) + enum ufs_trace_str_t str_t) { struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr; - trace_ufshcd_upiu(dev_name(hba->dev), str, &rq->header, &rq->qr); + trace_ufshcd_upiu(dev_name(hba->dev), str_t, &rq->header, &rq->qr); } static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int tag, - const char *str) + enum ufs_trace_str_t str_t) { int off = (int)tag - hba->nutrs; struct utp_task_req_desc *descp = &hba->utmrdl_base_addr[off]; - trace_ufshcd_upiu(dev_name(hba->dev), str, &descp->req_header, + trace_ufshcd_upiu(dev_name(hba->dev), str_t, &descp->req_header, &descp->input_param1); } static void ufshcd_add_uic_command_trace(struct ufs_hba *hba, struct uic_command *ucmd, - const char *str) + enum ufs_trace_str_t str_t) { u32 cmd; if (!trace_ufshcd_uic_command_enabled()) return; - if (!strcmp(str, "send")) + if (str_t == UFS_CMD_SEND) cmd = ucmd->command; else cmd = ufshcd_readl(hba, REG_UIC_COMMAND); - trace_ufshcd_uic_command(dev_name(hba->dev), str, cmd, + trace_ufshcd_uic_command(dev_name(hba->dev), str_t, cmd, ufshcd_readl(hba, REG_UIC_COMMAND_ARG_1), ufshcd_readl(hba, REG_UIC_COMMAND_ARG_2), ufshcd_readl(hba, REG_UIC_COMMAND_ARG_3)); } -static void ufshcd_add_command_trace(struct ufs_hba *hba, - unsigned int tag, const char *str) +static void ufshcd_add_command_trace(struct ufs_hba *hba, unsigned int tag, + enum ufs_trace_str_t str_t) { sector_t lba = -1; u8 opcode = 0, group_id = 0; @@ -363,13 +363,13 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, if (!trace_ufshcd_command_enabled()) { /* trace UPIU W/O tracing command */ if (cmd) - ufshcd_add_cmd_upiu_trace(hba, tag, str); + ufshcd_add_cmd_upiu_trace(hba, tag, str_t); return; } if (cmd) { /* data phase exists */ /* trace UPIU also */ - ufshcd_add_cmd_upiu_trace(hba, tag, str); + ufshcd_add_cmd_upiu_trace(hba, tag, str_t); opcode = cmd->cmnd[0]; if ((opcode == READ_10) || (opcode == WRITE_10)) { /* @@ -392,7 +392,7 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, 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, + trace_ufshcd_command(dev_name(hba->dev), str_t, tag, doorbell, transfer_len, intr, lba, opcode, group_id); } @@ -2001,7 +2001,7 @@ void ufshcd_send_command(struct ufs_hba *hba, unsigned int task_tag) lrbp->issue_time_stamp = ktime_get(); lrbp->compl_time_stamp = ktime_set(0, 0); ufshcd_vops_setup_xfer_req(hba, task_tag, (lrbp->cmd ? true : false)); - ufshcd_add_command_trace(hba, task_tag, "send"); + ufshcd_add_command_trace(hba, task_tag, UFS_CMD_SEND); 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); @@ -2137,7 +2137,7 @@ ufshcd_dispatch_uic_cmd(struct ufs_hba *hba, struct uic_command *uic_cmd) ufshcd_writel(hba, uic_cmd->argument2, REG_UIC_COMMAND_ARG_2); ufshcd_writel(hba, uic_cmd->argument3, REG_UIC_COMMAND_ARG_3); - ufshcd_add_uic_command_trace(hba, uic_cmd, "send"); + ufshcd_add_uic_command_trace(hba, uic_cmd, UFS_CMD_SEND); /* Write UIC Cmd */ ufshcd_writel(hba, uic_cmd->command & COMMAND_OPCODE_MASK, @@ -2856,7 +2856,7 @@ static int ufshcd_exec_dev_cmd(struct ufs_hba *hba, hba->dev_cmd.complete = &wait; - ufshcd_add_query_upiu_trace(hba, tag, "query_send"); + ufshcd_add_query_upiu_trace(hba, tag, UFS_QUERY_SEND); /* Make sure descriptors are ready before ringing the doorbell */ wmb(); spin_lock_irqsave(hba->host->host_lock, flags); @@ -2867,7 +2867,7 @@ static int ufshcd_exec_dev_cmd(struct ufs_hba *hba, out: ufshcd_add_query_upiu_trace(hba, tag, - err ? "query_complete_err" : "query_complete"); + err ? UFS_QUERY_ERR : UFS_QUERY_COMP); out_put_tag: blk_put_request(req); @@ -5030,7 +5030,7 @@ static irqreturn_t ufshcd_uic_cmd_compl(struct ufs_hba *hba, u32 intr_status) if (retval == IRQ_HANDLED) ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd, - "complete"); + UFS_CMD_COMP); return retval; } @@ -5054,7 +5054,7 @@ static void __ufshcd_transfer_req_compl(struct ufs_hba *hba, lrbp->compl_time_stamp = ktime_get(); cmd = lrbp->cmd; if (cmd) { - ufshcd_add_command_trace(hba, index, "complete"); + ufshcd_add_command_trace(hba, index, UFS_CMD_COMP); result = ufshcd_transfer_rsp_status(hba, lrbp); scsi_dma_unmap(cmd); cmd->result = result; @@ -5068,7 +5068,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_add_command_trace(hba, index, - "dev_complete"); + UFS_DEV_COMP); complete(hba->dev_cmd.complete); update_scaling = true; } @@ -6371,7 +6371,7 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba *hba, spin_unlock_irqrestore(host->host_lock, flags); - ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_send"); + ufshcd_add_tm_upiu_trace(hba, task_tag, UFS_TM_SEND); /* wait until the task management command is completed */ err = wait_for_completion_io_timeout(&wait, @@ -6382,7 +6382,7 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba *hba, * use-after-free. */ req->end_io_data = NULL; - ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_complete_err"); + ufshcd_add_tm_upiu_trace(hba, task_tag, UFS_TM_ERR); dev_err(hba->dev, "%s: task management cmd 0x%.2x timed-out\n", __func__, tm_function); if (ufshcd_clear_tm_cmd(hba, free_slot)) @@ -6393,7 +6393,7 @@ static int __ufshcd_issue_tm_cmd(struct ufs_hba *hba, err = 0; memcpy(treq, hba->utmrdl_base_addr + free_slot, sizeof(*treq)); - ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_complete"); + ufshcd_add_tm_upiu_trace(hba, task_tag, UFS_TM_COMP); } spin_lock_irqsave(hba->host->host_lock, flags); diff --git a/include/trace/events/ufs.h b/include/trace/events/ufs.h index fa75539..7613a5c 100644 --- a/include/trace/events/ufs.h +++ b/include/trace/events/ufs.h @@ -37,6 +37,17 @@ EM(REQ_CLKS_OFF, "REQ_CLKS_OFF") \ EMe(REQ_CLKS_ON, "REQ_CLKS_ON") +#define UFS_CMD_TRACE_STRINGS \ + EM(UFS_CMD_SEND, "send_req") \ + EM(UFS_CMD_COMP, "complete_rsp") \ + EM(UFS_DEV_COMP, "dev_complete") \ + EM(UFS_QUERY_SEND, "query_send") \ + EM(UFS_QUERY_COMP, "query_complete") \ + EM(UFS_QUERY_ERR, "query_complete_err") \ + EM(UFS_TM_SEND, "tm_send") \ + EM(UFS_TM_COMP, "tm_complete") \ + EMe(UFS_TM_ERR, "tm_complete_err") + /* Enums require being exported to userspace, for user tool parsing */ #undef EM #undef EMe @@ -46,6 +57,7 @@ UFS_LINK_STATES; UFS_PWR_MODES; UFSCHD_CLK_GATING_STATES; +UFS_CMD_TRACE_STRINGS /* * Now redefine the EM() and EMe() macros to map the enums to the strings @@ -56,6 +68,9 @@ UFSCHD_CLK_GATING_STATES; #define EM(a, b) {a, b}, #define EMe(a, b) {a, b} +#define show_ufs_cmd_trace_str(str_t) \ + __print_symbolic(str_t, UFS_CMD_TRACE_STRINGS) + TRACE_EVENT(ufshcd_clk_gating, TP_PROTO(const char *dev_name, int state), @@ -223,16 +238,16 @@ DEFINE_EVENT(ufshcd_template, ufshcd_init, TP_ARGS(dev_name, err, usecs, dev_state, link_state)); TRACE_EVENT(ufshcd_command, - TP_PROTO(const char *dev_name, const char *str, unsigned int tag, - u32 doorbell, int transfer_len, u32 intr, u64 lba, - u8 opcode, u8 group_id), + TP_PROTO(const char *dev_name, enum ufs_trace_str_t str_t, + unsigned int tag, u32 doorbell, int transfer_len, u32 intr, + u64 lba, u8 opcode, u8 group_id), - TP_ARGS(dev_name, str, tag, doorbell, transfer_len, + TP_ARGS(dev_name, str_t, tag, doorbell, transfer_len, intr, lba, opcode, group_id), TP_STRUCT__entry( __string(dev_name, dev_name) - __string(str, str) + __field(enum ufs_trace_str_t, str_t) __field(unsigned int, tag) __field(u32, doorbell) __field(int, transfer_len) @@ -244,7 +259,7 @@ TRACE_EVENT(ufshcd_command, TP_fast_assign( __assign_str(dev_name, dev_name); - __assign_str(str, str); + __entry->str_t = str_t; __entry->tag = tag; __entry->doorbell = doorbell; __entry->transfer_len = transfer_len; @@ -256,22 +271,22 @@ TRACE_EVENT(ufshcd_command, TP_printk( "%s: %s: tag: %u, DB: 0x%x, size: %d, IS: %u, LBA: %llu, opcode: 0x%x (%s), group_id: 0x%x", - __get_str(str), __get_str(dev_name), __entry->tag, - __entry->doorbell, __entry->transfer_len, + show_ufs_cmd_trace_str(__entry->str_t), __get_str(dev_name), + __entry->tag, __entry->doorbell, __entry->transfer_len, __entry->intr, __entry->lba, (u32)__entry->opcode, str_opcode(__entry->opcode), (u32)__entry->group_id ) ); TRACE_EVENT(ufshcd_uic_command, - TP_PROTO(const char *dev_name, const char *str, u32 cmd, + TP_PROTO(const char *dev_name, enum ufs_trace_str_t str_t, u32 cmd, u32 arg1, u32 arg2, u32 arg3), - TP_ARGS(dev_name, str, cmd, arg1, arg2, arg3), + TP_ARGS(dev_name, str_t, cmd, arg1, arg2, arg3), TP_STRUCT__entry( __string(dev_name, dev_name) - __string(str, str) + __field(enum ufs_trace_str_t, str_t) __field(u32, cmd) __field(u32, arg1) __field(u32, arg2) @@ -280,7 +295,7 @@ TRACE_EVENT(ufshcd_uic_command, TP_fast_assign( __assign_str(dev_name, dev_name); - __assign_str(str, str); + __entry->str_t = str_t; __entry->cmd = cmd; __entry->arg1 = arg1; __entry->arg2 = arg2; @@ -289,33 +304,34 @@ TRACE_EVENT(ufshcd_uic_command, TP_printk( "%s: %s: cmd: 0x%x, arg1: 0x%x, arg2: 0x%x, arg3: 0x%x", - __get_str(str), __get_str(dev_name), __entry->cmd, - __entry->arg1, __entry->arg2, __entry->arg3 + show_ufs_cmd_trace_str(__entry->str_t), __get_str(dev_name), + __entry->cmd, __entry->arg1, __entry->arg2, __entry->arg3 ) ); TRACE_EVENT(ufshcd_upiu, - TP_PROTO(const char *dev_name, const char *str, void *hdr, void *tsf), + TP_PROTO(const char *dev_name, enum ufs_trace_str_t str_t, void *hdr, + void *tsf), - TP_ARGS(dev_name, str, hdr, tsf), + TP_ARGS(dev_name, str_t, hdr, tsf), TP_STRUCT__entry( __string(dev_name, dev_name) - __string(str, str) + __field(enum ufs_trace_str_t, str_t) __array(unsigned char, hdr, 12) __array(unsigned char, tsf, 16) ), TP_fast_assign( __assign_str(dev_name, dev_name); - __assign_str(str, str); + __entry->str_t = str_t; memcpy(__entry->hdr, hdr, sizeof(__entry->hdr)); memcpy(__entry->tsf, tsf, sizeof(__entry->tsf)); ), TP_printk( "%s: %s: HDR:%s, CDB:%s", - __get_str(str), __get_str(dev_name), + show_ufs_cmd_trace_str(__entry->str_t), __get_str(dev_name), __print_hex(__entry->hdr, sizeof(__entry->hdr)), __print_hex(__entry->tsf, sizeof(__entry->tsf)) )