All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCHv3 00/10] scsi logging update: the real thing
@ 2014-11-17 13:25 Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
                   ` (10 more replies)
  0 siblings, 11 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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 v2:
- Include reviews and suggestions from Robert Elliott

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                    |  17 +-
 drivers/ata/libata-scsi.c                  |   2 +-
 drivers/block/nvme-scsi.c                  |   4 +-
 drivers/scsi/Kconfig                       |   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                | 489 +++++++++++++++++++++++++++++
 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                        |  15 +-
 include/scsi/scsi_dbg.h                    |  74 ++++-
 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 +-
 29 files changed, 636 insertions(+), 329 deletions(-)
 create mode 100644 drivers/scsi/scsi_logging.c

-- 
1.8.5.2


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

* [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
                   ` (9 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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.

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
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 c8bb6ab..fc6a60a 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 41b9c68b..4c340d8 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 0cf43f6..52afabd 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 4ebbeae..71e1380 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 b025713..378e0aa 100644
--- a/drivers/scsi/scsi_debug.c
+++ b/drivers/scsi/scsi_debug.c
@@ -4210,7 +4210,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 95bfb7b..f58f965 100644
--- a/drivers/scsi/sd.c
+++ b/drivers/scsi/sd.c
@@ -1982,7 +1982,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] 17+ messages in thread

* [PATCH 02/10] scsi: Add SPC-3 command definitions
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
                   ` (8 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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.

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
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                | 10 +++++++---
 tools/lib/traceevent/plugin_scsi.c |  5 ++++-
 4 files changed, 12 insertions(+), 9 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 52afabd..aee62f6 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..8a7f8ad 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
@@ -165,8 +169,8 @@ enum scsi_timeouts {
 #define MI_REPORT_ALIASES     0x0b
 #define MI_REPORT_SUPPORTED_OPERATION_CODES 0x0c
 #define MI_REPORT_SUPPORTED_TASK_MANAGEMENT_FUNCTIONS 0x0d
-#define MI_REPORT_PRIORITY   0x0e
-#define MI_REPORT_TIMESTAMP  0x0f
+#define MI_REPORT_PRIORITY    0x0e
+#define MI_REPORT_TIMESTAMP   0x0f
 #define MI_MANAGEMENT_PROTOCOL_IN 0x10
 /* value for MI_REPORT_TARGET_PGS ext header */
 #define MI_EXT_HDR_PARAM_FMT  0x20
diff --git a/tools/lib/traceevent/plugin_scsi.c b/tools/lib/traceevent/plugin_scsi.c
index c699f47..3727de4 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] 17+ messages in thread

* [PATCH 03/10] scsi: Implement per-cpu logging buffer
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 19:44   ` Douglas Gilbert
  2014-11-17 13:25 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
                   ` (7 subsequent siblings)
  10 siblings, 1 reply; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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().

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/Makefile       |   2 +-
 drivers/scsi/scsi_logging.c | 124 ++++++++++++++++++++++++++++++++++++++++++++
 include/scsi/scsi_device.h  |  21 +++-----
 3 files changed, 133 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..09d65de
--- /dev/null
+++ b/drivers/scsi/scsi_logging.c
@@ -0,0 +1,124 @@
+/*
+ * 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
+
+#if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG
+#warning SCSI logging bitmask too large
+#endif
+
+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 = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE;
+	unsigned long idx = 0;
+
+	preempt_disable();
+	buf = this_cpu_ptr(&scsi_format_log);
+	idx = find_first_zero_bit(&buf->map, map_bits);
+	if (likely(idx < 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 &&
+	    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(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)
+		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(scmd_printk);
diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h
index 0aeaa00..6fddcd2 100644
--- a/include/scsi/scsi_device.h
+++ b/include/scsi/scsi_device.h
@@ -230,9 +230,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)
 
@@ -240,16 +237,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] 17+ messages in thread

* [PATCH 04/10] scsi: log request tag for scmd_printk()
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (2 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
                   ` (6 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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>
Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
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 09d65de..4d20132 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -114,6 +114,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] 17+ messages in thread

