From 91a2c481a61a2cb24575a2df9b6bc711f86041c6 Mon Sep 17 00:00:00 2001 From: Vladislav Bolkhovitin Date: Thu, 14 Nov 2013 04:27:31 +0000 Subject: [PATCH] scst: Make it possible to inspect commands state Signed-off-by: Bart Van Assche with some improvements git-svn-id: http://svn.code.sf.net/p/scst/svn/trunk@5108 d57e44dd-8a1f-0410-8b47-8ef2f437770f --- scst/README | 6 ++ scst/README_in-tree | 6 ++ scst/include/scst.h | 6 ++ scst/include/scst_const.h | 7 +- scst/src/scst_main.c | 192 +++++++++++++++++++++++++++++++++++++- scst/src/scst_priv.h | 4 + scst/src/scst_sysfs.c | 109 +++++++++++++++++++++- 7 files changed, 325 insertions(+), 5 deletions(-) diff --git a/scst/README b/scst/README index d51773400..150965213 100644 --- a/scst/README +++ b/scst/README @@ -437,6 +437,12 @@ following entries: Those threads used with async. dev handlers, for instance, vdisk BLOCKIO or NULLIO. + - trace_cmds - shows current SCST commands up to size of the sysfs + buffer (4KB) + + - trace_mcmds - shows current SCST management commands up to size of + the sysfs buffer (4KB) + - trace_level - allows to enable and disable various tracing facilities. See content of this file for help how to use it. See also section "Dealing with massive logs" for more info how to make correct diff --git a/scst/README_in-tree b/scst/README_in-tree index 1e73cfb8d..abd4f88f4 100644 --- a/scst/README_in-tree +++ b/scst/README_in-tree @@ -299,6 +299,12 @@ following entries: Those threads used with async. dev handlers, for instance, vdisk BLOCKIO or NULLIO. + - trace_cmds - shows current SCST commands up to size of the sysfs + buffer (4KB) + + - trace_mcmds - shows current SCST management commands up to size of + the sysfs buffer (4KB) + - trace_level - allows to enable and disable various tracing facilities. See content of this file for help how to use it. See also section "Dealing with massive logs" for more info how to make correct diff --git a/scst/include/scst.h b/scst/include/scst.h index 9a29b658d..30f7da773 100644 --- a/scst/include/scst.h +++ b/scst/include/scst.h @@ -193,6 +193,9 @@ static inline bool list_entry_in_list(const struct list_head *entry) ** "active" states, then - "passive" ones. This is to have ** more efficient generated code of the corresponding ** "switch" statements. + ** + ** !! Adding new states don't forget to update scst_cmd_state_name + ** !! as well! *************************************************************/ enum { /* Dev handler's parse() is going to be called */ @@ -293,6 +296,9 @@ enum { /************************************************************* ** States of mgmt command processing state machine + ** + ** !! Adding new states don't forget to update + ** !! scst_mcmd_state_name as well! *************************************************************/ enum { /* LUN translation (mcmd->tgt_dev assignment) */ diff --git a/scst/include/scst_const.h b/scst/include/scst_const.h index 869c9d018..b6426a6bf 100644 --- a/scst/include/scst_const.h +++ b/scst/include/scst_const.h @@ -98,7 +98,12 @@ #define SCST_LUN_RESET 4 #define SCST_TARGET_RESET 5 -/** SCST extensions **/ +/** + ** SCST extensions + ** + ** !! Adding new extensions don't forget to update + ** !! scst_tm_fn_name as well! + **/ /* * Notifies about I_T nexus loss event in the corresponding session. diff --git a/scst/src/scst_main.c b/scst/src/scst_main.c index 663012c75..239994ae0 100644 --- a/scst/src/scst_main.c +++ b/scst/src/scst_main.c @@ -699,6 +699,173 @@ again: } EXPORT_SYMBOL(scst_unregister_target); +static const char *const scst_cmd_state_name[] = { + [SCST_CMD_STATE_PARSE] = "PARSE", + [SCST_CMD_STATE_PREPARE_SPACE] = "PREPARE_SPACE", + [SCST_CMD_STATE_PREPROCESSING_DONE] = "PREP_DONE", + [SCST_CMD_STATE_RDY_TO_XFER] = "RDY_TO_XFER", + [SCST_CMD_STATE_TGT_PRE_EXEC] = "TGT_PRE_EXEC", + [SCST_CMD_STATE_EXEC_CHECK_SN] = "EXEC_CHECK_SN", + [SCST_CMD_STATE_PRE_DEV_DONE] = "PRE_DEV_DONE", + [SCST_CMD_STATE_MODE_SELECT_CHECKS] = "MODE_SELECT_CHECKS", + [SCST_CMD_STATE_DEV_DONE] = "DEV_DONE", + [SCST_CMD_STATE_PRE_XMIT_RESP] = "PRE_XMIT_RESP", + [SCST_CMD_STATE_XMIT_RESP] = "XMIT_RESP", + [SCST_CMD_STATE_FINISHED] = "FINISHED", + [SCST_CMD_STATE_FINISHED_INTERNAL] = "FINISHED_INTERNAL", + [SCST_CMD_STATE_INIT_WAIT] = "INIT_WAIT", + [SCST_CMD_STATE_INIT] = "INIT", + [SCST_CMD_STATE_PREPROCESSING_DONE_CALLED] = "PREP_DONE_CALLED", + [SCST_CMD_STATE_DATA_WAIT] = "DATA_WAIT", + [SCST_CMD_STATE_EXEC_CHECK_BLOCKING] = "EXEC_CHECK_BLOCKING", + [SCST_CMD_STATE_LOCAL_EXEC] = "LOCAL_EXEC", + [SCST_CMD_STATE_REAL_EXEC] = "REAL_EXEC", + [SCST_CMD_STATE_EXEC_WAIT] = "EXEC_WAIT", + [SCST_CMD_STATE_XMIT_WAIT] = "XMIT_WAIT", +}; + +static void scst_get_cmd_state_name(char *name, int len, unsigned state) +{ + if (state < ARRAY_SIZE(scst_cmd_state_name) && + scst_cmd_state_name[state]) + strlcpy(name, scst_cmd_state_name[state], len); + else + snprintf(name, len, "%d", state); +} + +static char *scst_dump_cdb(char *buf, int buf_len, struct scst_cmd *cmd) +{ + char *p = buf, *end = buf + buf_len; + int i; + + for (i = 0; i < cmd->cdb_len && p < end; i++) + p += scnprintf(p, end - p, "%s%02x", i ? " " : "", cmd->cdb[i]); + + return buf; +} + +void scst_trace_cmds(scst_show_fn show, void *arg) +{ + struct scst_tgt_template *t; + struct scst_tgt *tgt; + struct scst_session *sess; + struct scst_cmd *cmd; + struct scst_tgt_dev *tgt_dev; + char state_name[32]; + char cdb[64]; + + mutex_lock(&scst_mutex); + list_for_each_entry(t, &scst_template_list, scst_template_list_entry) { + list_for_each_entry(tgt, &t->tgt_list, tgt_list_entry) { + list_for_each_entry(sess, &tgt->sess_list, + sess_list_entry) { + spin_lock_irq(&sess->sess_list_lock); + list_for_each_entry(cmd, &sess->sess_cmd_list, + sess_cmd_list_entry) { + tgt_dev = cmd->tgt_dev; + scst_dump_cdb(cdb, sizeof(cdb), cmd); + scst_get_cmd_state_name(state_name, + sizeof(state_name), + cmd->state); + show(arg, "cmd %p: state %s; tgtt %s; " + "tgt %s; session %s; grp %s; " + "LUN %lld; ini %s; cdb %s\n", + cmd, state_name, t->name, + tgt->tgt_name, sess->sess_name, + tgt_dev ? (tgt_dev->acg_dev->acg->acg_name ? + : "(default)") : "?", + cmd->lun, sess->initiator_name, cdb); + } + spin_unlock_irq(&sess->sess_list_lock); + } + } + } + mutex_unlock(&scst_mutex); + return; +} + +static const char *const scst_tm_fn_name[] = { + [SCST_ABORT_TASK] = "ABORT_TASK", + [SCST_ABORT_TASK_SET] = "ABORT_TASK_SET", + [SCST_CLEAR_ACA] = "CLEAR_ACA", + [SCST_CLEAR_TASK_SET] = "CLEAR_TASK_SET", + [SCST_LUN_RESET] = "LUN_RESET", + [SCST_TARGET_RESET] = "TARGET_RESET", + [SCST_NEXUS_LOSS_SESS] = "NEXUS_LOSS_SESS", + [SCST_ABORT_ALL_TASKS_SESS] = "ABORT_ALL_TASKS_SESS", + [SCST_NEXUS_LOSS] = "NEXUS_LOSS", + [SCST_ABORT_ALL_TASKS] = "ABORT_ALL_TASKS", + [SCST_UNREG_SESS_TM] = "UNREG_SESS_TM", + [SCST_PR_ABORT_ALL] = "PR_ABORT_ALL", +}; + +static void scst_get_tm_fn_name(char *name, int len, unsigned fn) +{ + if (fn < ARRAY_SIZE(scst_tm_fn_name) && scst_tm_fn_name[fn]) + strlcpy(name, scst_tm_fn_name[fn], len); + else + snprintf(name, len, "%d", fn); + return; +} + +static const char *const scst_mcmd_state_name[] = { + [SCST_MCMD_STATE_INIT] = "INIT", + [SCST_MCMD_STATE_EXEC] = "EXEC", + [SCST_MCMD_STATE_WAITING_AFFECTED_CMDS_DONE] = "WAITING_AFFECTED_CMDS_DONE", + [SCST_MCMD_STATE_AFFECTED_CMDS_DONE] = "AFFECTED_CMDS_DONE", + [SCST_MCMD_STATE_WAITING_AFFECTED_CMDS_FINISHED] = "WAITING_AFFECTED_CMDS_FINISHED", + [SCST_MCMD_STATE_DONE] = "DONE", + [SCST_MCMD_STATE_FINISHED] = "FINISHED", +}; + +static void scst_get_mcmd_state_name(char *name, int len, unsigned state) +{ + if (state < ARRAY_SIZE(scst_mcmd_state_name) && + scst_mcmd_state_name[state]) + strlcpy(name, scst_mcmd_state_name[state], len); + else + snprintf(name, len, "%d", state); + return; +} + +void scst_trace_mcmds(scst_show_fn show, void *arg) +{ + struct scst_mgmt_cmd *mcmd; + char fn_name[16], state_name[32]; + + spin_lock_irq(&scst_mcmd_lock); + list_for_each_entry(mcmd, &scst_active_mgmt_cmd_list, + mgmt_cmd_list_entry) { + scst_get_tm_fn_name(fn_name, sizeof(fn_name), mcmd->fn); + scst_get_mcmd_state_name(state_name, sizeof(state_name), + mcmd->state); + show(arg, "mcmd %p: state %s; tgtt %s; tgt %s; session %s; fn %s;" + " LUN %lld; tag %lld; cmd_done_wait_count %d\n", + mcmd, state_name, mcmd->sess->tgt->tgtt->name, + mcmd->sess->tgt->tgt_name, mcmd->sess->sess_name, fn_name, + mcmd->lun, mcmd->tag, mcmd->cmd_done_wait_count); + } + spin_unlock_irq(&scst_mcmd_lock); + return; +} + +static void __printf(2, 3) scst_to_syslog(void *arg, const char *fmt, ...) +{ + bool *header_printed = arg; + va_list args; + + if (!*header_printed) { + PRINT_INFO("Pending commands:"); + *header_printed = true; + } + + va_start(args, fmt); + printk(KERN_INFO " "); + vprintk(fmt, args); + va_end(args); + return; +} + int scst_get_cmd_counter(void) { int i, res = 0; @@ -709,13 +876,32 @@ int scst_get_cmd_counter(void) static int scst_susp_wait(unsigned long timeout) { - int res = 0; + int res; + unsigned long t; + bool hp = false; +#define SCST_SUSP_WAIT_REPORT_TIMEOUT (5UL * HZ) TRACE_ENTRY(); + if (timeout == SCST_SUSPEND_TIMEOUT_UNLIMITED) + t = SCST_SUSP_WAIT_REPORT_TIMEOUT; + else + t = min(timeout, SCST_SUSP_WAIT_REPORT_TIMEOUT); + + res = wait_event_interruptible_timeout(scst_dev_cmd_waitQ, + (scst_get_cmd_counter() == 0), t); + if (res > 0) { + res = 0; + goto out; + } else if ((res < 0) && (timeout != SCST_SUSPEND_TIMEOUT_UNLIMITED)) + goto out; + + scst_trace_cmds(scst_to_syslog, &hp); + scst_trace_mcmds(scst_to_syslog, &hp); + if (timeout != SCST_SUSPEND_TIMEOUT_UNLIMITED) { res = wait_event_interruptible_timeout(scst_dev_cmd_waitQ, - (scst_get_cmd_counter() == 0), timeout); + (scst_get_cmd_counter() == 0), timeout - t); if (res == 0) res = -EBUSY; else if (res > 0) @@ -723,10 +909,12 @@ static int scst_susp_wait(unsigned long timeout) } else wait_event(scst_dev_cmd_waitQ, scst_get_cmd_counter() == 0); +out: TRACE_MGMT_DBG("wait_event() returned %d", res); TRACE_EXIT_RES(res); return res; +#undef SCST_SUSP_WAIT_REPORT_TIMEOUT } /** diff --git a/scst/src/scst_priv.h b/scst/src/scst_priv.h index 0bf5f1170..dcac6301d 100644 --- a/scst/src/scst_priv.h +++ b/scst/src/scst_priv.h @@ -751,6 +751,10 @@ int gen_relative_target_port_id(uint16_t *id); bool scst_is_relative_target_port_id_unique(uint16_t id, const struct scst_tgt *t); +typedef void __printf(2, 3) (*scst_show_fn)(void *arg, const char *fmt, ...); +void scst_trace_cmds(scst_show_fn show, void *arg); +void scst_trace_mcmds(scst_show_fn show, void *arg); + #ifdef CONFIG_SCST_MEASURE_LATENCY void scst_set_start_time(struct scst_cmd *cmd); diff --git a/scst/src/scst_sysfs.c b/scst/src/scst_sysfs.c index 221e1ec6c..36913ae8f 100644 --- a/scst/src/scst_sysfs.c +++ b/scst/src/scst_sysfs.c @@ -5683,6 +5683,8 @@ static const struct attribute *scst_device_groups_attrs[] = { ** SCST sysfs root directory implementation **/ +static struct kobject scst_sysfs_root_kobj; + static ssize_t scst_threads_show(struct kobject *kobj, struct kobj_attribute *attr, char *buf) { @@ -5909,6 +5911,109 @@ static struct kobj_attribute scst_main_trace_level_attr = #endif /* defined(CONFIG_SCST_DEBUG) || defined(CONFIG_SCST_TRACING) */ +static void __printf(2, 3) scst_append(void *arg, const char *fmt, ...) +{ + char *buf = arg; + int len = strlen(buf); + va_list args; + + va_start(args, fmt); + vscnprintf(buf + len, SCST_SYSFS_BLOCK_SIZE - len, fmt, args); + va_end(args); +} + +static int scst_process_show_trace_cmds(struct scst_sysfs_work_item *work) +{ + int ret = -ENOMEM; + + work->res_buf = kmalloc(SCST_SYSFS_BLOCK_SIZE, GFP_KERNEL); + if (!work->res_buf) + goto put; + work->res_buf[0] = '\0'; + scst_trace_cmds(scst_append, work->res_buf); + ret = 0; + +put: + kobject_put(&scst_sysfs_root_kobj); + return ret; +} + +static ssize_t scst_show_trace_cmds(struct kobject *kobj, + struct kobj_attribute *attr, char *buf) +{ + struct scst_sysfs_work_item *work; + int res; + + res = scst_alloc_sysfs_work(scst_process_show_trace_cmds, true, + &work); + if (res != 0) + goto out; + + kobject_get(&scst_sysfs_root_kobj); + scst_sysfs_work_get(work); + res = scst_sysfs_queue_wait_work(work); + if (res != 0) + goto put; + + res = scnprintf(buf, SCST_SYSFS_BLOCK_SIZE, "%s", work->res_buf); + +put: + scst_sysfs_work_put(work); + +out: + return res; + +} + +static struct kobj_attribute scst_trace_cmds_attr = + __ATTR(trace_cmds, S_IRUGO, scst_show_trace_cmds, NULL); + +static int scst_process_show_trace_mcmds(struct scst_sysfs_work_item *work) +{ + int ret = -ENOMEM; + + work->res_buf = kmalloc(SCST_SYSFS_BLOCK_SIZE, GFP_KERNEL); + if (!work->res_buf) + goto put; + work->res_buf[0] = '\0'; + scst_trace_mcmds(scst_append, work->res_buf); + ret = 0; + +put: + kobject_put(&scst_sysfs_root_kobj); + return ret; +} + +static ssize_t scst_show_trace_mcmds(struct kobject *kobj, + struct kobj_attribute *attr, char *buf) +{ + struct scst_sysfs_work_item *work; + int res; + + res = scst_alloc_sysfs_work(scst_process_show_trace_mcmds, true, + &work); + if (res != 0) + goto out; + + kobject_get(&scst_sysfs_root_kobj); + scst_sysfs_work_get(work); + res = scst_sysfs_queue_wait_work(work); + if (res != 0) + goto put; + + res = scnprintf(buf, SCST_SYSFS_BLOCK_SIZE, "%s", work->res_buf); + +put: + scst_sysfs_work_put(work); + +out: + return res; + +} + +static struct kobj_attribute scst_trace_mcmds_attr = + __ATTR(trace_mcmds, S_IRUGO, scst_show_trace_mcmds, NULL); + static ssize_t scst_version_show(struct kobject *kobj, struct kobj_attribute *attr, char *buf) @@ -5998,6 +6103,8 @@ static struct attribute *scst_sysfs_root_default_attrs[] = { #if defined(CONFIG_SCST_DEBUG) || defined(CONFIG_SCST_TRACING) &scst_main_trace_level_attr.attr, #endif + &scst_trace_cmds_attr.attr, + &scst_trace_mcmds_attr.attr, &scst_version_attr.attr, &scst_last_sysfs_mgmt_res_attr.attr, NULL, @@ -6226,8 +6333,6 @@ out: } EXPORT_SYMBOL_GPL(scst_wait_info_completion); -static struct kobject scst_sysfs_root_kobj; - int __init scst_sysfs_init(void) { int res = 0;