Skip to content

Commit

Permalink
Add a perfmance counter..
Browse files Browse the repository at this point in the history 
Add the 'delay' information with CDB log entry

The '(delay xxx)' value is the delay time between previous SCSI OP code and
this SCSI OP code

Lets see if this is helps improve performance tuning.

Signed-off-by: Mark Harvey <markh794@gmail.com>
  • Loading branch information
@markh794
markh794 committed Aug 8, 2012
1 parent 8ebd752 commit 6f67beb
Show file tree
Hide file tree
Showing 6 changed files with 63 additions and 45 deletions.
8 changes: 4 additions & 4 deletions usr/logging.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -61,19 +61,19 @@ extern int verbose;
__func__, ## arg); \
}

#define MHVTL_DBG_PRT_CDB(lvl, sn, cdb) { \
#define MHVTL_DBG_PRT_CDB(lvl, cmd) { \
if (debug) { \
mhvtl_prt_cdb((lvl), (sn), (cdb)); \
mhvtl_prt_cdb((lvl), (cmd)); \
} else if ((verbose & MHVTL_OPT_NOISE) >= (lvl)) { \
mhvtl_prt_cdb((lvl), (sn), (cdb)); \
mhvtl_prt_cdb((lvl), (cmd)); \
} \
}

#else

#define MHVTL_DBG(lvl, s...)
#define MHVTL_DBG_NO_FUNC(lvl, s...)
#define MHVTL_DBG_PRT_CDB(lvl, sn, cdb)
#define MHVTL_DBG_PRT_CDB(lvl, cmd)

