>
> This includes functions to record contexts of incoming commands
> in a circular queue. ufshcd.c has already some function
> tracer calls to get command history but ftrace would be
> gone when system dies before you get the information,
> such as panic cases.
Maybe add one more line explaining how you are handling dump_on_oops differently
>
> This patch also implements callbacks compl_xfer_req
> to store IO contexts at completion times.
>
> When you turn on CONFIG_SCSI_UFS_EXYNOS_CMD_LOG,
> the driver collects the information from incoming commands
> in the circular queue.
>
> Signed-off-by: Kiwoong Kim <kwmad.kim@xxxxxxxxxxx>
> ---
> drivers/scsi/ufs/Kconfig | 14 +++
> drivers/scsi/ufs/Makefile | 2 +-
> drivers/scsi/ufs/ufs-exynos-dbg.c | 201
> ++++++++++++++++++++++++++++++++++++++
> drivers/scsi/ufs/ufs-exynos-if.h | 17 ++++
> drivers/scsi/ufs/ufs-exynos.c | 37 +++++++
> drivers/scsi/ufs/ufs-exynos.h | 12 +++
> 6 files changed, 282 insertions(+), 1 deletion(-)
> create mode 100644 drivers/scsi/ufs/ufs-exynos-dbg.c
> create mode 100644 drivers/scsi/ufs/ufs-exynos-if.h
>
> diff --git a/drivers/scsi/ufs/Kconfig b/drivers/scsi/ufs/Kconfig
> index 8cd9026..ebab446 100644
> --- a/drivers/scsi/ufs/Kconfig
> +++ b/drivers/scsi/ufs/Kconfig
> @@ -172,3 +172,17 @@ config SCSI_UFS_EXYNOS
>
> Select this if you have UFS host controller on EXYNOS chipset.
> If unsure, say N.
> +
> +config SCSI_UFS_EXYNOS_CMD_LOG
> + bool "EXYNOS specific command log"
> + default n
> + depends on SCSI_UFS_EXYNOS
> + help
> + This selects EXYNOS specific functions to get and even print
> + some information to see what's happening at both command
> + issue time completion time.
> + The information may contain gerernal things as well as
Typo: gerernal -> general
> + EXYNOS specific, such as vendor specific hardware contexts.
> +
> + Select this if you want to get and print the information.
> + If unsure, say N.
> diff --git a/drivers/scsi/ufs/Makefile b/drivers/scsi/ufs/Makefile
> index f0c5b95..d9e4da7 100644
> --- a/drivers/scsi/ufs/Makefile
> +++ b/drivers/scsi/ufs/Makefile
> @@ -4,7 +4,7 @@ obj-$(CONFIG_SCSI_UFS_DWC_TC_PCI) += tc-dwc-g210-pci.o
> ufshcd-dwc.o tc-dwc-g210.
> obj-$(CONFIG_SCSI_UFS_DWC_TC_PLATFORM) += tc-dwc-g210-pltfrm.o
> ufshcd-dwc.o tc-dwc-g210.o
> obj-$(CONFIG_SCSI_UFS_CDNS_PLATFORM) += cdns-pltfrm.o
> obj-$(CONFIG_SCSI_UFS_QCOM) += ufs-qcom.o
> -obj-$(CONFIG_SCSI_UFS_EXYNOS) += ufs-exynos.o
> +obj-$(CONFIG_SCSI_UFS_EXYNOS) += ufs-exynos.o ufs-exynos-dbg.o
If the key functionality depends on SCSI_UFS_EXYNOS_CMD_LOG,
Why not use it for make as well, and in your header as well?
> obj-$(CONFIG_SCSI_UFSHCD) += ufshcd-core.o
> ufshcd-core-y += ufshcd.o ufs-sysfs.o
> ufshcd-core-$(CONFIG_SCSI_UFS_BSG) += ufs_bsg.o
> diff --git a/drivers/scsi/ufs/ufs-exynos-dbg.c b/drivers/scsi/ufs/ufs-exynos-
> dbg.c
> new file mode 100644
> index 0000000..0663026
> --- /dev/null
> +++ b/drivers/scsi/ufs/ufs-exynos-dbg.c
> @@ -0,0 +1,201 @@
> +// SPDX-License-Identifier: GPL-2.0-only
> +/*
> + * UFS Exynos debugging functions
> + *
> + * Copyright (C) 2020 Samsung Electronics Co., Ltd.
> + * Author: Kiwoong Kim <kwmad.kim@xxxxxxxxxxx>
> + *
> + */
> +#include <linux/platform_device.h>
> +#include <linux/module.h>
> +#include "ufshcd.h"
> +#include "ufs-exynos-if.h"
> +
> +#define MAX_CMD_LOGS 32
> +
> +struct cmd_data {
> + unsigned int tag;
> + unsigned int sct;
> + u64 lba;
> + u64 start_time;
> + u64 end_time;
> + u64 outstanding_reqs;
> + int retries;
> + u8 op;
> +};
> +
> +struct ufs_cmd_info {
> + u32 total;
> + u32 last;
> + struct cmd_data data[MAX_CMD_LOGS];
> + struct cmd_data *pdata[MAX_CMD_LOGS];
> +};
> +
> +/*
> + * This structure points out several contexts on debugging
> + * per one host instant.
> + * Now command history exists in here but later handle may
> + * contains some mmio base addresses including vendor specific
> + * regions to get hardware contexts.
> + */
> +struct ufs_s_dbg_mgr {
> + struct ufs_exynos_handle *handle;
> + int active;
> + u64 first_time;
> + u64 time;
> +
> + /* cmd log */
> + struct ufs_cmd_info cmd_info;
> + struct cmd_data cmd_log; /* temp buffer to put */
> + spinlock_t cmd_lock;
> +};
> +
> +static void ufs_s_print_cmd_log(struct ufs_s_dbg_mgr *mgr, struct device
> *dev)
> +{
> + struct ufs_cmd_info *cmd_info = &mgr->cmd_info;
> + struct cmd_data *data = cmd_info->data;
> + u32 i;
> + u32 last;
> + u32 max = MAX_CMD_LOGS;
> + unsigned long flags;
> + u32 total;
> +
> + spin_lock_irqsave(&mgr->cmd_lock, flags);
> + total = cmd_info->total;
> + if (cmd_info->total < max)
> + max = cmd_info->total;
> + last = (cmd_info->last + MAX_CMD_LOGS - 1) % MAX_CMD_LOGS;
> + spin_unlock_irqrestore(&mgr->cmd_lock, flags);
> +
> + dev_err(dev, ":---------------------------------------------------\n");
> + dev_err(dev, ":\t\tSCSI CMD(%u)\n", total - 1);
> + dev_err(dev, ":---------------------------------------------------\n");
> + dev_err(dev, ":OP, TAG, LBA, SCT, RETRIES, STIME, ETIME, REQS\n\n");
> +
> + for (i = 0 ; i < max ; i++, data++) {
> + dev_err(dev, ": 0x%02x, %02d, 0x%08llx, 0x%04x, %d, %llu, %llu,
> 0x%llx %s",
> + data->op, data->tag, data->lba, data->sct, data->retries,
> + data->start_time, data->end_time, data->outstanding_reqs,
> + ((last == i) ? "<--" : " "));
> + if (last == i)
> + dev_err(dev, "\n");
> + }
> +}
Since you cache last, why not printing from first to last instead of marking it?
> +
> +static void ufs_s_put_cmd_log(struct ufs_s_dbg_mgr *mgr,
> + struct cmd_data *cmd_data)
> +{
> + struct ufs_cmd_info *cmd_info = &mgr->cmd_info;
> + unsigned long flags;
> + struct cmd_data *pdata;
> +
> + spin_lock_irqsave(&mgr->cmd_lock, flags);
> + pdata = &cmd_info->data[cmd_info->last];
> + ++cmd_info->total;
> + ++cmd_info->last;
> + cmd_info->last = cmd_info->last % MAX_CMD_LOGS;
> + spin_unlock_irqrestore(&mgr->cmd_lock, flags);
> +
> + pdata->op = cmd_data->op;
> + pdata->tag = cmd_data->tag;
> + pdata->lba = cmd_data->lba;
> + pdata->sct = cmd_data->sct;
> + pdata->retries = cmd_data->retries;
> + pdata->start_time = cmd_data->start_time;
> + pdata->end_time = 0;
> + pdata->outstanding_reqs = cmd_data->outstanding_reqs;
> + cmd_info->pdata[cmd_data->tag] = pdata;
> +}
> +
> +/*
> + * EXTERNAL FUNCTIONS
> + *
> + * There are two classes that are to initialize data structures for debug
> + * and to define actual behavior.
> + */
> +void exynos_ufs_dump_info(struct ufs_exynos_handle *handle, struct device
> *dev)
> +{
> + struct ufs_s_dbg_mgr *mgr = (struct ufs_s_dbg_mgr *)handle->private;
> +
> + if (mgr->active == 0)
> + goto out;
> +
> + mgr->time = cpu_clock(raw_smp_processor_id());
> +
> +#ifdef CONFIG_SCSI_UFS_EXYNOS_CMD_LOG
> + ufs_s_print_cmd_log(mgr, dev);
> +#endif
> +
> + if (mgr->first_time == 0ULL)
> + mgr->first_time = mgr->time;
> +out:
> + return;
> +}
> +
> +void exynos_ufs_cmd_log_start(struct ufs_exynos_handle *handle,
> + struct ufs_hba *hba, struct scsi_cmnd *cmd)
> +{
> + struct ufs_s_dbg_mgr *mgr = (struct ufs_s_dbg_mgr *)handle->private;
> + int cpu = raw_smp_processor_id();
> + struct cmd_data *cmd_log = &mgr->cmd_log; /* temp buffer to put
> */
> + u64 lba = (cmd->cmnd[2] << 24) |
> + (cmd->cmnd[3] << 16) |
> + (cmd->cmnd[4] << 8) |
> + (cmd->cmnd[5] << 0);
Use put_unaligned?
> + unsigned int sct = (cmd->cmnd[7] << 8) |
> + (cmd->cmnd[8] << 0);
ditto
> +
> + if (mgr->active == 0)
> + return;
> +
> + cmd_log->start_time = cpu_clock(cpu);
> + cmd_log->op = cmd->cmnd[0];
> + cmd_log->tag = cmd->request->tag;
> +
> + /* This function runtime is protected by spinlock from outside */
> + cmd_log->outstanding_reqs = hba->outstanding_reqs;
> +
> + /* unmap */
> + if (cmd->cmnd[0] != UNMAP)
> + cmd_log->lba = lba;
> +
> + cmd_log->sct = sct;
> + cmd_log->retries = cmd->allowed;
> +
> + ufs_s_put_cmd_log(mgr, cmd_log);
> +}
> +
> +void exynos_ufs_cmd_log_end(struct ufs_exynos_handle *handle,
> + struct ufs_hba *hba, struct scsi_cmnd *cmd)
> +{
> + struct ufs_s_dbg_mgr *mgr = (struct ufs_s_dbg_mgr *)handle->private;
> + struct ufs_cmd_info *cmd_info = &mgr->cmd_info;
> + int cpu = raw_smp_processor_id();
> + int tag = cmd->request->tag;
> +
> + if (mgr->active == 0)
> + return;
> +
> + cmd_info->pdata[tag]->end_time = cpu_clock(cpu);
> +}
> +
> +int exynos_ufs_init_dbg(struct ufs_exynos_handle *handle, struct device
> *dev)
> +{
> + struct ufs_s_dbg_mgr *mgr;
> +
> + mgr = devm_kzalloc(dev, sizeof(struct ufs_s_dbg_mgr), GFP_KERNEL);
> + if (!mgr)
> + return -ENOMEM;
> + handle->private = (void *)mgr;
> + mgr->handle = handle;
> + mgr->active = 1;
> +
> + /* cmd log */
> + spin_lock_init(&mgr->cmd_lock);
> +
> + return 0;
> +}
> +MODULE_AUTHOR("Kiwoong Kim <kwmad.kim@xxxxxxxxxxx>");
> +MODULE_DESCRIPTION("Exynos UFS debug information");
> +MODULE_LICENSE("GPL");
> +MODULE_VERSION("0.1");
> diff --git a/drivers/scsi/ufs/ufs-exynos-if.h b/drivers/scsi/ufs/ufs-exynos-if.h
> new file mode 100644
> index 0000000..c746f59
> --- /dev/null
> +++ b/drivers/scsi/ufs/ufs-exynos-if.h
> @@ -0,0 +1,17 @@
> +/* SPDX-License-Identifier: GPL-2.0-only */
> +/*
> + * UFS Exynos debugging functions
> + *
> + * Copyright (C) 2020 Samsung Electronics Co., Ltd.
> + * Author: Kiwoong Kim <kwmad.kim@xxxxxxxxxxx>
> + *
> + */
> +#ifndef _UFS_EXYNOS_IF_H_
> +#define _UFS_EXYNOS_IF_H_
> +
> +/* more members would be added in the future */
> +struct ufs_exynos_handle {
> + void *private;
> +};
> +
> +#endif /* _UFS_EXYNOS_IF_H_ */
> diff --git a/drivers/scsi/ufs/ufs-exynos.c b/drivers/scsi/ufs/ufs-exynos.c
> index 440f2af..8c60f7d 100644
> --- a/drivers/scsi/ufs/ufs-exynos.c
> +++ b/drivers/scsi/ufs/ufs-exynos.c
> @@ -700,11 +700,31 @@ static int exynos_ufs_post_pwr_mode(struct
> ufs_hba *hba,
> return 0;
> }
>
> +#ifdef CONFIG_SCSI_UFS_EXYNOS_CMD_LOG
> +static void exynos_ufs_cmd_log(struct ufs_hba *hba,
> + struct scsi_cmnd *cmd, int enter)
Maybe make it static inline in you header, e.g. ufs-exynos-if.h,
And make it empty if CONFIG_SCSI_UFS_EXYNOS_CMD_LOG is not defined?
> +{
> + struct exynos_ufs *ufs = ufshcd_get_variant(hba);
> + struct ufs_exynos_handle *handle = &ufs->handle;
> +
> + if (enter == 1)
Maybe use "start" instead of "enter"
If (start)
....
else
....
> + exynos_ufs_cmd_log_start(handle, hba, cmd);
> + else if (enter == 2)
> + exynos_ufs_cmd_log_end(handle, hba, cmd);
> +}
> +#endif
> +
> static void exynos_ufs_specify_nexus_t_xfer_req(struct ufs_hba *hba,
> int tag, bool op)
> {
> struct exynos_ufs *ufs = ufshcd_get_variant(hba);
> u32 type;
> +#ifdef CONFIG_SCSI_UFS_EXYNOS_CMD_LOG
> + struct scsi_cmnd *cmd = hba->lrb[tag].cmd;
> +
> + if (op)
> + exynos_ufs_cmd_log(hba, cmd, 1);
> +#endif
>
> type = hci_readl(ufs, HCI_UTRL_NEXUS_TYPE);
>
> @@ -714,6 +734,16 @@ static void
> exynos_ufs_specify_nexus_t_xfer_req(struct ufs_hba *hba,
> hci_writel(ufs, type & ~(1 << tag), HCI_UTRL_NEXUS_TYPE);
> }
>
> +static void exynos_ufs_compl_xfer_req(struct ufs_hba *hba, int tag, bool op)
> +{
> +#ifdef CONFIG_SCSI_UFS_EXYNOS_CMD_LOG
> + struct scsi_cmnd *cmd = hba->lrb[tag].cmd;
> +
> + if (op)
> + exynos_ufs_cmd_log(hba, cmd, 2);
> +#endif
> +}
> +
> static void exynos_ufs_specify_nexus_t_tm_req(struct ufs_hba *hba,
> int tag, u8 func)
> {
> @@ -1008,6 +1038,12 @@ static int exynos_ufs_init(struct ufs_hba *hba)
> goto out;
> exynos_ufs_specify_phy_time_attr(ufs);
> exynos_ufs_config_smu(ufs);
> +
> + /* init dbg */
> + ret = exynos_ufs_init_dbg(&ufs->handle, dev);
> + if (ret)
> + return ret;
> + spin_lock_init(&ufs->dbg_lock);
> return 0;
>
> phy_off:
> @@ -1217,6 +1253,7 @@ static struct ufs_hba_variant_ops
> ufs_hba_exynos_ops = {
> .link_startup_notify = exynos_ufs_link_startup_notify,
> .pwr_change_notify = exynos_ufs_pwr_change_notify,
> .setup_xfer_req = exynos_ufs_specify_nexus_t_xfer_req,
> + .compl_xfer_req = exynos_ufs_compl_xfer_req,
> .setup_task_mgmt = exynos_ufs_specify_nexus_t_tm_req,
> .hibern8_notify = exynos_ufs_hibern8_notify,
> .suspend = exynos_ufs_suspend,
> diff --git a/drivers/scsi/ufs/ufs-exynos.h b/drivers/scsi/ufs/ufs-exynos.h
> index 76d6e39..c947fd8 100644
> --- a/drivers/scsi/ufs/ufs-exynos.h
> +++ b/drivers/scsi/ufs/ufs-exynos.h
> @@ -8,6 +8,7 @@
>
> #ifndef _UFS_EXYNOS_H_
> #define _UFS_EXYNOS_H_
> +#include "ufs-exynos-if.h"
>
> /*
> * UNIPRO registers
> @@ -212,6 +213,10 @@ struct exynos_ufs {
> #define EXYNOS_UFS_OPT_BROKEN_AUTO_CLK_CTRL BIT(2)
> #define EXYNOS_UFS_OPT_BROKEN_RX_SEL_IDX BIT(3)
> #define EXYNOS_UFS_OPT_USE_SW_HIBERN8_TIMER BIT(4)
> +
> + struct ufs_exynos_handle handle;
> + spinlock_t dbg_lock;
> + int under_dump;
> };
>
> #define for_each_ufs_rx_lane(ufs, i) \
> @@ -284,4 +289,11 @@ struct exynos_ufs_uic_attr exynos7_uic_attr = {
> .rx_hs_g3_prep_sync_len_cap = PREP_LEN(0xf),
> .pa_dbg_option_suite = 0x30103,
> };
> +
> +/* public function declarations */
> +void exynos_ufs_cmd_log_start(struct ufs_exynos_handle *handle,
> + struct ufs_hba *hba, struct scsi_cmnd *cmd);
> +void exynos_ufs_cmd_log_end(struct ufs_exynos_handle *handle,
> + struct ufs_hba *hba, struct scsi_cmnd *cmd);
> +int exynos_ufs_init_dbg(struct ufs_exynos_handle *handle, struct device
> *dev);
> #endif /* _UFS_EXYNOS_H_ */
> --
> 2.7.4
