From 7412de833bbad6469cba2d33710575539074c92d Mon Sep 17 00:00:00 2001 From: Vladislav Bolkhovitin Date: Fri, 11 Jan 2008 18:09:38 +0000 Subject: [PATCH] Logging improvements git-svn-id: http://svn.code.sf.net/p/scst/svn/trunk@244 d57e44dd-8a1f-0410-8b47-8ef2f437770f --- iscsi-scst/kernel/iscsi.c | 4 +- iscsi-scst/kernel/iscsi_dbg.h | 51 ++-------- iscsi-scst/kernel/nthread.c | 8 +- qla2x00t/qla2x00-target/qla2x00t.c | 10 +- scst/include/scst_debug.h | 152 ++++++++++++----------------- scst/src/dev_handlers/scst_vdisk.c | 4 +- scst/src/scst_lib.c | 33 ++++--- scst/src/scst_priv.h | 24 +++-- scst/src/scst_proc.c | 12 +-- scst/src/scst_targ.c | 34 +++---- usr/fileio/debug.h | 48 ++++----- 11 files changed, 166 insertions(+), 214 deletions(-) diff --git a/iscsi-scst/kernel/iscsi.c b/iscsi-scst/kernel/iscsi.c index 5b90d74ca..2e860d268 100644 --- a/iscsi-scst/kernel/iscsi.c +++ b/iscsi-scst/kernel/iscsi.c @@ -998,7 +998,7 @@ static void send_r2t(struct iscsi_cmnd *req) req->r2t_length = 0; } - TRACE(TRACE_D_WRITE, "%x %u %u %u %u", cmnd_itt(req), + TRACE_WRITE("%x %u %u %u %u", cmnd_itt(req), be32_to_cpu(rsp_hdr->data_length), be32_to_cpu(rsp_hdr->buffer_offset), be32_to_cpu(rsp_hdr->r2t_sn), req->outstanding_r2t); @@ -1353,7 +1353,7 @@ static int data_out_start(struct iscsi_conn *conn, struct iscsi_cmnd *cmnd) goto out; } - TRACE(TRACE_D_WRITE, "%u %p %p %u %u", req_hdr->ttt, cmnd, req, + TRACE_WRITE("%u %p %p %u %u", req_hdr->ttt, cmnd, req, offset, cmnd->pdu.datasize); res = cmnd_prepare_recv_pdu(conn, req, offset, cmnd->pdu.datasize); diff --git a/iscsi-scst/kernel/iscsi_dbg.h b/iscsi-scst/kernel/iscsi_dbg.h index 874c69750..8f76aac75 100644 --- a/iscsi-scst/kernel/iscsi_dbg.h +++ b/iscsi-scst/kernel/iscsi_dbg.h @@ -54,53 +54,22 @@ extern void iscsi_dump_pdu(struct iscsi_pdu *pdu); #if defined(DEBUG) || defined(TRACING) extern unsigned long iscsi_trace_flag; #define trace_flag iscsi_trace_flag +#endif -#define TRACE_CONN_CLOSE(format, args...) \ -do { \ - if (trace_flag & TRACE_CONN_OC) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, LOG_PREFIX, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) +#ifdef DEBUG -#define TRACE_CONN_CLOSE_DBG(format, args...) \ -do { \ - if (trace_flag & TRACE_CONN_OC_DBG) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, LOG_PREFIX, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) +#define TRACE_CONN_CLOSE(args...) TRACE(TRACE_CONN_OC, args) +#define TRACE_CONN_CLOSE_DBG(args...) TRACE(TRACE_CONN_OC_DBG, args) +#define TRACE_NET_PAGE(args...) TRACE(TRACE_NET_PG, args) +#define TRACE_WRITE(args...) TRACE(TRACE_D_WRITE, args) +#define TRACE_READ(args...) TRACE(TRACE_D_READ, args) -#define TRACE_NET_PAGE(format, args...) \ -do { \ - if (trace_flag & TRACE_NET_PG) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, LOG_PREFIX, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) - -#else /* defined(DEBUG) || defined(TRACING) */ +#else /* DEBUG */ #define TRACE_CONN_CLOSE(format, args...) {} #define TRACE_CONN_CLOSE_DBG(format, args...) {} #define TRACE_NET_PAGE(format, args...) {} +#define TRACE_WRITE(args...) {} +#define TRACE_READ(args...) {} #endif #endif diff --git a/iscsi-scst/kernel/nthread.c b/iscsi-scst/kernel/nthread.c index 4cf37efd4..19139173b 100644 --- a/iscsi-scst/kernel/nthread.c +++ b/iscsi-scst/kernel/nthread.c @@ -773,8 +773,8 @@ retry: set_fs(KERNEL_DS); res = vfs_writev(file, (struct iovec __user *)iop, count, &off); set_fs(oldfs); - TRACE(TRACE_D_WRITE, "%#Lx:%u: %d(%ld)", - (unsigned long long) conn->session->sid, conn->cid, + TRACE_WRITE("%#Lx:%u: %d(%ld)", + (unsigned long long)conn->session->sid, conn->cid, res, (long) iop->iov_len); if (unlikely(res <= 0)) { if (res == -EAGAIN) { @@ -845,7 +845,7 @@ retry: if (size <= sendsize) { retry2: res = sendpage(sock, sg[idx].page, offset, size, flags); - TRACE(TRACE_D_WRITE, "%s %#Lx:%u: %d(%lu,%u,%u)", + TRACE_WRITE("%s %#Lx:%u: %d(%lu,%u,%u)", sock->ops->sendpage ? "sendpage" : "sock_no_sendpage", (unsigned long long)conn->session->sid, conn->cid, res, sg[idx].page->index, offset, size); @@ -868,7 +868,7 @@ retry2: retry1: res = sendpage(sock, sg[idx].page, offset, sendsize, flags | MSG_MORE); - TRACE(TRACE_D_WRITE, "%s %#Lx:%u: %d(%lu,%u,%u)", + TRACE_WRITE("%s %#Lx:%u: %d(%lu,%u,%u)", sock->ops->sendpage ? "sendpage" : "sock_no_sendpage", (unsigned long long ) conn->session->sid, conn->cid, res, sg[idx].page->index, offset, sendsize); diff --git a/qla2x00t/qla2x00-target/qla2x00t.c b/qla2x00t/qla2x00-target/qla2x00t.c index f128292d5..d7c4a5f9c 100644 --- a/qla2x00t/qla2x00-target/qla2x00t.c +++ b/qla2x00t/qla2x00-target/qla2x00t.c @@ -545,7 +545,7 @@ static void q2t_load_data_segments(struct q2t_prm *prm) prm->pkt->dseg_count = cpu_to_le16(prm->seg_cnt); /* If scatter gather */ - TRACE(TRACE_SG, "%s", "Building S/G data segments..."); + TRACE_SG("%s", "Building S/G data segments..."); /* Load command entry data segments */ for (cnt = 0; (cnt < prm->tgt->datasegs_per_cmd) && prm->seg_cnt; @@ -560,7 +560,7 @@ static void q2t_load_data_segments(struct q2t_prm *prm) } *dword_ptr++ = cpu_to_le32(sg_dma_len(prm->sg)); - TRACE(TRACE_SG, "S/G Segment phys_addr=%llx:%llx, len=%d", + TRACE_SG("S/G Segment phys_addr=%llx:%llx, len=%d", (long long unsigned int)pci_dma_hi32(sg_dma_address(prm->sg)), (long long unsigned int)pci_dma_lo32(sg_dma_address(prm->sg)), (int)sg_dma_len(prm->sg)); @@ -615,9 +615,7 @@ static void q2t_load_data_segments(struct q2t_prm *prm) } *dword_ptr++ = cpu_to_le32(sg_dma_len(prm->sg)); - TRACE(TRACE_SG, - "S/G Segment Cont. phys_addr=%llx:%llx, " - "len=%d", + TRACE_SG("S/G Segment Cont. phys_addr=%llx:%llx, len=%d", (long long unsigned int)pci_dma_hi32(sg_dma_address(prm->sg)), (long long unsigned int)pci_dma_lo32(sg_dma_address(prm->sg)), (int)sg_dma_len(prm->sg)); @@ -1781,7 +1779,7 @@ static void q2t_response_pkt(scsi_qla_host_t *ha, sts_entry_t *pkt) le16_to_cpu(atio->status)); break; } - TRACE_BUFF_FLAG(TRACE_SCSI, "CDB", atio->cdb, + PRINT_BUFF_FLAG(TRACE_SCSI, "CDB", atio->cdb, sizeof(atio->cdb)); rc = q2t_send_cmd_to_scst(ha, atio); if (unlikely(rc != 0)) { diff --git a/scst/include/scst_debug.h b/scst/include/scst_debug.h index 037d43dd4..a21dcb385 100644 --- a/scst/include/scst_debug.h +++ b/scst/include/scst_debug.h @@ -112,7 +112,7 @@ #define TRACE_ENTRYEXIT 0x00000010 #define TRACE_BUFF 0x00000020 #define TRACE_MEMORY 0x00000040 -#define TRACE_SG 0x00000080 +#define TRACE_SG_OP 0x00000080 #define TRACE_OUT_OF_MEM 0x00000100 #define TRACE_MINOR 0x00000200 /* less important events */ #define TRACE_MGMT 0x00000400 @@ -134,13 +134,19 @@ #if defined(DEBUG) || defined(TRACING) +#ifndef DEBUG +#define ___unlikely(a) (a) +#else +#define ___unlikely(a) unlikely(a) +#endif + extern int debug_print_prefix(unsigned long trace_flag, const char *prefix, const char *func, int line); extern void debug_print_buffer(const void *data, int len); #define TRACE(trace, format, args...) \ do { \ - if (trace_flag & (trace)) \ + if (___unlikely(trace_flag & (trace))) \ { \ char *__tflag = LOG_FLAG; \ if (debug_print_prefix(trace_flag, __LOG_PREFIX, __FUNCTION__, \ @@ -152,6 +158,58 @@ do { \ } \ } while(0) +#define PRINT_BUFFER(message, buff, len) \ +do { \ + PRINT(NO_FLAG, "%s:", message); \ + debug_print_buffer(buff, len); \ +} while(0) + +#define PRINT_BUFF_FLAG(flag, message, buff, len) \ +do { \ + if (___unlikely(trace_flag & (flag))) \ + { \ + char *__tflag = LOG_FLAG; \ + if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ + __LINE__) > 0) \ + { \ + __tflag = NO_FLAG; \ + } \ + PRINT(NO_FLAG, "%s%s:", __tflag, message); \ + debug_print_buffer(buff, len); \ + } \ +} while(0) + +#else /* DEBUG || TRACING */ + +#define TRACE(trace, args...) {} +#define PRINT_BUFFER(message, buff, len) {} +#define PRINT_BUFF_FLAG(flag, message, buff, len) {} + +#endif /* DEBUG || TRACING */ + +#ifdef DEBUG + +#define __TRACE(trace, format, args...) \ +do { \ + if (trace_flag & (trace)) \ + { \ + char *__tflag = LOG_FLAG; \ + if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ + __LINE__) > 0) \ + { \ + __tflag = NO_FLAG; \ + } \ + PRINT(NO_FLAG, "%s" format, __tflag, args); \ + } \ +} while(0) + +#define TRACE_MEM(args...) __TRACE(TRACE_MEMORY, args) +#define TRACE_SG(args...) __TRACE(TRACE_SG_OP, args) +#define TRACE_DBG(args...) __TRACE(TRACE_DEBUG, args) +#define TRACE_DBG_SPECIAL(args...) __TRACE((TRACE_DEBUG|TRACE_SPECIAL, args) +#define TRACE_MGMT_DBG(args...) __TRACE(TRACE_MGMT_DEBUG, args) +#define TRACE_MGMT_DBG_SPECIAL(args...) __TRACE(TRACE_MGMT_DEBUG|TRACE_SPECIAL, args) + #define TRACE_BUFFER(message, buff, len) \ do { \ if (trace_flag & TRACE_BUFF) \ @@ -182,93 +240,6 @@ do { \ } \ } while(0) -#define PRINT_BUFFER(message, buff, len) \ -do { \ - PRINT(NO_FLAG, "%s:", message); \ - debug_print_buffer(buff, len); \ -} while(0) - -#else /* DEBUG || TRACING */ - -#define TRACE(trace, args...) {} -#define TRACE_BUFFER(message, buff, len) {} -#define TRACE_BUFF_FLAG(flag, message, buff, len) {} -#define PRINT_BUFFER(message, buff, len) {} - -#endif /* DEBUG || TRACING */ - -#ifdef DEBUG - -#define TRACE_MEM(format, args...) \ -do { \ - if (trace_flag & TRACE_MEMORY) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) - -#define TRACE_DBG(format, args...) \ -do { \ - if (trace_flag & TRACE_DEBUG) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) - -#define TRACE_DBG_SPECIAL(format, args...) \ -do { \ - if (trace_flag & (TRACE_DEBUG|TRACE_SPECIAL)) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) - -#define TRACE_MGMT_DBG(format, args...) \ -do { \ - if (trace_flag & TRACE_MGMT_DEBUG) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) - -#define TRACE_MGMT_DBG_SPECIAL(format, args...) \ -do { \ - if (trace_flag & (TRACE_MGMT_DEBUG|TRACE_SPECIAL)) \ - { \ - char *__tflag = LOG_FLAG; \ - if (debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__) > 0) \ - { \ - __tflag = NO_FLAG; \ - } \ - PRINT(NO_FLAG, "%s" format, __tflag, args); \ - } \ -} while(0) - #define PRINT_LOG_FLAG(log_flag, format, args...) \ do { \ char *__tflag = log_flag; \ @@ -365,10 +336,13 @@ do { \ #else /* DEBUG */ #define TRACE_MEM(format, args...) {} +#define TRACE_SG(format, args...) {} #define TRACE_DBG(format, args...) {} #define TRACE_DBG_SPECIAL(format, args...) {} #define TRACE_MGMT_DBG(format, args...) {} #define TRACE_MGMT_DBG_SPECIAL(format, args...) {} +#define TRACE_BUFFER(message, buff, len) {} +#define TRACE_BUFF_FLAG(flag, message, buff, len) {} #define TRACE_ENTRY() {} #define TRACE_EXIT() {} #define TRACE_EXIT_RES(res) {} diff --git a/scst/src/dev_handlers/scst_vdisk.c b/scst/src/dev_handlers/scst_vdisk.c index 886f8c95a..e4976ba6e 100644 --- a/scst/src/dev_handlers/scst_vdisk.c +++ b/scst/src/dev_handlers/scst_vdisk.c @@ -43,15 +43,17 @@ #include "scsi_tgt.h" +#if defined(DEBUG) || defined(TRACING) + #define TRACE_ORDER 0x80000000 -#if defined(DEBUG) || defined(TRACING) static struct scst_proc_log vdisk_proc_local_trace_tbl[] = { { TRACE_ORDER, "order" }, { 0, NULL } }; #define trace_log_tbl vdisk_proc_local_trace_tbl + #endif #include "scst_dev_handler.h" diff --git a/scst/src/scst_lib.c b/scst/src/scst_lib.c index c6b2e86e5..35fd55521 100644 --- a/scst/src/scst_lib.c +++ b/scst/src/scst_lib.c @@ -141,10 +141,12 @@ void scst_set_resp_data_len(struct scst_cmd *cmd, int resp_data_len) l += cmd->sg[i].length; if (l >= resp_data_len) { int left = resp_data_len - (l - cmd->sg[i].length); - TRACE(TRACE_SG|TRACE_MEMORY, "cmd %p (tag %llu), " +#ifdef DEBUG + TRACE(TRACE_SG_OP|TRACE_MEMORY, "cmd %p (tag %llu), " "resp_data_len %d, i %d, cmd->sg[i].length %d, " "left %d", cmd, cmd->tag, resp_data_len, i, cmd->sg[i].length, left); +#endif cmd->orig_sg_cnt = cmd->sg_cnt; cmd->orig_sg_entry = i; cmd->orig_entry_len = cmd->sg[i].length; @@ -919,7 +921,7 @@ struct scst_cmd *scst_complete_request_sense(struct scst_cmd *cmd) if (scsi_status_is_good(cmd->status) && (len > 0) && SCST_SENSE_VALID(buf) && (!SCST_NO_SENSE(buf))) { - TRACE_BUFF_FLAG(TRACE_SCSI, "REQUEST SENSE returned", + PRINT_BUFF_FLAG(TRACE_SCSI, "REQUEST SENSE returned", buf, len); memcpy(orig_cmd->sense_buffer, buf, ((int)sizeof(orig_cmd->sense_buffer) > len) ? @@ -1039,7 +1041,7 @@ static void scst_send_release(struct scst_tgt_dev *tgt_dev) break; } else { PRINT_ERROR("RELEASE failed: %d", rc); - TRACE_BUFFER("RELEASE sense", sense, + PRINT_BUFFER("RELEASE sense", sense, SCST_SENSE_BUFFERSIZE); scst_check_internal_sense(tgt_dev->dev, rc, sense, SCST_SENSE_BUFFERSIZE); @@ -1363,7 +1365,7 @@ void scst_check_retries(struct scst_tgt *tgt) struct scst_cmd *c, *tc; unsigned long flags; - TRACE(TRACE_RETRY, "Checking retry cmd list (retry_cmds %d)", + TRACE_RETRY("Checking retry cmd list (retry_cmds %d)", tgt->retry_cmds); spin_lock_irqsave(&tgt->tgt_lock, flags); @@ -1372,7 +1374,7 @@ void scst_check_retries(struct scst_tgt *tgt) { tgt->retry_cmds--; - TRACE(TRACE_RETRY, "Moving retry cmd %p to head of active " + TRACE_RETRY("Moving retry cmd %p to head of active " "cmd list (retry_cmds left %d)", c, tgt->retry_cmds); spin_lock(&c->cmd_lists->cmd_list_lock); list_move(&c->cmd_list_entry, &c->cmd_lists->active_cmd_list); @@ -1395,8 +1397,7 @@ void scst_tgt_retry_timer_fn(unsigned long arg) struct scst_tgt *tgt = (struct scst_tgt*)arg; unsigned long flags; - TRACE(TRACE_RETRY, "Retry timer expired (retry_cmds %d)", - tgt->retry_cmds); + TRACE_RETRY("Retry timer expired (retry_cmds %d)", tgt->retry_cmds); spin_lock_irqsave(&tgt->tgt_lock, flags); tgt->retry_timer_active = 0; @@ -2127,7 +2128,7 @@ int scst_block_generic_dev_done(struct scst_cmd *cmd, else sh = 0; set_block_shift(cmd, sh); - TRACE(TRACE_SCSI, "block_shift %d", sh); + TRACE_DBG("block_shift %d", sh); break; } default: @@ -2250,7 +2251,7 @@ int scst_obtain_device_parameters(struct scst_device *dev) memset(buffer, 0, sizeof(buffer)); memset(sense_buffer, 0, sizeof(sense_buffer)); - TRACE_DBG("%s", "Doing MODE_SENSE"); + TRACE(TRACE_SCSI, "%s", "Doing internal MODE_SENSE"); res = scsi_execute(dev->scsi_dev, cmd, SCST_DATA_READ, buffer, sizeof(buffer), sense_buffer, SCST_DEFAULT_TIMEOUT, 0, GFP_KERNEL); @@ -2260,8 +2261,8 @@ int scst_obtain_device_parameters(struct scst_device *dev) if (scsi_status_is_good(res)) { int q; - TRACE_BUFFER("Returned control mode page data", buffer, - sizeof(buffer)); + PRINT_BUFF_FLAG(TRACE_SCSI, "Returned control mode page data", + buffer, sizeof(buffer)); dev->tst = buffer[4+2] >> 5; q = buffer[4+3] >> 4; @@ -2282,7 +2283,7 @@ int scst_obtain_device_parameters(struct scst_device *dev) */ dev->has_own_order_mgmt = !dev->queue_alg; - TRACE(TRACE_MGMT_MINOR, "Device %d:%d:%d:%d: TST %x, " + TRACE(TRACE_SCSI|TRACE_MGMT_MINOR, "Device %d:%d:%d:%d: TST %x, " "QUEUE ALG %x, SWP %x, TAS %x, has_own_order_mgmt " "%d", dev->scsi_dev->host->host_no, dev->scsi_dev->channel, dev->scsi_dev->id, @@ -2294,7 +2295,7 @@ int scst_obtain_device_parameters(struct scst_device *dev) if ((status_byte(res) == CHECK_CONDITION) && SCST_SENSE_VALID(sense_buffer) && (sense_buffer[2] == ILLEGAL_REQUEST)) { - TRACE(TRACE_MGMT_MINOR, "Device %d:%d:%d:%d " + TRACE(TRACE_SCSI|TRACE_MGMT_MINOR, "Device %d:%d:%d:%d " "doesn't support control mode page, using " "defaults: TST %x, QUEUE ALG %x, SWP %x, " "TAS %x, has_own_order_mgmt %d", @@ -2305,13 +2306,13 @@ int scst_obtain_device_parameters(struct scst_device *dev) res = 0; goto out; } else { - TRACE(TRACE_MGMT_MINOR, "Internal MODE SENSE to " + TRACE(TRACE_SCSI|TRACE_MGMT_MINOR, "Internal MODE SENSE to " "device %d:%d:%d:%d failed: %x", dev->scsi_dev->host->host_no, dev->scsi_dev->channel, dev->scsi_dev->id, dev->scsi_dev->lun, res); - TRACE_BUFF_FLAG(TRACE_MGMT_MINOR, "MODE SENSE sense", - sense_buffer, sizeof(sense_buffer)); + PRINT_BUFF_FLAG(TRACE_SCSI|TRACE_MGMT_MINOR, "MODE SENSE " + "sense", sense_buffer, sizeof(sense_buffer)); } scst_check_internal_sense(dev, res, sense_buffer, sizeof(sense_buffer)); diff --git a/scst/src/scst_priv.h b/scst/src/scst_priv.h index b678ca45e..b120990cb 100644 --- a/scst/src/scst_priv.h +++ b/scst/src/scst_priv.h @@ -36,12 +36,12 @@ #define SCST_MAJOR 177 -#define TRACE_RETRY 0x80000000 +#define TRACE_RTRY 0x80000000 #define TRACE_SCSI_SERIALIZING 0x40000000 -#define TRACE_SEND_TOP 0x20000000 /** top being the edge away from the interupt */ -#define TRACE_RECV_TOP 0x01000000 -#define TRACE_SEND_BOT 0x08000000 /** bottom being the edge toward the interupt */ -#define TRACE_RECV_BOT 0x04000000 +#define TRACE_SND_TOP 0x20000000 /** top being the edge away from the interupt */ +#define TRACE_RCV_TOP 0x01000000 +#define TRACE_SND_BOT 0x08000000 /** bottom being the edge toward the interupt */ +#define TRACE_RCV_BOT 0x04000000 #if defined(DEBUG) || defined(TRACING) #define trace_flag scst_trace_flag @@ -56,9 +56,14 @@ extern unsigned long scst_trace_flag; */ #define SCST_DEFAULT_LOG_FLAGS (TRACE_OUT_OF_MEM | TRACE_MINOR | TRACE_PID | \ TRACE_LINE | TRACE_FUNCTION | TRACE_SPECIAL | TRACE_MGMT | \ - TRACE_MGMT_MINOR | TRACE_MGMT_DEBUG | TRACE_RETRY) + TRACE_MGMT_MINOR | TRACE_MGMT_DEBUG | TRACE_RTRY) -#define TRACE_SN(args...) TRACE(TRACE_SCSI_SERIALIZING, args) +#define TRACE_RETRY(args...) __TRACE(TRACE_RTRY, args) +#define TRACE_SN(args...) __TRACE(TRACE_SCSI_SERIALIZING, args) +#define TRACE_SEND_TOP(args...) __TRACE(TRACE_SND_TOP, args) +#define TRACE_RECV_TOP(args...) __TRACE(TRACE_RCV_TOP, args) +#define TRACE_SEND_BOT(args...) __TRACE(TRACE_SND_BOT, args) +#define TRACE_RECV_BOT(args...) __TRACE(TRACE_RCV_BOT, args) #else /* DEBUG */ @@ -68,7 +73,12 @@ extern unsigned long scst_trace_flag; #define SCST_DEFAULT_LOG_FLAGS 0 # endif +#define TRACE_RETRY(args...) #define TRACE_SN(args...) +#define TRACE_SEND_TOP(args...) +#define TRACE_RECV_TOP(args...) +#define TRACE_SEND_BOT(args...) +#define TRACE_RECV_BOT(args...) #endif diff --git a/scst/src/scst_proc.c b/scst/src/scst_proc.c index defc373c9..44a376551 100644 --- a/scst/src/scst_proc.c +++ b/scst/src/scst_proc.c @@ -90,7 +90,7 @@ static struct scst_proc_log scst_proc_trace_tbl[] = { { TRACE_OUT_OF_MEM, "out_of_mem" }, { TRACE_MINOR, "minor" }, - { TRACE_SG, "sg" }, + { TRACE_SG_OP, "sg" }, { TRACE_MEMORY, "mem" }, { TRACE_BUFF, "buff" }, { TRACE_ENTRYEXIT, "entryexit" }, @@ -108,12 +108,12 @@ static struct scst_proc_log scst_proc_trace_tbl[] = static struct scst_proc_log scst_proc_local_trace_tbl[] = { - { TRACE_RETRY, "retry" }, + { TRACE_RTRY, "retry" }, { TRACE_SCSI_SERIALIZING, "scsi_serializing" }, - { TRACE_RECV_BOT, "recv_bot" }, - { TRACE_SEND_BOT, "send_bot" }, - { TRACE_RECV_TOP, "recv_top" }, - { TRACE_SEND_TOP, "send_top" }, + { TRACE_RCV_BOT, "recv_bot" }, + { TRACE_SND_BOT, "send_bot" }, + { TRACE_RCV_TOP, "recv_top" }, + { TRACE_SND_TOP, "send_top" }, { 0, NULL } }; #endif diff --git a/scst/src/scst_targ.c b/scst/src/scst_targ.c index 00c01f288..aa6ec1979 100644 --- a/scst/src/scst_targ.c +++ b/scst/src/scst_targ.c @@ -172,7 +172,7 @@ void scst_cmd_init_done(struct scst_cmd *cmd, int pref_context) TRACE_DBG("Preferred context: %d (cmd %p)", pref_context, cmd); TRACE(TRACE_SCSI, "tag=%llu, lun=%Ld, CDB len=%d", cmd->tag, (uint64_t)cmd->lun, cmd->cdb_len); - TRACE_BUFF_FLAG(TRACE_SCSI|TRACE_RECV_BOT, "Recieving CDB", + PRINT_BUFF_FLAG(TRACE_SCSI|TRACE_RCV_BOT, "Recieving CDB", cmd->cdb, cmd->cdb_len); #ifdef EXTRACHECKS @@ -410,7 +410,7 @@ static int scst_parse_cmd(struct scst_cmd *cmd) if (likely(!scst_is_cmd_local(cmd))) { TRACE_DBG("Calling dev handler %s parse(%p)", dev->handler->name, cmd); - TRACE_BUFF_FLAG(TRACE_SEND_BOT, "Parsing: ", cmd->cdb, cmd->cdb_len); + TRACE_BUFF_FLAG(TRACE_SND_BOT, "Parsing: ", cmd->cdb, cmd->cdb_len); state = dev->handler->parse(cmd); /* Caution: cmd can be already dead here */ TRACE_DBG("Dev handler %s parse() returned %d", @@ -759,12 +759,12 @@ static int scst_queue_retry_cmd(struct scst_cmd *cmd, int finished_cmds) spin_lock_irqsave(&tgt->tgt_lock, flags); tgt->retry_cmds++; smp_mb(); - TRACE(TRACE_RETRY, "TGT QUEUE FULL: incrementing retry_cmds %d", + TRACE_RETRY("TGT QUEUE FULL: incrementing retry_cmds %d", tgt->retry_cmds); if (finished_cmds != atomic_read(&tgt->finished_cmds)) { /* At least one cmd finished, so try again */ tgt->retry_cmds--; - TRACE(TRACE_RETRY, "Some command(s) finished, direct retry " + TRACE_RETRY("Some command(s) finished, direct retry " "(finished_cmds=%d, tgt->finished_cmds=%d, " "retry_cmds=%d)", finished_cmds, atomic_read(&tgt->finished_cmds), tgt->retry_cmds); @@ -772,7 +772,7 @@ static int scst_queue_retry_cmd(struct scst_cmd *cmd, int finished_cmds) goto out_unlock_tgt; } - TRACE(TRACE_RETRY, "Adding cmd %p to retry cmd list", cmd); + TRACE_RETRY("Adding cmd %p to retry cmd list", cmd); list_add_tail(&cmd->cmd_list_entry, &tgt->retry_cmd_list); if (!tgt->retry_timer_active) { @@ -1157,16 +1157,15 @@ static void scst_cmd_done_local(struct scst_cmd *cmd, int next_state) if (next_state == SCST_CMD_STATE_DEFAULT) next_state = SCST_CMD_STATE_PRE_DEV_DONE; -#if defined(DEBUG) || defined(TRACING) +#if defined(DEBUG) if (next_state == SCST_CMD_STATE_PRE_DEV_DONE) { if (cmd->sg) { int i; struct scatterlist *sg = cmd->sg; - TRACE(TRACE_RECV_TOP, - "Exec'd %d S/G(s) at %p sg[0].page at %p", - cmd->sg_cnt, sg, (void*)sg[0].page); + TRACE_RECV_TOP("Exec'd %d S/G(s) at %p sg[0].page at " + "%p", cmd->sg_cnt, sg, (void*)sg[0].page); for(i = 0; i < cmd->sg_cnt; ++i) { - TRACE_BUFF_FLAG(TRACE_RECV_TOP, + TRACE_BUFF_FLAG(TRACE_RCV_TOP, "Exec'd sg", page_address(sg[i].page), sg[i].length); } @@ -1664,7 +1663,7 @@ static int scst_do_send_to_midlev(struct scst_cmd *cmd) struct scst_device *dev = cmd->dev; TRACE_DBG("Calling dev handler %s exec(%p)", dev->handler->name, cmd); - TRACE_BUFF_FLAG(TRACE_SEND_TOP, "Execing: ", cmd->cdb, cmd->cdb_len); + TRACE_BUFF_FLAG(TRACE_SND_TOP, "Execing: ", cmd->cdb, cmd->cdb_len); cmd->scst_cmd_done = scst_cmd_done_local; rc = dev->handler->exec(cmd); /* !! At this point cmd, sess & tgt_dev can be already freed !! */ @@ -1955,7 +1954,7 @@ static int scst_check_sense(struct scst_cmd *cmd) if (unlikely(cmd->status == SAM_STAT_CHECK_CONDITION) && SCST_SENSE_VALID(cmd->sense_buffer)) { - TRACE_BUFF_FLAG(TRACE_SCSI, "Sense", cmd->sense_buffer, + PRINT_BUFF_FLAG(TRACE_SCSI, "Sense", cmd->sense_buffer, sizeof(cmd->sense_buffer)); /* Check Unit Attention Sense Key */ if (scst_is_ua_sense(cmd->sense_buffer)) { @@ -2153,8 +2152,8 @@ static int scst_done_cmd_check(struct scst_cmd *cmd, int *pres) TRACE(TRACE_SCSI, "Real RESERVE failed lun=%Ld, status=%x", (uint64_t)cmd->lun, cmd->status); - TRACE_BUFF_FLAG(TRACE_SCSI, "Sense", cmd->sense_buffer, - sizeof(cmd->sense_buffer)); + PRINT_BUFF_FLAG(TRACE_SCSI, "Sense", cmd->sense_buffer, + sizeof(cmd->sense_buffer)); /* Clearing the reservation */ spin_lock_bh(&dev->dev_lock); @@ -2461,15 +2460,14 @@ static int scst_xmit_response(struct scst_cmd *cmd) TRACE_DBG("Calling xmit_response(%p)", cmd); -#if defined(DEBUG) || defined(TRACING) +#if defined(DEBUG) if (cmd->sg) { int i; struct scatterlist *sg = cmd->sg; - TRACE(TRACE_SEND_BOT, - "Xmitting %d S/G(s) at %p sg[0].page at %p", + TRACE_SEND_BOT("Xmitting %d S/G(s) at %p sg[0].page at %p", cmd->sg_cnt, sg, (void*)sg[0].page); for(i = 0; i < cmd->sg_cnt; ++i) { - TRACE_BUFF_FLAG(TRACE_SEND_BOT, + TRACE_BUFF_FLAG(TRACE_SND_BOT, "Xmitting sg", page_address(sg[i].page), sg[i].length); } diff --git a/usr/fileio/debug.h b/usr/fileio/debug.h index ee9929bd5..73805bdb0 100644 --- a/usr/fileio/debug.h +++ b/usr/fileio/debug.h @@ -88,28 +88,6 @@ do { \ } \ } while(0) -#define TRACE_BUFFER(message, buff, len) \ -do { \ - if (trace_flag & TRACE_BUFF) \ - { \ - debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__); \ - PRINT("%s:", message); \ - debug_print_buffer(buff, len); \ - } \ -} while(0) - -#define TRACE_BUFF_FLAG(flag, message, buff, len) \ -do { \ - if (trace_flag & (flag)) \ - { \ - debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ - __LINE__); \ - PRINT("%s:", message); \ - debug_print_buffer(buff, len); \ - } \ -} while(0) - #define PRINT_BUFFER(message, buff, len) \ do { \ PRINT("%s:", message); \ @@ -119,8 +97,6 @@ do { \ #else /* DEBUG || TRACING */ #define TRACE(trace, args...) {} -#define TRACE_BUFFER(message, buff, len) {} -#define TRACE_BUFF_FLAG(flag, message, buff, len) {} #define PRINT_BUFFER(message, buff, len) {} static inline int debug_init(void) { return 0; } @@ -162,6 +138,28 @@ do { \ } \ } while(0) +#define TRACE_BUFFER(message, buff, len) \ +do { \ + if (trace_flag & TRACE_BUFF) \ + { \ + debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ + __LINE__); \ + PRINT("%s:", message); \ + debug_print_buffer(buff, len); \ + } \ +} while(0) + +#define TRACE_BUFF_FLAG(flag, message, buff, len) \ +do { \ + if (trace_flag & (flag)) \ + { \ + debug_print_prefix(trace_flag, NULL, __FUNCTION__, \ + __LINE__); \ + PRINT("%s:", message); \ + debug_print_buffer(buff, len); \ + } \ +} while(0) + #define PRINT_ERROR(format, args...) \ do { \ debug_print_prefix(trace_flag, __LOG_PREFIX, __FUNCTION__, \ @@ -248,6 +246,8 @@ do { \ #define TRACE_MEM(format, args...) {} #define TRACE_DBG(format, args...) {} #define TRACE_MGMT_DBG(format, args...) {} +#define TRACE_BUFFER(message, buff, len) {} +#define TRACE_BUFF_FLAG(flag, message, buff, len) {} #define TRACE_ENTRY() {} #define TRACE_EXIT() {} #define TRACE_EXIT_RES(res) {}