* [PATCH 05/10] scsi: use external buffer for command logging
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (3 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
                   ` (5 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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.

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
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 | 182 ++++++++++++++++++++++++++++++++++++++++----
 drivers/scsi/sr_ioctl.c     |  13 +++-
 include/scsi/scsi.h         |   3 +
 include/scsi/scsi_dbg.h     |   6 +-
 6 files changed, 192 insertions(+), 92 deletions(-)

diff --git a/drivers/scsi/ch.c b/drivers/scsi/ch.c
index 4f502f9..abcc46f 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, sizeof(logbuf), 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 aee62f6..e5daf0e 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 4d20132..afba995 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
 
 #if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG
 #warning SCSI logging bitmask too large
@@ -69,6 +69,24 @@ 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 (WARN_ON(off >= logbuf_len))
+		return off;
+
+	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, ...)
 {
@@ -87,9 +105,11 @@ int sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
 	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);
+	if (!WARN_ON(off >= logbuf_len)) {
+		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;
@@ -111,18 +131,152 @@ 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);
-	va_start(args, fmt);
-	off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
-	va_end(args);
+	off = scmd_format_header(logbuf, logbuf_len, disk,
+				 scmd->request->tag);
+	if (off < logbuf_len) {
+		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(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, "opcode=0x%x", cdb0);
+			if (WARN_ON(off >= buf_len))
+				return off;
+			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,
+					"opcode=0x%x, sa=0x%x", cdb0, sa);
+	}
+	WARN_ON(off >= buf_len);
+	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);
+	if (off >= logbuf_len)
+		return off;
+	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 > logbuf_len - 3)
+			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)
+		return;
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return;
+
+	off = scmd_format_header(logbuf, logbuf_len, disk, cmd->request->tag);
+	if (off >= logbuf_len)
+		goto out_printk;
+	off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");
+	if (WARN_ON(off >= logbuf_len))
+		goto out_printk;
+
+	off += scsi_format_opcode_name(logbuf + off, logbuf_len - off,
+				       cmd->cmnd);
+	if (off >= logbuf_len)
+		goto out_printk;
+
+	/* 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);
+			if (!WARN_ON(off > logbuf_len - 58)) {
+				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);
+		}
+		return;
+	}
+	if (!WARN_ON(off > logbuf_len - 49)) {
+		off += scnprintf(logbuf + off, logbuf_len - off, " ");
+		hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,
+				   logbuf + off, logbuf_len - off,
+				   false);
+	}
+out_printk:
+	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..e8deb9c 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, sizeof(logbuf),
+					      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, sizeof(logbuf),
+					      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 8a7f8ad..d0a66aa 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] 17+ messages in thread

* [PATCH 06/10] libata: use __scsi_format_command()
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (4 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
                   ` (4 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, linux-scsi,
	Hannes Reinecke

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

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
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 | 17 +++++++----------
 1 file changed, 7 insertions(+), 10 deletions(-)

diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index dad83df..0f0460a 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -2481,6 +2481,7 @@ static void ata_eh_link_report(struct ata_link *link)
 		struct ata_queued_cmd *qc = __ata_qc_from_tag(ap, tag);
 		struct ata_taskfile *cmd = &qc->tf, *res = &qc->result_tf;
 		const u8 *cdb = qc->cdb;
+		size_t cdb_len = qc->dev->cdb_len;
 		char data_buf[20] = "";
 		char cdb_buf[70] = "";
 
@@ -2508,16 +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);
-			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]);
+			if (qc->scsicmd) {
+				cdb = qc->scsicmd->cmnd;
+				cdb_len = qc->scsicmd->cmd_len;
+			}
+			__scsi_format_command(cdb_buf, sizeof(cdb_buf),
+					      cdb, cdb_len);
 		} else {
 			const char *descr = ata_get_cmd_descript(cmd->command);
 			if (descr)
-- 
1.8.5.2


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

* [PATCH 07/10] scsi: use per-cpu buffer for formatting sense
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (5 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
                   ` (3 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, linux-scsi,
	Hannes Reinecke

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

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c    | 107 ----------------------------
 drivers/scsi/scsi_logging.c | 166 +++++++++++++++++++++++++++++++++++++++++---
 drivers/scsi/sd.c           |   7 +-
 drivers/scsi/ufs/ufshcd.c   |   6 +-
 4 files changed, 161 insertions(+), 125 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index e5daf0e..657701e 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1217,113 +1217,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 afba995..c7cba31 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -69,14 +69,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 (WARN_ON(off >= logbuf_len))
 		return off;
@@ -119,7 +125,6 @@ EXPORT_SYMBOL(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;
@@ -131,7 +136,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);
 	if (off < logbuf_len) {
 		va_start(args, fmt);
@@ -218,7 +223,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;
@@ -230,7 +234,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);
 	if (off >= logbuf_len)
 		goto out_printk;
 	off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");
@@ -254,7 +259,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);
 			if (!WARN_ON(off > logbuf_len - 58)) {
 				off += scnprintf(logbuf + off, logbuf_len - off,
@@ -280,3 +286,145 @@ out_printk:
 	scsi_log_release_buffer(logbuf);
 }
 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)
+{
+	char *logbuf;
+	size_t logbuf_len;
+	int i;
+
+	logbuf = scsi_log_reserve_buffer(&logbuf_len);
+	if (!logbuf)
+		return;
+
+	for (i = 0; i < sense_len; i += 16) {
+		int len = min(sense_len - i, 16);
+		size_t off;
+
+		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)
+{
+	scsi_log_print_sense(cmd->device, scmd_name(cmd), 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 f58f965..8f1ac2c 100644
--- a/drivers/scsi/sd.c
+++ b/drivers/scsi/sd.c
@@ -3317,11 +3317,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 362b818..3fcaefe 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -4705,10 +4705,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] 17+ messages in thread

* [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result()
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (6 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
                   ` (2 subsequent siblings)
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, linux-scsi,
	Hannes Reinecke

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

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c    | 22 -----------------
 drivers/scsi/scsi.c         |  2 +-
 drivers/scsi/scsi_logging.c | 59 +++++++++++++++++++++++++++++++++++++++++++++
 include/scsi/scsi_dbg.h     |  2 +-
 4 files changed, 61 insertions(+), 24 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 657701e..a391ca9 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1287,25 +1287,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 106fa2f..57fe1e2 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 c7cba31..6128303 100644
--- a/drivers/scsi/scsi_logging.c
+++ b/drivers/scsi/scsi_logging.c
@@ -428,3 +428,62 @@ void scsi_print_sense(const struct scsi_cmnd *cmd)
 			     cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
 }
 EXPORT_SYMBOL(scsi_print_sense);
+
+void scsi_print_result(const 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 (off >= logbuf_len)
+		goto out_printk;
+
+	if (msg) {
+		off += scnprintf(logbuf + off, logbuf_len - off,
+				 "%s: ", msg);
+		if (WARN_ON(off >= logbuf_len))
+			goto out_printk;
+	}
+	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);
+	if (WARN_ON(off >= logbuf_len))
+		goto out_printk;
+
+	off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");
+	if (WARN_ON(off >= logbuf_len))
+		goto out_printk;
+
+	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 (WARN_ON(off >= logbuf_len))
+		goto out_printk;
+
+	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));
+out_printk:
+	dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf);
+	scsi_log_release_buffer(logbuf);
+}
+EXPORT_SYMBOL(scsi_print_result);
diff --git a/include/scsi/scsi_dbg.h b/include/scsi/scsi_dbg.h
index c7ed7b8..365b674 100644
--- a/include/scsi/scsi_dbg.h
+++ b/include/scsi/scsi_dbg.h
@@ -21,7 +21,7 @@ extern void scsi_print_sense(const struct scsi_cmnd *);
 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 void scsi_print_result(const 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);
