All the mail mirrored from lore.kernel.org
 help / color / mirror / Atom feed
* [PATCHv2 00/10] scsi logging update: the real thing
@ 2014-11-06  8:30 Hannes Reinecke
  2014-11-06  8:30 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
                   ` (10 more replies)
  0 siblings, 11 replies; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

Hi all,

this is the second part of my scsi logging update, covering
CDB and sense code printing. With this patchset CDBs and
sense code bytes will be formatted on a single line
(where possible), and prefixed with the device and command
tag.

To ensure CDBs and sense code bytes are not broken up during
printk I've implemented a per-cpu buffer for formatting
messages. One can allocate a chunk from the buffer using
scsi_log_reserve_buffer() and return it via scsi_log_release_buffer().
Both function do an implicit preempt_disable() / preempt_enable()
to ensure we're not scheduled away from that cpu whilst writing
into the buffer.

With that I've been able to clean up constants.c to remove all the
#ifdef CONFIG_SCSI_CONSTANTS statements. It'll now be compiled in
conditionally if CONFIG_SCSI_CONSTANTS is set.

Additionally I've updated the SCSI command definitions to SPC-3.

Thanks go to Stephen Rostedt who suffered my annoying questions
during LPC.

Changes to v1:
- Reshuffled patches to have SCSI command definition updates first
- Added Reviewed-by: tags where appropriate
- Implemented scmd_namd() helper as suggested by hch
- Dropped buffer pointer logging in scsi_log_send()
- Updated description for per-cpu logging buffer patch

Hannes Reinecke (10):
  scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16
  scsi: Add SPC-3 command definitions
  scsi: Implement per-cpu logging buffer
  scsi: log request tag for scmd_printk()
  scsi: use external buffer for command logging
  libata: use __scsi_format_command()
  scsi: use per-cpu buffer for formatting sense
  scsi: use per-cpu buffer for formatting scsi_print_result()
  scsi: Conditionally compile in constants.c
  scsi: Do not display buffer pointers in scsi_log_send()

 block/scsi_ioctl.c                         |   2 +-
 drivers/ata/libata-eh.c                    |  13 +-
 drivers/ata/libata-scsi.c                  |   2 +-
 drivers/block/nvme-scsi.c                  |   4 +-
 drivers/scsi/Makefile                      |   6 +-
 drivers/scsi/aacraid/aachba.c              |   4 +-
 drivers/scsi/aacraid/linit.c               |   2 +-
 drivers/scsi/ch.c                          |   6 +-
 drivers/scsi/constants.c                   | 250 +---------------
 drivers/scsi/gdth.c                        |   4 +-
 drivers/scsi/scsi.c                        |  11 +-
 drivers/scsi/scsi_debug.c                  |   2 +-
 drivers/scsi/scsi_logging.c                | 444 +++++++++++++++++++++++++++++
 drivers/scsi/scsi_trace.c                  |   2 +-
 drivers/scsi/sd.c                          |   9 +-
 drivers/scsi/sr_ioctl.c                    |  13 +-
 drivers/scsi/ufs/ufshcd.c                  |   6 +-
 drivers/target/target_core_alua.c          |   2 +-
 drivers/target/target_core_pr.c            |   2 +-
 drivers/target/target_core_sbc.c           |   2 +-
 drivers/usb/gadget/legacy/tcm_usb_gadget.c |   2 +-
 drivers/xen/xen-scsiback.c                 |   1 +
 include/scsi/scsi.h                        |  11 +-
 include/scsi/scsi_dbg.h                    |  72 ++++-
 include/scsi/scsi_device.h                 |  21 +-
 include/trace/events/scsi.h                |   2 +-
 include/trace/events/target.h              |   2 +-
 tools/lib/traceevent/plugin_scsi.c         |   9 +-
 28 files changed, 584 insertions(+), 322 deletions(-)
 create mode 100644 drivers/scsi/scsi_logging.c

-- 
1.8.5.2


^ permalink raw reply	[flat|nested] 24+ messages in thread

* [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-14 16:10   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
                   ` (9 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

SPC-3 defines SERVICE ACTION IN(12) and SERVICE ACTION IN(16).
So rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 to be
consistent with SPC and to allow for better distinction.

Reviewed-by: Christoph Hellwig <hch@lst.de>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 block/scsi_ioctl.c                         | 2 +-
 drivers/ata/libata-scsi.c                  | 2 +-
 drivers/block/nvme-scsi.c                  | 4 ++--
 drivers/scsi/aacraid/aachba.c              | 4 ++--
 drivers/scsi/aacraid/linit.c               | 2 +-
 drivers/scsi/constants.c                   | 1 -
 drivers/scsi/gdth.c                        | 4 ++--
 drivers/scsi/scsi_debug.c                  | 2 +-
 drivers/scsi/scsi_trace.c                  | 2 +-
 drivers/scsi/sd.c                          | 2 +-
 drivers/target/target_core_alua.c          | 2 +-
 drivers/target/target_core_sbc.c           | 2 +-
 drivers/usb/gadget/legacy/tcm_usb_gadget.c | 2 +-
 include/scsi/scsi.h                        | 2 +-
 include/trace/events/scsi.h                | 2 +-
 include/trace/events/target.h              | 2 +-
 tools/lib/traceevent/plugin_scsi.c         | 4 ++--
 17 files changed, 20 insertions(+), 21 deletions(-)

diff --git a/block/scsi_ioctl.c b/block/scsi_ioctl.c
index 1e053d9..c7bbc19 100644
--- a/block/scsi_ioctl.c
+++ b/block/scsi_ioctl.c
@@ -142,7 +142,7 @@ static void blk_set_cmd_filter_defaults(struct blk_cmd_filter *filter)
 	__set_bit(GPCMD_VERIFY_10, filter->read_ok);
 	__set_bit(VERIFY_16, filter->read_ok);
 	__set_bit(REPORT_LUNS, filter->read_ok);
-	__set_bit(SERVICE_ACTION_IN, filter->read_ok);
+	__set_bit(SERVICE_ACTION_IN_16, filter->read_ok);
 	__set_bit(RECEIVE_DIAGNOSTIC, filter->read_ok);
 	__set_bit(MAINTENANCE_IN, filter->read_ok);
 	__set_bit(GPCMD_READ_BUFFER_CAPACITY, filter->read_ok);
diff --git a/drivers/ata/libata-scsi.c b/drivers/ata/libata-scsi.c
index 0586f66..52a1b7e 100644
--- a/drivers/ata/libata-scsi.c
+++ b/drivers/ata/libata-scsi.c
@@ -3570,7 +3570,7 @@ void ata_scsi_simulate(struct ata_device *dev, struct scsi_cmnd *cmd)
 		ata_scsi_rbuf_fill(&args, ata_scsiop_read_cap);
 		break;
 
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		if ((scsicmd[1] & 0x1f) == SAI_READ_CAPACITY_16)
 			ata_scsi_rbuf_fill(&args, ata_scsiop_read_cap);
 		else
diff --git a/drivers/block/nvme-scsi.c b/drivers/block/nvme-scsi.c
index a4cd6d6..0b4b277 100644
--- a/drivers/block/nvme-scsi.c
+++ b/drivers/block/nvme-scsi.c
@@ -329,7 +329,7 @@ INQUIRY_EVPD_BIT_MASK) ? 1 : 0)
 (GET_U32_FROM_CDB(cdb, READ_CAP_16_CDB_ALLOC_LENGTH_OFFSET))
 
 #define IS_READ_CAP_16(cdb)					\
-((cdb[0] == SERVICE_ACTION_IN && cdb[1] == SAI_READ_CAPACITY_16) ? 1 : 0)
+((cdb[0] == SERVICE_ACTION_IN_16 && cdb[1] == SAI_READ_CAPACITY_16) ? 1 : 0)
 
 /* Request Sense Helper Macros */
 #define GET_REQUEST_SENSE_ALLOC_LENGTH(cdb)			\
@@ -2947,7 +2947,7 @@ static int nvme_scsi_translate(struct nvme_ns *ns, struct sg_io_hdr *hdr)
 	case READ_CAPACITY:
 		retcode = nvme_trans_read_capacity(ns, hdr, cmd);
 		break;
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		if (IS_READ_CAP_16(cmd))
 			retcode = nvme_trans_read_capacity(ns, hdr, cmd);
 		else