#define MHVTL_ERR(format, arg...) { \
syslog(LOG_DAEMON|LOG_ERR, "ERROR: %s(): " format, \
Expand Down
16 changes: 8 additions & 8 deletions usr/ssc.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -540,30 +540,30 @@ uint8_t ssc_a3_service_action(struct scsi_cmd *cmd)
{
switch (cmd->scb[1]) {
case MANAGEMENT_PROTOCOL_IN:
log_opcode("MANAGEMENT PROTOCOL IN **", cmd->scb, cmd->dbuf_p);
log_opcode("MANAGEMENT PROTOCOL IN **", cmd);
break;
case REPORT_ALIASES:
log_opcode("REPORT ALIASES **", cmd->scb, cmd->dbuf_p);
log_opcode("REPORT ALIASES **", cmd);
break;
}
log_opcode("Unknown service action A3 **", cmd->scb, cmd->dbuf_p);
log_opcode("Unknown service action A3 **", cmd);
return cmd->dbuf_p->sam_stat;
}

uint8_t ssc_a4_service_action(struct scsi_cmd *cmd)
{
switch (cmd->scb[1]) {
case MANAGEMENT_PROTOCOL_OUT:
log_opcode("MANAGEMENT PROTOCOL OUT **", cmd->scb, cmd->dbuf_p);
log_opcode("MANAGEMENT PROTOCOL OUT **", cmd);
break;
case CHANGE_ALIASES:
log_opcode("CHANGE ALIASES **", cmd->scb, cmd->dbuf_p);
log_opcode("CHANGE ALIASES **", cmd);
break;
case FORCED_EJECT:
log_opcode("FORCED EJECT **", cmd->scb, cmd->dbuf_p);
log_opcode("FORCED EJECT **", cmd);
break;
}
log_opcode("Unknown service action A4 **", cmd->scb, cmd->dbuf_p);
log_opcode("Unknown service action A4 **", cmd);
return cmd->dbuf_p->sam_stat;
}

Expand Down Expand Up @@ -873,7 +873,7 @@ uint8_t ssc_mode_select(struct scsi_cmd *cmd)
break;

default:
MHVTL_DBG_PRT_CDB(1, cmd->dbuf_p->serialNo, cmd->scb);
MHVTL_DBG_PRT_CDB(1, cmd);
MHVTL_DBG(1, "Mode page 0x%02x not handled", buf[i]);
break;
}
Expand Down
42 changes: 26 additions & 16 deletions usr/vtllib.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -100,56 +100,66 @@ static struct state_description {
uint8_t sense[SENSE_BUF_SIZE];
uint8_t modeBlockDescriptor[8] = {0, 0, 0, 0, 0, 0, 0, 0 };

void mhvtl_prt_cdb(int lvl, uint64_t sn, uint8_t *cdb)
void mhvtl_prt_cdb(int lvl, struct scsi_cmd *cmd)
{
int groupCode;
uint64_t sn = cmd->dbuf_p->serialNo;
uint8_t *cdb = cmd->scb;
uint64_t delay = (uint64_t)cmd->pollInterval;

groupCode = (cdb[0] & 0xe0) >> 5;
switch (groupCode) {
case 0: /* 6 byte commands */
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") "
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") (delay %ld): "
"%02x %02x %02x %02x %02x %02x",
sn, cdb[0], cdb[1], cdb[2], cdb[3], cdb[4], cdb[5]);
sn, delay,
cdb[0], cdb[1], cdb[2], cdb[3], cdb[4], cdb[5]);
break;
case 1: /* 10 byte commands */
case 2: /* 10 byte commands */
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") "
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") (delay %ld): "
"%02x %02x %02x %02x %02x %02x"
" %02x %02x %02x %02x",
sn, cdb[0], cdb[1], cdb[2], cdb[3],
sn, delay,
cdb[0], cdb[1], cdb[2], cdb[3],
cdb[4], cdb[5], cdb[6], cdb[7],
cdb[8], cdb[9]);
break;
case 3: /* Reserved - There is always one exception ;) */
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") "
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") (delay %ld): "
"%02x %02x %02x %02x %02x %02x"
" %02x %02x %02x %02x %02x %02x",
sn, cdb[0], cdb[1], cdb[2], cdb[3],
sn, delay,
cdb[0], cdb[1], cdb[2], cdb[3],
cdb[4], cdb[5], cdb[6], cdb[7],
cdb[8], cdb[9], cdb[10], cdb[11]);
break;
case 4: /* 16 byte commands */
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") "
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") (delay %ld): "
"%02x %02x %02x %02x %02x %02x"
" %02x %02x %02x %02x %02x %02x %02x %02x %02x %02x",
sn, cdb[0], cdb[1], cdb[2], cdb[3],
sn, delay,
cdb[0], cdb[1], cdb[2], cdb[3],
cdb[4], cdb[5], cdb[6], cdb[7],
cdb[8], cdb[9], cdb[10], cdb[11],
cdb[12], cdb[13], cdb[14], cdb[15]);
break;
case 5: /* 12 byte commands */
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") "
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") (delay %ld): "
"%02x %02x %02x %02x %02x %02x %02x"
" %02x %02x %02x %02x %02x",
sn, cdb[0], cdb[1], cdb[2], cdb[3],
sn, delay,
cdb[0], cdb[1], cdb[2], cdb[3],
cdb[4], cdb[5], cdb[6], cdb[7],
cdb[8], cdb[9], cdb[10], cdb[11]);
break;
case 6: /* Vendor Specific */
case 7: /* Vendor Specific */
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") VENDOR SPECIFIC !! "
MHVTL_DBG_NO_FUNC(lvl, "CDB (%" PRId64 ") (delay %ld), "
"VENDOR SPECIFIC !! "
" %02x %02x %02x %02x %02x %02x",
sn, cdb[0], cdb[1], cdb[2], cdb[3],
sn, delay,
cdb[0], cdb[1], cdb[2], cdb[3],
cdb[4], cdb[5]);
break;
}
Expand Down Expand Up @@ -689,11 +699,11 @@ char *get_version(void)
return c;
}