-- 
1.8.5.2


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

* [PATCH 09/10] scsi: Conditionally compile in constants.c
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (7 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2014-11-17 13:25 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
  2015-01-05 16:59 ` [PATCHv3 00/10] scsi logging update: the real thing Christoph Hellwig
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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.
And update the Kconfig description to reflect the
actual size difference.

Suggested-by: Christoph Hellwig <hch@infradead.org>
Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
Reviewed-by: Robert Elliott <elliott@hp.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/Kconfig       |  4 +--
 drivers/scsi/Makefile      |  4 +--
 drivers/scsi/constants.c   | 42 ----------------------------
 drivers/xen/xen-scsiback.c |  1 +
 include/scsi/scsi_dbg.h    | 68 +++++++++++++++++++++++++++++++++++++++++++---
 5 files changed, 69 insertions(+), 50 deletions(-)

diff --git a/drivers/scsi/Kconfig b/drivers/scsi/Kconfig
index 3a820f6..21bc674 100644
--- a/drivers/scsi/Kconfig
+++ b/drivers/scsi/Kconfig
@@ -201,12 +201,12 @@ config SCSI_ENCLOSURE
 	  certain enclosure conditions to be reported and is not required.
 
 config SCSI_CONSTANTS
-	bool "Verbose SCSI error reporting (kernel size +=12K)"
+	bool "Verbose SCSI error reporting (kernel size +=75K)"
 	depends on SCSI
 	help
 	  The error messages regarding your SCSI hardware will be easier to
 	  understand if you say Y here; it will enlarge your kernel by about
-	  12 KB. If in doubt, say Y.
+	  75 KB. If in doubt, say Y.
 
 config SCSI_LOGGING
 	bool "SCSI logging facility"
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 a391ca9..bef3629 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);
 
@@ -1212,13 +1183,10 @@ scsi_extd_sense_format(unsigned char asc, unsigned char ascq, const char **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",
@@ -1230,17 +1198,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);
@@ -1248,17 +1212,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),
@@ -1271,11 +1232,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;
 
@@ -1283,7 +1242,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 365b674..f8170e9 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(const 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] 17+ messages in thread

* [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send()
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (8 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
@ 2014-11-17 13:25 ` Hannes Reinecke
  2015-01-05 16:59 ` [PATCHv3 00/10] scsi logging update: the real thing Christoph Hellwig
  10 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-17 13:25 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, 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.

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
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 57fe1e2..6761f5f 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] 17+ messages in thread

* Re: [PATCH 03/10] scsi: Implement per-cpu logging buffer
  2014-11-17 13:25 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
@ 2014-11-17 19:44   ` Douglas Gilbert
  2014-11-18 15:25     ` Hannes Reinecke
  0 siblings, 1 reply; 17+ messages in thread
From: Douglas Gilbert @ 2014-11-17 19:44 UTC (permalink / raw)
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, linux-scsi

On 14-11-17 08:25 AM, Hannes Reinecke wrote:
> 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().
>
> Tested-by: Robert Elliott <elliott@hp.com>
> Reviewed-by: Robert Elliott <elliott@hp.com>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> ---
>   drivers/scsi/Makefile       |   2 +-
>   drivers/scsi/scsi_logging.c | 124 ++++++++++++++++++++++++++++++++++++++++++++
>   include/scsi/scsi_device.h  |  21 +++-----
>   3 files changed, 133 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..09d65de
> --- /dev/null
> +++ b/drivers/scsi/scsi_logging.c
> @@ -0,0 +1,124 @@
> +/*
> + * 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
> +
> +#if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG
> +#warning SCSI logging bitmask too large
> +#endif
> +
> +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 = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE;
> +	unsigned long idx = 0;
> +
> +	preempt_disable();
> +	buf = this_cpu_ptr(&scsi_format_log);
> +	idx = find_first_zero_bit(&buf->map, map_bits);
> +	if (likely(idx < 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 &&
> +	    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(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)
> +		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(scmd_printk);
> diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h
> index 0aeaa00..6fddcd2 100644
> --- a/include/scsi/scsi_device.h
> +++ b/include/scsi/scsi_device.h
> @@ -230,9 +230,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)
>
> @@ -240,16 +237,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 {								   \
>

The gcc compiler knows about the idiosyncrasies of printf()
and will warn about abuses like this:
    int k;
    printf("string=%s\n", k);


In sg3_utils I sometimes collapse fprintf(stderr, const char fmt ...)
with a new function declaration like this:
    int pr2serr(const char * fmt, ...)
         __attribute__ ((format (printf, 1, 2)));

The "1" is the position of the fmt string (origin 1) and the
"2" is the position of the first arg to check. That __attribute__
tells the compiler how to do printf() style checking on
pr2serr().


In the kernel include compiler-gcc.h contains this define:

   #define __printf(a, b)   __attribute__((format(printf, a, b)))

So I would suggest changing:
   extern int sdev_prefix_printk(const char *, const struct scsi_device *,
   			        const char *, const char *, ...);
to
   extern __printf(4, 5) int
      sdev_prefix_printk(const char *, const struct scsi_device *,
   			        const char *, const char *, ...);


plus a similar change to the scmd_printk() declaration (and any
other printf() style functions being introduced).

Doug Gilbert


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

* Re: [PATCH 03/10] scsi: Implement per-cpu logging buffer
  2014-11-17 19:44   ` Douglas Gilbert
@ 2014-11-18 15:25     ` Hannes Reinecke
  0 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2014-11-18 15:25 UTC (permalink / raw)
  To: dgilbert, James Bottomley
  Cc: Christoph Hellwig, Robert Elliott, Ewan Milne, linux-scsi

On 11/17/2014 08:44 PM, Douglas Gilbert wrote:
> On 14-11-17 08:25 AM, Hannes Reinecke wrote:
>> 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().
>>
>> Tested-by: Robert Elliott <elliott@hp.com>
>> Reviewed-by: Robert Elliott <elliott@hp.com>
>> Signed-off-by: Hannes Reinecke <hare@suse.de>
>> ---
>>   drivers/scsi/Makefile       |   2 +-
>>   drivers/scsi/scsi_logging.c | 124
>> ++++++++++++++++++++++++++++++++++++++++++++
>>   include/scsi/scsi_device.h  |  21 +++-----
>>   3 files changed, 133 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..09d65de
>> --- /dev/null
>> +++ b/drivers/scsi/scsi_logging.c
>> @@ -0,0 +1,124 @@
>> +/*
>> + * 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
>> +
>> +#if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG
>> +#warning SCSI logging bitmask too large
>> +#endif
>> +
>> +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 = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE;
>> +    unsigned long idx = 0;
>> +
>> +    preempt_disable();
>> +    buf = this_cpu_ptr(&scsi_format_log);
>> +    idx = find_first_zero_bit(&buf->map, map_bits);
>> +    if (likely(idx < 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 &&
>> +        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(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)
>> +        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(scmd_printk);
>> diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h
>> index 0aeaa00..6fddcd2 100644
>> --- a/include/scsi/scsi_device.h
>> +++ b/include/scsi/scsi_device.h
>> @@ -230,9 +230,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)
>>
>> @@ -240,16 +237,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 {                                   \
>>
> 
> The gcc compiler knows about the idiosyncrasies of printf()
> and will warn about abuses like this:
>    int k;
>    printf("string=%s\n", k);
> 
> 
> In sg3_utils I sometimes collapse fprintf(stderr, const char fmt ...)
> with a new function declaration like this:
>    int pr2serr(const char * fmt, ...)
>         __attribute__ ((format (printf, 1, 2)));
> 
> The "1" is the position of the fmt string (origin 1) and the
> "2" is the position of the first arg to check. That __attribute__
> tells the compiler how to do printf() style checking on
> pr2serr().
> 
> 
> In the kernel include compiler-gcc.h contains this define:
> 
>   #define __printf(a, b)   __attribute__((format(printf, a, b)))
> 
> So I would suggest changing:
>   extern int sdev_prefix_printk(const char *, const struct
> scsi_device *,
>                       const char *, const char *, ...);
> to
>   extern __printf(4, 5) int
>      sdev_prefix_printk(const char *, const struct scsi_device *,
>                       const char *, const char *, ...);
> 
> 
> plus a similar change to the scmd_printk() declaration (and any
> other printf() style functions being introduced).
> 
Hmm. I guess you are right. Will be updating the patch.

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] 17+ messages in thread

* Re: [PATCHv3 00/10] scsi logging update: the real thing
  2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
                   ` (9 preceding siblings ...)
  2014-11-17 13:25 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
@ 2015-01-05 16:59 ` Christoph Hellwig
  2015-01-06 18:26   ` Hannes Reinecke
  10 siblings, 1 reply; 17+ messages in thread
From: Christoph Hellwig @ 2015-01-05 16:59 UTC (permalink / raw)
  To: Hannes Reinecke
  Cc: James Bottomley, Christoph Hellwig, Robert Elliott, Ewan Milne,
	linux-scsi

Can you send an updated version against the scsi-for-3.20 tree so that
we can get this series in early for the 3.20 cycle?


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

* Re: [PATCHv3 00/10] scsi logging update: the real thing
  2015-01-05 16:59 ` [PATCHv3 00/10] scsi logging update: the real thing Christoph Hellwig
@ 2015-01-06 18:26   ` Hannes Reinecke
  0 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2015-01-06 18:26 UTC (permalink / raw)
  To: Christoph Hellwig
  Cc: James Bottomley, Christoph Hellwig, Robert Elliott, Ewan Milne,
	linux-scsi

On 01/05/2015 05:59 PM, Christoph Hellwig wrote:
> Can you send an updated version against the scsi-for-3.20 tree so that
> we can get this series in early for the 3.20 cycle?
> 
I'm about to prepare it.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (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] 17+ 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; 17+ 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

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] 17+ messages in thread