diff --git a/drivers/scsi/aacraid/aachba.c b/drivers/scsi/aacraid/aachba.c
index 681434e..b32e77d 100644
--- a/drivers/scsi/aacraid/aachba.c
+++ b/drivers/scsi/aacraid/aachba.c
@@ -2181,7 +2181,7 @@ int aac_scsi_cmd(struct scsi_cmnd * scsicmd)
 			  (fsa_dev_ptr[cid].sense_data.sense_key ==
 			   NOT_READY)) {
 				switch (scsicmd->cmnd[0]) {
-				case SERVICE_ACTION_IN:
+				case SERVICE_ACTION_IN_16:
 					if (!(dev->raw_io_interface) ||
 					    !(dev->raw_io_64) ||
 					    ((scsicmd->cmnd[1] & 0x1f) != SAI_READ_CAPACITY_16))
@@ -2309,7 +2309,7 @@ int aac_scsi_cmd(struct scsi_cmnd * scsicmd)
 		scsi_sg_copy_from_buffer(scsicmd, &inq_data, sizeof(inq_data));
 		return aac_get_container_name(scsicmd);
 	}
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		if (!(dev->raw_io_interface) ||
 		    !(dev->raw_io_64) ||
 		    ((scsicmd->cmnd[1] & 0x1f) != SAI_READ_CAPACITY_16))
diff --git a/drivers/scsi/aacraid/linit.c b/drivers/scsi/aacraid/linit.c
index a759cb2..0ba7758 100644
--- a/drivers/scsi/aacraid/linit.c
+++ b/drivers/scsi/aacraid/linit.c
@@ -555,7 +555,7 @@ static int aac_eh_abort(struct scsi_cmnd* cmd)
 		AAC_DRIVERNAME,
 		host->host_no, sdev_channel(dev), sdev_id(dev), dev->lun);
 	switch (cmd->cmnd[0]) {
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		if (!(aac->raw_io_interface) ||
 		    !(aac->raw_io_64) ||
 		    ((cmd->cmnd[1] & 0x1f) != SAI_READ_CAPACITY_16))
diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index a1a7fca..09ddede 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -24,7 +24,6 @@
 #define SERVICE_ACTION_IN_12 0xab
 #define SERVICE_ACTION_OUT_12 0xa9
 #define SERVICE_ACTION_BIDIRECTIONAL 0x9d
-#define SERVICE_ACTION_IN_16 0x9e
 #define SERVICE_ACTION_OUT_16 0x9f
 #define THIRD_PARTY_COPY_OUT 0x83
 #define THIRD_PARTY_COPY_IN 0x84
diff --git a/drivers/scsi/gdth.c b/drivers/scsi/gdth.c
index 0f1ae13..28c7b54 100644
--- a/drivers/scsi/gdth.c
+++ b/drivers/scsi/gdth.c
@@ -2159,7 +2159,7 @@ static void gdth_next(gdth_ha_str *ha)
               case VERIFY:
               case START_STOP:
               case MODE_SENSE:
-              case SERVICE_ACTION_IN:
+              case SERVICE_ACTION_IN_16:
                 TRACE(("cache cmd %x/%x/%x/%x/%x/%x\n",nscp->cmnd[0],
                        nscp->cmnd[1],nscp->cmnd[2],nscp->cmnd[3],
                        nscp->cmnd[4],nscp->cmnd[5]));
@@ -2391,7 +2391,7 @@ static int gdth_internal_cache_cmd(gdth_ha_str *ha, Scsi_Cmnd *scp)
         gdth_copy_internal_data(ha, scp, (char*)&rdc, sizeof(gdth_rdcap_data));
         break;
 
-      case SERVICE_ACTION_IN:
+      case SERVICE_ACTION_IN_16:
         if ((scp->cmnd[1] & 0x1f) == SAI_READ_CAPACITY_16 &&
             (ha->cache_feat & GDT_64BIT)) {
             gdth_rdcap16_data rdc16;
diff --git a/drivers/scsi/scsi_debug.c b/drivers/scsi/scsi_debug.c
index 238e06f..99fc31d 100644
--- a/drivers/scsi/scsi_debug.c
+++ b/drivers/scsi/scsi_debug.c
@@ -4214,7 +4214,7 @@ scsi_debug_queuecommand(struct scsi_cmnd *SCpnt)
 	case READ_CAPACITY:
 		errsts = resp_readcap(SCpnt, devip);
 		break;
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		if (cmd[1] == SAI_READ_CAPACITY_16)
 			errsts = resp_readcap16(SCpnt, devip);
 		else if (cmd[1] == SAI_GET_LBA_STATUS) {
diff --git a/drivers/scsi/scsi_trace.c b/drivers/scsi/scsi_trace.c
index 503594e..82af28b 100644
--- a/drivers/scsi/scsi_trace.c
+++ b/drivers/scsi/scsi_trace.c
@@ -278,7 +278,7 @@ scsi_trace_parse_cdb(struct trace_seq *p, unsigned char *cdb, int len)
 		return scsi_trace_rw16(p, cdb, len);
 	case UNMAP:
 		return scsi_trace_unmap(p, cdb, len);
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		return scsi_trace_service_action_in(p, cdb, len);
 	case VARIABLE_LENGTH_CMD:
 		return scsi_trace_varlen(p, cdb, len);
diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c
index b041eca..e57baaf 100644
--- a/drivers/scsi/sd.c
+++ b/drivers/scsi/sd.c
@@ -1980,7 +1980,7 @@ static int read_capacity_16(struct scsi_disk *sdkp, struct scsi_device *sdp,
 
 	do {
 		memset(cmd, 0, 16);
-		cmd[0] = SERVICE_ACTION_IN;
+		cmd[0] = SERVICE_ACTION_IN_16;
 		cmd[1] = SAI_READ_CAPACITY_16;
 		cmd[13] = RC16_LEN;
 		memset(buffer, 0, RC16_LEN);
diff --git a/drivers/target/target_core_alua.c b/drivers/target/target_core_alua.c
index fb87780..75cbde1 100644
--- a/drivers/target/target_core_alua.c
+++ b/drivers/target/target_core_alua.c
@@ -576,7 +576,7 @@ static inline int core_alua_state_standby(
 	case SEND_DIAGNOSTIC:
 	case READ_CAPACITY:
 		return 0;
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		switch (cdb[1] & 0x1f) {
 		case SAI_READ_CAPACITY_16:
 			return 0;
diff --git a/drivers/target/target_core_sbc.c b/drivers/target/target_core_sbc.c
index ebe62af..8d171ff 100644
--- a/drivers/target/target_core_sbc.c
+++ b/drivers/target/target_core_sbc.c
@@ -852,7 +852,7 @@ sbc_parse_cdb(struct se_cmd *cmd, struct sbc_ops *ops)
 		size = READ_CAP_LEN;
 		cmd->execute_cmd = sbc_emulate_readcapacity;
 		break;
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		switch (cmd->t_task_cdb[1] & 0x1f) {
 		case SAI_READ_CAPACITY_16:
 			cmd->execute_cmd = sbc_emulate_readcapacity_16;
diff --git a/drivers/usb/gadget/legacy/tcm_usb_gadget.c b/drivers/usb/gadget/legacy/tcm_usb_gadget.c
index 6cdb7a5..024f584 100644
--- a/drivers/usb/gadget/legacy/tcm_usb_gadget.c
+++ b/drivers/usb/gadget/legacy/tcm_usb_gadget.c
@@ -912,7 +912,7 @@ static int get_cmd_dir(const unsigned char *cdb)
 	case INQUIRY:
 	case MODE_SENSE:
 	case MODE_SENSE_10:
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 	case MAINTENANCE_IN:
 	case PERSISTENT_RESERVE_IN:
 	case SECURITY_PROTOCOL_IN:
diff --git a/include/scsi/scsi.h b/include/scsi/scsi.h
index d17178e..b354c0d 100644
--- a/include/scsi/scsi.h
+++ b/include/scsi/scsi.h
@@ -151,7 +151,7 @@ enum scsi_timeouts {
 #define VERIFY_16	      0x8f
 #define SYNCHRONIZE_CACHE_16  0x91
 #define WRITE_SAME_16	      0x93
-#define SERVICE_ACTION_IN     0x9e
+#define SERVICE_ACTION_IN_16  0x9e
 /* values for service action in */
 #define	SAI_READ_CAPACITY_16  0x10
 #define SAI_GET_LBA_STATUS    0x12
diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index db6c935..079bd10 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -94,7 +94,7 @@
 		scsi_opcode_name(WRITE_16),			\
 		scsi_opcode_name(VERIFY_16),			\
 		scsi_opcode_name(WRITE_SAME_16),		\
-		scsi_opcode_name(SERVICE_ACTION_IN),		\
+		scsi_opcode_name(SERVICE_ACTION_IN_16),		\
 		scsi_opcode_name(SAI_READ_CAPACITY_16),		\
 		scsi_opcode_name(SAI_GET_LBA_STATUS),		\
 		scsi_opcode_name(MI_REPORT_TARGET_PGS),		\
diff --git a/include/trace/events/target.h b/include/trace/events/target.h
index da9cc0f..4540344 100644
--- a/include/trace/events/target.h
+++ b/include/trace/events/target.h
@@ -96,7 +96,7 @@
 		scsi_opcode_name(WRITE_16),			\
 		scsi_opcode_name(VERIFY_16),			\
 		scsi_opcode_name(WRITE_SAME_16),		\
-		scsi_opcode_name(SERVICE_ACTION_IN),		\
+		scsi_opcode_name(SERVICE_ACTION_IN_16),		\
 		scsi_opcode_name(SAI_READ_CAPACITY_16),		\
 		scsi_opcode_name(SAI_GET_LBA_STATUS),		\
 		scsi_opcode_name(MI_REPORT_TARGET_PGS),		\
diff --git a/tools/lib/traceevent/plugin_scsi.c b/tools/lib/traceevent/plugin_scsi.c
index eda326f..c699f47 100644
--- a/tools/lib/traceevent/plugin_scsi.c
+++ b/tools/lib/traceevent/plugin_scsi.c
@@ -107,7 +107,7 @@ typedef unsigned int u32;
 #define VERIFY_16			0x8f
 #define SYNCHRONIZE_CACHE_16		0x91
 #define WRITE_SAME_16			0x93
-#define SERVICE_ACTION_IN		0x9e
+#define SERVICE_ACTION_IN_16		0x9e
 /* values for service action in */
 #define	SAI_READ_CAPACITY_16		0x10
 #define SAI_GET_LBA_STATUS		0x12
@@ -393,7 +393,7 @@ scsi_trace_parse_cdb(struct trace_seq *p, unsigned char *cdb, int len)
 		return scsi_trace_rw16(p, cdb, len);
 	case UNMAP:
 		return scsi_trace_unmap(p, cdb, len);
-	case SERVICE_ACTION_IN:
+	case SERVICE_ACTION_IN_16:
 		return scsi_trace_service_action_in(p, cdb, len);
 	case VARIABLE_LENGTH_CMD:
 		return scsi_trace_varlen(p, cdb, len);
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 02/10] scsi: Add SPC-3 command definitions
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
  2014-11-06  8:30 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-12 17:07   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
                   ` (8 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

SPC-3 defines SERVICE ACTION IN(12), SERVICE_ACTION OUT(12),
SERVICE ACTION OUT(16), and SERVICE ACTION BIDIRECTIONAL.
And READ MEDIA SERIAL NUMBER has long since been deprecated.
So update callers to refer to the new cdb name.

Reviewed-by: Christoph Hellwig <hch@lst.de>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c           | 4 ----
 drivers/target/target_core_pr.c    | 2 +-
 include/scsi/scsi.h                | 6 +++++-
 tools/lib/traceevent/plugin_scsi.c | 5 ++++-
 4 files changed, 10 insertions(+), 7 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 09ddede..62c96ab 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -21,10 +21,6 @@
 
 
 /* Commands with service actions that change the command name */
-#define SERVICE_ACTION_IN_12 0xab
-#define SERVICE_ACTION_OUT_12 0xa9
-#define SERVICE_ACTION_BIDIRECTIONAL 0x9d
-#define SERVICE_ACTION_OUT_16 0x9f
 #define THIRD_PARTY_COPY_OUT 0x83
 #define THIRD_PARTY_COPY_IN 0x84
 
diff --git a/drivers/target/target_core_pr.c b/drivers/target/target_core_pr.c
index 8c60a1a..806bfba 100644
--- a/drivers/target/target_core_pr.c
+++ b/drivers/target/target_core_pr.c
@@ -459,7 +459,7 @@ static int core_scsi3_pr_seq_non_holder(
 	case ACCESS_CONTROL_OUT:
 	case INQUIRY:
 	case LOG_SENSE:
-	case READ_MEDIA_SERIAL_NUMBER:
+	case SERVICE_ACTION_IN_12:
 	case REPORT_LUNS:
 	case REQUEST_SENSE:
 	case PERSISTENT_RESERVE_IN:
diff --git a/include/scsi/scsi.h b/include/scsi/scsi.h
index b354c0d..df00fd1 100644
--- a/include/scsi/scsi.h
+++ b/include/scsi/scsi.h
@@ -128,8 +128,10 @@ enum scsi_timeouts {
 #define MOVE_MEDIUM           0xa5
 #define EXCHANGE_MEDIUM       0xa6
 #define READ_12               0xa8
+#define SERVICE_ACTION_OUT_12 0xa9
 #define WRITE_12              0xaa
-#define READ_MEDIA_SERIAL_NUMBER 0xab
+#define READ_MEDIA_SERIAL_NUMBER 0xab /* Obsolete with SPC-2 */
+#define SERVICE_ACTION_IN_12 0xab
 #define WRITE_VERIFY_12       0xae
 #define VERIFY_12	      0xaf
 #define SEARCH_HIGH_12        0xb0
@@ -151,7 +153,9 @@ enum scsi_timeouts {
 #define VERIFY_16	      0x8f
 #define SYNCHRONIZE_CACHE_16  0x91
 #define WRITE_SAME_16	      0x93
+#define SERVICE_ACTION_BIDIRECTIONAL 0x9d
 #define SERVICE_ACTION_IN_16  0x9e
+#define SERVICE_ACTION_OUT_16 0x9f
 /* values for service action in */
 #define	SAI_READ_CAPACITY_16  0x10
 #define SAI_GET_LBA_STATUS    0x12
diff --git a/tools/lib/traceevent/plugin_scsi.c b/tools/lib/traceevent/plugin_scsi.c
index c699f47..63aba97 100644
--- a/tools/lib/traceevent/plugin_scsi.c
+++ b/tools/lib/traceevent/plugin_scsi.c
@@ -85,8 +85,9 @@ typedef unsigned int u32;
 #define MOVE_MEDIUM			0xa5
 #define EXCHANGE_MEDIUM			0xa6
 #define READ_12				0xa8
+#define SERVICE_ACTION_out_12		0xa9
 #define WRITE_12			0xaa
-#define READ_MEDIA_SERIAL_NUMBER	0xab
+#define SERVICE_ACTION_IN_12		0xab
 #define WRITE_VERIFY_12			0xae
 #define VERIFY_12			0xaf
 #define SEARCH_HIGH_12			0xb0
@@ -107,7 +108,9 @@ typedef unsigned int u32;
 #define VERIFY_16			0x8f
 #define SYNCHRONIZE_CACHE_16		0x91
 #define WRITE_SAME_16			0x93
+#define SERVICE_ACTION_BIDIRECTIONAL	0x9d
 #define SERVICE_ACTION_IN_16		0x9e
+#define SERVICE_ACTION_OUT_16		0x9f
 /* values for service action in */
 #define	SAI_READ_CAPACITY_16		0x10
 #define SAI_GET_LBA_STATUS		0x12
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 03/10] scsi: Implement per-cpu logging buffer
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
  2014-11-06  8:30 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
  2014-11-06  8:30 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-13  2:22   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
                   ` (7 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

Implement a per-cpu buffer for formatting messages to
avoid line break up under high load.
This patch implements scmd_printk() and sdev_prefix_printk()
using the per-cpu buffer and makes sdev_printk() a wrapper
for sdev_prefix_printk().

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/Makefile       |   2 +-
 drivers/scsi/scsi_logging.c | 119 ++++++++++++++++++++++++++++++++++++++++++++
 include/scsi/scsi_device.h  |  21 +++-----
 3 files changed, 128 insertions(+), 14 deletions(-)
 create mode 100644 drivers/scsi/scsi_logging.c

diff --git a/drivers/scsi/Makefile b/drivers/scsi/Makefile
index 59f1ce6..4991b62 100644
--- a/drivers/scsi/Makefile
+++ b/drivers/scsi/Makefile
@@ -166,7 +166,7 @@ scsi_mod-y			+= scsi_scan.o scsi_sysfs.o scsi_devinfo.o
 scsi_mod-$(CONFIG_SCSI_NETLINK)	+= scsi_netlink.o
 scsi_mod-$(CONFIG_SYSCTL)	+= scsi_sysctl.o
 scsi_mod-$(CONFIG_SCSI_PROC_FS)	+= scsi_proc.o
-scsi_mod-y			+= scsi_trace.o
+scsi_mod-y			+= scsi_trace.o scsi_logging.o
 scsi_mod-$(CONFIG_PM)		+= scsi_pm.o
 
 hv_storvsc-y			:= storvsc_drv.o
diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c
new file mode 100644
index 0000000..4a76796
--- /dev/null
+++ b/drivers/scsi/scsi_logging.c
@@ -0,0 +1,119 @@
+/*
+ * scsi_logging.c
+ *
+ * Copyright (C) 2014 SUSE Linux Products GmbH
+ * Copyright (C) 2014 Hannes Reinecke <hare@suse.de>
+ *
+ * This file is released under the GPLv2
+ */
+
+#include <linux/kernel.h>
+#include <linux/atomic.h>
+
+#include <scsi/scsi.h>
+#include <scsi/scsi_cmnd.h>
+#include <scsi/scsi_device.h>
+#include <scsi/scsi_dbg.h>
+
+#define SCSI_LOG_SPOOLSIZE 4096
+#define SCSI_LOG_BUFSIZE 128
+
+struct scsi_log_buf {
+	char buffer[SCSI_LOG_SPOOLSIZE];
+	unsigned long map;
+};
+
+static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log);
+
+static char *scsi_log_reserve_buffer(size_t *len)
+{
+	struct scsi_log_buf *buf;
+	unsigned long map_bits = SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE;
+	unsigned long idx = 0;
+
+	WARN_ON(map_bits > BITS_PER_LONG);
+	preempt_disable();
+	buf = this_cpu_ptr(&scsi_format_log);
+	idx = find_first_zero_bit(&buf->map, map_bits);
+	while (test_and_set_bit(idx, &buf->map)) {
+		idx = find_next_zero_bit(&buf->map, map_bits, idx);
+		if (idx >= map_bits) {
+			break;
+		}
+	}
+	if (WARN_ON(idx >= map_bits)) {
+		preempt_enable();
+		return NULL;
+	}
+	*len = SCSI_LOG_BUFSIZE;
+	return buf->buffer + idx * SCSI_LOG_BUFSIZE;
+}
+
+static void scsi_log_release_buffer(char *bufptr)
+{
+	struct scsi_log_buf *buf;
+	unsigned long idx;
+	int ret;
+
+	buf = this_cpu_ptr(&scsi_format_log);
+	if (bufptr < buf->buffer + SCSI_LOG_SPOOLSIZE) {
+		idx = (bufptr - buf->buffer) / SCSI_LOG_BUFSIZE;
+		ret = test_and_clear_bit(idx, &buf->map);
+		WARN_ON(!ret);
+	}
+	preempt_enable();
+}
+
+int sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
+		       const char *name, const char *fmt, ...)
+{
+	va_list args;
+	char *logbuf;
+	size_t off = 0, logbuf_len;
+	int ret;
+
+	if (!sdev)
+		return 0;
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return 0;
+
+	if (name)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "[%s] ", name);
+	va_start(args, fmt);
+	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
+	va_end(args);
+	ret = dev_printk(level, &sdev->sdev_gendev, "%s", logbuf);
+	scsi_log_release_buffer(logbuf);
+	return ret;
+}
+EXPORT_SYMBOL_GPL(sdev_prefix_printk);
+
+int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
+		const char *fmt, ...)
+{
+	struct gendisk *disk = scmd->request->rq_disk;
+	va_list args;
+	char *logbuf;
+	size_t off = 0, logbuf_len;
+	int ret;
+
+	if (!scmd || scmd->cmnd == NULL)
+		return 0;
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return 0;
+	if (disk)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "[%s] ", disk->disk_name);
+	va_start(args, fmt);
+	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
+	va_end(args);
+	ret = dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf);
+	scsi_log_release_buffer(logbuf);
+	return ret;
+}
+EXPORT_SYMBOL_GPL(scmd_printk);
diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h
index 0b18a09..daa62df 100644
--- a/include/scsi/scsi_device.h
+++ b/include/scsi/scsi_device.h
@@ -238,9 +238,6 @@ struct scsi_dh_data {
 #define transport_class_to_sdev(class_dev) \
 	to_scsi_device(class_dev->parent)
 
-#define sdev_printk(prefix, sdev, fmt, a...)	\
-	dev_printk(prefix, &(sdev)->sdev_gendev, fmt, ##a)
-
 #define sdev_dbg(sdev, fmt, a...) \
 	dev_dbg(&(sdev)->sdev_gendev, fmt, ##a)
 
@@ -248,16 +245,14 @@ struct scsi_dh_data {
  * like scmd_printk, but the device name is passed in
  * as a string pointer
  */
-#define sdev_prefix_printk(l, sdev, p, fmt, a...)			\
-	(p) ?								\
-	sdev_printk(l, sdev, "[%s] " fmt, p, ##a) :			\
-	sdev_printk(l, sdev, fmt, ##a)
-
-#define scmd_printk(prefix, scmd, fmt, a...)				\
-        (scmd)->request->rq_disk ?					\
-	sdev_printk(prefix, (scmd)->device, "[%s] " fmt,		\
-		    (scmd)->request->rq_disk->disk_name, ##a) :		\
-	sdev_printk(prefix, (scmd)->device, fmt, ##a)
+extern int sdev_prefix_printk(const char *, const struct scsi_device *,
+			      const char *, const char *, ...);
+
+#define sdev_printk(l, sdev, fmt, a...)				\
+	sdev_prefix_printk(l, sdev, NULL, fmt, ##a)
+
+extern int scmd_printk(const char *, const struct scsi_cmnd *,
+		       const char *, ...);
 
 #define scmd_dbg(scmd, fmt, a...)					   \
 	do {								   \
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 04/10] scsi: log request tag for scmd_printk()
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (2 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-12 17:18   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
                   ` (6 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

The request tag provides a concise identification of a SCSI
command, so we should be printing that out for scmd_printk().

Suggested-by: Christoph Hellwig <hch@lst.de>
Reviewed-by: Christoph Hellwig <hch@lst.de>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi_logging.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c
index 4a76796..dca45fe 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -109,6 +109,10 @@ int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
 	if (disk)
 		off += scnprintf(logbuf + off, logbuf_len - off,
 				 "[%s] ", disk->disk_name);
+
+	if (scmd->request->tag >= 0)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "tag#%d ", scmd->request->tag);
 	va_start(args, fmt);
 	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
 	va_end(args);
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 05/10] scsi: use external buffer for command logging
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (3 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-13  2:24   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
                   ` (5 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

Use an external buffer for __scsi_print_command() and
move command logging over to use the per-cpu logging
buffer. With that we can guarantee the command always
will always be formatted in one line.
So we can even print out a variable length command
correctly across several lines.
Finally rename __scsi_print_command() to
__scsi_format_comment() to better reflect the
functionality.

Reviewed-by: Christoph Hellwig <hch@lst.de>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/ch.c           |   6 +-
 drivers/scsi/constants.c    |  74 +----------------------
 drivers/scsi/scsi_logging.c | 144 +++++++++++++++++++++++++++++++++++++++++---
 drivers/scsi/sr_ioctl.c     |  13 +++-
 include/scsi/scsi.h         |   3 +
 include/scsi/scsi_dbg.h     |   6 +-
 6 files changed, 160 insertions(+), 86 deletions(-)

diff --git a/drivers/scsi/ch.c b/drivers/scsi/ch.c
index 4f502f9..ed0d10d 100644
--- a/drivers/scsi/ch.c
+++ b/drivers/scsi/ch.c
@@ -195,8 +195,10 @@ ch_do_scsi(scsi_changer *ch, unsigned char *cmd, int cmd_len,
  retry:
 	errno = 0;
 	if (debug) {
-		DPRINTK("command: ");
-		__scsi_print_command(cmd, cmd_len);
+		char logbuf[SCSI_LOG_BUFSIZE];
+
+		__scsi_format_command(logbuf, SCSI_LOG_BUFSIZE, cmd, cmd_len);
+		DPRINTK("command: %s", logbuf);
 	}
 
 	result = scsi_execute_req(ch->device, cmd, direction, buffer,
diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 62c96ab..003735f 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -24,8 +24,6 @@
 #define THIRD_PARTY_COPY_OUT 0x83
 #define THIRD_PARTY_COPY_IN 0x84
 
-#define VENDOR_SPECIFIC_CDB 0xc0
-
 struct sa_name_list {
 	int opcode;
 	const struct value_name_pair *arr;
@@ -281,8 +279,8 @@ static struct sa_name_list sa_names_arr[] = {
 };
 #endif /* CONFIG_SCSI_CONSTANTS */
 
-static bool scsi_opcode_sa_name(int opcode, int service_action,
-				const char **cdb_name, const char **sa_name)
+bool scsi_opcode_sa_name(int opcode, int service_action,
+			 const char **cdb_name, const char **sa_name)
 {
 	struct sa_name_list *sa_name_ptr;
 	const struct value_name_pair *arr = NULL;
@@ -315,74 +313,6 @@ static bool scsi_opcode_sa_name(int opcode, int service_action,
 	return true;
 }
 
-static void print_opcode_name(const unsigned char *cdbp, size_t cdb_len)
-{
-	int sa, cdb0;
-	const char *cdb_name = NULL, *sa_name = NULL;
-
-	cdb0 = cdbp[0];
-	if (cdb0 == VARIABLE_LENGTH_CMD) {
-		if (cdb_len < 10) {
-			printk("short variable length command, len=%zu",
-			       cdb_len);
-			return;
-		}
-		sa = (cdbp[8] << 8) + cdbp[9];
-	} else
-		sa = cdbp[1] & 0x1f;
-
-	if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) {
-		if (cdb_name)
-			printk("%s", cdb_name);
-		else if (cdb0 >= VENDOR_SPECIFIC_CDB)
-			printk("cdb[0]=0x%x (vendor)", cdb0);
-		else if (cdb0 >= 0x60 && cdb0 < 0x7e)
-			printk("cdb[0]=0x%x (reserved)", cdb0);
-		else
-			printk("cdb[0]=0x%x", cdb0);
-	} else {
-		if (sa_name)
-			printk("%s", sa_name);
-		else if (cdb_name)
-			printk("%s, sa=0x%x", cdb_name, sa);
-		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
-	}
-}
-
-void __scsi_print_command(const unsigned char *cdb, size_t cdb_len)
-{
-	int k, len;
-
-	print_opcode_name(cdb, cdb_len);
-	len = scsi_command_size(cdb);
-	if (cdb_len < len)
-		len = cdb_len;
-	/* print out all bytes in cdb */
-	for (k = 0; k < len; ++k)
-		printk(" %02x", cdb[k]);
-	printk("\n");
-}
-EXPORT_SYMBOL(__scsi_print_command);
-
-void scsi_print_command(struct scsi_cmnd *cmd)
-{
-	int k;
-
-	if (cmd->cmnd == NULL)
-		return;
-
-	scmd_printk(KERN_INFO, cmd, "CDB: ");
-	print_opcode_name(cmd->cmnd, cmd->cmd_len);
-
-	/* print out all bytes in cdb */
-	printk(":");
-	for (k = 0; k < cmd->cmd_len; ++k)
-		printk(" %02x", cmd->cmnd[k]);
-	printk("\n");
-}
-EXPORT_SYMBOL(scsi_print_command);
-
 #ifdef CONFIG_SCSI_CONSTANTS
 
 struct error_info {
diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c
index dca45fe..d166d12 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -13,10 +13,10 @@
 #include <scsi/scsi.h>
 #include <scsi/scsi_cmnd.h>
 #include <scsi/scsi_device.h>
+#include <scsi/scsi_eh.h>
 #include <scsi/scsi_dbg.h>
 
 #define SCSI_LOG_SPOOLSIZE 4096
-#define SCSI_LOG_BUFSIZE 128
 
 struct scsi_log_buf {
 	char buffer[SCSI_LOG_SPOOLSIZE];
@@ -64,6 +64,21 @@ static void scsi_log_release_buffer(char *bufptr)
 	preempt_enable();
 }
 
+static size_t scmd_format_header(char *logbuf, size_t logbuf_len,
+				 struct gendisk *disk, int tag)
+{
+	size_t off = 0;
+
+	if (disk)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "[%s] ", disk->disk_name);
+
+	if (tag >= 0)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "tag#%d ", tag);
+	return off;
+}
+
 int sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
 		       const char *name, const char *fmt, ...)
 {
@@ -106,13 +121,8 @@ int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
 	logbuf = scsi_log_reserve_buffer(&logbuf_len);
 	if (!logbuf)
 		return 0;
-	if (disk)
-		off += scnprintf(logbuf + off, logbuf_len - off,
-				 "[%s] ", disk->disk_name);
-
-	if (scmd->request->tag >= 0)
-		off += scnprintf(logbuf + off, logbuf_len - off,
-				 "tag#%d ", scmd->request->tag);
+	off = scmd_format_header(logbuf, logbuf_len, disk,
+				 scmd->request->tag);
 	va_start(args, fmt);
 	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
 	va_end(args);
@@ -121,3 +131,121 @@ int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
 	return ret;
 }
 EXPORT_SYMBOL_GPL(scmd_printk);
+
+static size_t scsi_format_opcode_name(char *buffer, size_t buf_len,
+				      const unsigned char *cdbp)
+{
+	int sa, cdb0;
+	const char *cdb_name = NULL, *sa_name = NULL;
+	size_t off;
+
+	cdb0 = cdbp[0];
+	if (cdb0 == VARIABLE_LENGTH_CMD) {
+		int len = scsi_varlen_cdb_length(cdbp);
+
+		if (len < 10) {
+			off = scnprintf(buffer, buf_len,
+					"short variable length command, len=%d",
+					len);
+			return off;
+		}
+		sa = (cdbp[8] << 8) + cdbp[9];
+	} else
+		sa = cdbp[1] & 0x1f;
+
+	if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) {
+		if (cdb_name)
+			off = scnprintf(buffer, buf_len, "%s", cdb_name);
+		else {
+			off = scnprintf(buffer, buf_len, "cdb[0]=0x%x", cdb0);
+			if (cdb0 > VENDOR_SPECIFIC_CDB)
+				off += scnprintf(buffer + off, buf_len - off,
+						 " (vendor)");
+			else if (cdb0 > 0x60 && cdb0 < 0x7e)
+				off += scnprintf(buffer + off, buf_len - off,
+						 " (reserved)");
+		}
+	} else {
+		if (sa_name)
+			off = scnprintf(buffer, buf_len, "%s", sa_name);
+		else if (cdb_name)
+			off = scnprintf(buffer, buf_len, "%s, sa=0x%x",
+					cdb_name, sa);
+		else
+			off = scnprintf(buffer, buf_len,
+					"cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+	}
+	return off;
+}
+
+size_t __scsi_format_command(char *logbuf, size_t logbuf_len,
+			     const unsigned char *cdb, size_t cdb_len)
+{
+	int len, k;
+	size_t off;
+
+	off = scsi_format_opcode_name(logbuf, logbuf_len, cdb);
+	len = scsi_command_size(cdb);
+	if (cdb_len < len)
+		len = cdb_len;
+	/* print out all bytes in cdb */
+	for (k = 0; k < len; ++k) {
+		if (off + 3 > logbuf_len)
+			break;
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 " %02x", cdb[k]);
+	}
+	return off;
+}
+EXPORT_SYMBOL(__scsi_format_command);
+
+void scsi_print_command(struct scsi_cmnd *cmd)
+{
+	struct gendisk *disk = cmd->request->rq_disk;
+	int k;
+	char *logbuf;
+	size_t off, logbuf_len;
+
+	if (cmd->cmnd == NULL)
+		return;
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return;
+
+	off = scmd_format_header(logbuf, logbuf_len, disk, cmd->request->tag);
+	off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");
+	off += scsi_format_opcode_name(logbuf + off, logbuf_len - off,
+				       cmd->cmnd);
+	/* print out all bytes in cdb */
+	if (cmd->cmd_len > 16) {
+		/* Print opcode in one line and use separate lines for CDB */
+		off += scnprintf(logbuf + off, logbuf_len - off, "\n");
+		dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf);
+		scsi_log_release_buffer(logbuf);
+		for (k = 0; k < cmd->cmd_len; k += 16) {
+			size_t linelen = min(cmd->cmd_len - k, 16);
+
+			logbuf = scsi_log_reserve_buffer(&logbuf_len);
+			if (!logbuf)
+				break;
+			off = scmd_format_header(logbuf, logbuf_len, disk,
+						 cmd->request->tag);
+			off += scnprintf(logbuf + off, logbuf_len - off,
+					 "CDB[%02x]: ", k);
+			hex_dump_to_buffer(&cmd->cmnd[k], linelen, 16, 1,
+					   logbuf + off, logbuf_len - off,
+					   false);
+			dev_printk(KERN_INFO, &cmd->device->sdev_gendev,
+				   logbuf);
+			scsi_log_release_buffer(logbuf);
+		}
+	} else {
+		off += scnprintf(logbuf + off, logbuf_len - off, " ");
+		hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,
+				   logbuf + off, logbuf_len - off, false);
+		dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf);
+		scsi_log_release_buffer(logbuf);
+	}
+}
+EXPORT_SYMBOL(scsi_print_command);
diff --git a/drivers/scsi/sr_ioctl.c b/drivers/scsi/sr_ioctl.c
index fb929fa..4f9fb3c 100644
--- a/drivers/scsi/sr_ioctl.c
+++ b/drivers/scsi/sr_ioctl.c
@@ -188,6 +188,7 @@ int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
 	struct scsi_sense_hdr sshdr;
 	int result, err = 0, retries = 0;
 	struct request_sense *sense = cgc->sense;
+	char logbuf[SCSI_LOG_BUFSIZE];
 
 	SDev = cd->device;
 
@@ -257,14 +258,20 @@ int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
 				/* sense: Invalid command operation code */
 				err = -EDRIVE_CANT_DO_THIS;
 #ifdef DEBUG
-			__scsi_print_command(cgc->cmd, CDROM_PACKET_SIZE);
+			__scsi_format_command(logbuf, SCSI_LOG_BUFSIZE,
+					      cgc->cmd, CDROM_PACKET_SIZE);
+			sr_printk(KERN_INFO, cd,
+				  "CDROM (ioctl) invalid command: %s\n",
+				  logbuf);
 			scsi_print_sense_hdr(cd->device, cd->cdi.name, &sshdr);
 #endif
 			break;
 		default:
+			__scsi_format_command(logbuf, SCSI_LOG_BUFSIZE,
+					      cgc->cmd, CDROM_PACKET_SIZE);
 			sr_printk(KERN_ERR, cd,
-				  "CDROM (ioctl) error, command: ");
-			__scsi_print_command(cgc->cmd, CDROM_PACKET_SIZE);
+				  "CDROM (ioctl) error, command: %s\n",
+				  logbuf);
 			scsi_print_sense_hdr(cd->device, cd->cdi.name, &sshdr);
 			err = -EIO;
 		}
diff --git a/include/scsi/scsi.h b/include/scsi/scsi.h
index df00fd1..5607594 100644
--- a/include/scsi/scsi.h
+++ b/include/scsi/scsi.h
@@ -195,6 +195,9 @@ enum scsi_timeouts {
 #define	ATA_16		      0x85	/* 16-byte pass-thru */
 #define	ATA_12		      0xa1	/* 12-byte pass-thru */
 
+/* Vendor specific CDBs start here */
+#define VENDOR_SPECIFIC_CDB 0xc0
+
 /*
  *	SCSI command lengths
  */
diff --git a/include/scsi/scsi_dbg.h b/include/scsi/scsi_dbg.h
index 7982795..c7ed7b8 100644
--- a/include/scsi/scsi_dbg.h
+++ b/include/scsi/scsi_dbg.h
@@ -5,8 +5,12 @@ struct scsi_cmnd;
 struct scsi_device;
 struct scsi_sense_hdr;
 
+#define SCSI_LOG_BUFSIZE 128
+
+extern bool scsi_opcode_sa_name(int, int, const char **, const char **);
 extern void scsi_print_command(struct scsi_cmnd *);
-extern void __scsi_print_command(const unsigned char *, size_t);
+extern size_t __scsi_format_command(char *, size_t,
+				   const unsigned char *, size_t);
 extern void scsi_show_extd_sense(const struct scsi_device *, const char *,
 				 unsigned char, unsigned char);
 extern void scsi_show_sense_hdr(const struct scsi_device *, const char *,
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 06/10] libata: use __scsi_format_command()
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (4 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-14 16:02   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
                   ` (4 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke, linux-ide, LKML

libata already uses an internal buffer, so we should be using
__scsi_format_command() here.

Cc: linux-ide@vger.kernel.org
Cc: LKML <linux-kernel@vger.kernel.org>
Reviewed-by: Christoph Hellwig <hch@lst.de>
Acked-by: Tejun Heo <tj@kernel.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/ata/libata-eh.c | 13 +++++--------
 1 file changed, 5 insertions(+), 8 deletions(-)

diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index dad83df..6550a9a 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -2509,15 +2509,12 @@ static void ata_eh_link_report(struct ata_link *link)
 
 		if (ata_is_atapi(qc->tf.protocol)) {
 			if (qc->scsicmd)
-				scsi_print_command(qc->scsicmd);
+				__scsi_format_command(cdb_buf, sizeof(cdb_buf),
+						      qc->scsicmd->cmnd,
+						      qc->scsicmd->cmd_len);
 			else
-				snprintf(cdb_buf, sizeof(cdb_buf),
-				 "cdb %02x %02x %02x %02x %02x %02x %02x %02x  "
-				 "%02x %02x %02x %02x %02x %02x %02x %02x\n         ",
-				 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]);
+				__scsi_format_command(cdb_buf, sizeof(cdb_buf),
+						      cdb, qc->dev->cdb_len);
 		} else {
 			const char *descr = ata_get_cmd_descript(cmd->command);
 			if (descr)
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 07/10] scsi: use per-cpu buffer for formatting sense
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (5 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-14 16:52   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
                   ` (3 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

Convert sense buffer logging to use the per-cpu
buffer to avoid line breakup.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c    | 107 ----------------------------
 drivers/scsi/scsi_logging.c | 167 +++++++++++++++++++++++++++++++++++++++++---
 drivers/scsi/sd.c           |   7 +-
 drivers/scsi/ufs/ufshcd.c   |   6 +-
 4 files changed, 162 insertions(+), 125 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 003735f..82c8d68 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1216,113 +1216,6 @@ scsi_extd_sense_format(unsigned char asc, unsigned char ascq, const char **fmt)
 }
 EXPORT_SYMBOL(scsi_extd_sense_format);
 
-void
-scsi_show_extd_sense(const struct scsi_device *sdev, const char *name,
-		     unsigned char asc, unsigned char ascq)
-{
-	const char *extd_sense_fmt = NULL;
-	const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,
-							    &extd_sense_fmt);
-
-	if (extd_sense_str) {
-		if (extd_sense_fmt)
-			sdev_prefix_printk(KERN_INFO, sdev, name,
-					   "Add. Sense: %s (%s%x)",
-					   extd_sense_str, extd_sense_fmt,
-					   ascq);
-		else
-			sdev_prefix_printk(KERN_INFO, sdev, name,
-					   "Add. Sense: %s", extd_sense_str);
-
-	} else {
-		sdev_prefix_printk(KERN_INFO, sdev, name,
-				   "%sASC=0x%x %sASCQ=0x%x\n",
-				   asc >= 0x80 ? "<<vendor>> " : "", asc,
-				   ascq >= 0x80 ? "<<vendor>> " : "", ascq);
-	}
-}
-EXPORT_SYMBOL(scsi_show_extd_sense);
-
-void
-scsi_show_sense_hdr(const struct scsi_device *sdev, const char *name,
-		    const struct scsi_sense_hdr *sshdr)
-{
-	const char *sense_txt;
-
-	sense_txt = scsi_sense_key_string(sshdr->sense_key);
-	if (sense_txt)
-		sdev_prefix_printk(KERN_INFO, sdev, name,
-				   "Sense Key : %s [%s]%s\n", sense_txt,
-				   scsi_sense_is_deferred(sshdr) ?
-				   "deferred" : "current",
-				   sshdr->response_code >= 0x72 ?
-				   " [descriptor]" : "");
-	else
-		sdev_prefix_printk(KERN_INFO, sdev, name,
-				   "Sense Key : 0x%x [%s]%s", sshdr->sense_key,
-				   scsi_sense_is_deferred(sshdr) ?
-				   "deferred" : "current",
-				   sshdr->response_code >= 0x72 ?
-				   " [descriptor]" : "");
-}
-EXPORT_SYMBOL(scsi_show_sense_hdr);
-
-/*
- * Print normalized SCSI sense header with a prefix.
- */
-void
-scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name,
-		     const struct scsi_sense_hdr *sshdr)
-{
-	scsi_show_sense_hdr(sdev, name, sshdr);
-	scsi_show_extd_sense(sdev, name, sshdr->asc, sshdr->ascq);
-}
-EXPORT_SYMBOL(scsi_print_sense_hdr);
-
-static void
-scsi_dump_sense_buffer(const unsigned char *sense_buffer, int sense_len)
-{
-	int k, num;
-
-	num = (sense_len < 32) ? sense_len : 32;
-	printk("Unrecognized sense data (in hex):");
-	for (k = 0; k < num; ++k) {
-		if (0 == (k % 16)) {
-			printk("\n");
-			printk(KERN_INFO "        ");
-		}
-		printk("%02x ", sense_buffer[k]);
-	}
-	printk("\n");
-	return;
-}
-
-/* Normalize and print sense buffer with name prefix */
-void __scsi_print_sense(const struct scsi_device *sdev, const char *name,
-			const unsigned char *sense_buffer, int sense_len)
-{
-	struct scsi_sense_hdr sshdr;
-
-	if (!scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) {
-		scsi_dump_sense_buffer(sense_buffer, sense_len);
-		return;
-	}
-	scsi_show_sense_hdr(sdev, name, &sshdr);
-	scsi_show_extd_sense(sdev, name, sshdr.asc, sshdr.ascq);
-}
-EXPORT_SYMBOL(__scsi_print_sense);
-
-/* Normalize and print sense buffer in SCSI command */
-void scsi_print_sense(const struct scsi_cmnd *cmd)
-{
-	struct gendisk *disk = cmd->request->rq_disk;
-	const char *disk_name = disk ? disk->disk_name : NULL;
-
-	__scsi_print_sense(cmd->device, disk_name, cmd->sense_buffer,
-			   SCSI_SENSE_BUFFERSIZE);
-}
-EXPORT_SYMBOL(scsi_print_sense);
-
 #ifdef CONFIG_SCSI_CONSTANTS
 
 static const char * const hostbyte_table[]={
diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c
index d166d12..065792a3 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -64,14 +64,20 @@ static void scsi_log_release_buffer(char *bufptr)
 	preempt_enable();
 }
 
-static size_t scmd_format_header(char *logbuf, size_t logbuf_len,
-				 struct gendisk *disk, int tag)
+static inline const char *scmd_name(const struct scsi_cmnd *scmd)
+{
+	return scmd->request->rq_disk ?
+		scmd->request->rq_disk->disk_name : NULL;
+}
+
+static size_t sdev_format_header(char *logbuf, size_t logbuf_len,
+				 const char *name, int tag)
 {
 	size_t off = 0;
 
-	if (disk)
+	if (name)
 		off += scnprintf(logbuf + off, logbuf_len - off,
-				 "[%s] ", disk->disk_name);
+				 "[%s] ", name);
 
 	if (tag >= 0)
 		off += scnprintf(logbuf + off, logbuf_len - off,
@@ -109,7 +115,6 @@ EXPORT_SYMBOL_GPL(sdev_prefix_printk);
 int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
 		const char *fmt, ...)
 {
-	struct gendisk *disk = scmd->request->rq_disk;
 	va_list args;
 	char *logbuf;
 	size_t off = 0, logbuf_len;
@@ -121,7 +126,7 @@ int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
 	logbuf = scsi_log_reserve_buffer(&logbuf_len);
 	if (!logbuf)
 		return 0;
-	off = scmd_format_header(logbuf, logbuf_len, disk,
+	off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd),
 				 scmd->request->tag);
 	va_start(args, fmt);
 	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
@@ -201,7 +206,6 @@ EXPORT_SYMBOL(__scsi_format_command);
 
 void scsi_print_command(struct scsi_cmnd *cmd)
 {
-	struct gendisk *disk = cmd->request->rq_disk;
 	int k;
 	char *logbuf;
 	size_t off, logbuf_len;
@@ -213,7 +217,8 @@ void scsi_print_command(struct scsi_cmnd *cmd)
 	if (!logbuf)
 		return;
 
-	off = scmd_format_header(logbuf, logbuf_len, disk, cmd->request->tag);
+	off = sdev_format_header(logbuf, logbuf_len,
+				 scmd_name(cmd), cmd->request->tag);
 	off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");
 	off += scsi_format_opcode_name(logbuf + off, logbuf_len - off,
 				       cmd->cmnd);
@@ -229,7 +234,8 @@ void scsi_print_command(struct scsi_cmnd *cmd)
 			logbuf = scsi_log_reserve_buffer(&logbuf_len);
 			if (!logbuf)
 				break;
-			off = scmd_format_header(logbuf, logbuf_len, disk,
+			off = sdev_format_header(logbuf, logbuf_len,
+						 scmd_name(cmd),
 						 cmd->request->tag);
 			off += scnprintf(logbuf + off, logbuf_len - off,
 					 "CDB[%02x]: ", k);
@@ -249,3 +255,146 @@ void scsi_print_command(struct scsi_cmnd *cmd)
 	}
 }
 EXPORT_SYMBOL(scsi_print_command);
+
+static size_t
+scsi_format_extd_sense(char *buffer, size_t buf_len,
+		       unsigned char asc, unsigned char ascq)
+{
+	size_t off = 0;
+	const char *extd_sense_fmt = NULL;
+	const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,
+							    &extd_sense_fmt);
+
+	if (extd_sense_str) {
+		off = scnprintf(buffer, buf_len, "Add. Sense: %s",
+				extd_sense_str);
+		if (extd_sense_fmt)
+			off += scnprintf(buffer + off, buf_len - off,
+					 "(%s%x)", extd_sense_fmt, ascq);
+	} else {
+		if (asc >= 0x80)
+			off = scnprintf(buffer, buf_len, "<<vendor>>");
+		off += scnprintf(buffer + off, buf_len - off,
+				 "ASC=0x%x ", asc);
+		if (ascq >= 0x80)
+			off += scnprintf(buffer + off, buf_len - off,
+					 "<<vendor>>");
+		off += scnprintf(buffer + off, buf_len - off,
+				 "ASCQ=0x%x ", ascq);
+	}
+	return off;
+}
+
+static size_t
+scsi_format_sense_hdr(char *buffer, size_t buf_len,
+		      const struct scsi_sense_hdr *sshdr)
+{
+	const char *sense_txt;
+	size_t off;
+
+	off = scnprintf(buffer, buf_len, "Sense Key : ");
+	sense_txt = scsi_sense_key_string(sshdr->sense_key);
+	if (sense_txt)
+		off += scnprintf(buffer + off, buf_len - off,
+				 "%s ", sense_txt);
+	else
+		off += scnprintf(buffer + off, buf_len - off,
+				 "0x%x ", sshdr->sense_key);
+	off += scnprintf(buffer + off, buf_len - off,
+		scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] ");
+
+	if (sshdr->response_code >= 0x72)
+		off += scnprintf(buffer + off, buf_len - off, "[descriptor] ");
+	return off;
+}
+
+static void
+scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag,
+		    const unsigned char *sense_buffer, int sense_len)
+{
+	int i;
+
+	for (i = 0; i < sense_len; i += 16) {
+		char *logbuf;
+		int len = min(sense_len - i, 16);
+		size_t off, logbuf_len;
+
+		logbuf = scsi_log_reserve_buffer(&logbuf_len);
+		if (!logbuf)
+			break;
+		off = sdev_format_header(logbuf, logbuf_len,
+					 name, tag);
+		hex_dump_to_buffer(&sense_buffer[i], len, 16, 1,
+				   logbuf + off, logbuf_len - off,
+				   false);
+		dev_printk(KERN_INFO, &sdev->sdev_gendev, logbuf);
+		scsi_log_release_buffer(logbuf);
+	}
+}
+
+static void
+scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name,
+			 int tag, const struct scsi_sense_hdr *sshdr)
+{
+	char *logbuf;
+	size_t off, logbuf_len;
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return;
+	off = sdev_format_header(logbuf, logbuf_len, name, tag);
+	off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr);
+	dev_printk(KERN_INFO, &sdev->sdev_gendev, logbuf);
+	scsi_log_release_buffer(logbuf);
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return;
+	off = sdev_format_header(logbuf, logbuf_len, name, tag);
+	off += scsi_format_extd_sense(logbuf + off, logbuf_len - off,
+				      sshdr->asc, sshdr->ascq);
+	dev_printk(KERN_INFO, &sdev->sdev_gendev, logbuf);
+	scsi_log_release_buffer(logbuf);
+}
+
+static void
+scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag,
+		     const unsigned char *sense_buffer, int sense_len)
+{
+	struct scsi_sense_hdr sshdr;
+
+	if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr))
+		scsi_log_print_sense_hdr(sdev, name, tag, &sshdr);
+	else
+		scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len);
+}
+
+/*
+ * Print normalized SCSI sense header with a prefix.
+ */
+void
+scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name,
+		     const struct scsi_sense_hdr *sshdr)
+{
+	scsi_log_print_sense_hdr(sdev, name, -1, sshdr);
+}
+EXPORT_SYMBOL(scsi_print_sense_hdr);
+
+/* Normalize and print sense buffer with name prefix */
+void __scsi_print_sense(const struct scsi_device *sdev, const char *name,
+			const unsigned char *sense_buffer, int sense_len)
+{
+	scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len);
+}
+EXPORT_SYMBOL(__scsi_print_sense);
+
+/* Normalize and print sense buffer in SCSI command */
+void scsi_print_sense(const struct scsi_cmnd *cmd)
+{
+	struct gendisk *disk = cmd->request->rq_disk;
+	const char *disk_name = disk ? disk->disk_name : NULL;
+
+	scsi_log_print_sense(cmd->device, disk_name, cmd->request->tag,
+			     cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
+}
+EXPORT_SYMBOL(scsi_print_sense);
diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c
index e57baaf..5f6b199 100644
--- a/drivers/scsi/sd.c
+++ b/drivers/scsi/sd.c
@@ -3315,11 +3315,8 @@ module_exit(exit_sd);
 static void sd_print_sense_hdr(struct scsi_disk *sdkp,
 			       struct scsi_sense_hdr *sshdr)
 {
-	scsi_show_sense_hdr(sdkp->device,
-			    sdkp->disk ? sdkp->disk->disk_name : NULL, sshdr);
-	scsi_show_extd_sense(sdkp->device,
-			     sdkp->disk ? sdkp->disk->disk_name : NULL,
-			     sshdr->asc, sshdr->ascq);
+	scsi_print_sense_hdr(sdkp->device,
+			     sdkp->disk ? sdkp->disk->disk_name : NULL, sshdr);
 }
 
 static void sd_print_result(const struct scsi_disk *sdkp, const char *msg,
diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index 9da3191..5c0298e 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -4709,10 +4709,8 @@ static int ufshcd_set_dev_pwr_mode(struct ufs_hba *hba,
 		sdev_printk(KERN_WARNING, sdp,
 			    "START_STOP failed for power mode: %d, result %x\n",
 			    pwr_mode, ret);
-		if (driver_byte(ret) & DRIVER_SENSE) {
-			scsi_show_sense_hdr(sdp, NULL, &sshdr);
-			scsi_show_extd_sense(sdp, NULL, sshdr.asc, sshdr.ascq);
-		}
+		if (driver_byte(ret) & DRIVER_SENSE)
+			scsi_print_sense_hdr(sdp, NULL, &sshdr);
 	}
 
 	if (!ret)
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result()
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (6 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-14 22:20   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
                   ` (2 subsequent siblings)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

Convert scsi_print_result() to use the per-cpu buffer for
decoding the command result and disposition.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c    | 22 ----------------------
 drivers/scsi/scsi.c         |  2 +-
 drivers/scsi/scsi_logging.c | 44 ++++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 45 insertions(+), 23 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 82c8d68..dfa8639 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1286,25 +1286,3 @@ const char *scsi_mlreturn_string(int result)
 	return NULL;
 }
 EXPORT_SYMBOL(scsi_mlreturn_string);
-
-void scsi_print_result(struct scsi_cmnd *cmd, const char *msg, int disposition)
-{
-	const char *mlret_string = scsi_mlreturn_string(disposition);
-	const char *hb_string = scsi_hostbyte_string(cmd->result);
-	const char *db_string = scsi_driverbyte_string(cmd->result);
-
-	if (hb_string || db_string)
-		scmd_printk(KERN_INFO, cmd,
-			    "%s%s Result: hostbyte=%s driverbyte=%s",
-			    msg ? msg : "",
-			    mlret_string ? mlret_string : "UNKNOWN",
-			    hb_string ? hb_string : "invalid",
-			    db_string ? db_string : "invalid");
-	else
-		scmd_printk(KERN_INFO, cmd,
-			    "%s%s Result: hostbyte=0x%02x driverbyte=0x%02x",
-			    msg ? msg : "",
-			    mlret_string ? mlret_string : "UNKNOWN",
-			    host_byte(cmd->result), driver_byte(cmd->result));
-}
-EXPORT_SYMBOL(scsi_print_result);
diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index bc52bbd..92d5912 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -572,7 +572,7 @@ void scsi_log_completion(struct scsi_cmnd *cmd, int disposition)
 				       SCSI_LOG_MLCOMPLETE_BITS);
 		if (((level > 0) && (cmd->result || disposition != SUCCESS)) ||
 		    (level > 1)) {
-			scsi_print_result(cmd, "Done: ", disposition);
+			scsi_print_result(cmd, "Done", disposition);
 			scsi_print_command(cmd);
 			if (status_byte(cmd->result) & CHECK_CONDITION)
 				scsi_print_sense(cmd);
diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c
index 065792a3..e7e7cab 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -398,3 +398,47 @@ void scsi_print_sense(const struct scsi_cmnd *cmd)
 			     cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
 }
 EXPORT_SYMBOL(scsi_print_sense);
+
+void scsi_print_result(struct scsi_cmnd *cmd, const char *msg, int disposition)
+{
+	char *logbuf;
+	size_t off, logbuf_len;
+	const char *mlret_string = scsi_mlreturn_string(disposition);
+	const char *hb_string = scsi_hostbyte_string(cmd->result);
+	const char *db_string = scsi_driverbyte_string(cmd->result);
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return;
+
+	off = sdev_format_header(logbuf, logbuf_len,
+				 scmd_name(cmd), cmd->request->tag);
+
+	if (msg)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "%s: ", msg);
+	if (mlret_string)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "%s ", mlret_string);
+	else
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "UNKNOWN(0x%02x) ", disposition);
+	off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");
+	if (hb_string)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "hostbyte=%s ", hb_string);
+	else
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "hostbyte=0x%02x ", host_byte(cmd->result));
+
+	if (db_string)
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "driverbyte=%s", db_string);
+	else
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "driverbyte=0x%02x", driver_byte(cmd->result));
+
+	dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf);
+	scsi_log_release_buffer(logbuf);
+}
+EXPORT_SYMBOL(scsi_print_result);
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 09/10] scsi: Conditionally compile in constants.c
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (7 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-14 22:40   ` Elliott, Robert (Server Storage)
  2014-11-06  8:30 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
  2014-11-14 22:59 ` [PATCHv2 00/10] scsi logging update: the real thing Elliott, Robert (Server Storage)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

Instead of having constants.c littered with ifdef statements
we should be moving dummy functions into the header and
condintionally compile in constants.c if selected.

Suggested-by: Christoph Hellwig <hch@infradead.org>
Reviewed-by: Christoph Hellwig <hch@lst.de>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/Makefile      |  4 +--
 drivers/scsi/constants.c   | 42 ----------------------------
 drivers/xen/xen-scsiback.c |  1 +
 include/scsi/scsi_dbg.h    | 68 +++++++++++++++++++++++++++++++++++++++++++---
 4 files changed, 67 insertions(+), 48 deletions(-)

diff --git a/drivers/scsi/Makefile b/drivers/scsi/Makefile
index 4991b62..76f8932 100644
--- a/drivers/scsi/Makefile
+++ b/drivers/scsi/Makefile
@@ -158,9 +158,9 @@ obj-$(CONFIG_SCSI_OSD_INITIATOR) += osd/
 
 # This goes last, so that "real" scsi devices probe earlier
 obj-$(CONFIG_SCSI_DEBUG)	+= scsi_debug.o
-
-scsi_mod-y			+= scsi.o hosts.o scsi_ioctl.o constants.o \
+scsi_mod-y			+= scsi.o hosts.o scsi_ioctl.o \
 				   scsicam.o scsi_error.o scsi_lib.o
+scsi_mod-$(CONFIG_SCSI_CONSTANTS) += constants.o
 scsi_mod-$(CONFIG_SCSI_DMA)	+= scsi_lib_dma.o
 scsi_mod-y			+= scsi_scan.o scsi_sysfs.o scsi_devinfo.o
 scsi_mod-$(CONFIG_SCSI_NETLINK)	+= scsi_netlink.o
diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index dfa8639..a66572b 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -18,8 +18,6 @@
 #include <scsi/scsi_eh.h>
 #include <scsi/scsi_dbg.h>
 
-
-
 /* Commands with service actions that change the command name */
 #define THIRD_PARTY_COPY_OUT 0x83
 #define THIRD_PARTY_COPY_IN 0x84
@@ -35,7 +33,6 @@ struct value_name_pair {
 	const char * name;
 };
 
-#ifdef CONFIG_SCSI_CONSTANTS
 static const char * cdb_byte0_names[] = {
 /* 00-03 */ "Test Unit Ready", "Rezero Unit/Rewind", NULL, "Request Sense",
 /* 04-07 */ "Format Unit/Medium", "Read Block Limits", NULL,
@@ -259,26 +256,6 @@ static struct sa_name_list sa_names_arr[] = {
 	{0, NULL, 0},
 };
 
-#else /* ifndef CONFIG_SCSI_CONSTANTS */
-static const char *cdb_byte0_names[0];
-
-static struct sa_name_list sa_names_arr[] = {
-	{VARIABLE_LENGTH_CMD, NULL, 0},
-	{MAINTENANCE_IN, NULL, 0},
-	{MAINTENANCE_OUT, NULL, 0},
-	{PERSISTENT_RESERVE_IN, NULL, 0},
-	{PERSISTENT_RESERVE_OUT, NULL, 0},
-	{SERVICE_ACTION_IN_12, NULL, 0},
-	{SERVICE_ACTION_OUT_12, NULL, 0},
-	{SERVICE_ACTION_BIDIRECTIONAL, NULL, 0},
-	{SERVICE_ACTION_IN_16, NULL, 0},
-	{SERVICE_ACTION_OUT_16, NULL, 0},
-	{THIRD_PARTY_COPY_IN, NULL, 0},
-	{THIRD_PARTY_COPY_OUT, NULL, 0},
-	{0, NULL, 0},
-};
-#endif /* CONFIG_SCSI_CONSTANTS */
-
 bool scsi_opcode_sa_name(int opcode, int service_action,
 			 const char **cdb_name, const char **sa_name)
 {
@@ -313,8 +290,6 @@ bool scsi_opcode_sa_name(int opcode, int service_action,
 	return true;
 }
 
-#ifdef CONFIG_SCSI_CONSTANTS
-
 struct error_info {
 	unsigned short code12;	/* 0x0302 looks better than 0x03,0x02 */
 	const char * text;
@@ -1177,15 +1152,12 @@ static const char * const snstext[] = {
 	"Completed",	    /* F: command completed sense data reported,
 				  may occur for successful command */
 };
-#endif
 
 /* Get sense key string or NULL if not available */
 const char *
 scsi_sense_key_string(unsigned char key) {
-#ifdef CONFIG_SCSI_CONSTANTS
 	if (key <= 0xE)
 		return snstext[key];
-#endif
 	return NULL;
 }
 EXPORT_SYMBOL(scsi_sense_key_string);
@@ -1197,7 +1169,6 @@ EXPORT_SYMBOL(scsi_sense_key_string);
 const char *
 scsi_extd_sense_format(unsigned char asc, unsigned char ascq, const char **fmt)
 {
-#ifdef CONFIG_SCSI_CONSTANTS
 	int i;
 	unsigned short code = ((asc << 8) | ascq);
 
@@ -1211,13 +1182,10 @@ scsi_extd_sense_format(unsigned char asc, unsigned char ascq, const char **fmt)
 			*fmt = additional2[i].fmt;
 			return additional2[i].str;
 	}
-#endif
 	return NULL;
 }
 EXPORT_SYMBOL(scsi_extd_sense_format);
 
-#ifdef CONFIG_SCSI_CONSTANTS
-
 static const char * const hostbyte_table[]={
 "DID_OK", "DID_NO_CONNECT", "DID_BUS_BUSY", "DID_TIME_OUT", "DID_BAD_TARGET",
 "DID_ABORT", "DID_PARITY", "DID_ERROR", "DID_RESET", "DID_BAD_INTR",
@@ -1229,17 +1197,13 @@ static const char * const driverbyte_table[]={
 "DRIVER_OK", "DRIVER_BUSY", "DRIVER_SOFT",  "DRIVER_MEDIA", "DRIVER_ERROR",
 "DRIVER_INVALID", "DRIVER_TIMEOUT", "DRIVER_HARD", "DRIVER_SENSE"};
 
-#endif
-
 const char *scsi_hostbyte_string(int result)
 {
 	const char *hb_string = NULL;
-#ifdef CONFIG_SCSI_CONSTANTS
 	int hb = host_byte(result);
 
 	if (hb < ARRAY_SIZE(hostbyte_table))
 		hb_string = hostbyte_table[hb];
-#endif
 	return hb_string;
 }
 EXPORT_SYMBOL(scsi_hostbyte_string);
@@ -1247,17 +1211,14 @@ EXPORT_SYMBOL(scsi_hostbyte_string);
 const char *scsi_driverbyte_string(int result)
 {
 	const char *db_string = NULL;
-#ifdef CONFIG_SCSI_CONSTANTS
 	int db = driver_byte(result);
 
 	if (db < ARRAY_SIZE(driverbyte_table))
 		db_string = driverbyte_table[db];
-#endif
 	return db_string;
 }
 EXPORT_SYMBOL(scsi_driverbyte_string);
 
-#ifdef CONFIG_SCSI_CONSTANTS
 #define scsi_mlreturn_name(result)	{ result, #result }
 static const struct value_name_pair scsi_mlreturn_arr[] = {
 	scsi_mlreturn_name(NEEDS_RETRY),
@@ -1270,11 +1231,9 @@ static const struct value_name_pair scsi_mlreturn_arr[] = {
 	scsi_mlreturn_name(SCSI_RETURN_NOT_HANDLED),
 	scsi_mlreturn_name(FAST_IO_FAIL)
 };
-#endif
 
 const char *scsi_mlreturn_string(int result)
 {
-#ifdef CONFIG_SCSI_CONSTANTS
 	const struct value_name_pair *arr = scsi_mlreturn_arr;
 	int k;
 
@@ -1282,7 +1241,6 @@ const char *scsi_mlreturn_string(int result)
 		if (result == arr->value)
 			return arr->name;
 	}
-#endif
 	return NULL;
 }
 EXPORT_SYMBOL(scsi_mlreturn_string);
diff --git a/drivers/xen/xen-scsiback.c b/drivers/xen/xen-scsiback.c
index 50610a6..cc0ebf2 100644
--- a/drivers/xen/xen-scsiback.c
+++ b/drivers/xen/xen-scsiback.c
@@ -47,6 +47,7 @@
 
 #include <generated/utsrelease.h>
 
+#include <scsi/scsi.h>
 #include <scsi/scsi_dbg.h>
 #include <scsi/scsi_eh.h>
 #include <scsi/scsi_tcq.h>
diff --git a/include/scsi/scsi_dbg.h b/include/scsi/scsi_dbg.h
index c7ed7b8..6434130 100644
--- a/include/scsi/scsi_dbg.h
+++ b/include/scsi/scsi_dbg.h
@@ -7,7 +7,6 @@ struct scsi_sense_hdr;
 
 #define SCSI_LOG_BUFSIZE 128
 
-extern bool scsi_opcode_sa_name(int, int, const char **, const char **);
 extern void scsi_print_command(struct scsi_cmnd *);
 extern size_t __scsi_format_command(char *, size_t,
 				   const unsigned char *, size_t);
@@ -22,11 +21,72 @@ extern void __scsi_print_sense(const struct scsi_device *, const char *name,
 			       const unsigned char *sense_buffer,
 			       int sense_len);
 extern void scsi_print_result(struct scsi_cmnd *, const char *, int);
-extern const char *scsi_hostbyte_string(int);
-extern const char *scsi_driverbyte_string(int);
-extern const char *scsi_mlreturn_string(int);
+
+#ifdef CONFIG_SCSI_CONSTANTS
+extern bool scsi_opcode_sa_name(int, int, const char **, const char **);
 extern const char *scsi_sense_key_string(unsigned char);
 extern const char *scsi_extd_sense_format(unsigned char, unsigned char,
 					  const char **);
+extern const char *scsi_mlreturn_string(int);
+extern const char *scsi_hostbyte_string(int);
+extern const char *scsi_driverbyte_string(int);
+#else
+static inline bool
+scsi_opcode_sa_name(int cmd, int sa,
+		    const char **cdb_name, const char **sa_name)
+{
+	*cdb_name = NULL;
+	switch (cmd) {
+	case VARIABLE_LENGTH_CMD:
+	case MAINTENANCE_IN:
+	case MAINTENANCE_OUT:
+	case PERSISTENT_RESERVE_IN:
+	case PERSISTENT_RESERVE_OUT:
+	case SERVICE_ACTION_IN_12:
+	case SERVICE_ACTION_OUT_12:
+	case SERVICE_ACTION_BIDIRECTIONAL:
+	case SERVICE_ACTION_IN_16:
+	case SERVICE_ACTION_OUT_16:
+	case EXTENDED_COPY:
+	case RECEIVE_COPY_RESULTS:
+		*sa_name = NULL;
+		return true;
+	default:
+		return false;
+	}
+}
+
+static inline const char *
+scsi_sense_key_string(unsigned char key)
+{
+	return NULL;
+}
+
+static inline const char *
+scsi_extd_sense_format(unsigned char asc, unsigned char ascq, const char **fmt)
+{
+	*fmt = NULL;
+	return NULL;
+}
+
+static inline const char *
+scsi_mlreturn_string(int result)
+{
+	return NULL;
+}
+
+static inline const char *
+scsi_hostbyte_string(int result)
+{
+	return NULL;
+}
+
+static inline const char *
+scsi_driverbyte_string(int result)
+{
+	return NULL;
+}
+
+#endif
 
 #endif /* _SCSI_SCSI_DBG_H */
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send()
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (8 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-14 22:53   ` Elliott, Robert (Server Storage)
  2014-11-14 22:59 ` [PATCHv2 00/10] scsi logging update: the real thing Elliott, Robert (Server Storage)
  10 siblings, 1 reply; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-06  8:30 UTC (permalink / raw
  To: James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, Robert Elliott, linux-scsi,
	Hannes Reinecke

scsi_log_send() would display buffer pointer for higher
logging levels. This is not only of questionable value
but also exposes kernel pointer to userspace, which is
discouraged in some setups. So drop this message
altogether.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi.c | 9 +--------
 1 file changed, 1 insertion(+), 8 deletions(-)

diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index 92d5912..9ec576d 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -531,7 +531,7 @@ void scsi_log_send(struct scsi_cmnd *cmd)
 	 *
 	 * 3: same as 2
 	 *
-	 * 4: same as 3 plus dump extra junk
+	 * 4: same as 3
 	 */
 	if (unlikely(scsi_logging_level)) {
 		level = SCSI_LOG_LEVEL(SCSI_LOG_MLQUEUE_SHIFT,
@@ -540,13 +540,6 @@ void scsi_log_send(struct scsi_cmnd *cmd)
 			scmd_printk(KERN_INFO, cmd,
 				    "Send: scmd 0x%p\n", cmd);
 			scsi_print_command(cmd);
-			if (level > 3) {
-				printk(KERN_INFO "buffer = 0x%p, bufflen = %d,"
-				       " queuecommand 0x%p\n",
-					scsi_sglist(cmd), scsi_bufflen(cmd),
-					cmd->device->host->hostt->queuecommand);
-
-			}
 		}
 	}
 }
-- 
1.8.5.2


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* RE: [PATCH 02/10] scsi: Add SPC-3 command definitions
  2014-11-06  8:30 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
@ 2014-11-12 17:07   ` Elliott, Robert (Server Storage)
  2014-11-17  7:56     ` Hannes Reinecke
  0 siblings, 1 reply; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-12 17:07 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 02/10] scsi: Add SPC-3 command definitions
> 
> SPC-3 defines SERVICE ACTION IN(12), SERVICE_ACTION OUT(12),
> SERVICE ACTION OUT(16), and SERVICE ACTION BIDIRECTIONAL.
> And READ MEDIA SERIAL NUMBER has long since been deprecated.
> So update callers to refer to the new cdb name.
> 
> Reviewed-by: Christoph Hellwig <hch@lst.de>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  drivers/scsi/constants.c           | 4 ----
>  drivers/target/target_core_pr.c    | 2 +-
>  include/scsi/scsi.h                | 6 +++++-
>  tools/lib/traceevent/plugin_scsi.c | 5 ++++-
>  4 files changed, 10 insertions(+), 7 deletions(-)
> 
...
> diff --git a/include/scsi/scsi.h b/include/scsi/scsi.h
> index b354c0d..df00fd1 100644
> --- a/include/scsi/scsi.h
> +++ b/include/scsi/scsi.h
> @@ -128,8 +128,10 @@ enum scsi_timeouts {
>  #define MOVE_MEDIUM           0xa5
>  #define EXCHANGE_MEDIUM       0xa6
>  #define READ_12               0xa8
> +#define SERVICE_ACTION_OUT_12 0xa9
>  #define WRITE_12              0xaa
> -#define READ_MEDIA_SERIAL_NUMBER 0xab
> +#define READ_MEDIA_SERIAL_NUMBER 0xab /* Obsolete with SPC-2 */
> +#define SERVICE_ACTION_IN_12 0xab

That needs one more space before 0xab to line up with the others.

...
> diff --git a/tools/lib/traceevent/plugin_scsi.c
> b/tools/lib/traceevent/plugin_scsi.c
> index c699f47..63aba97 100644
> --- a/tools/lib/traceevent/plugin_scsi.c
> +++ b/tools/lib/traceevent/plugin_scsi.c
> @@ -85,8 +85,9 @@ typedef unsigned int u32;
>  #define MOVE_MEDIUM			0xa5
>  #define EXCHANGE_MEDIUM			0xa6
>  #define READ_12				0xa8
> +#define SERVICE_ACTION_out_12		0xa9
...

out should be capitalized

Reviewed-by: Robert Elliott <elliott@hp.com>



^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 04/10] scsi: log request tag for scmd_printk()
  2014-11-06  8:30 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
@ 2014-11-12 17:18   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-12 17:18 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 04/10] scsi: log request tag for scmd_printk()
> 
> The request tag provides a concise identification of a SCSI
> command, so we should be printing that out for scmd_printk().
> 
> Suggested-by: Christoph Hellwig <hch@lst.de>
> Reviewed-by: Christoph Hellwig <hch@lst.de>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  drivers/scsi/scsi_logging.c | 4 ++++
>  1 file changed, 4 insertions(+)
> 
> diff --git a/drivers/scsi/scsi_logging.c
> b/drivers/scsi/scsi_logging.c
> index 4a76796..dca45fe 100644
> --- a/drivers/scsi/scsi_logging.c
> +++ b/drivers/scsi/scsi_logging.c
> @@ -109,6 +109,10 @@ int scmd_printk(const char *level, const struct
> scsi_cmnd *scmd,
>  	if (disk)
>  		off += scnprintf(logbuf + off, logbuf_len - off,
>  				 "[%s] ", disk->disk_name);
> +
> +	if (scmd->request->tag >= 0)
> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 "tag#%d ", scmd->request->tag);
>  	va_start(args, fmt);
>  	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
>  	va_end(args);
> --
> 1.8.5.2

Reviewed-by: Robert Elliott <elliott@hp.com>


^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 03/10] scsi: Implement per-cpu logging buffer
  2014-11-06  8:30 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
@ 2014-11-13  2:22   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-13  2:22 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org

One more comment on this one (which was PATCH 01 in v1 of the series,
to which I sent most of my comments)...

> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 03/10] scsi: Implement per-cpu logging buffer
> 
> +++ b/drivers/scsi/scsi_logging.c
> @@ -0,0 +1,119 @@
...
> +static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log);
> +
> +static char *scsi_log_reserve_buffer(size_t *len)
> +{
> +	struct scsi_log_buf *buf;
> +	unsigned long map_bits = SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE;

sizeof(buf->buffer) would be a bit safer than 
SCSI_LOG_SPOOLSIZE - adapts automatically if the real value
used in the structure definition ever changes.


---
Rob Elliott    HP Server Storage





^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 05/10] scsi: use external buffer for command logging
  2014-11-06  8:30 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
@ 2014-11-13  2:24   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-13  2:24 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 05/10] scsi: use external buffer for command logging
> 
...
> diff --git a/drivers/scsi/ch.c b/drivers/scsi/ch.c
> index 4f502f9..ed0d10d 100644
> --- a/drivers/scsi/ch.c
> +++ b/drivers/scsi/ch.c
> @@ -195,8 +195,10 @@ ch_do_scsi(scsi_changer *ch, unsigned char *cmd,
> int cmd_len,
>   retry:
>  	errno = 0;
>  	if (debug) {
> -		DPRINTK("command: ");
> -		__scsi_print_command(cmd, cmd_len);
> +		char logbuf[SCSI_LOG_BUFSIZE];
> +
> +		__scsi_format_command(logbuf, SCSI_LOG_BUFSIZE, cmd,
> cmd_len);

Use sizeof(logbuf) rather than SCSI_LOG_BUFSIZE to avoid 
the macro name ever mismatching.

> +		DPRINTK("command: %s", logbuf);
>  	}
> 
>  	result = scsi_execute_req(ch->device, cmd, direction, buffer,
...
> diff --git a/drivers/scsi/scsi_logging.c
> b/drivers/scsi/scsi_logging.c
> index dca45fe..d166d12 100644
> --- a/drivers/scsi/scsi_logging.c
> +++ b/drivers/scsi/scsi_logging.c
> @@ -13,10 +13,10 @@
>  #include <scsi/scsi.h>
>  #include <scsi/scsi_cmnd.h>
>  #include <scsi/scsi_device.h>
> +#include <scsi/scsi_eh.h>
>  #include <scsi/scsi_dbg.h>
> 
>  #define SCSI_LOG_SPOOLSIZE 4096
> -#define SCSI_LOG_BUFSIZE 128
> 
>  struct scsi_log_buf {
>  	char buffer[SCSI_LOG_SPOOLSIZE];
> @@ -64,6 +64,21 @@ static void scsi_log_release_buffer(char *bufptr)
>  	preempt_enable();
>  }
> 
> +static size_t scmd_format_header(char *logbuf, size_t logbuf_len,
> +				 struct gendisk *disk, int tag)
> +{
> +	size_t off = 0;
> +
> +	if (disk)
> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 "[%s] ", disk->disk_name);
> +
> +	if (tag >= 0)
> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 "tag#%d ", tag);

If the first scnprintf consumes the full logbuf_len, then
logbuf_len - off will cause an unsigned wrap (since it's
using size_t types; it'd go negative if it used signed types), 
triggering this from vsnprintf (called by scnprintf):
        if (WARN_ON_ONCE((int) size < 0))
                return 0;

It might be prudent to check that it hasn't gone too far
before calling scnprintf again.

> +	return off;
> +}
> +
>  int sdev_prefix_printk(const char *level, const struct scsi_device
> *sdev,
>  		       const char *name, const char *fmt, ...)
>  {
> @@ -106,13 +121,8 @@ int scmd_printk(const char *level, const struct
> scsi_cmnd *scmd,
>  	logbuf = scsi_log_reserve_buffer(&logbuf_len);
>  	if (!logbuf)
>  		return 0;
> -	if (disk)
> -		off += scnprintf(logbuf + off, logbuf_len - off,
> -				 "[%s] ", disk->disk_name);
> -
> -	if (scmd->request->tag >= 0)
> -		off += scnprintf(logbuf + off, logbuf_len - off,
> -				 "tag#%d ", scmd->request->tag);
> +	off = scmd_format_header(logbuf, logbuf_len, disk,
> +				 scmd->request->tag);
>  	va_start(args, fmt);

Same comment about ensuring off hasn't gone too far.

>  	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
>  	va_end(args);
> @@ -121,3 +131,121 @@ int scmd_printk(const char *level, const struct
> scsi_cmnd *scmd,
>  	return ret;
>  }
>  EXPORT_SYMBOL_GPL(scmd_printk);
> +
> +static size_t scsi_format_opcode_name(char *buffer, size_t buf_len,
> +				      const unsigned char *cdbp)
> +{
> +	int sa, cdb0;
> +	const char *cdb_name = NULL, *sa_name = NULL;
> +	size_t off;
> +
> +	cdb0 = cdbp[0];
> +	if (cdb0 == VARIABLE_LENGTH_CMD) {
> +		int len = scsi_varlen_cdb_length(cdbp);
> +
> +		if (len < 10) {
> +			off = scnprintf(buffer, buf_len,
> +					"short variable length command,
> len=%d",
> +					len);
> +			return off;
> +		}
> +		sa = (cdbp[8] << 8) + cdbp[9];
> +	} else
> +		sa = cdbp[1] & 0x1f;
> +
> +	if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) {
> +		if (cdb_name)
> +			off = scnprintf(buffer, buf_len, "%s", cdb_name);
> +		else {
> +			off = scnprintf(buffer, buf_len, "cdb[0]=0x%x",
> cdb0);

Since the service action is printed using "sa=" below,
consider using "op=" or "opcode=" rather than "cdb[0]=".
That might be clearer to readers who don't know the CDB
layout but do have an opcode table handy.


> +			if (cdb0 > VENDOR_SPECIFIC_CDB)

The > should be >= since that define is 0xc0 (which itself
is vendor-specific).

> +				off += scnprintf(buffer + off, buf_len -
> off,
> +						 " (vendor)");
> +			else if (cdb0 > 0x60 && cdb0 < 0x7e)

The > should be >= since 0x60 is reserved.  
The < is correct (0x7e is "extended CDB").


> +				off += scnprintf(buffer + off, buf_len -
> off,
> +						 " (reserved)");
> +		}
> +	} else {
> +		if (sa_name)
> +			off = scnprintf(buffer, buf_len, "%s", sa_name);
> +		else if (cdb_name)
> +			off = scnprintf(buffer, buf_len, "%s, sa=0x%x",
> +					cdb_name, sa);
> +		else
> +			off = scnprintf(buffer, buf_len,
> +					"cdb[0]=0x%x, sa=0x%x", cdb0, sa);
> +	}
> +	return off;
> +}
> +
> +size_t __scsi_format_command(char *logbuf, size_t logbuf_len,
> +			     const unsigned char *cdb, size_t cdb_len)
> +{
> +	int len, k;
> +	size_t off;
> +
> +	off = scsi_format_opcode_name(logbuf, logbuf_len, cdb);
> +	len = scsi_command_size(cdb);
> +	if (cdb_len < len)
> +		len = cdb_len;
> +	/* print out all bytes in cdb */
> +	for (k = 0; k < len; ++k) {
> +		if (off + 3 > logbuf_len)
> +			break;

Might need a check for logbuf_len - off causing an unsigned
wraparound problem before proceeding to scnprintf.


> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 " %02x", cdb[k]);
> +	}
> +	return off;
> +}
> +EXPORT_SYMBOL(__scsi_format_command);
> +
> +void scsi_print_command(struct scsi_cmnd *cmd)
> +{
> +	struct gendisk *disk = cmd->request->rq_disk;
> +	int k;
> +	char *logbuf;
> +	size_t off, logbuf_len;
> +
> +	if (cmd->cmnd == NULL)
> +		return;

Using !cmd->cmnd seems more common in SCSI midlayer code.

> +
> +	logbuf = scsi_log_reserve_buffer(&logbuf_len);
> +	if (!logbuf)
> +		return;
> +
> +	off = scmd_format_header(logbuf, logbuf_len, disk, cmd-
> >request->tag);

Repeat the logbuf_len - off wraparound concern.

> +	off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");

Repeat the logbuf_len - off wraparound concern.

> +	off += scsi_format_opcode_name(logbuf + off, logbuf_len - off,
> +				       cmd->cmnd);
> +	/* print out all bytes in cdb */
> +	if (cmd->cmd_len > 16) {
> +		/* Print opcode in one line and use separate lines for
> CDB */
> +		off += scnprintf(logbuf + off, logbuf_len - off, "\n");
> +		dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf);
> +		scsi_log_release_buffer(logbuf);
> +		for (k = 0; k < cmd->cmd_len; k += 16) {
> +			size_t linelen = min(cmd->cmd_len - k, 16);
> +
> +			logbuf = scsi_log_reserve_buffer(&logbuf_len);
> +			if (!logbuf)
> +				break;
> +			off = scmd_format_header(logbuf, logbuf_len, disk,
> +						 cmd->request->tag);

Repeat the logbuf_len - off wraparound concern.

> +			off += scnprintf(logbuf + off, logbuf_len - off,
> +					 "CDB[%02x]: ", k);

Repeat the logbuf_len - off wraparound concern.

> +			hex_dump_to_buffer(&cmd->cmnd[k], linelen, 16, 1,
> +					   logbuf + off, logbuf_len - off,
> +					   false);
> +			dev_printk(KERN_INFO, &cmd->device->sdev_gendev,
> +				   logbuf);
> +			scsi_log_release_buffer(logbuf);
> +		}
> +	} else {
> +		off += scnprintf(logbuf + off, logbuf_len - off, " ");

Repeat the logbuf_len - off wraparound concern.

> +		hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,
> +				   logbuf + off, logbuf_len - off, false);
> +		dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf);
> +		scsi_log_release_buffer(logbuf);
> +	}
> +}
> +EXPORT_SYMBOL(scsi_print_command);
> diff --git a/drivers/scsi/sr_ioctl.c b/drivers/scsi/sr_ioctl.c
> index fb929fa..4f9fb3c 100644
> --- a/drivers/scsi/sr_ioctl.c
> +++ b/drivers/scsi/sr_ioctl.c
> @@ -188,6 +188,7 @@ int sr_do_ioctl(Scsi_CD *cd, struct
> packet_command *cgc)
>  	struct scsi_sense_hdr sshdr;
>  	int result, err = 0, retries = 0;
>  	struct request_sense *sense = cgc->sense;
> +	char logbuf[SCSI_LOG_BUFSIZE];
> 
>  	SDev = cd->device;
> 
> @@ -257,14 +258,20 @@ int sr_do_ioctl(Scsi_CD *cd, struct
> packet_command *cgc)
>  				/* sense: Invalid command operation code */
>  				err = -EDRIVE_CANT_DO_THIS;
>  #ifdef DEBUG
> -			__scsi_print_command(cgc->cmd, CDROM_PACKET_SIZE);
> +			__scsi_format_command(logbuf, SCSI_LOG_BUFSIZE,
> +					      cgc->cmd, CDROM_PACKET_SIZE);

Use sizeof(logbuf) rather than SCSI_LOG_BUFSIZE to avoid 
the macro name ever mismatching.

> +			sr_printk(KERN_INFO, cd,
> +				  "CDROM (ioctl) invalid command: %s\n",
> +				  logbuf);
>  			scsi_print_sense_hdr(cd->device, cd->cdi.name,
> &sshdr);
>  #endif
>  			break;
>  		default:
> +			__scsi_format_command(logbuf, SCSI_LOG_BUFSIZE,
> +					      cgc->cmd, CDROM_PACKET_SIZE);

Use sizeof(logbuf) rather than SCSI_LOG_BUFSIZE to avoid 
the macro name ever mismatching.

>  			sr_printk(KERN_ERR, cd,
> -				  "CDROM (ioctl) error, command: ");
> -			__scsi_print_command(cgc->cmd, CDROM_PACKET_SIZE);
> +				  "CDROM (ioctl) error, command: %s\n",
> +				  logbuf);
>  			scsi_print_sense_hdr(cd->device, cd->cdi.name,
> &sshdr);
>  			err = -EIO;
>  		}
...


^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 06/10] libata: use __scsi_format_command()
  2014-11-06  8:30 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
@ 2014-11-14 16:02   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 16:02 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org,
	linux-ide@vger.kernel.org, LKML



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke; linux-
> ide@vger.kernel.org; LKML
> Subject: [PATCH 06/10] libata: use __scsi_format_command()
> 
> libata already uses an internal buffer, so we should be using
> __scsi_format_command() here.
> 
> Cc: linux-ide@vger.kernel.org
> Cc: LKML <linux-kernel@vger.kernel.org>
> Reviewed-by: Christoph Hellwig <hch@lst.de>
> Acked-by: Tejun Heo <tj@kernel.org>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  drivers/ata/libata-eh.c | 13 +++++--------
>  1 file changed, 5 insertions(+), 8 deletions(-)
> 
> diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
> index dad83df..6550a9a 100644
> --- a/drivers/ata/libata-eh.c
> +++ b/drivers/ata/libata-eh.c
> @@ -2509,15 +2509,12 @@ static void ata_eh_link_report(struct
> ata_link *link)
> 
>  		if (ata_is_atapi(qc->tf.protocol)) {
>  			if (qc->scsicmd)
> -				scsi_print_command(qc->scsicmd);
> +				__scsi_format_command(cdb_buf,
> sizeof(cdb_buf),
> +						      qc->scsicmd->cmnd,
> +						      qc->scsicmd->cmd_len);
>  			else
> -				snprintf(cdb_buf, sizeof(cdb_buf),
> -				 "cdb %02x %02x %02x %02x %02x %02x %02x
> %02x  "
> -				 "%02x %02x %02x %02x %02x %02x %02x %02x\n
> ",
> -				 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]);
> +				__scsi_format_command(cdb_buf,
> sizeof(cdb_buf),
> +						      cdb, qc->dev->cdb_len);

Since results in just one "cdb" variable usage, you could change
"cdb" to qc->cdb" to get rid of the variable declaration and 
slightly simplify the code.
                const u8 *cdb = qc->cdb;


>  		} else {
>  			const char *descr = ata_get_cmd_descript(cmd-
> >command);
>  			if (descr)
> --
> 1.8.5.2

Reviewed-by: Robert Elliott <elliott@hp.com>


^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16
  2014-11-06  8:30 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
@ 2014-11-14 16:10   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 16:10 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to
> SERVICE_ACTION_IN_16
> 
> SPC-3 defines SERVICE ACTION IN(12) and SERVICE ACTION IN(16).
> So rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 to be
> consistent with SPC and to allow for better distinction.
> 
> Reviewed-by: Christoph Hellwig <hch@lst.de>
> Signed-off-by: Hannes Reinecke <hare@suse.de>

Reviewed-by: Robert Elliott <elliott@hp.com>


^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 07/10] scsi: use per-cpu buffer for formatting sense
  2014-11-06  8:30 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
@ 2014-11-14 16:52   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 16:52 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
...

> diff --git a/drivers/scsi/scsi_logging.c
...
> @@ -249,3 +255,146 @@ void scsi_print_command(struct scsi_cmnd *cmd)
>  	}
>  }
>  EXPORT_SYMBOL(scsi_print_command);
> +
> +static size_t
> +scsi_format_extd_sense(char *buffer, size_t buf_len,
> +		       unsigned char asc, unsigned char ascq)
> +{
> +	size_t off = 0;
> +	const char *extd_sense_fmt = NULL;
> +	const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,
> +							    &extd_sense_fmt);

As Dan Carpenter noted, there's a missing {} in 
scsi_extd_sense_format (from the previous logging series)
that causes it to return incorrectly.

...
> +static void
> +scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char
> *name,
> +			 int tag, const struct scsi_sense_hdr *sshdr)
> +{
> +	char *logbuf;
> +	size_t off, logbuf_len;
> +
> +	logbuf = scsi_log_reserve_buffer(&logbuf_len);
> +	if (!logbuf)
> +		return;
> +	off = sdev_format_header(logbuf, logbuf_len, name, tag);
> +	off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off,
> sshdr);
> +	dev_printk(KERN_INFO, &sdev->sdev_gendev, logbuf);
> +	scsi_log_release_buffer(logbuf);
> +
> +	logbuf = scsi_log_reserve_buffer(&logbuf_len);
> +	if (!logbuf)
> +		return;
> +	off = sdev_format_header(logbuf, logbuf_len, name, tag);
> +	off += scsi_format_extd_sense(logbuf + off, logbuf_len - off,
> +				      sshdr->asc, sshdr->ascq);
> +	dev_printk(KERN_INFO, &sdev->sdev_gendev, logbuf);
> +	scsi_log_release_buffer(logbuf);
> +}

This releases the buffer, but reserves it on the next line.
Should the buffer just be held between these two portions?
The subfunctions being called aren't functions that will cause
delays and thus delay other functions waiting on a buffer.
Although the tag on each line helps tremendously, the serial
log will be even more readable if the prints are back-to-back.

The same question applies to scsi_print_command in patch 05/10.
That function prints several lines in a for loop (for long CDBs):

+		for (k = 0; k < cmd->cmd_len; k += 16) {
+			size_t linelen = min(cmd->cmd_len - k, 16);
+
+			logbuf = scsi_log_reserve_buffer(&logbuf_len);
...
+			scsi_log_release_buffer(logbuf);
+		}

Perhaps the reserve/release should be outside the for loop
so they all reuse one buffer and are printed adjacently.

...
> +/* Normalize and print sense buffer in SCSI command */
> +void scsi_print_sense(const struct scsi_cmnd *cmd)
> +{
> +	struct gendisk *disk = cmd->request->rq_disk;
> +	const char *disk_name = disk ? disk->disk_name : NULL;
> +	scsi_log_print_sense(cmd->device, disk_name, cmd->request->tag,
> +			     cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
> +}
> +EXPORT_SYMBOL(scsi_print_sense);

This function should use the new scmd_name function, which does:
        return scmd->request->rq_disk ?
                scmd->request->rq_disk->disk_name : NULL;


Reviewed-by: Robert Elliott <elliott@hp.com>


---
Rob Elliott    HP Server Storage



^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result()
  2014-11-06  8:30 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
@ 2014-11-14 22:20   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 22:20 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org

> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
...
> diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
...
> diff --git a/drivers/scsi/scsi_logging.c
> b/drivers/scsi/scsi_logging.c
> index 065792a3..e7e7cab 100644
> --- a/drivers/scsi/scsi_logging.c
> +++ b/drivers/scsi/scsi_logging.c
> @@ -398,3 +398,47 @@ void scsi_print_sense(const struct scsi_cmnd
> *cmd)
>  			     cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
>  }
>  EXPORT_SYMBOL(scsi_print_sense);
> +
> +void scsi_print_result(struct scsi_cmnd *cmd, const char *msg, int
> disposition)

Since this function does not modify anything pointed to by cmd,
consider adding const to that argument.

> +{
> +	char *logbuf;
> +	size_t off, logbuf_len;
> +	const char *mlret_string = scsi_mlreturn_string(disposition);

As mentioned in the last series, it might be good to
change the midlayer string from SUCCESS to COMPLETE,
since that is printed even for commands that fail with
errors.  

(This patch series doesn't touch that function, so mentioning
the issue here at the only caller)

>
> +	const char *hb_string = scsi_hostbyte_string(cmd->result);
> +	const char *db_string = scsi_driverbyte_string(cmd->result);
> +
> +	logbuf = scsi_log_reserve_buffer(&logbuf_len);
> +	if (!logbuf)
> +		return;
> +
> +	off = sdev_format_header(logbuf, logbuf_len,
> +				 scmd_name(cmd), cmd->request->tag);
> +
> +	if (msg)
> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 "%s: ", msg);
> +	if (mlret_string)
> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 "%s ", mlret_string);
> +	else
> +		off += scnprintf(logbuf + off, logbuf_len - off,
> +				 "UNKNOWN(0x%02x) ", disposition);
> +	off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");
...

Consider printing "Result: " first.  That would make
the messages more consistent since "Done:" is not always there.

Current:
 [491784.462209] sd 1:0:0:0: [sdq] tag#0 Done: SUCCESS Result: hostbyte=DID_OK driverbyte=DRIVER_OK
 [491784.464962] sd 1:0:0:0: [sdq] tag#0 CDB: Write(10) 2a 00 39 8c fa 80 00 00 08 00
 [  259.667383] sd 2:0:0:0: [sdr] tag#334 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
 [  259.667387] sd 2:0:0:0: [sdr] tag#334 Sense Key : Hardware Error [current]
 [  259.667391] sd 2:0:0:0: [sdr] tag#334 Add. Sense: Logical unit failure
 [  259.667395] sd 2:0:0:0: [sdr] tag#334 CDB: Read(10) 28 00 1b 85 9d 30 00 00 08 00
 [27907.647377] sd 1:0:0:0: [sdq] tag#768 Done: TIMEOUT_ERROR Result: hostbyte=DID_OK driverbyte=DRIVER_OK
 [27907.647380] sd 1:0:0:0: [sdq] tag#768 CDB: Write(10) 2a 00 39 8a f4 e0 00 00 08 00
 [27907.647382] sd 1:0:0:0: [sdq] tag#768 scmd ffff880424761470 abort scheduled

Proposed:
 [491784.462209] sd 1:0:0:0: [sdq] tag#0 Result: Done: COMPLETE hostbyte=DID_OK driverbyte=DRIVER_OK
 [491784.464962] sd 1:0:0:0: [sdq] tag#0 CDB: Write(10) 2a 00 39 8c fa 80 00 00 08 00
 [  259.667383] sd 2:0:0:0: [sdr] tag#334 Result: FAILED hostbyte=DID_OK driverbyte=DRIVER_SENSE
 [  259.667387] sd 2:0:0:0: [sdr] tag#334 Sense Key : Hardware Error [current]
 [  259.667391] sd 2:0:0:0: [sdr] tag#334 Add. Sense: Logical unit failure
 [  259.667395] sd 2:0:0:0: [sdr] tag#334 CDB: Read(10) 28 00 1b 85 9d 30 00 00 08 00
 [27907.647377] sd 1:0:0:0: [sdq] tag#768 Result: Done: TIMEOUT_ERROR hostbyte=DID_OK driverbyte=DRIVER_OK
 [27907.647380] sd 1:0:0:0: [sdq] tag#768 CDB: Write(10) 2a 00 39 8a f4 e0 00 00 08 00
 [27907.647382] sd 1:0:0:0: [sdq] tag#768 scmd ffff880424761470 abort scheduled

Furthermore, consider dropping "Done" (the only msg argument 
ever used) altogether.  "Done" means scsi_log_completion is
printing this. No "Done" means scsi_io_completion's ACTION_FAIL
case is printing this.

The disposition (COMPLETE, FAILED, TIMEOUT_ERROR, etc.) seems
to convey that same information, in more detail.


Reviewed-by: Robert Elliott <elliott@hp.com>

---
Rob Elliott    HP Server Storage




^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 09/10] scsi: Conditionally compile in constants.c
  2014-11-06  8:30 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
@ 2014-11-14 22:40   ` Elliott, Robert (Server Storage)
  0 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 22:40 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 09/10] scsi: Conditionally compile in constants.c
> 
> Instead of having constants.c littered with ifdef statements
> we should be moving dummy functions into the header and
> condintionally compile in constants.c if selected.
> 
> Suggested-by: Christoph Hellwig <hch@infradead.org>
> Reviewed-by: Christoph Hellwig <hch@lst.de>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  drivers/scsi/Makefile      |  4 +--
>  drivers/scsi/constants.c   | 42 ----------------------------
>  drivers/xen/xen-scsiback.c |  1 +
>  include/scsi/scsi_dbg.h    | 68
> +++++++++++++++++++++++++++++++++++++++++++---
>  4 files changed, 67 insertions(+), 48 deletions(-)
> 
> diff --git a/drivers/scsi/Makefile b/drivers/scsi/Makefile
> index 4991b62..76f8932 100644
> --- a/drivers/scsi/Makefile
> +++ b/drivers/scsi/Makefile
> @@ -158,9 +158,9 @@ obj-$(CONFIG_SCSI_OSD_INITIATOR) += osd/
> 
>  # This goes last, so that "real" scsi devices probe earlier
>  obj-$(CONFIG_SCSI_DEBUG)	+= scsi_debug.o
> -
> -scsi_mod-y			+= scsi.o hosts.o scsi_ioctl.o constants.o \
> +scsi_mod-y			+= scsi.o hosts.o scsi_ioctl.o \
>  				   scsicam.o scsi_error.o scsi_lib.o
> +scsi_mod-$(CONFIG_SCSI_CONSTANTS) += constants.o
>  scsi_mod-$(CONFIG_SCSI_DMA)	+= scsi_lib_dma.o
>  scsi_mod-y			+= scsi_scan.o scsi_sysfs.o scsi_devinfo.o
>  scsi_mod-$(CONFIG_SCSI_NETLINK)	+= scsi_netlink.o
...

I has no compile issues with and without CONFIG_SCSI_CONSTANTS.

make menuconfig says SCSI_CONSTANTS causes "(kernel size +=12K)".
That appears low now (although other config settings might
be exaggerating that on my machine).

Without CONFIG_SCSI_CONSTANTS:
-rwxrwxr-x 1 relliott relliott 133057434 Nov 14 16:27 vmlinux
-rw-rw-r-- 1 relliott relliott 313306350 Nov 14 16:27 vmlinux.o

With CONFIG_SCSI_CONSTANTS:
-rwxrwxr-x 1 relliott relliott 133132674 Nov 14 16:33 vmlinux
-rw-rw-r-- 1 relliott relliott 313575486 Nov 14 16:33 vmlinux.o

vmlinux is 75,240 bytes different.  So, you might want to
modify the Kconfig description.

Reviewed-by: Robert Elliott <elliott@hp.com>

---
Rob Elliott    HP Server Storage




^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send()
  2014-11-06  8:30 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
@ 2014-11-14 22:53   ` Elliott, Robert (Server Storage)
  2014-11-17  9:14     ` Hannes Reinecke
  0 siblings, 1 reply; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 22:53 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:31 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCH 10/10] scsi: Do not display buffer pointers in
> scsi_log_send()
> 
> scsi_log_send() would display buffer pointer for higher
> logging levels. This is not only of questionable value
> but also exposes kernel pointer to userspace, which is
> discouraged in some setups. So drop this message
> altogether.
> 
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>  drivers/scsi/scsi.c | 9 +--------
>  1 file changed, 1 insertion(+), 8 deletions(-)
> 
> diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
> index 92d5912..9ec576d 100644
> --- a/drivers/scsi/scsi.c
> +++ b/drivers/scsi/scsi.c
> @@ -531,7 +531,7 @@ void scsi_log_send(struct scsi_cmnd *cmd)
>  	 *
>  	 * 3: same as 2
>  	 *
> -	 * 4: same as 3 plus dump extra junk
> +	 * 4: same as 3
>  	 */
>  	if (unlikely(scsi_logging_level)) {
>  		level = SCSI_LOG_LEVEL(SCSI_LOG_MLQUEUE_SHIFT,
> @@ -540,13 +540,6 @@ void scsi_log_send(struct scsi_cmnd *cmd)
>  			scmd_printk(KERN_INFO, cmd,
>  				    "Send: scmd 0x%p\n", cmd);
>  			scsi_print_command(cmd);
> -			if (level > 3) {
> -				printk(KERN_INFO "buffer = 0x%p, bufflen =
> %d,"
> -				       " queuecommand 0x%p\n",
> -					scsi_sglist(cmd), scsi_bufflen(cmd),
> -					cmd->device->host->hostt-
> >queuecommand);
> -
> -			}
>  		}
>  	}
>  }