void log_opcode(char *opcode, uint8_t *cdb, struct vtl_ds *dbuf_p)
void log_opcode(char *opcode, struct scsi_cmd *cmd)
{
MHVTL_DBG(1, "*** Unsupported op code: %s ***", opcode);
mkSenseBuf(ILLEGAL_REQUEST, E_INVALID_OP_CODE, &dbuf_p->sam_stat);
MHVTL_DBG_PRT_CDB(1, dbuf_p->serialNo, cdb);
mkSenseBuf(ILLEGAL_REQUEST, E_INVALID_OP_CODE, &cmd->dbuf_p->sam_stat);
MHVTL_DBG_PRT_CDB(1, cmd);
}

/*
Expand Down
6 changes: 4 additions & 2 deletions usr/vtllib.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
#endif
#include <inttypes.h>
#include <sys/types.h>
#include <unistd.h>

#include "vtl_common.h"

Expand Down Expand Up @@ -325,6 +326,7 @@ struct scsi_cmd {
uint8_t *scb; /* SCSI Command Block */
int scb_len;
int cdev; /* filepointer to char dev */
useconds_t pollInterval; /* Poor mans Performance counter */
struct vtl_ds *dbuf_p;
struct lu_phy_attr *lu;
};
Expand Down Expand Up @@ -509,7 +511,7 @@ void status_change(FILE *fifo_fd, int current_status, int my_id, char **msg);
char *readline(char *s, int len, FILE *f);
void blank_fill(uint8_t *dest, char *src, int len);

void log_opcode(char *opcode, uint8_t *SCpnt, struct vtl_ds *dbuf_p);
void log_opcode(char *opcode, struct scsi_cmd *cmd);

struct vpd *alloc_vpd(uint16_t sz);
pid_t add_lu(int minor, struct vtl_ctl *ctl);
Expand All @@ -520,7 +522,7 @@ int retrieve_CDB_data(int cdev, struct vtl_ds *dbuf_p);
void get_sn_inquiry(int, struct vtl_sn_inquiry *);
int check_for_running_daemons(int minor);

void mhvtl_prt_cdb(int l, uint64_t sn, uint8_t * cdb);
void mhvtl_prt_cdb(int l, struct scsi_cmd *cmd);
void checkstrlen(char *s, unsigned int len);
extern int device_type_register(struct lu_phy_attr *lu,
struct device_type_template *t);
Expand Down
2 changes: 1 addition & 1 deletion usr/vtllibrary.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -276,7 +276,7 @@ static void processCommand(int cdev, uint8_t *cdb, struct vtl_ds *dbuf_p)
cmd->dbuf_p = dbuf_p;
cmd->lu = &lunit;

MHVTL_DBG_PRT_CDB(1, dbuf_p->serialNo, cdb);
MHVTL_DBG_PRT_CDB(1, cmd);

