Author: mav
Date: Thu Oct 23 07:36:33 2014
New Revision: 273531
URL: https://svnweb.freebsd.org/changeset/base/273531
Log:
MFC r273163: Implement more functional CTL debug logging.
Setting bits in kern.cam.ctl.debug allows to log errors, commands and some
commands data respectively.
Modified:
stable/10/sys/cam/ctl/ctl.c
stable/10/sys/cam/ctl/ctl_debug.h
stable/10/sys/cam/ctl/ctl_private.h
stable/10/sys/cam/ctl/ctl_scsi_all.c
stable/10/sys/cam/ctl/ctl_util.c
stable/10/sys/cam/ctl/ctl_util.h
Directory Properties:
stable/10/ (props changed)
Modified: stable/10/sys/cam/ctl/ctl.c
==============================================================================
--- stable/10/sys/cam/ctl/ctl.c Thu Oct 23 07:22:18 2014 (r273530)
+++ stable/10/sys/cam/ctl/ctl.c Thu Oct 23 07:36:33 2014 (r273531)
@@ -315,10 +315,10 @@ static int worker_threads = -1;
TUNABLE_INT("kern.cam.ctl.worker_threads", &worker_threads);
SYSCTL_INT(_kern_cam_ctl, OID_AUTO, worker_threads, CTLFLAG_RDTUN,
&worker_threads, 1, "Number of worker threads");
-static int verbose = 0;
-TUNABLE_INT("kern.cam.ctl.verbose", &verbose);
-SYSCTL_INT(_kern_cam_ctl, OID_AUTO, verbose, CTLFLAG_RWTUN,
- &verbose, 0, "Show SCSI errors returned to initiator");
+static int ctl_debug = CTL_DEBUG_NONE;
+TUNABLE_INT("kern.cam.ctl.debug", &ctl_debug);
+SYSCTL_INT(_kern_cam_ctl, OID_AUTO, debug, CTLFLAG_RWTUN,
+ &ctl_debug, 0, "Enabled debug flags");
/*
* Supported pages (0x00), Serial number (0x80), Device ID (0x83),
@@ -5294,6 +5294,8 @@ ctl_config_move_done(union ctl_io *io)
*
* - Call some other function once the data is in?
*/
+ if (ctl_debug & CTL_DEBUG_CDB_DATA)
+ ctl_data_print(io);
/*
* XXX KDM call ctl_scsiio() again for now, and check flag
@@ -13766,17 +13768,14 @@ ctl_process_done(union ctl_io *io)
case CTL_IO_SCSI:
break;
case CTL_IO_TASK:
- if (bootverbose || verbose > 0)
+ if (bootverbose || (ctl_debug & CTL_DEBUG_INFO))
ctl_io_error_print(io, NULL);
if (io->io_hdr.flags & CTL_FLAG_FROM_OTHER_SC)
ctl_free_io(io);
else
fe_done(io);
return (CTL_RETVAL_COMPLETE);
- break;
default:
- printf("ctl_process_done: invalid io type %d\n",
- io->io_hdr.io_type);
panic("ctl_process_done: invalid io type %d\n",
io->io_hdr.io_type);
break; /* NOTREACHED */
@@ -13870,74 +13869,28 @@ ctl_process_done(union ctl_io *io)
ctl_set_task_aborted(&io->scsiio);
/*
- * We print out status for every task management command. For SCSI
- * commands, we filter out any unit attention errors; they happen
- * on every boot, and would clutter up the log. Note: task
- * management commands aren't printed here, they are printed above,
- * since they should never even make it down here.
+ * If enabled, print command error status.
+ * We don't print UAs unless debugging was enabled explicitly.
*/
- switch (io->io_hdr.io_type) {
- case CTL_IO_SCSI: {
- int error_code, sense_key, asc, ascq;
-
- sense_key = 0;
+ do {
+ if ((io->io_hdr.status & CTL_STATUS_MASK) == CTL_SUCCESS)
+ break;
+ if (!bootverbose && (ctl_debug & CTL_DEBUG_INFO) == 0)
+ break;
+ if ((ctl_debug & CTL_DEBUG_INFO) == 0 &&
+ ((io->io_hdr.status & CTL_STATUS_MASK) == CTL_SCSI_ERROR) &&
+ (io->scsiio.scsi_status == SCSI_STATUS_CHECK_COND)) {
+ int error_code, sense_key, asc, ascq;
- if (((io->io_hdr.status & CTL_STATUS_MASK) == CTL_SCSI_ERROR)
- && (io->scsiio.scsi_status == SCSI_STATUS_CHECK_COND)) {
- /*
- * Since this is just for printing, no need to
- * show errors here.
- */
scsi_extract_sense_len(&io->scsiio.sense_data,
- io->scsiio.sense_len,
- &error_code,
- &sense_key,
- &asc,
- &ascq,
- /*show_errors*/ 0);
+ io->scsiio.sense_len, &error_code, &sense_key,
+ &asc, &ascq, /*show_errors*/ 0);
+ if (sense_key == SSD_KEY_UNIT_ATTENTION)
+ break;
}
- if (((io->io_hdr.status & CTL_STATUS_MASK) != CTL_SUCCESS)
- && (((io->io_hdr.status & CTL_STATUS_MASK) != CTL_SCSI_ERROR)
- || (io->scsiio.scsi_status != SCSI_STATUS_CHECK_COND)
- || (sense_key != SSD_KEY_UNIT_ATTENTION))) {
-
- if ((time_uptime - ctl_softc->last_print_jiffies) <= 0){
- ctl_softc->skipped_prints++;
- } else {
- uint32_t skipped_prints;
-
- skipped_prints = ctl_softc->skipped_prints;
-
- ctl_softc->skipped_prints = 0;
- ctl_softc->last_print_jiffies = time_uptime;
-
- if (skipped_prints > 0) {
-#ifdef NEEDTOPORT
- csevent_log(CSC_CTL | CSC_SHELF_SW |
- CTL_ERROR_REPORT,
- csevent_LogType_Trace,
- csevent_Severity_Information,
- csevent_AlertLevel_Green,
- csevent_FRU_Firmware,
- csevent_FRU_Unknown,
- "High CTL error volume, %d prints "
- "skipped", skipped_prints);
-#endif
- }
- if (bootverbose || verbose > 0)
- ctl_io_error_print(io, NULL);
- }
- }
- break;
- }
- case CTL_IO_TASK:
- if (bootverbose || verbose > 0)
- ctl_io_error_print(io, NULL);
- break;
- default:
- break;
- }
+ ctl_io_error_print(io, NULL);
+ } while (0);
/*
* Tell the FETD or the other shelf controller we're done with this
@@ -14082,6 +14035,8 @@ ctl_queue(union ctl_io *io)
switch (io->io_hdr.io_type) {
case CTL_IO_SCSI:
case CTL_IO_TASK:
+ if (ctl_debug & CTL_DEBUG_CDB)
+ ctl_io_print(io);
ctl_enqueue_incoming(io);
break;
default:
Modified: stable/10/sys/cam/ctl/ctl_debug.h
==============================================================================
--- stable/10/sys/cam/ctl/ctl_debug.h Thu Oct 23 07:22:18 2014
(r273530)
+++ stable/10/sys/cam/ctl/ctl_debug.h Thu Oct 23 07:36:33 2014
(r273531)
@@ -39,6 +39,16 @@
#ifndef _CTL_DEBUG_H_
#define _CTL_DEBUG_H_
+/*
+ * Debugging flags.
+ */
+typedef enum {
+ CTL_DEBUG_NONE = 0x00, /* no debugging */
+ CTL_DEBUG_INFO = 0x01, /* SCSI errors */
+ CTL_DEBUG_CDB = 0x02, /* SCSI CDBs and tasks */
+ CTL_DEBUG_CDB_DATA = 0x04 /* SCSI CDB DATA */
+} ctl_debug_flags;
+
#ifdef CAM_CTL_DEBUG
#define CTL_DEBUG_PRINT(X) \
do { \
Modified: stable/10/sys/cam/ctl/ctl_private.h
==============================================================================
--- stable/10/sys/cam/ctl/ctl_private.h Thu Oct 23 07:22:18 2014
(r273530)
+++ stable/10/sys/cam/ctl/ctl_private.h Thu Oct 23 07:36:33 2014
(r273531)
@@ -456,8 +456,6 @@ struct ctl_softc {
uint32_t num_pools;
uint32_t cur_pool_id;
STAILQ_HEAD(, ctl_io_pool) io_pools;
- time_t last_print_jiffies;
- uint32_t skipped_prints;
struct ctl_thread threads[CTL_MAX_THREADS];
TAILQ_HEAD(tpc_tokens, tpc_token) tpc_tokens;
struct callout tpc_timeout;
Modified: stable/10/sys/cam/ctl/ctl_scsi_all.c
==============================================================================
--- stable/10/sys/cam/ctl/ctl_scsi_all.c Thu Oct 23 07:22:18 2014
(r273530)
+++ stable/10/sys/cam/ctl/ctl_scsi_all.c Thu Oct 23 07:36:33 2014
(r273531)
@@ -112,32 +112,10 @@ ctl_scsi_command_string(struct ctl_scsii
void
ctl_scsi_path_string(union ctl_io *io, char *path_str, int len)
{
- if (io->io_hdr.nexus.targ_target.wwid[0] == 0) {
- snprintf(path_str, len, "(%ju:%d:%ju:%d): ",
- (uintmax_t)io->io_hdr.nexus.initid.id,
- io->io_hdr.nexus.targ_port,
- (uintmax_t)io->io_hdr.nexus.targ_target.id,
- io->io_hdr.nexus.targ_lun);
- } else {
- /*
- * XXX KDM find a better way to display FC WWIDs.
- */
-#ifdef _KERNEL
- snprintf(path_str, len, "(%ju:%d:%#jx,%#jx:%d): ",
- (uintmax_t)io->io_hdr.nexus.initid.id,
- io->io_hdr.nexus.targ_port,
- (intmax_t)io->io_hdr.nexus.targ_target.wwid[0],
- (intmax_t)io->io_hdr.nexus.targ_target.wwid[1],
- io->io_hdr.nexus.targ_lun);
-#else /* _KERNEL */
- snprintf(path_str, len, "(%ju:%d:%#jx,%#jx:%d): ",
- (uintmax_t)io->io_hdr.nexus.initid.id,
- io->io_hdr.nexus.targ_port,
- (intmax_t)io->io_hdr.nexus.targ_target.wwid[0],
- (intmax_t)io->io_hdr.nexus.targ_target.wwid[1],
- io->io_hdr.nexus.targ_lun);
-#endif /* _KERNEL */
- }
+
+ snprintf(path_str, len, "(%u:%u:%u/%u): ",
+ io->io_hdr.nexus.initid.id, io->io_hdr.nexus.targ_port,
+ io->io_hdr.nexus.targ_lun, io->io_hdr.nexus.targ_mapped_lun);
}
/*
Modified: stable/10/sys/cam/ctl/ctl_util.c
==============================================================================
--- stable/10/sys/cam/ctl/ctl_util.c Thu Oct 23 07:22:18 2014
(r273530)
+++ stable/10/sys/cam/ctl/ctl_util.c Thu Oct 23 07:36:33 2014
(r273531)
@@ -731,69 +731,64 @@ ctl_scsi_task_string(struct ctl_taskio *
}
void
-ctl_io_error_sbuf(union ctl_io *io, struct scsi_inquiry_data *inq_data,
- struct sbuf *sb)
+ctl_io_sbuf(union ctl_io *io, struct sbuf *sb)
{
- struct ctl_status_desc *status_desc;
+ const char *task_desc;
char path_str[64];
- unsigned int i;
-
- status_desc = NULL;
-
- for (i = 0; i < (sizeof(ctl_status_table)/sizeof(ctl_status_table[0]));
- i++) {
- if ((io->io_hdr.status & CTL_STATUS_MASK) ==
- ctl_status_table[i].status) {
- status_desc = &ctl_status_table[i];
- break;
- }
- }
ctl_scsi_path_string(io, path_str, sizeof(path_str));
switch (io->io_hdr.io_type) {
case CTL_IO_SCSI:
sbuf_cat(sb, path_str);
-
ctl_scsi_command_string(&io->scsiio, NULL, sb);
-
- sbuf_printf(sb, "\n");
-
- sbuf_printf(sb, "%sTag: 0x%04x, Type: %d\n", path_str,
+ sbuf_printf(sb, " Tag: %#x/%d\n",
io->scsiio.tag_num, io->scsiio.tag_type);
break;
- case CTL_IO_TASK: {
- const char *task_desc;
-
+ case CTL_IO_TASK:
sbuf_cat(sb, path_str);
-
task_desc = ctl_scsi_task_string(&io->taskio);
-
if (task_desc == NULL)
sbuf_printf(sb, "Unknown Task Action %d (%#x)",
- io->taskio.task_action,
- io->taskio.task_action);
+ io->taskio.task_action, io->taskio.task_action);
else
sbuf_printf(sb, "Task Action: %s", task_desc);
-
- sbuf_printf(sb, "\n");
-
switch (io->taskio.task_action) {
case CTL_TASK_ABORT_TASK:
- case CTL_TASK_ABORT_TASK_SET:
- case CTL_TASK_CLEAR_TASK_SET:
- sbuf_printf(sb, "%sTag: 0x%04x, Type: %d\n", path_str,
- io->taskio.tag_num,
- io->taskio.tag_type);
+ sbuf_printf(sb, " Tag: %#x/%d\n",
+ io->taskio.tag_num, io->taskio.tag_type);
break;
default:
+ sbuf_printf(sb, "\n");
break;
}
break;
- }
default:
break;
}
+}
+
+void
+ctl_io_error_sbuf(union ctl_io *io, struct scsi_inquiry_data *inq_data,
+ struct sbuf *sb)
+{
+ struct ctl_status_desc *status_desc;
+ char path_str[64];
+ unsigned int i;
+
+ ctl_io_sbuf(io, sb);
+
+ status_desc = NULL;
+ for (i = 0; i < (sizeof(ctl_status_table)/sizeof(ctl_status_table[0]));
+ i++) {
+ if ((io->io_hdr.status & CTL_STATUS_MASK) ==
+ ctl_status_table[i].status) {
+ status_desc = &ctl_status_table[i];
+ break;
+ }
+ }
+
+ ctl_scsi_path_string(io, path_str, sizeof(path_str));
sbuf_cat(sb, path_str);
if (status_desc == NULL)
@@ -815,23 +810,39 @@ ctl_io_error_sbuf(union ctl_io *io, stru
}
char *
+ctl_io_string(union ctl_io *io, char *str, int str_len)
+{
+ struct sbuf sb;
+
+ sbuf_new(&sb, str, str_len, SBUF_FIXEDLEN);
+ ctl_io_sbuf(io, &sb);
+ sbuf_finish(&sb);
+ return (sbuf_data(&sb));
+}
+
+char *
ctl_io_error_string(union ctl_io *io, struct scsi_inquiry_data *inq_data,
char *str, int str_len)
{
struct sbuf sb;
sbuf_new(&sb, str, str_len, SBUF_FIXEDLEN);
-
ctl_io_error_sbuf(io, inq_data, &sb);
-
sbuf_finish(&sb);
-
return (sbuf_data(&sb));
}
#ifdef _KERNEL
void
+ctl_io_print(union ctl_io *io)
+{
+ char str[512];
+
+ printf("%s", ctl_io_string(io, str, sizeof(str)));
+}
+
+void
ctl_io_error_print(union ctl_io *io, struct scsi_inquiry_data *inq_data)
{
char str[512];
@@ -856,6 +867,37 @@ ctl_io_error_print(union ctl_io *io, str
}
+void
+ctl_data_print(union ctl_io *io)
+{
+ char str[128];
+ char path_str[64];
+ struct sbuf sb;
+ int i, j, len;
+
+ if (io->io_hdr.io_type != CTL_IO_SCSI)
+ return;
+ if (io->io_hdr.flags & CTL_FLAG_BUS_ADDR)
+ return;
+ if (io->io_hdr.flags & CTL_FLAG_EDPTR_SGLIST) /* XXX: Implement */
+ return;
+ ctl_scsi_path_string(io, path_str, sizeof(path_str));
+ len = min(io->scsiio.kern_data_len, 4096);
+ for (i = 0; i < len; ) {
+ sbuf_new(&sb, str, sizeof(str), SBUF_FIXEDLEN);
+ sbuf_cat(&sb, path_str);
+ sbuf_printf(&sb, " %#6x:%04x:", io->scsiio.tag_num, i);
+ for (j = 0; j < 16 && i < len; i++, j++) {
+ if (j == 8)
+ sbuf_cat(&sb, " ");
+ sbuf_printf(&sb, " %02x", io->scsiio.kern_data_ptr[i]);
+ }
+ sbuf_cat(&sb, "\n");
+ sbuf_finish(&sb);
+ printf("%s", sbuf_data(&sb));
+ }
+}
+
#else /* _KERNEL */
void
Modified: stable/10/sys/cam/ctl/ctl_util.h
==============================================================================
--- stable/10/sys/cam/ctl/ctl_util.h Thu Oct 23 07:22:18 2014
(r273530)
+++ stable/10/sys/cam/ctl/ctl_util.h Thu Oct 23 07:36:33 2014
(r273531)
@@ -99,19 +99,20 @@ void ctl_scsi_free_io(union ctl_io *io);
#endif /* !_KERNEL */
void ctl_scsi_zero_io(union ctl_io *io);
const char *ctl_scsi_task_string(struct ctl_taskio *taskio);
+void ctl_io_sbuf(union ctl_io *io, struct sbuf *sb);
void ctl_io_error_sbuf(union ctl_io *io,
struct scsi_inquiry_data *inq_data, struct sbuf *sb);
+char *ctl_io_string(union ctl_io *io, char *str, int str_len);
char *ctl_io_error_string(union ctl_io *io,
struct scsi_inquiry_data *inq_data, char *str,
int str_len);
#ifdef _KERNEL
-
+void ctl_io_print(union ctl_io *io);
void ctl_io_error_print(union ctl_io *io, struct scsi_inquiry_data *inq_data);
+void ctl_data_print(union ctl_io *io);
#else /* _KERNEL */
-void
-ctl_io_error_print(union ctl_io *io, struct scsi_inquiry_data *inq_data,
+void ctl_io_error_print(union ctl_io *io, struct scsi_inquiry_data *inq_data,
FILE *ofile);
-
#endif /* _KERNEL */
__END_DECLS
_______________________________________________
svn-src-all@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-all
To unsubscribe, send any mail to "svn-src-all-unsubscr...@freebsd.org"