Reviewed-by: Robert Elliott <elliott@hp.com>

One more comment on the series:

After the tags, there are still a few scmd %p prints left
including the one above.  Is this series supposed to get
rid of the rest of them?

drivers/scsi/scsi.c:                                "Send: scmd 0x%p\n", cmd);
drivers/scsi/scsi_error.c:                                  "scmd %p eh timeout, not aborting\n",
drivers/scsi/scsi_error.c:                                  "aborting command %p\n", scmd));
drivers/scsi/scsi_error.c:                                                  "scmd %p eh timeout, "
drivers/scsi/scsi_error.c:                                                  "scmd %p retry "
drivers/scsi/scsi_error.c:                                                  "scmd %p finish "
drivers/scsi/scsi_error.c:                                          "scmd %p abort %s\n", scmd,
drivers/scsi/scsi_error.c:                                  "scmd %p terminate "
drivers/scsi/scsi_error.c:                                  "scmd %p previous abort failed\n", scmd));
drivers/scsi/scsi_error.c:                                  "scmd %p not aborting, host in recovery\n",
drivers/scsi/scsi_error.c:                          "scmd %p abort scheduled\n", scmd));
drivers/scsi/scsi_error.c:                      "%s scmd: %p result: %x\n",
drivers/scsi/scsi_error.c:                      "%s: scmd: %p, timeleft: %ld\n",
drivers/scsi/scsi_error.c:                      "sense requested for %p result %x\n",
drivers/scsi/scsi_error.c:              "%s: scmd %p rtn %x\n", __func__, scmd, rtn));
drivers/scsi/scsi_error.c:                                           "%s: flush retry cmd: %p\n",
drivers/scsi/scsi_error.c:                                           "%s: flush finish cmd: %p\n",
drivers/scsi/scsi_lib.c:                "Inserting command %p into mlqueue\n", cmd));
drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s no slave_alloc function in hostt %p\n", __func__, shost->hostt);
drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "sdev %p scmd %p sending INQUIRY\n", sdev, scsi_cmd);
drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from lookup_by_target\n", __func__, sdev);
drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from alloc_sdev\n", __func__, sdev);
drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from alloc_sdev\n", __func__, sdev);
drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from lookup_by_target\n", __func__, sdev);
drivers/scsi/scsi_scan.c:       printk(KERN_WARNING "%s sdev %p from alloc_sdev\n", __func__, sdev);