* [PATCH 03/10] scsi: Implement per-cpu logging buffer
  2014-11-06  8:30 [PATCHv2 " Hannes Reinecke
@ 2014-11-06  8:30 ` Hannes Reinecke
  2014-11-13  2:22   ` Elliott, Robert (Server Storage)
  0 siblings, 1 reply; 17+ 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] 17+ messages in thread

end of thread, other threads:[~2015-01-06 18:26 UTC | newest]

Thread overview: 17+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-11-17 13:25 [PATCHv3 00/10] scsi logging update: the real thing Hannes Reinecke
2014-11-17 13:25 ` [PATCH 01/10] scsi: Rename SERVICE_ACTION_IN to SERVICE_ACTION_IN_16 Hannes Reinecke
2014-11-17 13:25 ` [PATCH 02/10] scsi: Add SPC-3 command definitions Hannes Reinecke
2014-11-17 13:25 ` [PATCH 03/10] scsi: Implement per-cpu logging buffer Hannes Reinecke
2014-11-17 19:44   ` Douglas Gilbert
2014-11-18 15:25     ` Hannes Reinecke
2014-11-17 13:25 ` [PATCH 04/10] scsi: log request tag for scmd_printk() Hannes Reinecke
2014-11-17 13:25 ` [PATCH 05/10] scsi: use external buffer for command logging Hannes Reinecke
2014-11-17 13:25 ` [PATCH 06/10] libata: use __scsi_format_command() Hannes Reinecke
2014-11-17 13:25 ` [PATCH 07/10] scsi: use per-cpu buffer for formatting sense Hannes Reinecke
2014-11-17 13:25 ` [PATCH 08/10] scsi: use per-cpu buffer for formatting scsi_print_result() Hannes Reinecke
2014-11-17 13:25 ` [PATCH 09/10] scsi: Conditionally compile in constants.c Hannes Reinecke
2014-11-17 13:25 ` [PATCH 10/10] scsi: Do not display buffer pointers in scsi_log_send() Hannes Reinecke
2015-01-05 16:59 ` [PATCHv3 00/10] scsi logging update: the real thing Christoph Hellwig
2015-01-06 18:26   ` Hannes Reinecke
  -- strict thread matches above, loose matches on Subject: below --
2014-11-06  8:30 [PATCHv2 " 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)

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.