mirrors/scst
1
0
Fork 0
mirror of https://github.com/SCST-project/scst.git synced 2026-05-26 00:10:19 +00:00
Code Issues Packages Projects Releases Wiki Activity

scst: improve latency statistics

Browse Source 
git-svn-id: http://svn.code.sf.net/p/scst/svn/trunk@7074 d57e44dd-8a1f-0410-8b47-8ef2f437770f
This commit is contained in:
Vladislav Bolkhovitin
2016-12-20 06:17:11 +00:00
parent 2475def30d
commit 807836950b
5 changed files with 109 additions and 61 deletions
Download Patch File Download Diff File Expand all files Collapse all files

10
scst/include/scst.h
View File

@@ -2585,11 +2585,13 @@ struct scst_cmd {
#endif
#ifdef CONFIG_SCST_MEASURE_LATENCY
uint64_t start, curr_start, parse_time, alloc_buf_time;
uint64_t start, curr_start, parse_time;
uint64_t tgt_alloc_buf_time, dev_alloc_buf_time;
uint64_t restart_waiting_time, rdy_to_xfer_time;
uint64_t pre_exec_time, exec_time, dev_done_time;
uint64_t xmit_time;
uint64_t pre_exec_time;
bool exec_time_counting;
uint64_t exec_time, dev_done_time;
uint64_t xmit_time;
#endif
#ifdef CONFIG_SCST_DEBUG_TM
@@ -5231,7 +5233,7 @@ void scst_resume_activity(void);
void scst_process_active_cmd(struct scst_cmd *cmd, bool atomic);
void scst_post_parse(struct scst_cmd *cmd);
void scst_post_alloc_data_buf(struct scst_cmd *cmd);
void scst_post_dev_alloc_data_buf(struct scst_cmd *cmd);
int __scst_check_local_events(struct scst_cmd *cmd, bool preempt_tests_only);

4
scst/src/dev_handlers/scst_user.c
View File

@@ -1344,7 +1344,7 @@ static int dev_user_process_reply_alloc(struct scst_user_cmd *ucmd,
}
out_process:
scst_post_alloc_data_buf(cmd);
scst_post_dev_alloc_data_buf(cmd);
scst_process_active_cmd(cmd, false);
TRACE_DBG("%s", "ALLOC_MEM finished");
@@ -2663,7 +2663,7 @@ static void dev_user_unjam_cmd(struct scst_user_cmd *ucmd, int busy,
if (state == UCMD_STATE_PARSING)
scst_post_parse(ucmd->cmd);
else
scst_post_alloc_data_buf(ucmd->cmd);
scst_post_dev_alloc_data_buf(ucmd->cmd);
TRACE_MGMT_DBG("Adding ucmd %p to active list", ucmd);
list_add(&ucmd->cmd->cmd_list_entry,

136
scst/src/scst_lib.c
View File

@@ -15466,22 +15466,28 @@ void scst_check_debug_sn(struct scst_cmd *cmd)
#ifdef CONFIG_SCST_MEASURE_LATENCY
#if LINUX_VERSION_CODE < KERNEL_VERSION(2, 6, 16)
static uint64_t scst_get_usec(void)
{
struct timespec ts;
ktime_get_ts(&ts);
#if LINUX_VERSION_CODE < KERNEL_VERSION(2, 6, 16)
return ((uint64_t)ts.tv_sec * 1000000000 + ts.tv_nsec) / 1000;
#else
#if (BITS_PER_LONG > 32)
return timespec_to_ns(&ts) / 1000;
#else
return timespec_to_ns(&ts) >> 10;
#endif
#endif
}
#else /* LINUX_VERSION_CODE < KERNEL_VERSION(2, 6, 16) */
static uint64_t scst_get_usec(void)
{
ktime_t t;
t = ktime_get();
return ktime_to_us(t);
}
#endif
void scst_set_start_time(struct scst_cmd *cmd)
{
cmd->start = scst_get_usec();
@@ -15500,10 +15506,16 @@ void scst_set_parse_time(struct scst_cmd *cmd)
TRACE_DBG("cmd %p: parse_time %lld", cmd, cmd->parse_time);
}
void scst_set_alloc_buf_time(struct scst_cmd *cmd)
void scst_set_dev_alloc_buf_time(struct scst_cmd *cmd)
{
cmd->alloc_buf_time += scst_get_usec() - cmd->curr_start;
TRACE_DBG("cmd %p: alloc_buf_time %lld", cmd, cmd->alloc_buf_time);
cmd->dev_alloc_buf_time += scst_get_usec() - cmd->curr_start;
TRACE_DBG("cmd %p: dev_alloc_buf_time %lld", cmd, cmd->dev_alloc_buf_time);
}
void scst_set_tgt_alloc_buf_time(struct scst_cmd *cmd)
{
cmd->tgt_alloc_buf_time += scst_get_usec() - cmd->curr_start;
TRACE_DBG("cmd %p: tgt_alloc_buf_time %lld", cmd, cmd->tgt_alloc_buf_time);
}
void scst_set_restart_waiting_time(struct scst_cmd *cmd)
@@ -15533,6 +15545,9 @@ void scst_set_exec_start(struct scst_cmd *cmd)
void scst_set_exec_time(struct scst_cmd *cmd)
{
if (!cmd->exec_time_counting)
return;
cmd->exec_time_counting = false;
cmd->exec_time += scst_get_usec() - cmd->curr_start;
TRACE_DBG("cmd %p: exec_time %lld", cmd, cmd->exec_time);
}
@@ -15551,11 +15566,12 @@ void scst_set_xmit_time(struct scst_cmd *cmd)
void scst_update_lat_stats(struct scst_cmd *cmd)
{
uint64_t finish, scst_time, tgt_time, dev_time;
int64_t finish, scst_time, tgt_time, dev_time;
struct scst_session *sess = cmd->sess;
int data_len;
int i;
struct scst_ext_latency_stat *latency_stat, *dev_latency_stat;
bool ignore_max = false;
finish = scst_get_usec();
@@ -15578,12 +15594,30 @@ void scst_update_lat_stats(struct scst_cmd *cmd)
/* Calculate the latencies */
scst_time = finish - cmd->start - (cmd->parse_time +
cmd->alloc_buf_time + cmd->restart_waiting_time +
cmd->dev_alloc_buf_time + cmd->tgt_alloc_buf_time +
cmd->restart_waiting_time +
cmd->rdy_to_xfer_time + cmd->pre_exec_time +
cmd->exec_time + cmd->dev_done_time + cmd->xmit_time);
tgt_time = cmd->alloc_buf_time + cmd->restart_waiting_time +
cmd->rdy_to_xfer_time + cmd->pre_exec_time;
dev_time = cmd->parse_time + cmd->exec_time + cmd->dev_done_time;
tgt_time = cmd->tgt_alloc_buf_time + cmd->restart_waiting_time +
cmd->rdy_to_xfer_time + cmd->pre_exec_time + cmd->xmit_time;
dev_time = cmd->parse_time + cmd->dev_alloc_buf_time +
cmd->exec_time + cmd->dev_done_time;
if (unlikely((scst_time < 0) || (tgt_time < 0) || (dev_time < 0))) {
/* It might happen due to small difference in time between CPUs */
static int q;
if (q++ < 20) {
PRINT_WARNING("Ignoring max latency sample, because time is "
"moving backward (cmd %p, scst %lld, tgt %lld, "
"dev %lld)", cmd, (long long) scst_time,
(long long) tgt_time, (long long) dev_time);
}
ignore_max = true;
/*
* We should not ignore this sample, because the time
* difference mistake can be both negative and positive.
*/
}
spin_lock_bh(&sess->lat_lock);
@@ -15603,12 +15637,14 @@ void scst_update_lat_stats(struct scst_cmd *cmd)
(sess->min_dev_time > dev_time))
sess->min_dev_time = dev_time;
if (sess->max_scst_time < scst_time)
sess->max_scst_time = scst_time;
if (sess->max_tgt_time < tgt_time)
sess->max_tgt_time = tgt_time;
if (sess->max_dev_time < dev_time)
sess->max_dev_time = dev_time;
if (likely(!ignore_max)) {
if (sess->max_scst_time < scst_time)
sess->max_scst_time = scst_time;
if (sess->max_tgt_time < tgt_time)
sess->max_tgt_time = tgt_time;
if (sess->max_dev_time < dev_time)
sess->max_dev_time = dev_time;
}
/* Save the extended latency information */
if (cmd->data_direction & SCST_DATA_READ) {
@@ -15627,12 +15663,14 @@ void scst_update_lat_stats(struct scst_cmd *cmd)
(latency_stat->min_dev_time_rd > dev_time))
latency_stat->min_dev_time_rd = dev_time;
if (latency_stat->max_scst_time_rd < scst_time)
latency_stat->max_scst_time_rd = scst_time;
if (latency_stat->max_tgt_time_rd < tgt_time)
latency_stat->max_tgt_time_rd = tgt_time;
if (latency_stat->max_dev_time_rd < dev_time)
latency_stat->max_dev_time_rd = dev_time;
if (likely(!ignore_max)) {
if (latency_stat->max_scst_time_rd < scst_time)
latency_stat->max_scst_time_rd = scst_time;
if (latency_stat->max_tgt_time_rd < tgt_time)
latency_stat->max_tgt_time_rd = tgt_time;
if (latency_stat->max_dev_time_rd < dev_time)
latency_stat->max_dev_time_rd = dev_time;
}
if (dev_latency_stat != NULL) {
dev_latency_stat->scst_time_rd += scst_time;
@@ -15650,12 +15688,14 @@ void scst_update_lat_stats(struct scst_cmd *cmd)
(dev_latency_stat->min_dev_time_rd > dev_time))
dev_latency_stat->min_dev_time_rd = dev_time;
if (dev_latency_stat->max_scst_time_rd < scst_time)
dev_latency_stat->max_scst_time_rd = scst_time;
if (dev_latency_stat->max_tgt_time_rd < tgt_time)
dev_latency_stat->max_tgt_time_rd = tgt_time;
if (dev_latency_stat->max_dev_time_rd < dev_time)
dev_latency_stat->max_dev_time_rd = dev_time;
if (likely(!ignore_max)) {
if (dev_latency_stat->max_scst_time_rd < scst_time)
dev_latency_stat->max_scst_time_rd = scst_time;
if (dev_latency_stat->max_tgt_time_rd < tgt_time)
dev_latency_stat->max_tgt_time_rd = tgt_time;
if (dev_latency_stat->max_dev_time_rd < dev_time)
dev_latency_stat->max_dev_time_rd = dev_time;
}
}
} else if (cmd->data_direction & SCST_DATA_WRITE) {
latency_stat->scst_time_wr += scst_time;
@@ -15673,12 +15713,14 @@ void scst_update_lat_stats(struct scst_cmd *cmd)
(latency_stat->min_dev_time_wr > dev_time))
latency_stat->min_dev_time_wr = dev_time;
if (latency_stat->max_scst_time_wr < scst_time)
latency_stat->max_scst_time_wr = scst_time;
if (latency_stat->max_tgt_time_wr < tgt_time)
latency_stat->max_tgt_time_wr = tgt_time;
if (latency_stat->max_dev_time_wr < dev_time)
latency_stat->max_dev_time_wr = dev_time;
if (likely(!ignore_max)) {
if (latency_stat->max_scst_time_wr < scst_time)
latency_stat->max_scst_time_wr = scst_time;
if (latency_stat->max_tgt_time_wr < tgt_time)
latency_stat->max_tgt_time_wr = tgt_time;
if (latency_stat->max_dev_time_wr < dev_time)
latency_stat->max_dev_time_wr = dev_time;
}
if (dev_latency_stat != NULL) {
dev_latency_stat->scst_time_wr += scst_time;
@@ -15696,12 +15738,14 @@ void scst_update_lat_stats(struct scst_cmd *cmd)
(dev_latency_stat->min_dev_time_wr > dev_time))
dev_latency_stat->min_dev_time_wr = dev_time;
if (dev_latency_stat->max_scst_time_wr < scst_time)
dev_latency_stat->max_scst_time_wr = scst_time;
if (dev_latency_stat->max_tgt_time_wr < tgt_time)
dev_latency_stat->max_tgt_time_wr = tgt_time;
if (dev_latency_stat->max_dev_time_wr < dev_time)
dev_latency_stat->max_dev_time_wr = dev_time;
if (likely(!ignore_max)) {
if (dev_latency_stat->max_scst_time_wr < scst_time)
dev_latency_stat->max_scst_time_wr = scst_time;
if (dev_latency_stat->max_tgt_time_wr < tgt_time)
dev_latency_stat->max_tgt_time_wr = tgt_time;
if (dev_latency_stat->max_dev_time_wr < dev_time)
dev_latency_stat->max_dev_time_wr = dev_time;
}
}
}