^ permalink raw reply	[flat|nested] 24+ messages in thread

* RE: [PATCHv2 00/10] scsi logging update: the real thing
  2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (9 preceding siblings ...)
  2014-11-06  8:30 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
@ 2014-11-14 22:59 ` Elliott, Robert (Server Storage)
  10 siblings, 0 replies; 24+ messages in thread
From: Elliott, Robert (Server Storage) @ 2014-11-14 22:59 UTC (permalink / raw
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org



> -----Original Message-----
> From: Hannes Reinecke [mailto:hare@suse.de]
> Sent: Thursday, 06 November, 2014 2:30 AM
> To: James Bottomley
> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
> linux-scsi@vger.kernel.org; Hannes Reinecke
> Subject: [PATCHv2 00/10] scsi logging update: the real thing
> 
> Hi all,
> 
> this is the second part of my scsi logging update, covering
> CDB and sense code printing. With this patchset CDBs and
> sense code bytes will be formatted on a single line
> (where possible), and prefixed with the device and command
> tag.
> 
> To ensure CDBs and sense code bytes are not broken up during
> printk I've implemented a per-cpu buffer for formatting
> messages. One can allocate a chunk from the buffer using
> scsi_log_reserve_buffer() and return it via
> scsi_log_release_buffer().
> Both function do an implicit preempt_disable() / preempt_enable()
> to ensure we're not scheduled away from that cpu whilst writing
> into the buffer.
> 
> With that I've been able to clean up constants.c to remove all the
> #ifdef CONFIG_SCSI_CONSTANTS statements. It'll now be compiled in
> conditionally if CONFIG_SCSI_CONSTANTS is set.
> 
> Additionally I've updated the SCSI command definitions to SPC-3.
> 
> Thanks go to Stephen Rostedt who suffered my annoying questions
> during LPC.
> 

I've run with v2 for a while.  Tag prints look good;
CDBs are coming out on one line, etc.

I haven't tested every line of every patch, but I think I
exercised patches 3, 5, 7, and 8 pretty thoroughly, so you
may add this to those:

Tested-by: Robert Elliott <elliott@hp.com>

---
Rob Elliott    HP Server Storage




^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [PATCH 02/10] scsi: Add SPC-3 command definitions
  2014-11-12 17:07   ` Elliott, Robert (Server Storage)