switch (cdb[0]) {
case REPORT_LUNS:
Expand Down
34 changes: 20 additions & 14 deletions usr/vtltape.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -122,6 +122,7 @@ long my_id;
* and call usleep() before polling again.
*/
long backoff = 0;
static useconds_t cumul_pollInterval;

int library_id = 0;

Expand Down Expand Up @@ -1565,7 +1566,8 @@ static void updateMAM(uint8_t *sam_stat, int loadCount)
* cdb -> SCSI Command buffer pointer,
* dbuf -> struct vtl_ds *
*/
static void processCommand(int cdev, uint8_t *cdb, struct vtl_ds *dbuf_p)
static void processCommand(int cdev, uint8_t *cdb, struct vtl_ds *dbuf_p,
useconds_t pollInterval)
{
static int last_count;
struct scsi_cmd _cmd;
Expand All @@ -1577,19 +1579,20 @@ static void processCommand(int cdev, uint8_t *cdb, struct vtl_ds *dbuf_p)
cmd->dbuf_p = dbuf_p;
cmd->lu = &lunit;
cmd->cdev = cdev;
cmd->pollInterval = pollInterval;

dbuf_p->sz = 0;

if ((cdb[0] == READ_6 || cdb[0] == WRITE_6) && cdb[0] == last_cmd) {
MHVTL_DBG_PRT_CDB(2, dbuf_p->serialNo, cdb);
MHVTL_DBG_PRT_CDB(2, cmd);
if ((++last_count % 50) == 0) {
MHVTL_DBG(1, "%dth contiguous %s request (%ld) ",
last_count,
last_cmd == READ_6 ? "READ_6" : "WRITE_6",
(long)dbuf_p->serialNo);
}
} else {
MHVTL_DBG_PRT_CDB(1, dbuf_p->serialNo, cdb);
MHVTL_DBG_PRT_CDB(1, cmd);
last_count = 0;
}

Expand Down Expand Up @@ -2563,7 +2566,8 @@ static int init_lu(struct lu_phy_attr *lu, int minor, struct vtl_ctl *ctl)
return found;
}

static void process_cmd(int cdev, uint8_t *buf, struct vtl_header *vtl_cmd)
static void process_cmd(int cdev, uint8_t *buf, struct vtl_header *vtl_cmd,
useconds_t pollInterval)
{
struct vtl_ds dbuf;
uint8_t *cdb;
Expand All @@ -2582,7 +2586,7 @@ static void process_cmd(int cdev, uint8_t *buf, struct vtl_header *vtl_cmd)
dbuf.sam_stat = lu_ssc.sam_status;
dbuf.sense_buf = &sense;

processCommand(cdev, cdb, &dbuf);
processCommand(cdev, cdb, &dbuf, pollInterval);

/* Complete SCSI cmd processing */
completeSCSICommand(cdev, &dbuf);
Expand Down Expand Up @@ -2614,6 +2618,8 @@ static void init_lu_ssc(struct priv_lu_ssc *lu_priv)
INIT_LIST_HEAD(&lu_priv->supported_media_list);
lu_priv->pm = NULL;
lu_priv->state_msg = NULL;

cumul_pollInterval = 0L;
}

void personality_module_register(struct ssc_personality_template *pm)
Expand All @@ -2635,7 +2641,7 @@ int main(int argc, char *argv[])
int cdev;
int ret;
int last_state = MHVTL_STATE_UNKNOWN;
useconds_t pollInterval = 50000L;
useconds_t sleep_time = 50000L; /* Used as backoff counter */
uint8_t *buf;
pid_t child_cleanup, pid, sid;
struct sigaction new_action, old_action;
Expand Down Expand Up @@ -2878,7 +2884,7 @@ int main(int argc, char *argv[])
if (debug)
printf("ioctl(VX_TAPE_POLL_STATUS) "
"returned: %d, interval: %ld\n",
ret, (long)pollInterval);
ret, (long)sleep_time);
if (child_cleanup) {
if (waitpid(child_cleanup, NULL, WNOHANG)) {
MHVTL_DBG(1,
Expand All @@ -2894,24 +2900,24 @@ int main(int argc, char *argv[])
cmd = malloc(sizeof(struct vtl_header));
if (!cmd) {
MHVTL_ERR("Out of memory");
pollInterval = 1000000;
sleep_time = 1000000;
} else {
memcpy(cmd, &vtl_cmd, sizeof(vtl_cmd));
process_cmd(cdev, buf, cmd);
process_cmd(cdev, buf, cmd, sleep_time);
/* Something to do, reduce poll time */
pollInterval = 10;
sleep_time = 10;
free(cmd);
}
break;

case VTL_IDLE:
usleep(pollInterval);
usleep(sleep_time);

/* While nothing to do, increase
* time we sleep before polling again.
*/
if (pollInterval < 1000000)
pollInterval += backoff;
if (sleep_time < 1000000)
sleep_time += backoff;

break;

Expand All @@ -2928,7 +2934,7 @@ int main(int argc, char *argv[])
&lu_ssc.state_msg);
last_state = current_state;
}
if (pollInterval > 0xf000) {
if (sleep_time > 0xf000) {
if (lu_ssc.tapeLoaded == TAPE_LOADED)
current_state = MHVTL_STATE_LOADED_IDLE;
else
Expand Down

0 comments on commit 6f67beb

Please sign in to comment.