6
scst/src/scst_priv.h
View File

@@ -1024,7 +1024,8 @@ void scst_trace_mcmds(scst_show_fn show, void *arg);
void scst_set_start_time(struct scst_cmd *cmd);
void scst_set_cur_start(struct scst_cmd *cmd);
void scst_set_parse_time(struct scst_cmd *cmd);
void scst_set_alloc_buf_time(struct scst_cmd *cmd);
void scst_set_dev_alloc_buf_time(struct scst_cmd *cmd);
void scst_set_tgt_alloc_buf_time(struct scst_cmd *cmd);
void scst_set_restart_waiting_time(struct scst_cmd *cmd);
void scst_set_rdy_to_xfer_time(struct scst_cmd *cmd);
void scst_set_pre_exec_time(struct scst_cmd *cmd);
@@ -1039,7 +1040,8 @@ void scst_update_lat_stats(struct scst_cmd *cmd);
static inline void scst_set_start_time(struct scst_cmd *cmd) {}
static inline void scst_set_cur_start(struct scst_cmd *cmd) {}
static inline void scst_set_parse_time(struct scst_cmd *cmd) {}
static inline void scst_set_alloc_buf_time(struct scst_cmd *cmd) {}
static inline void scst_set_dev_alloc_buf_time(struct scst_cmd *cmd) {}
static inline void scst_set_tgt_alloc_buf_time(struct scst_cmd *cmd) {}
static inline void scst_set_restart_waiting_time(struct scst_cmd *cmd) {}
static inline void scst_set_rdy_to_xfer_time(struct scst_cmd *cmd) {}
static inline void scst_set_pre_exec_time(struct scst_cmd *cmd) {}