@ 2014-11-17  7:56     ` Hannes Reinecke
  0 siblings, 0 replies; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-17  7:56 UTC (permalink / raw
  To: Elliott, Robert (Server Storage), James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org

On 11/12/2014 06:07 PM, Elliott, Robert (Server Storage) wrote:
> 
> 
>> -----Original Message-----
>> From: Hannes Reinecke [mailto:hare@suse.de]
>> Sent: Thursday, 06 November, 2014 2:31 AM
>> To: James Bottomley
>> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
>> linux-scsi@vger.kernel.org; Hannes Reinecke
>> Subject: [PATCH 02/10] scsi: Add SPC-3 command definitions
>>
>> SPC-3 defines SERVICE ACTION IN(12), SERVICE_ACTION OUT(12),
>> SERVICE ACTION OUT(16), and SERVICE ACTION BIDIRECTIONAL.
>> And READ MEDIA SERIAL NUMBER has long since been deprecated.
>> So update callers to refer to the new cdb name.
>>
>> Reviewed-by: Christoph Hellwig <hch@lst.de>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
>> ---
>>  drivers/scsi/constants.c           | 4 ----
>>  drivers/target/target_core_pr.c    | 2 +-
>>  include/scsi/scsi.h                | 6 +++++-
>>  tools/lib/traceevent/plugin_scsi.c | 5 ++++-
>>  4 files changed, 10 insertions(+), 7 deletions(-)
>>
> ...
>> diff --git a/include/scsi/scsi.h b/include/scsi/scsi.h
>> index b354c0d..df00fd1 100644
>> --- a/include/scsi/scsi.h
>> +++ b/include/scsi/scsi.h
>> @@ -128,8 +128,10 @@ enum scsi_timeouts {
>>  #define MOVE_MEDIUM           0xa5
>>  #define EXCHANGE_MEDIUM       0xa6
>>  #define READ_12               0xa8
>> +#define SERVICE_ACTION_OUT_12 0xa9
>>  #define WRITE_12              0xaa
>> -#define READ_MEDIA_SERIAL_NUMBER 0xab
>> +#define READ_MEDIA_SERIAL_NUMBER 0xab /* Obsolete with SPC-2 */
>> +#define SERVICE_ACTION_IN_12 0xab
> 
> That needs one more space before 0xab to line up with the others.
> 
> ...
>> diff --git a/tools/lib/traceevent/plugin_scsi.c
>> b/tools/lib/traceevent/plugin_scsi.c
>> index c699f47..63aba97 100644
>> --- a/tools/lib/traceevent/plugin_scsi.c
>> +++ b/tools/lib/traceevent/plugin_scsi.c
>> @@ -85,8 +85,9 @@ typedef unsigned int u32;
>>  #define MOVE_MEDIUM			0xa5
>>  #define EXCHANGE_MEDIUM			0xa6
>>  #define READ_12				0xa8
>> +#define SERVICE_ACTION_out_12		0xa9
> ...
> 
> out should be capitalized
> 
Fixed in my next round of patches.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 21284 (AG Nürnberg)
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

^ permalink raw reply	[flat|nested] 24+ messages in thread

* Re: [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send()
  2014-11-14 22:53   ` Elliott, Robert (Server Storage)