14
scst/src/scst_targ.c
View File

@@ -60,17 +60,17 @@ void scst_post_parse(struct scst_cmd *cmd)
EXPORT_SYMBOL_GPL(scst_post_parse);
/**
* scst_post_alloc_data_buf() - do post dev_alloc_data_buf actions
* scst_post_dev_alloc_data_buf() - do post dev_alloc_data_buf actions
*
* This function must be called by dev handler after its dev_alloc_data_buf()
* callback returned SCST_CMD_STATE_STOP before calling
* scst_process_active_cmd().
*/
void scst_post_alloc_data_buf(struct scst_cmd *cmd)
void scst_post_dev_alloc_data_buf(struct scst_cmd *cmd)
{
scst_set_alloc_buf_time(cmd);
scst_set_dev_alloc_buf_time(cmd);
}
EXPORT_SYMBOL_GPL(scst_post_alloc_data_buf);
EXPORT_SYMBOL_GPL(scst_post_dev_alloc_data_buf);
static inline void scst_schedule_tasklet(struct scst_cmd *cmd)
{
@@ -1515,7 +1515,7 @@ static int scst_prepare_space(struct scst_cmd *cmd)
switch (state) {
case SCST_CMD_STATE_NEED_THREAD_CTX:
scst_set_alloc_buf_time(cmd);
scst_set_dev_alloc_buf_time(cmd);
TRACE_DBG("Dev handler %s dev_alloc_data_buf() requested "
"thread context, rescheduling", devt->name);
res = SCST_CMD_STATE_RES_NEED_THREAD;
@@ -1529,7 +1529,7 @@ static int scst_prepare_space(struct scst_cmd *cmd)
goto out;
}
scst_set_alloc_buf_time(cmd);
scst_set_dev_alloc_buf_time(cmd);
if (unlikely(state != SCST_CMD_STATE_DEFAULT)) {
cmd->state = state;
@@ -1545,7 +1545,7 @@ static int scst_prepare_space(struct scst_cmd *cmd)
scst_set_cur_start(cmd);
r = cmd->tgtt->tgt_alloc_data_buf(cmd);
scst_set_alloc_buf_time(cmd);
scst_set_tgt_alloc_buf_time(cmd);
if (r > 0)
goto alloc;