@ 2014-11-17  9:14     ` Hannes Reinecke
  0 siblings, 0 replies; 24+ messages in thread
From: Hannes Reinecke @ 2014-11-17  9:14 UTC (permalink / raw
  To: Elliott, Robert (Server Storage), James Bottomley
  Cc: Christoph Hellwig, Ewan Milne, linux-scsi@vger.kernel.org

On 11/14/2014 11:53 PM, Elliott, Robert (Server Storage) wrote:
> 
> 
>> -----Original Message-----
>> From: Hannes Reinecke [mailto:hare@suse.de]
>> Sent: Thursday, 06 November, 2014 2:31 AM
>> To: James Bottomley
>> Cc: Christoph Hellwig; Ewan Milne; Elliott, Robert (Server Storage);
>> linux-scsi@vger.kernel.org; Hannes Reinecke
>> Subject: [PATCH 10/10] scsi: Do not display buffer pointers in
>> scsi_log_send()
>>
>> scsi_log_send() would display buffer pointer for higher
>> logging levels. This is not only of questionable value
>> but also exposes kernel pointer to userspace, which is
>> discouraged in some setups. So drop this message
>> altogether.
>>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
>> ---
>>  drivers/scsi/scsi.c | 9 +--------
>>  1 file changed, 1 insertion(+), 8 deletions(-)
>>
>> diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
>> index 92d5912..9ec576d 100644
>> --- a/drivers/scsi/scsi.c
>> +++ b/drivers/scsi/scsi.c
>> @@ -531,7 +531,7 @@ void scsi_log_send(struct scsi_cmnd *cmd)
>>  	 *
>>  	 * 3: same as 2
>>  	 *
>> -	 * 4: same as 3 plus dump extra junk
>> +	 * 4: same as 3
>>  	 */
>>  	if (unlikely(scsi_logging_level)) {
>>  		level = SCSI_LOG_LEVEL(SCSI_LOG_MLQUEUE_SHIFT,
>> @@ -540,13 +540,6 @@ void scsi_log_send(struct scsi_cmnd *cmd)
>>  			scmd_printk(KERN_INFO, cmd,
>>  				    "Send: scmd 0x%p\n", cmd);
>>  			scsi_print_command(cmd);
>> -			if (level > 3) {
>> -				printk(KERN_INFO "buffer = 0x%p, bufflen =
>> %d,"
>> -				       " queuecommand 0x%p\n",
>> -					scsi_sglist(cmd), scsi_bufflen(cmd),
>> -					cmd->device->host->hostt-
>>> queuecommand);
>> -
>> -			}
>>  		}
>>  	}
>>  }
> 
> Reviewed-by: Robert Elliott <elliott@hp.com>
> 
> One more comment on the series:
> 
> After the tags, there are still a few scmd %p prints left
> including the one above.  Is this series supposed to get
> rid of the rest of them?
> 
> drivers/scsi/scsi.c:                                "Send: scmd 0x%p\n", cmd);
> drivers/scsi/scsi_error.c:                                  "scmd %p eh timeout, not aborting\n",
> drivers/scsi/scsi_error.c:                                  "aborting command %p\n", scmd));
> drivers/scsi/scsi_error.c:                                                  "scmd %p eh timeout, "
> drivers/scsi/scsi_error.c:                                                  "scmd %p retry "
> drivers/scsi/scsi_error.c:                                                  "scmd %p finish "
> drivers/scsi/scsi_error.c:                                          "scmd %p abort %s\n", scmd,
> drivers/scsi/scsi_error.c:                                  "scmd %p terminate "
> drivers/scsi/scsi_error.c:                                  "scmd %p previous abort failed\n", scmd));
> drivers/scsi/scsi_error.c:                                  "scmd %p not aborting, host in recovery\n",
> drivers/scsi/scsi_error.c:                          "scmd %p abort scheduled\n", scmd));
> drivers/scsi/scsi_error.c:                      "%s scmd: %p result: %x\n",
> drivers/scsi/scsi_error.c:                      "%s: scmd: %p, timeleft: %ld\n",
> drivers/scsi/scsi_error.c:                      "sense requested for %p result %x\n",
> drivers/scsi/scsi_error.c:              "%s: scmd %p rtn %x\n", __func__, scmd, rtn));
> drivers/scsi/scsi_error.c:                                           "%s: flush retry cmd: %p\n",
> drivers/scsi/scsi_error.c:                                           "%s: flush finish cmd: %p\n",
> drivers/scsi/scsi_lib.c:                "Inserting command %p into mlqueue\n", cmd));
> drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s no slave_alloc function in hostt %p\n", __func__, shost->hostt);
> drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "sdev %p scmd %p sending INQUIRY\n", sdev, scsi_cmd);
> drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from lookup_by_target\n", __func__, sdev);
> drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from alloc_sdev\n", __func__, sdev);
> drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from alloc_sdev\n", __func__, sdev);
> drivers/scsi/scsi_scan.c:               printk(KERN_WARNING "%s sdev %p from lookup_by_target\n", __func__, sdev);
> drivers/scsi/scsi_scan.c:       printk(KERN_WARNING "%s sdev %p from alloc_sdev\n", __func__, sdev);
> 
Ideally, yes. However, for this to work we need an additional means
of identifying the command uniquely.
With the current infrastructure 'tags' are only ever assigned for
devices using the SCSI TCQ mechanism. Everything else is left in the
dark, even though it might be allowing for a queue depths > 1.
So I'll need to revisit this now that the tag rework from Christoph
Hellwig is in.
But I'd rather have this postponed to a next patch series. That
series would also included the proposed 'SUCCESS' to 'COMPLETE' change.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 21284 (AG Nürnberg)
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

^ permalink raw reply	[flat|nested] 24+ messages in thread

end of thread, other threads:[~2014-11-17  9:14 UTC | newest]

Thread overview: 24+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-11-06  8:30 [PATCHv2 00/10] scsi logging update: the real thing Hannes Reinecke
2014-11-06  8:30 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
2014-11-14 16:10   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
2014-11-12 17:07   ` Elliott, Robert (Server Storage)
2014-11-17  7:56     ` Hannes Reinecke
2014-11-06  8:30 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
2014-11-13  2:22   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
2014-11-12 17:18   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
2014-11-13  2:24   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
2014-11-14 16:02   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
2014-11-14 16:52   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
2014-11-14 22:20   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
2014-11-14 22:40   ` Elliott, Robert (Server Storage)
2014-11-06  8:30 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
2014-11-14 22:53   ` Elliott, Robert (Server Storage)
2014-11-17  9:14     ` Hannes Reinecke
2014-11-14 22:59 ` [PATCHv2 00/10] scsi logging update: the real thing Elliott, Robert (Server Storage)

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.