linux-scsi.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH 00/10] scsi: avoid linebreaks in syslog output
@ 2012-10-12  8:33 Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 01/10] sg: Use dev_printk Hannes Reinecke
                   ` (11 more replies)
  0 siblings, 12 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke

This patchset updates the SCSI midlayer to use dev_printk() instead
of the simple printk(). The main objective here is to avoid line-breaks
in syslog output; with the current state it's nearly impossible to match
the output to the occurring device; under high load even the CDB will
be split off into individual bytes, spread randomly across the lines.
Which makes debugging via scsi_logging_level _really_ hard.
In addition we'll be getting the syslog messages nicely prefixed with
the device, which will make userspace logging daemons happy.

Before:
[  297.300605] sd 2:0:3:2: Send: 
[  297.300607] 0xffff8802348b0980 
[  297.300610] sd 2:0:3:2: CDB: 
[  297.300615] Test Unit Ready: 00 00 00 00 00 00
[  297.300747] sd 2:0:3:2: Done: 
[  297.300750] 0xffff8802348b0980 SUCCESS
[  297.300753] sd 2:0:3:2:  
[  297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  297.300758] sd 2:0:3:2: CDB: 
[  297.300764] Test Unit Ready: 00 00 00 00 00 00
[  297.300766] sd 2:0:3:2:  
[  297.300769] Sense Key : Unit Attention [current] 
[  297.300771] Info fld=0x0
[  297.300772] sd 2:0:3:2:  
[  297.300776] Add. Sense: Capacity data has changed

After:
[  636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0
[  636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
[  636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS
[  636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
[  636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
[  636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current] 
[  637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed


Hannes Reinecke (10):
  sg: Use dev_printk
  sr: Use dev_printk()
  scsi: Avoid linebreaks in syslog output
  scsi: Use sdev_printk() for logging
  scsi: use buffer for print_opcode_name()
  scsi: use single printk call in scsi_print_command()
  scsi: use buffer for scsi_show_result()
  scsi: open-code scsi_decode_sense_buffer()
  scsi: decode descriptor sense
  scsi: use local buffer for decoding sense data

 drivers/scsi/constants.c  |  406 +++++++++++++++++++++++++--------------------
 drivers/scsi/scsi.c       |   54 ++++---
 drivers/scsi/scsi_error.c |  190 ++++++++++++++-------
 drivers/scsi/scsi_lib.c   |   13 +-
 drivers/scsi/scsi_scan.c  |   68 ++++----
 drivers/scsi/sd.c         |   16 +-
 drivers/scsi/sg.c         |  187 ++++++++++++---------
 drivers/scsi/sr.c         |   47 +++---
 drivers/scsi/sr.h         |    4 +
 include/scsi/scsi_dbg.h   |    6 +-
 include/scsi/scsi_eh.h    |    8 +-
 11 files changed, 588 insertions(+), 411 deletions(-)

-- 
1.7.4.2


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

* [PATCH 01/10] sg: Use dev_printk
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12 14:34   ` Douglas Gilbert
  2012-10-12  8:33 ` [PATCH 02/10] sr: Use dev_printk() Hannes Reinecke
                   ` (10 subsequent siblings)
  11 siblings, 1 reply; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers, Doug Gilbert

Every sg device has a reference to the underlying scsi device, so
this patch adds dev_printk() macros to have the messages prefixed
with the correct device.

Before:
[772330.437378] sg_open: dev=2, flags=0x8800
[772330.475425] sg_add_sfp: sfp=0xffff880429d3e000

After:
[  409.399888] sr 2:0:0:0: [sg2] sg_open: flags=0x8800
[  409.446029] sr 2:0:0:0: [sg2] sg_add_sfp: sfp=0xffff880425856000

Cc: Kay Sievers <kay@vrfy.org>
Cc: Doug Gilbert <dgilbert@interlog.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/sg.c |  187 +++++++++++++++++++++++++++++++----------------------
 1 files changed, 109 insertions(+), 78 deletions(-)

diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c
index 9c5c5f2..2e6056f 100644
--- a/drivers/scsi/sg.c
+++ b/drivers/scsi/sg.c
@@ -101,6 +101,13 @@ static int scatter_elem_sz_prev = SG_SCATTER_SZ;
 
 #define SG_SECTOR_SZ 512
 
+#define sgdev_printk(prefix, sgdev, fmt, a...)	\
+	dev_printk(prefix, &(sgdev)->device->sdev_gendev, "[%s] " fmt, \
+		   (sgdev)->disk->disk_name, ##a)
+
+#define sgfp_printk(prefix, sgfp, fmt, a...)				\
+	sgdev_printk(prefix, (sgfp)->parentdp, fmt, ##a)
+
 static int sg_add(struct device *, struct class_interface *);
 static void sg_remove(struct device *, struct class_interface *);
 
@@ -196,7 +203,7 @@ static ssize_t sg_new_write(Sg_fd *sfp, struct file *file,
 static int sg_common_write(Sg_fd * sfp, Sg_request * srp,
 			   unsigned char *cmnd, int timeout, int blocking);
 static int sg_read_oxfer(Sg_request * srp, char __user *outp, int num_read_xfer);
-static void sg_remove_scat(Sg_scatter_hold * schp);
+static void sg_remove_scat(Sg_scatter_hold * schp, Sg_fd * sfp);
 static void sg_build_reserve(Sg_fd * sfp, int req_size);
 static void sg_link_reserve(Sg_fd * sfp, Sg_request * srp, int size);
 static void sg_unlink_reserve(Sg_fd * sfp, Sg_request * srp);
@@ -268,13 +275,14 @@ sg_open(struct inode *inode, struct file *filp)
 	int retval;
 
 	nonseekable_open(inode, filp);
-	SCSI_LOG_TIMEOUT(3, printk("sg_open: dev=%d, flags=0x%x\n", dev, flags));
 	sdp = sg_get_dev(dev);
 	if (IS_ERR(sdp)) {
 		retval = PTR_ERR(sdp);
 		sdp = NULL;
 		goto sg_put;
 	}
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp,
+					 "sg_open: flags=0x%x\n", flags));
 
 	/* This driver's module count bumped by fops_get in <linux/fs.h> */
 	/* Prevent the device driver from vanishing while we sleep */
@@ -360,7 +368,7 @@ sg_release(struct inode *inode, struct file *filp)
 
 	if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))
 		return -ENXIO;
-	SCSI_LOG_TIMEOUT(3, printk("sg_release: %s\n", sdp->disk->disk_name));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_release"));
 
 	set_exclude(sdp, 0);
 	wake_up_interruptible(&sdp->o_excl_wait);
@@ -383,8 +391,8 @@ sg_read(struct file *filp, char __user *buf, size_t count, loff_t * ppos)
 
 	if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))
 		return -ENXIO;
-	SCSI_LOG_TIMEOUT(3, printk("sg_read: %s, count=%d\n",
-				   sdp->disk->disk_name, (int) count));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_read: count=%d",
+					 (int) count));
 
 	if (!access_ok(VERIFY_WRITE, buf, count))
 		return -EFAULT;
@@ -569,8 +577,8 @@ sg_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 
 	if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))
 		return -ENXIO;
-	SCSI_LOG_TIMEOUT(3, printk("sg_write: %s, count=%d\n",
-				   sdp->disk->disk_name, (int) count));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_write: count=%d",
+					 (int) count));
 	if (sdp->detached)
 		return -ENODEV;
 	if (!((filp->f_flags & O_NONBLOCK) ||
@@ -591,14 +599,17 @@ sg_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 		return -EIO;	/* The minimum scsi command length is 6 bytes. */
 
 	if (!(srp = sg_add_request(sfp))) {
-		SCSI_LOG_TIMEOUT(1, printk("sg_write: queue full\n"));
+		SCSI_LOG_TIMEOUT(1, sgdev_printk(KERN_INFO, sdp,
+						 "sg_write: queue full"));
 		return -EDOM;
 	}
 	buf += SZ_SG_HEADER;
 	__get_user(opcode, buf);
 	if (sfp->next_cmd_len > 0) {
 		if (sfp->next_cmd_len > MAX_COMMAND_SIZE) {
-			SCSI_LOG_TIMEOUT(1, printk("sg_write: command length too long\n"));
+			SCSI_LOG_TIMEOUT(1, sgdev_printk(KERN_INFO, sdp,
+							 "sg_write: command "
+							 "length too long\n"));
 			sfp->next_cmd_len = 0;
 			sg_remove_request(sfp, srp);
 			return -EIO;
@@ -610,7 +621,7 @@ sg_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 		if ((opcode >= 0xc0) && old_hdr.twelve_byte)
 			cmd_size = 12;
 	}
-	SCSI_LOG_TIMEOUT(4, printk(
+	SCSI_LOG_TIMEOUT(4, sgdev_printk(KERN_INFO, sdp,
 		"sg_write:   scsi opcode=0x%02x, cmd_size=%d\n", (int) opcode, cmd_size));
 /* Determine buffer size.  */
 	input_size = count - cmd_size;
@@ -685,7 +696,8 @@ sg_new_write(Sg_fd *sfp, struct file *file, const char __user *buf,
 
 	sfp->cmd_q = 1;	/* when sg_io_hdr seen, set command queuing on */
 	if (!(srp = sg_add_request(sfp))) {
-		SCSI_LOG_TIMEOUT(1, printk("sg_new_write: queue full\n"));
+		SCSI_LOG_TIMEOUT(1, sgfp_printk(KERN_INFO, sfp,
+						"sg_new_write: queue full\n"));
 		return -EDOM;
 	}
 	srp->sg_io_owned = sg_io_owned;
@@ -754,12 +766,14 @@ sg_common_write(Sg_fd * sfp, Sg_request * srp,
 	hp->host_status = 0;
 	hp->driver_status = 0;
 	hp->resid = 0;
-	SCSI_LOG_TIMEOUT(4, printk("sg_common_write:  scsi opcode=0x%02x, cmd_size=%d\n",
-			  (int) cmnd[0], (int) hp->cmd_len));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+			"sg_common_write:  scsi opcode=0x%02x, cmd_size=%d\n",
+			(int) cmnd[0], (int) hp->cmd_len));
 
 	k = sg_start_req(srp, cmnd);
 	if (k) {
-		SCSI_LOG_TIMEOUT(1, printk("sg_common_write: start_req err=%d\n", k));
+		SCSI_LOG_TIMEOUT(1, sgfp_printk(KERN_INFO, sfp,
+				"sg_common_write: start_req err=%d\n", k));
 		sg_finish_rem_req(srp);
 		return k;	/* probably out of space --> ENOMEM */
 	}
@@ -819,8 +833,8 @@ sg_ioctl(struct file *filp, unsigned int cmd_in, unsigned long arg)
 	if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))
 		return -ENXIO;
 
-	SCSI_LOG_TIMEOUT(3, printk("sg_ioctl: %s, cmd=0x%x\n",
-				   sdp->disk->disk_name, (int) cmd_in));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_ioctl: cmd=0x%x\n",
+				   (int) cmd_in));
 	read_only = (O_RDWR != (filp->f_flags & O_ACCMODE));
 
 	switch (cmd_in) {
@@ -872,7 +886,7 @@ sg_ioctl(struct file *filp, unsigned int cmd_in, unsigned long arg)
 			sfp->low_dma = 1;
 			if ((0 == sfp->low_dma) && (0 == sg_res_in_use(sfp))) {
 				val = (int) sfp->reserve.bufflen;
-				sg_remove_scat(&sfp->reserve);
+				sg_remove_scat(&sfp->reserve, sfp);
 				sg_build_reserve(sfp, val);
 			}
 		} else {
@@ -948,7 +962,7 @@ sg_ioctl(struct file *filp, unsigned int cmd_in, unsigned long arg)
 		if (val != sfp->reserve.bufflen) {
 			if (sg_res_in_use(sfp) || sfp->mmap_called)
 				return -EBUSY;
-			sg_remove_scat(&sfp->reserve);
+			sg_remove_scat(&sfp->reserve, sfp);
 			sg_build_reserve(sfp, val);
 		}
 		return 0;
@@ -1171,8 +1185,8 @@ sg_poll(struct file *filp, poll_table * wait)
 			res |= POLLOUT | POLLWRNORM;
 	} else if (count < SG_MAX_QUEUE)
 		res |= POLLOUT | POLLWRNORM;
-	SCSI_LOG_TIMEOUT(3, printk("sg_poll: %s, res=0x%x\n",
-				   sdp->disk->disk_name, (int) res));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_poll: res=0x%x\n",
+				   (int) res));
 	return res;
 }
 
@@ -1184,8 +1198,8 @@ sg_fasync(int fd, struct file *filp, int mode)
 
 	if ((!(sfp = (Sg_fd *) filp->private_data)) || (!(sdp = sfp->parentdp)))
 		return -ENXIO;
-	SCSI_LOG_TIMEOUT(3, printk("sg_fasync: %s, mode=%d\n",
-				   sdp->disk->disk_name, mode));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_fasync: mode=%d",
+					 mode));
 
 	return fasync_helper(fd, filp, mode, &sfp->async_qp);
 }
@@ -1204,8 +1218,9 @@ sg_vma_fault(struct vm_area_struct *vma, struct vm_fault *vmf)
 	offset = vmf->pgoff << PAGE_SHIFT;
 	if (offset >= rsv_schp->bufflen)
 		return VM_FAULT_SIGBUS;
-	SCSI_LOG_TIMEOUT(3, printk("sg_vma_fault: offset=%lu, scatg=%d\n",
-				   offset, rsv_schp->k_use_sg));
+	SCSI_LOG_TIMEOUT(3, sgfp_printk(KERN_INFO, sfp,
+				"sg_vma_fault: offset=%lu, scatg=%d\n",
+				offset, rsv_schp->k_use_sg));
 	sa = vma->vm_start;
 	length = 1 << (PAGE_SHIFT + rsv_schp->page_order);
 	for (k = 0; k < rsv_schp->k_use_sg && sa < vma->vm_end; k++) {
@@ -1240,8 +1255,9 @@ sg_mmap(struct file *filp, struct vm_area_struct *vma)
 	if ((!filp) || (!vma) || (!(sfp = (Sg_fd *) filp->private_data)))
 		return -ENXIO;
 	req_sz = vma->vm_end - vma->vm_start;
-	SCSI_LOG_TIMEOUT(3, printk("sg_mmap starting, vm_start=%p, len=%d\n",
-				   (void *) vma->vm_start, (int) req_sz));
+	SCSI_LOG_TIMEOUT(3, sgfp_printk(KERN_INFO, sfp,
+				"sg_mmap starting, vm_start=%p, len=%d\n",
+				(void *) vma->vm_start, (int) req_sz));
 	if (vma->vm_pgoff)
 		return -EINVAL;	/* want no offset */
 	rsv_schp = &sfp->reserve;
@@ -1295,14 +1311,15 @@ static void sg_rq_end_io(struct request *rq, int uptodate)
 
 	sdp = sfp->parentdp;
 	if (unlikely(sdp->detached))
-		printk(KERN_INFO "sg_rq_end_io: device detached\n");
+		sgdev_printk(KERN_INFO, sdp, "sg_rq_end_io: device detached");
 
 	sense = rq->sense;
 	result = rq->errors;
 	resid = rq->resid_len;
 
-	SCSI_LOG_TIMEOUT(4, printk("sg_cmd_done: %s, pack_id=%d, res=0x%x\n",
-		sdp->disk->disk_name, srp->header.pack_id, result));
+	SCSI_LOG_TIMEOUT(4, sgdev_printk(KERN_INFO, sdp,
+		"sg_cmd_done: pack_id=%d, res=0x%x",
+		srp->header.pack_id, result));
 	srp->header.resid = resid;
 	ms = jiffies_to_msecs(jiffies);
 	srp->header.duration = (ms > srp->header.duration) ?
@@ -1387,12 +1404,14 @@ static Sg_device *sg_alloc(struct gendisk *disk, struct scsi_device *scsidp)
 
 	sdp = kzalloc(sizeof(Sg_device), GFP_KERNEL);
 	if (!sdp) {
-		printk(KERN_WARNING "kmalloc Sg_device failure\n");
+		sdev_printk(KERN_WARNING, scsidp,
+			   "kmalloc Sg_device failure");
 		return ERR_PTR(-ENOMEM);
 	}
 
 	if (!idr_pre_get(&sg_index_idr, GFP_KERNEL)) {
-		printk(KERN_WARNING "idr expansion Sg_device failure\n");
+		sdev_printk(KERN_WARNING, scsidp,
+			   "idr expansion Sg_device failure");
 		error = -ENOMEM;
 		goto out;
 	}
@@ -1402,19 +1421,20 @@ static Sg_device *sg_alloc(struct gendisk *disk, struct scsi_device *scsidp)
 	error = idr_get_new(&sg_index_idr, sdp, &k);
 	if (error) {
 		write_unlock_irqrestore(&sg_index_lock, iflags);
-		printk(KERN_WARNING "idr allocation Sg_device failure: %d\n",
-		       error);
+		sdev_printk(KERN_WARNING, scsidp,
+			   "idr allocation Sg_device failure: %d\n",
+			   error);
 		goto out;
 	}
 
 	if (unlikely(k >= SG_MAX_DEVS))
 		goto overflow;
 
-	SCSI_LOG_TIMEOUT(3, printk("sg_alloc: dev=%d \n", k));
 	sprintf(disk->disk_name, "sg%d", k);
 	disk->first_minor = k;
 	sdp->disk = disk;
 	sdp->device = scsidp;
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_alloc"));
 	INIT_LIST_HEAD(&sdp->sfds);
 	init_waitqueue_head(&sdp->o_excl_wait);
 	sdp->sg_tablesize = queue_max_segments(q);
@@ -1453,7 +1473,7 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf)
 
 	disk = alloc_disk(1);
 	if (!disk) {
-		printk(KERN_WARNING "alloc_disk failed\n");
+		sdev_printk(KERN_WARNING, scsidp, "alloc_disk failed");
 		return -ENOMEM;
 	}
 	disk->major = SCSI_GENERIC_MAJOR;
@@ -1461,7 +1481,7 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf)
 	error = -ENOMEM;
 	cdev = cdev_alloc();
 	if (!cdev) {
-		printk(KERN_WARNING "cdev_alloc failed\n");
+		sdev_printk(KERN_WARNING, scsidp, "cdev_alloc failed");
 		goto out;
 	}
 	cdev->owner = THIS_MODULE;
@@ -1469,7 +1489,7 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf)
 
 	sdp = sg_alloc(disk, scsidp);
 	if (IS_ERR(sdp)) {
-		printk(KERN_WARNING "sg_alloc failed\n");
+		sdev_printk(KERN_WARNING, scsidp, "sg_alloc failed");
 		error = PTR_ERR(sdp);
 		goto out;
 	}
@@ -1487,18 +1507,19 @@ sg_add(struct device *cl_dev, struct class_interface *cl_intf)
 						      sdp->index),
 						sdp, "%s", disk->disk_name);
 		if (IS_ERR(sg_class_member)) {
-			printk(KERN_ERR "sg_add: "
-			       "device_create failed\n");
+			sdev_printk(KERN_ERR, scsidp, "sg_add: "
+				     "device_create failed");
 			error = PTR_ERR(sg_class_member);
 			goto cdev_add_err;
 		}
 		error = sysfs_create_link(&scsidp->sdev_gendev.kobj,
 					  &sg_class_member->kobj, "generic");
 		if (error)
-			printk(KERN_ERR "sg_add: unable to make symlink "
-					"'generic' back to sg%d\n", sdp->index);
+			sdev_printk(KERN_ERR, scsidp,
+				    "sg_add: unable to make symlink "
+				    "'generic' back to sg%d", sdp->index);
 	} else
-		printk(KERN_WARNING "sg_add: sg_sys Invalid\n");
+		sdev_printk(KERN_WARNING, scsidp, "sg_add: sg_sys Invalid\n");
 
 	sdev_printk(KERN_NOTICE, scsidp,
 		    "Attached scsi generic sg%d type %d\n", sdp->index,
@@ -1535,9 +1556,7 @@ static void sg_device_destroy(struct kref *kref)
 	idr_remove(&sg_index_idr, sdp->index);
 	write_unlock_irqrestore(&sg_index_lock, flags);
 
-	SCSI_LOG_TIMEOUT(3,
-		printk("sg_device_destroy: %s\n",
-			sdp->disk->disk_name));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_device_destroy"));
 
 	put_disk(sdp->disk);
 	kfree(sdp);
@@ -1553,7 +1572,7 @@ static void sg_remove(struct device *cl_dev, struct class_interface *cl_intf)
 	if (!sdp || sdp->detached)
 		return;
 
-	SCSI_LOG_TIMEOUT(3, printk("sg_remove: %s\n", sdp->disk->disk_name));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp, "sg_remove"));
 
 	/* Need a write lock to set sdp->detached. */
 	write_lock_irqsave(&sg_index_lock, iflags);
@@ -1654,8 +1673,9 @@ static int sg_start_req(Sg_request *srp, unsigned char *cmd)
 	struct rq_map_data *md, map_data;
 	int rw = hp->dxfer_direction == SG_DXFER_TO_DEV ? WRITE : READ;
 
-	SCSI_LOG_TIMEOUT(4, printk(KERN_INFO "sg_start_req: dxfer_len=%d\n",
-				   dxfer_len));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+					"sg_start_req: dxfer_len=%d",
+					dxfer_len));
 
 	rq = blk_get_request(q, rw, GFP_ATOMIC);
 	if (!rq)
@@ -1742,7 +1762,9 @@ static int sg_finish_rem_req(Sg_request * srp)
 	Sg_fd *sfp = srp->parentfp;
 	Sg_scatter_hold *req_schp = &srp->data;
 
-	SCSI_LOG_TIMEOUT(4, printk("sg_finish_rem_req: res_used=%d\n", (int) srp->res_used));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+					"sg_finish_rem_req: res_used=%d",
+					(int) srp->res_used));
 	if (srp->rq) {
 		if (srp->bio)
 			ret = blk_rq_unmap_user(srp->bio);
@@ -1753,7 +1775,7 @@ static int sg_finish_rem_req(Sg_request * srp)
 	if (srp->res_used)
 		sg_unlink_reserve(sfp, srp);
 	else
-		sg_remove_scat(req_schp);
+		sg_remove_scat(req_schp, sfp);
 
 	sg_remove_request(sfp, srp);
 
@@ -1787,8 +1809,9 @@ sg_build_indirect(Sg_scatter_hold * schp, Sg_fd * sfp, int buff_size)
 		++blk_size;	/* don't know why */
 	/* round request up to next highest SG_SECTOR_SZ byte boundary */
 	blk_size = ALIGN(blk_size, SG_SECTOR_SZ);
-	SCSI_LOG_TIMEOUT(4, printk("sg_build_indirect: buff_size=%d, blk_size=%d\n",
-				   buff_size, blk_size));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp, "sg_build_indirect: "
+					"buff_size=%d, blk_size=%d",
+					buff_size, blk_size));
 
 	/* N.B. ret_sz carried into this block ... */
 	mx_sc_elems = sg_build_sgat(schp, sfp, sg_tablesize);
@@ -1831,14 +1854,16 @@ retry:
 			}
 		}
 
-		SCSI_LOG_TIMEOUT(5, printk("sg_build_indirect: k=%d, num=%d, "
-				 "ret_sz=%d\n", k, num, ret_sz));
+		SCSI_LOG_TIMEOUT(5, sgfp_printk(KERN_INFO, sfp,
+				"sg_build_indirect: k=%d, num=%d, "
+				"ret_sz=%d", k, num, ret_sz));
 	}		/* end of for loop */
 
 	schp->page_order = order;
 	schp->k_use_sg = k;
-	SCSI_LOG_TIMEOUT(5, printk("sg_build_indirect: k_use_sg=%d, "
-			 "rem_sz=%d\n", k, rem_sz));
+	SCSI_LOG_TIMEOUT(5, sgfp_printk(KERN_INFO, sfp,
+			"sg_build_indirect: k_use_sg=%d, "
+			 "rem_sz=%d", k, rem_sz));
 
 	schp->bufflen = blk_size;
 	if (rem_sz > 0)	/* must have failed */
@@ -1855,16 +1880,17 @@ out:
 }
 
 static void
-sg_remove_scat(Sg_scatter_hold * schp)
+sg_remove_scat(Sg_scatter_hold * schp, Sg_fd * sfp)
 {
-	SCSI_LOG_TIMEOUT(4, printk("sg_remove_scat: k_use_sg=%d\n", schp->k_use_sg));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+		"sg_remove_scat: k_use_sg=%d", schp->k_use_sg));
 	if (schp->pages && schp->sglist_len > 0) {
 		if (!schp->dio_in_use) {
 			int k;
 
 			for (k = 0; k < schp->k_use_sg && schp->pages[k]; k++) {
-				SCSI_LOG_TIMEOUT(5, printk(
-				    "sg_remove_scat: k=%d, pg=0x%p\n",
+				SCSI_LOG_TIMEOUT(5, sgfp_printk(KERN_INFO, sfp,
+				    "sg_remove_scat: k=%d, pg=0x%p",
 				    k, schp->pages[k]));
 				__free_pages(schp->pages[k], schp->page_order);
 			}
@@ -1881,8 +1907,8 @@ sg_read_oxfer(Sg_request * srp, char __user *outp, int num_read_xfer)
 	Sg_scatter_hold *schp = &srp->data;
 	int k, num;
 
-	SCSI_LOG_TIMEOUT(4, printk("sg_read_oxfer: num_read_xfer=%d\n",
-				   num_read_xfer));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, srp->parentfp,
+		"sg_read_oxfer: num_read_xfer=%d", num_read_xfer));
 	if ((!outp) || (num_read_xfer <= 0))
 		return 0;
 
@@ -1912,14 +1938,15 @@ sg_build_reserve(Sg_fd * sfp, int req_size)
 {
 	Sg_scatter_hold *schp = &sfp->reserve;
 
-	SCSI_LOG_TIMEOUT(4, printk("sg_build_reserve: req_size=%d\n", req_size));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+		"sg_build_reserve: req_size=%d", req_size));
 	do {
 		if (req_size < PAGE_SIZE)
 			req_size = PAGE_SIZE;
 		if (0 == sg_build_indirect(schp, sfp, req_size))
 			return;
 		else
-			sg_remove_scat(schp);
+			sg_remove_scat(schp, sfp);
 		req_size >>= 1;	/* divide by 2 */
 	} while (req_size > (PAGE_SIZE / 2));
 }
@@ -1932,7 +1959,8 @@ sg_link_reserve(Sg_fd * sfp, Sg_request * srp, int size)
 	int k, num, rem;
 
 	srp->res_used = 1;
-	SCSI_LOG_TIMEOUT(4, printk("sg_link_reserve: size=%d\n", size));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+		"sg_link_reserve: size=%d", size));
 	rem = size;
 
 	num = 1 << (PAGE_SHIFT + rsv_schp->page_order);
@@ -1950,7 +1978,8 @@ sg_link_reserve(Sg_fd * sfp, Sg_request * srp, int size)
 	}
 
 	if (k >= rsv_schp->k_use_sg)
-		SCSI_LOG_TIMEOUT(1, printk("sg_link_reserve: BAD size\n"));
+		SCSI_LOG_TIMEOUT(1, sgfp_printk(KERN_INFO, sfp,
+			"sg_link_reserve: BAD size"));
 }
 
 static void
@@ -1958,8 +1987,9 @@ sg_unlink_reserve(Sg_fd * sfp, Sg_request * srp)
 {
 	Sg_scatter_hold *req_schp = &srp->data;
 
-	SCSI_LOG_TIMEOUT(4, printk("sg_unlink_reserve: req->k_use_sg=%d\n",
-				   (int) req_schp->k_use_sg));
+	SCSI_LOG_TIMEOUT(4, sgfp_printk(KERN_INFO, sfp,
+		"sg_unlink_reserve: req->k_use_sg=%d",
+		(int) req_schp->k_use_sg));
 	req_schp->k_use_sg = 0;
 	req_schp->bufflen = 0;
 	req_schp->pages = NULL;
@@ -2089,15 +2119,17 @@ sg_add_sfp(Sg_device * sdp, int dev)
 	write_lock_irqsave(&sg_index_lock, iflags);
 	list_add_tail(&sfp->sfd_siblings, &sdp->sfds);
 	write_unlock_irqrestore(&sg_index_lock, iflags);
-	SCSI_LOG_TIMEOUT(3, printk("sg_add_sfp: sfp=0x%p\n", sfp));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp,
+		"sg_add_sfp: sfp=0x%p", sfp));
 	if (unlikely(sg_big_buff != def_reserved_size))
 		sg_big_buff = def_reserved_size;
 
 	bufflen = min_t(int, sg_big_buff,
 			queue_max_sectors(sdp->device->request_queue) * 512);
 	sg_build_reserve(sfp, bufflen);
-	SCSI_LOG_TIMEOUT(3, printk("sg_add_sfp:   bufflen=%d, k_use_sg=%d\n",
-			   sfp->reserve.bufflen, sfp->reserve.k_use_sg));
+	SCSI_LOG_TIMEOUT(3, sgdev_printk(KERN_INFO, sdp,
+		"sg_add_sfp:   bufflen=%d, k_use_sg=%d",
+		sfp->reserve.bufflen, sfp->reserve.k_use_sg));
 
 	kref_get(&sdp->d_ref);
 	__module_get(THIS_MODULE);
@@ -2115,16 +2147,15 @@ static void sg_remove_sfp_usercontext(struct work_struct *work)
 
 	if (sfp->reserve.bufflen > 0) {
 		SCSI_LOG_TIMEOUT(6,
-			printk("sg_remove_sfp:    bufflen=%d, k_use_sg=%d\n",
-				(int) sfp->reserve.bufflen,
-				(int) sfp->reserve.k_use_sg));
-		sg_remove_scat(&sfp->reserve);
+			sgdev_printk(KERN_INFO, sdp,
+				     "sg_remove_sfp:   bufflen=%d, k_use_sg=%d",
+				     (int) sfp->reserve.bufflen,
+				     (int) sfp->reserve.k_use_sg));
+		sg_remove_scat(&sfp->reserve, sfp);
 	}
 
 	SCSI_LOG_TIMEOUT(6,
-		printk("sg_remove_sfp: %s, sfp=0x%p\n",
-			sdp->disk->disk_name,
-			sfp));
+		sgdev_printk(KERN_INFO, sdp, "sg_remove_sfp: sfp=0x%p", sfp));
 	kfree(sfp);
 
 	scsi_device_put(sdp->device);
-- 
1.7.4.2


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

* [PATCH 02/10] sr: Use dev_printk()
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 01/10] sg: Use dev_printk Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 03/10] scsi: Avoid linebreaks in syslog output Hannes Reinecke
                   ` (9 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers, Jens Axboe

Convert sr to use dev_printk() to avoid linebreaks in kernel
messages.

Cc: Kay Sievers <kay@vrfy.org>
Cc: Jens Axboe <axboe@kernel.dk>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/sr.c |   47 ++++++++++++++++++++++++++---------------------
 drivers/scsi/sr.h |    4 ++++
 2 files changed, 30 insertions(+), 21 deletions(-)

diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c
index 5fc97d2..26404ca 100644
--- a/drivers/scsi/sr.c
+++ b/drivers/scsi/sr.c
@@ -276,8 +276,8 @@ do_tur:
 	if (!cd->tur_changed) {
 		if (cd->get_event_changed) {
 			if (cd->tur_mismatch++ > 8) {
-				sdev_printk(KERN_WARNING, cd->device,
-					    "GET_EVENT and TUR disagree continuously, suppress GET_EVENT events\n");
+				sr_printk(KERN_WARNING, cd,
+					  "GET_EVENT and TUR disagree continuously, suppress GET_EVENT events\n");
 				cd->ignore_get_event = true;
 			}
 		} else {
@@ -306,7 +306,7 @@ static int sr_done(struct scsi_cmnd *SCpnt)
 	struct scsi_cd *cd = scsi_cd(SCpnt->request->rq_disk);
 
 #ifdef DEBUG
-	printk("sr.c done: %x\n", result);
+	sr_printk(KERN_INFO, cd, "sr.c done: %x\n", result);
 #endif
 
 	/*
@@ -389,13 +389,16 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)
 	 * is used for a killable error condition */
 	ret = BLKPREP_KILL;
 
-	SCSI_LOG_HLQUEUE(1, printk("Doing sr request, dev = %s, block = %d\n",
-				cd->disk->disk_name, block));
+	SCSI_LOG_HLQUEUE(1,
+		scmd_printk(KERN_INFO, SCpnt,
+			    "Doing sr request, block = %d\n", block));
 
 	if (!cd->device || !scsi_device_online(cd->device)) {
-		SCSI_LOG_HLQUEUE(2, printk("Finishing %u sectors\n",
-					   blk_rq_sectors(rq)));
-		SCSI_LOG_HLQUEUE(2, printk("Retry with 0x%p\n", SCpnt));
+		SCSI_LOG_HLQUEUE(2, scmd_printk(KERN_INFO, SCpnt,
+						"Finishing %u sectors\n",
+					      blk_rq_sectors(rq)));
+		SCSI_LOG_HLQUEUE(2, scmd_printk(KERN_INFO, SCpnt,
+						"Retry with 0x%p\n", SCpnt));
 		goto out;
 	}
 
@@ -416,7 +419,8 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)
 		if (!in_interrupt())
 			sr_set_blocklength(cd, 2048);
 		else
-			printk("sr: can't switch blocksize: in interrupt\n");
+			scmd_printk(KERN_INFO, SCpnt,
+				  "sr: can't switch blocksize: in interrupt\n");
 	}
 
 	if (s_size != 512 && s_size != 1024 && s_size != 2048) {
@@ -429,7 +433,7 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)
 			goto out;
 		SCpnt->cmnd[0] = WRITE_10;
 		SCpnt->sc_data_direction = DMA_TO_DEVICE;
- 	 	cd->cdi.media_written = 1;
+		cd->cdi.media_written = 1;
 	} else if (rq_data_dir(rq) == READ) {
 		SCpnt->cmnd[0] = READ_10;
 		SCpnt->sc_data_direction = DMA_FROM_DEVICE;
@@ -447,8 +451,8 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)
 
 		if (size != scsi_bufflen(SCpnt)) {
 			scmd_printk(KERN_ERR, SCpnt,
-				"mismatch count %d, bytes %d\n",
-				size, scsi_bufflen(SCpnt));
+				    "mismatch count %d, bytes %d\n",
+				    size, scsi_bufflen(SCpnt));
 			if (scsi_bufflen(SCpnt) > size)
 				SCpnt->sdb.length = size;
 		}
@@ -466,11 +470,11 @@ static int sr_prep_fn(struct request_queue *q, struct request *rq)
 	this_count = (scsi_bufflen(SCpnt) >> 9) / (s_size >> 9);
 
 
-	SCSI_LOG_HLQUEUE(2, printk("%s : %s %d/%u 512 byte blocks.\n",
-				cd->cdi.name,
-				(rq_data_dir(rq) == WRITE) ?
-					"writing" : "reading",
-				this_count, blk_rq_sectors(rq)));
+	SCSI_LOG_HLQUEUE(2, sr_printk(KERN_INFO, cd,
+				      "%s %d/%u 512 byte blocks.\n",
+				      (rq_data_dir(rq) == WRITE) ?
+				      "writing" : "reading",
+				      this_count, blk_rq_sectors(rq)));
 
 	SCpnt->cmnd[1] = 0;
 	block = (unsigned int)blk_rq_pos(rq) / (s_size >> 9);
@@ -790,8 +794,9 @@ static void get_sectorsize(struct scsi_cd *cd)
 		case 512:
 			break;
 		default:
-			printk("%s: unsupported sector size %d.\n",
-			       cd->cdi.name, sector_size);
+			sr_printk(KERN_INFO, cd,
+				  "unsupported sector size %d.\n",
+				  sector_size);
 			cd->capacity = 0;
 		}
 
@@ -852,7 +857,7 @@ static void get_capabilities(struct scsi_cd *cd)
 				 CDC_SELECT_DISC | CDC_SELECT_SPEED |
 				 CDC_MRW | CDC_MRW_W | CDC_RAM);
 		kfree(buffer);
-		printk("%s: scsi-1 drive\n", cd->cdi.name);
+		sr_printk(KERN_INFO, cd, "scsi-1 drive");
 		return;
 	}
 
@@ -861,7 +866,7 @@ static void get_capabilities(struct scsi_cd *cd)
 	cd->readcd_known = 1;
 	cd->readcd_cdda = buffer[n + 5] & 0x01;
 	/* print some capability bits */
-	printk("%s: scsi3-mmc drive: %dx/%dx %s%s%s%s%s%s\n", cd->cdi.name,
+	sr_printk(KERN_INFO, cd, "scsi3-mmc drive: %dx/%dx %s%s%s%s%s%s",
 	       ((buffer[n + 14] << 8) + buffer[n + 15]) / 176,
 	       cd->cdi.speed,
 	       buffer[n + 3] & 0x01 ? "writer " : "", /* CD Writer */
diff --git a/drivers/scsi/sr.h b/drivers/scsi/sr.h
index 37c8f6b..1610cac 100644
--- a/drivers/scsi/sr.h
+++ b/drivers/scsi/sr.h
@@ -55,6 +55,10 @@ typedef struct scsi_cd {
 	struct gendisk *disk;
 } Scsi_CD;
 
+#define sr_printk(prefix, scd, fmt, a...)				\
+	sdev_printk(prefix, (scd)->device, "[%s] " fmt,		\
+		    (scd)->cdi.name, ##a)
+
 int sr_do_ioctl(Scsi_CD *, struct packet_command *);
 
 int sr_lock_door(struct cdrom_device_info *, int);
-- 
1.7.4.2


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

* [PATCH 03/10] scsi: Avoid linebreaks in syslog output
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 01/10] sg: Use dev_printk Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 02/10] sr: Use dev_printk() Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 04/10] scsi: Use sdev_printk() for logging Hannes Reinecke
                   ` (8 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

sdev_printk() is adding a linebreak automatically, causing the
syslog output to be garbled:
[  542.494393] sr 2:0:0:0: Send:
[  542.494394] 0xffff8804291e5dc0
which will make debuggging painful.
So reshuffle sdev_printk invokation to have it printed on
the same line.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi.c |   38 ++++++++++++++++++++++----------------
 1 files changed, 22 insertions(+), 16 deletions(-)

diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index 2936b44..28b294b 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -551,14 +551,15 @@ void scsi_log_send(struct scsi_cmnd *cmd)
 		level = SCSI_LOG_LEVEL(SCSI_LOG_MLQUEUE_SHIFT,
 				       SCSI_LOG_MLQUEUE_BITS);
 		if (level > 1) {
-			scmd_printk(KERN_INFO, cmd, "Send: ");
 			if (level > 2)
-				printk("0x%p ", cmd);
-			printk("\n");
+				scmd_printk(KERN_INFO, cmd, "Send: 0x%p", cmd);
+			else
+				scmd_printk(KERN_INFO, cmd, "Send:");
 			scsi_print_command(cmd);
 			if (level > 3) {
-				printk(KERN_INFO "buffer = 0x%p, bufflen = %d,"
-				       " queuecommand 0x%p\n",
+				scmd_printk(KERN_INFO, cmd,
+				       "buffer = 0x%p, bufflen = %d,"
+				       " queuecommand 0x%p",
 					scsi_sglist(cmd), scsi_bufflen(cmd),
 					cmd->device->host->hostt->queuecommand);
 
@@ -588,42 +589,47 @@ void scsi_log_completion(struct scsi_cmnd *cmd, int disposition)
 				       SCSI_LOG_MLCOMPLETE_BITS);
 		if (((level > 0) && (cmd->result || disposition != SUCCESS)) ||
 		    (level > 1)) {
-			scmd_printk(KERN_INFO, cmd, "Done: ");
-			if (level > 2)
-				printk("0x%p ", cmd);
+			const char *disp_str;
+
 			/*
 			 * Dump truncated values, so we usually fit within
 			 * 80 chars.
 			 */
 			switch (disposition) {
 			case SUCCESS:
-				printk("SUCCESS\n");
+				disp_str = "SUCCESS";
 				break;
 			case NEEDS_RETRY:
-				printk("RETRY\n");
+				disp_str = "RETRY";
 				break;
 			case ADD_TO_MLQUEUE:
-				printk("MLQUEUE\n");
+				disp_str = "MLQUEUE";
 				break;
 			case FAILED:
-				printk("FAILED\n");
+				disp_str = "FAILED";
 				break;
 			case TIMEOUT_ERROR:
-				/* 
+				/*
 				 * If called via scsi_times_out.
 				 */
-				printk("TIMEOUT\n");
+				disp_str = "TIMEOUT";
 				break;
 			default:
-				printk("UNKNOWN\n");
+				disp_str = "UNKNOWN";
 			}
+			if (level > 2)
+				scmd_printk(KERN_INFO, cmd, "Done: 0x%p %s",
+					    cmd, disp_str);
+			else
+				scmd_printk(KERN_INFO, cmd, "Done: %s",
+					    disp_str);
 			scsi_print_result(cmd);
 			scsi_print_command(cmd);
 			if (status_byte(cmd->result) & CHECK_CONDITION)
 				scsi_print_sense("", cmd);
 			if (level > 3)
 				scmd_printk(KERN_INFO, cmd,
-					    "scsi host busy %d failed %d\n",
+					    "scsi host busy %d failed %d",
 					    cmd->device->host->host_busy,
 					    cmd->device->host->host_failed);
 		}
-- 
1.7.4.2


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

* [PATCH 04/10] scsi: Use sdev_printk() for logging
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (2 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 03/10] scsi: Avoid linebreaks in syslog output Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 05/10] scsi: use buffer for print_opcode_name() Hannes Reinecke
                   ` (7 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

Most scsi logging messages are using a plain printk, making it
hard to relate to the originating device.
This patchs moves the scsi logging messages to use sdev_printk()
and friends.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi.c       |   16 +++--
 drivers/scsi/scsi_error.c |  147 ++++++++++++++++++++++++++-------------------
 drivers/scsi/scsi_lib.c   |   13 +++--
 drivers/scsi/scsi_scan.c  |   68 +++++++++++----------
 4 files changed, 139 insertions(+), 105 deletions(-)

diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index 28b294b..5797f61 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -691,7 +691,8 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 
 		scsi_queue_insert(cmd, SCSI_MLQUEUE_DEVICE_BUSY);
 
-		SCSI_LOG_MLQUEUE(3, printk("queuecommand : device blocked \n"));
+		SCSI_LOG_MLQUEUE(3, scmd_printk(KERN_INFO, cmd,
+			"queuecommand : device blocked"));
 
 		/*
 		 * NOTE: rtn is still zero here because we don't need the
@@ -739,8 +740,9 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 	 */
 	if (cmd->cmd_len > cmd->device->host->max_cmd_len) {
 		SCSI_LOG_MLQUEUE(3,
-			printk("queuecommand : command too long. "
-			       "cdb_size=%d host->max_cmd_len=%d\n",
+			       scmd_printk(KERN_INFO, cmd,
+			       "queuecommand : command too long. "
+			       "cdb_size=%d host->max_cmd_len=%d",
 			       cmd->cmd_len, cmd->device->host->max_cmd_len));
 		cmd->result = (DID_ABORT << 16);
 
@@ -766,11 +768,13 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 		scsi_queue_insert(cmd, rtn);
 
 		SCSI_LOG_MLQUEUE(3,
-		    printk("queuecommand : request rejected\n"));
+			scmd_printk(KERN_INFO, cmd,
+				    "queuecommand : request rejected"));
 	}
 
  out:
-	SCSI_LOG_MLQUEUE(3, printk("leaving scsi_dispatch_cmnd()\n"));
+	SCSI_LOG_MLQUEUE(3, scmd_printk(KERN_INFO, cmd,
+					"leaving scsi_dispatch_cmnd()"));
 	return rtn;
 }
 
@@ -830,7 +834,7 @@ void scsi_finish_command(struct scsi_cmnd *cmd)
 	if (SCSI_SENSE_VALID(cmd))
 		cmd->result |= (DRIVER_SENSE << 24);
 
-	SCSI_LOG_MLCOMPLETE(4, sdev_printk(KERN_INFO, sdev,
+	SCSI_LOG_MLCOMPLETE(4, scmd_printk(KERN_INFO, cmd,
 				"Notifying upper driver of completion "
 				"(result %x)\n", cmd->result));
 
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index c1b05a8..f8d51c5 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -62,7 +62,8 @@ void scsi_eh_wakeup(struct Scsi_Host *shost)
 		trace_scsi_eh_wakeup(shost);
 		wake_up_process(shost->ehandler);
 		SCSI_LOG_ERROR_RECOVERY(5,
-				printk("Waking error handler thread\n"));
+			shost_printk(KERN_INFO, shost,
+				     "Waking error handler thread"));
 	}
 }
 
@@ -172,8 +173,9 @@ int scsi_block_when_processing_errors(struct scsi_device *sdev)
 
 	online = scsi_device_online(sdev);
 
-	SCSI_LOG_ERROR_RECOVERY(5, printk("%s: rtn: %d\n", __func__,
-					  online));
+	SCSI_LOG_ERROR_RECOVERY(5, sdev_printk(KERN_INFO, sdev,
+					       "%s: rtn: %d", __func__,
+					       online));
 
 	return online;
 }
@@ -218,7 +220,8 @@ static inline void scsi_eh_prt_fail_stats(struct Scsi_Host *shost,
 		}
 	}
 
-	SCSI_LOG_ERROR_RECOVERY(2, printk("Total of %d commands on %d"
+	SCSI_LOG_ERROR_RECOVERY(2, shost_printk(KERN_INFO, shost,
+					  "Total of %d commands on %d"
 					  " devices require eh work\n",
 				   total_failures, devices_failed));
 }
@@ -527,7 +530,8 @@ static void scsi_eh_done(struct scsi_cmnd *scmd)
 	struct completion *eh_action;
 
 	SCSI_LOG_ERROR_RECOVERY(3,
-		printk("%s scmd: %p result: %x\n",
+			scmd_printk(KERN_INFO, scmd,
+			"%s scmd: %p result: %x\n",
 			__func__, scmd, scmd->result));
 
 	eh_action = scmd->device->host->eh_action;
@@ -546,7 +550,8 @@ static int scsi_try_host_reset(struct scsi_cmnd *scmd)
 	struct Scsi_Host *host = scmd->device->host;
 	struct scsi_host_template *hostt = host->hostt;
 
-	SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Snd Host RST\n",
+	SCSI_LOG_ERROR_RECOVERY(3, sdev_printk(KERN_INFO, scmd->device,
+					  "%s: Snd Host RST\n",
 					  __func__));
 
 	if (!hostt->eh_host_reset_handler)
@@ -576,8 +581,8 @@ static int scsi_try_bus_reset(struct scsi_cmnd *scmd)
 	struct Scsi_Host *host = scmd->device->host;
 	struct scsi_host_template *hostt = host->hostt;
 
-	SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Snd Bus RST\n",
-					  __func__));
+	SCSI_LOG_ERROR_RECOVERY(3, sdev_printk(KERN_INFO, scmd->device,
+					       "%s: Snd Bus RST\n", __func__));
 
 	if (!hostt->eh_bus_reset_handler)
 		return FAILED;
@@ -809,7 +814,8 @@ static int scsi_send_eh_cmnd(struct scsi_cmnd *scmd, unsigned char *cmnd,
 	scsi_log_completion(scmd, SUCCESS);
 
 	SCSI_LOG_ERROR_RECOVERY(3,
-		printk("%s: scmd: %p, timeleft: %ld\n",
+			sdev_printk(KERN_INFO, scmd->device,
+			"%s: scmd: %p, timeleft: %ld",
 			__func__, scmd, timeleft));
 
 	/*
@@ -821,8 +827,9 @@ static int scsi_send_eh_cmnd(struct scsi_cmnd *scmd, unsigned char *cmnd,
 	if (timeleft) {
 		rtn = scsi_eh_completed_normally(scmd);
 		SCSI_LOG_ERROR_RECOVERY(3,
-			printk("%s: scsi_eh_completed_normally %x\n",
-			       __func__, rtn));
+				sdev_printk(KERN_INFO, scmd->device,
+				"%s: scsi_eh_completed_normally %x",
+				__func__, rtn));
 
 		switch (rtn) {
 		case SUCCESS:
@@ -925,7 +932,8 @@ int scsi_eh_get_sense(struct list_head *work_q,
 		if (rtn != SUCCESS)
 			continue;
 
-		SCSI_LOG_ERROR_RECOVERY(3, printk("sense requested for %p"
+		SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+						  "sense requested for %p"
 						  " result %x\n", scmd,
 						  scmd->result));
 		SCSI_LOG_ERROR_RECOVERY(3, scsi_print_sense("bh", scmd));
@@ -967,8 +975,8 @@ static int scsi_eh_tur(struct scsi_cmnd *scmd)
 retry_tur:
 	rtn = scsi_send_eh_cmnd(scmd, tur_command, 6, SENSE_TIMEOUT, 0);
 
-	SCSI_LOG_ERROR_RECOVERY(3, printk("%s: scmd %p rtn %x\n",
-		__func__, scmd, rtn));
+	SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+		"%s: scmd %p rtn %x", __func__, scmd, rtn));
 
 	switch (rtn) {
 	case NEEDS_RETRY:
@@ -1046,7 +1054,8 @@ static int scsi_eh_abort_cmds(struct list_head *work_q,
 	list_for_each_entry_safe(scmd, next, work_q, eh_entry) {
 		if (!(scmd->eh_eflags & SCSI_EH_CANCEL_CMD))
 			continue;
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: aborting cmd:"
+		SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+						  "%s: aborting cmd:"
 						  "0x%p\n", current->comm,
 						  scmd));
 		rtn = scsi_try_to_abort_cmd(scmd->device->host->hostt, scmd);
@@ -1057,7 +1066,8 @@ static int scsi_eh_abort_cmds(struct list_head *work_q,
 			else
 				list_move_tail(&scmd->eh_entry, &check_list);
 		} else
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: aborting"
+			SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+							  "%s: aborting"
 							  " cmd failed:"
 							  "0x%p\n",
 							  current->comm,
@@ -1120,8 +1130,10 @@ static int scsi_eh_stu(struct Scsi_Host *shost,
 		if (!stu_scmd)
 			continue;
 
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Sending START_UNIT to sdev:"
-						  " 0x%p\n", current->comm, sdev));
+		SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+						"%s: Sending START_UNIT to"
+						" sdev: 0x%p\n",
+						current->comm, sdev));
 
 		if (!scsi_eh_try_stu(stu_scmd)) {
 			if (!scsi_device_online(sdev) ||
@@ -1134,8 +1146,9 @@ static int scsi_eh_stu(struct Scsi_Host *shost,
 			}
 		} else {
 			SCSI_LOG_ERROR_RECOVERY(3,
-						printk("%s: START_UNIT failed to sdev:"
-						       " 0x%p\n", current->comm, sdev));
+				scmd_printk(KERN_INFO, scmd,
+					    "%s: START_UNIT failed to sdev:"
+					    " 0x%p\n", current->comm, sdev));
 		}
 	}
 
@@ -1174,7 +1187,8 @@ static int scsi_eh_bus_device_reset(struct Scsi_Host *shost,
 		if (!bdr_scmd)
 			continue;
 
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Sending BDR sdev:"
+		SCSI_LOG_ERROR_RECOVERY(3, sdev_printk(KERN_INFO, sdev,
+						  "%s: Sending BDR sdev:"
 						  " 0x%p\n", current->comm,
 						  sdev));
 		rtn = scsi_try_bus_device_reset(bdr_scmd);
@@ -1190,7 +1204,8 @@ static int scsi_eh_bus_device_reset(struct Scsi_Host *shost,
 				}
 			}
 		} else {
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: BDR"
+			SCSI_LOG_ERROR_RECOVERY(3, sdev_printk(KERN_INFO, sdev,
+							  "%s: BDR"
 							  " failed sdev:"
 							  "0x%p\n",
 							  current->comm,
@@ -1227,15 +1242,15 @@ static int scsi_eh_target_reset(struct Scsi_Host *shost,
 		scmd = list_entry(tmp_list.next, struct scsi_cmnd, eh_entry);
 		id = scmd_id(scmd);
 
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Sending target reset "
-						  "to target %d\n",
-						  current->comm, id));
+		SCSI_LOG_ERROR_RECOVERY(3, sdev_printk(KERN_INFO, scmd->device,
+						  "%s: Sending target reset",
+						  current->comm));
 		rtn = scsi_try_target_reset(scmd);
 		if (rtn != SUCCESS && rtn != FAST_IO_FAIL)
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Target reset"
-							  " failed target: "
-							  "%d\n",
-							  current->comm, id));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				sdev_printk(KERN_INFO, scmd->device,
+					    "%s: Target reset failed",
+					    current->comm));
 		list_for_each_entry_safe(scmd, next, &tmp_list, eh_entry) {
 			if (scmd_id(scmd) != id)
 				continue;
@@ -1290,9 +1305,9 @@ static int scsi_eh_bus_reset(struct Scsi_Host *shost,
 
 		if (!chan_scmd)
 			continue;
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Sending BRST chan:"
-						  " %d\n", current->comm,
-						  channel));
+		SCSI_LOG_ERROR_RECOVERY(3,
+			sdev_printk(KERN_INFO, chan_scmd->device,
+				    "%s: Sending BRST", current->comm));
 		rtn = scsi_try_bus_reset(chan_scmd);
 		if (rtn == SUCCESS || rtn == FAST_IO_FAIL) {
 			list_for_each_entry_safe(scmd, next, work_q, eh_entry) {
@@ -1306,10 +1321,9 @@ static int scsi_eh_bus_reset(struct Scsi_Host *shost,
 				}
 			}
 		} else {
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: BRST"
-							  " failed chan: %d\n",
-							  current->comm,
-							  channel));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				sdev_printk(KERN_INFO, chan_scmd->device,
+					    "%s: BRST failed", current->comm));
 		}
 	}
 	return scsi_eh_test_devices(&check_list, work_q, done_q, 0);
@@ -1331,8 +1345,9 @@ static int scsi_eh_host_reset(struct list_head *work_q,
 		scmd = list_entry(work_q->next,
 				  struct scsi_cmnd, eh_entry);
 
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: Sending HRST\n"
-						  , current->comm));
+		SCSI_LOG_ERROR_RECOVERY(3, sdev_printk(KERN_INFO, scmd->device,
+						       "%s: Sending HRST",
+						       current->comm));
 
 		rtn = scsi_try_host_reset(scmd);
 		if (rtn == SUCCESS) {
@@ -1342,9 +1357,10 @@ static int scsi_eh_host_reset(struct list_head *work_q,
 					scsi_eh_finish_cmd(scmd, done_q);
 			}
 		} else {
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: HRST"
-							  " failed\n",
-							  current->comm));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				sdev_printk(KERN_INFO, scmd->device,
+					    "%s: HRST failed",
+					    current->comm));
 		}
 	}
 	return scsi_eh_test_devices(&check_list, work_q, done_q, 1);
@@ -1433,7 +1449,8 @@ int scsi_decide_disposition(struct scsi_cmnd *scmd)
 	 * up to the top level.
 	 */
 	if (!scsi_device_online(scmd->device)) {
-		SCSI_LOG_ERROR_RECOVERY(5, printk("%s: device offline - report"
+		SCSI_LOG_ERROR_RECOVERY(5, sdev_printk(KERN_INFO, scmd->device,
+						  "%s: device offline - report"
 						  " as SUCCESS\n",
 						  __func__));
 		return SUCCESS;
@@ -1681,8 +1698,9 @@ static void scsi_restart_operations(struct Scsi_Host *shost)
 	 * will be requests for character device operations, and also for
 	 * ioctls to queued block devices.
 	 */
-	SCSI_LOG_ERROR_RECOVERY(3, printk("%s: waking up host to restart\n",
-					  __func__));
+	SCSI_LOG_ERROR_RECOVERY(3, shost_printk(KERN_INFO, shost,
+					"%s: waking up host to restart",
+					__func__));
 
 	spin_lock_irqsave(shost->host_lock, flags);
 	if (scsi_host_set_state(shost, SHOST_RUNNING))
@@ -1748,10 +1766,10 @@ void scsi_eh_flush_done_q(struct list_head *done_q)
 		if (scsi_device_online(scmd->device) &&
 		    !scsi_noretry_cmd(scmd) &&
 		    (++scmd->retries <= scmd->allowed)) {
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: flush"
-							  " retry cmd: %p\n",
-							  current->comm,
-							  scmd));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				scmd_printk(KERN_INFO, scmd,
+					    "%s: flush retry cmd: %p\n",
+					    current->comm, scmd));
 				scsi_queue_insert(scmd, SCSI_MLQUEUE_EH_RETRY);
 		} else {
 			/*
@@ -1761,9 +1779,10 @@ void scsi_eh_flush_done_q(struct list_head *done_q)
 			 */
 			if (!scmd->result)
 				scmd->result |= (DRIVER_TIMEOUT << 24);
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: flush finish"
-							" cmd: %p\n",
-							current->comm, scmd));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				scmd_printk(KERN_INFO, scmd,
+					    "%s: flush finish cmd: %p\n",
+					    current->comm, scmd));
 			scsi_finish_command(scmd);
 		}
 	}
@@ -1835,16 +1854,18 @@ int scsi_error_handler(void *data)
 		if ((shost->host_failed == 0 && shost->host_eh_scheduled == 0) ||
 		    shost->host_failed != shost->host_busy) {
 			SCSI_LOG_ERROR_RECOVERY(1,
-				printk("Error handler scsi_eh_%d sleeping\n",
-					shost->host_no));
+				shost_printk(KERN_INFO, shost,
+					     "Error handler scsi_eh_%d"
+					     " sleeping", shost->host_no));
 			schedule();
 			continue;
 		}
 
 		__set_current_state(TASK_RUNNING);
 		SCSI_LOG_ERROR_RECOVERY(1,
-			printk("Error handler scsi_eh_%d waking up\n",
-				shost->host_no));
+			shost_printk(KERN_INFO, shost,
+				     "Error handler scsi_eh_%d waking up",
+				     shost->host_no));
 
 		/*
 		 * We have a host that is failing for some reason.  Figure out
@@ -1853,9 +1874,10 @@ int scsi_error_handler(void *data)
 		 */
 		if (!shost->eh_noresume && scsi_autopm_get_host(shost) != 0) {
 			SCSI_LOG_ERROR_RECOVERY(1,
-				printk(KERN_ERR "Error handler scsi_eh_%d "
-						"unable to autoresume\n",
-						shost->host_no));
+				shost_printk(KERN_ERR, shost,
+					     "Error handler scsi_eh_%d "
+					     "unable to autoresume\n",
+					     shost->host_no));
 			continue;
 		}
 
@@ -1878,7 +1900,9 @@ int scsi_error_handler(void *data)
 	__set_current_state(TASK_RUNNING);
 
 	SCSI_LOG_ERROR_RECOVERY(1,
-		printk("Error handler scsi_eh_%d exiting\n", shost->host_no));
+		shost_printk(KERN_INFO, shost,
+			     "Error handler scsi_eh_%d exiting",
+			     shost->host_no));
 	shost->ehandler = NULL;
 	return 0;
 }
@@ -2028,8 +2052,9 @@ scsi_reset_provider(struct scsi_device *dev, int flag)
 	 * suspended while we performed the TMF.
 	 */
 	SCSI_LOG_ERROR_RECOVERY(3,
-		printk("%s: waking up host to restart after TMF\n",
-		__func__));
+		shost_printk(KERN_INFO, shost,
+			     "%s: waking up host to restart after TMF",
+			     __func__));
 
 	wake_up(&shost->host_wait);
 
diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index da36a3a..a8dbbb1 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -135,7 +135,8 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, int unbusy)
 	unsigned long flags;
 
 	SCSI_LOG_MLQUEUE(1,
-		 printk("Inserting command %p into mlqueue\n", cmd));
+		scmd_printk(KERN_INFO, cmd,
+			    "Inserting command %p into mlqueue", cmd));
 
 	/*
 	 * Set the appropriate busy bit for the device/host.
@@ -820,8 +821,8 @@ void scsi_io_completion(struct scsi_cmnd *cmd, unsigned int good_bytes)
 	 * Next deal with any sectors which we were able to correctly
 	 * handle.
 	 */
-	SCSI_LOG_HLCOMPLETE(1, printk("%u sectors total, "
-				      "%d bytes done.\n",
+	SCSI_LOG_HLCOMPLETE(1, scmd_printk(KERN_INFO, cmd,
+				      "%u sectors total, %d bytes done.",
 				      blk_rq_sectors(req), good_bytes));
 
 	/*
@@ -1370,7 +1371,8 @@ static inline int scsi_host_queue_ready(struct request_queue *q,
 		 */
 		if (--shost->host_blocked == 0) {
 			SCSI_LOG_MLQUEUE(3,
-				printk("scsi%d unblocking host at zero depth\n",
+				sdev_printk(KERN_INFO, sdev,
+					"scsi%d unblocking host at zero depth",
 					shost->host_no));
 		} else {
 			return 0;
@@ -1555,7 +1557,8 @@ static void scsi_request_fn(struct request_queue *q)
 		spin_unlock(q->queue_lock);
 		cmd = req->special;
 		if (unlikely(cmd == NULL)) {
-			printk(KERN_CRIT "impossible request in %s.\n"
+			sdev_printk(KERN_CRIT, sdev,
+					 "impossible request in %s.\n"
 					 "please mail a stack trace to "
 					 "linux-scsi@vger.kernel.org\n",
 					 __func__);
diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
index 3e58b22..cbf36e1 100644
--- a/drivers/scsi/scsi_scan.c
+++ b/drivers/scsi/scsi_scan.c
@@ -198,7 +198,7 @@ static void scsi_unlock_floptical(struct scsi_device *sdev,
 {
 	unsigned char scsi_cmd[MAX_COMMAND_SIZE];
 
-	printk(KERN_NOTICE "scsi: unlocking floptical drive\n");
+	sdev_printk(KERN_NOTICE, sdev, "scsi: unlocking floptical drive");
 	scsi_cmd[0] = MODE_SENSE;
 	scsi_cmd[1] = 0;
 	scsi_cmd[2] = 0x2e;
@@ -396,7 +396,8 @@ static struct scsi_target *scsi_alloc_target(struct device *parent,
 
 	starget = kzalloc(size, GFP_KERNEL);
 	if (!starget) {
-		printk(KERN_ERR "%s: allocation failure\n", __func__);
+		shost_printk(KERN_ERR, shost,
+			   "%s: allocation failure", __func__);
 		return NULL;
 	}
 	dev = &starget->dev;
@@ -576,8 +577,8 @@ static int scsi_probe_lun(struct scsi_device *sdev, unsigned char *inq_result,
 					  HZ / 2 + HZ * scsi_inq_timeout, 3,
 					  &resid);
 
-		SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: INQUIRY %s "
-				"with code 0x%x\n",
+		SCSI_LOG_SCAN_BUS(3, sdev_printk(KERN_INFO, sdev,
+				"scsi scan: INQUIRY %s with code 0x%x\n",
 				result ? "failed" : "successful", result));
 
 		if (result) {
@@ -647,7 +648,8 @@ static int scsi_probe_lun(struct scsi_device *sdev, unsigned char *inq_result,
 		}
 
 	} else if (pass == 2) {
-		printk(KERN_INFO "scsi scan: %d byte inquiry failed.  "
+		sdev_printk(KERN_INFO, sdev,
+				"scsi scan: %d byte inquiry failed.  "
 				"Consider BLIST_INQUIRY_36 for this device\n",
 				try_inquiry_len);
 
@@ -682,7 +684,8 @@ static int scsi_probe_lun(struct scsi_device *sdev, unsigned char *inq_result,
 	 * strings.
 	 */
 	if (sdev->inquiry_len < 36) {
-		printk(KERN_INFO "scsi scan: INQUIRY result too short (%d),"
+		sdev_printk(KERN_INFO, sdev,
+				"scsi scan: INQUIRY result too short (%d),"
 				" using 36\n", sdev->inquiry_len);
 		sdev->inquiry_len = 36;
 	}
@@ -802,7 +805,8 @@ static int scsi_add_lun(struct scsi_device *sdev, unsigned char *inq_result,
 		sdev->writeable = 0;
 		break;
 	default:
-		printk(KERN_INFO "scsi: unknown device type %d\n", sdev->type);
+		sdev_printk(KERN_INFO, sdev, "unknown device type %d",
+			    sdev->type);
 	}
 
 	if (sdev->type == TYPE_RBC || sdev->type == TYPE_ROM) {
@@ -1016,7 +1020,7 @@ static int scsi_probe_and_add_lun(struct scsi_target *starget,
 	sdev = scsi_device_lookup_by_target(starget, lun);
 	if (sdev) {
 		if (rescan || !scsi_device_created(sdev)) {
-			SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO
+			SCSI_LOG_SCAN_BUS(3, sdev_printk(KERN_INFO, sdev,
 				"scsi scan: device exists on %s\n",
 				dev_name(&sdev->sdev_gendev)));
 			if (sdevp)
@@ -1103,9 +1107,9 @@ static int scsi_probe_and_add_lun(struct scsi_target *starget,
 	if (((result[0] >> 5) == 1 || starget->pdt_1f_for_no_lun) &&
 	    (result[0] & 0x1f) == 0x1f &&
 	    !scsi_is_wlun(lun)) {
-		SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO
+		SCSI_LOG_SCAN_BUS(3, sdev_printk(KERN_INFO, sdev,
 					"scsi scan: peripheral device type"
-					" of 31, no device added\n"));
+					" of 31, no device added"));
 		res = SCSI_SCAN_TARGET_PRESENT;
 		goto out_free_result;
 	}
@@ -1156,8 +1160,8 @@ static void scsi_sequential_lun_scan(struct scsi_target *starget,
 	unsigned int sparse_lun, lun, max_dev_lun;
 	struct Scsi_Host *shost = dev_to_shost(starget->dev.parent);
 
-	SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: Sequential scan of"
-				    "%s\n", dev_name(&starget->dev)));
+	SCSI_LOG_SCAN_BUS(3, dev_printk(KERN_INFO, &(starget->dev),
+					"scsi scan: Sequential scan"));
 
 	max_dev_lun = min(max_scsi_luns, shost->max_lun);
 	/*
@@ -1365,7 +1369,7 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
 	lun_data = kmalloc(length, GFP_ATOMIC |
 			   (sdev->host->unchecked_isa_dma ? __GFP_DMA : 0));
 	if (!lun_data) {
-		printk(ALLOC_FAILURE_MSG, __func__);
+		sdev_printk(KERN_INFO, sdev, ALLOC_FAILURE_MSG, __func__);
 		goto out;
 	}
 
@@ -1398,16 +1402,17 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
 	 * a retry.
 	 */
 	for (retries = 0; retries < 3; retries++) {
-		SCSI_LOG_SCAN_BUS(3, printk (KERN_INFO "scsi scan: Sending"
-				" REPORT LUNS to %s (try %d)\n", devname,
+		SCSI_LOG_SCAN_BUS(3, sdev_printk(KERN_INFO, sdev,
+				"scsi scan: Sending REPORT LUNS (try %d)",
 				retries));
 
 		result = scsi_execute_req(sdev, scsi_cmd, DMA_FROM_DEVICE,
 					  lun_data, length, &sshdr,
 					  SCSI_TIMEOUT + 4 * HZ, 3, NULL);
 
-		SCSI_LOG_SCAN_BUS(3, printk (KERN_INFO "scsi scan: REPORT LUNS"
-				" %s (try %d) result 0x%x\n", result
+		SCSI_LOG_SCAN_BUS(3, sdev_printk(KERN_INFO, sdev,
+				"scsi scan: REPORT LUNS"
+				" %s (try %d) result 0x%x", result
 				?  "failed" : "successful", retries, result));
 		if (result == 0)
 			break;
@@ -1434,9 +1439,10 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
 
 	num_luns = (length / sizeof(struct scsi_lun));
 	if (num_luns > max_scsi_report_luns) {
-		printk(KERN_WARNING "scsi: On %s only %d (max_scsi_report_luns)"
+		sdev_printk(KERN_WARNING, sdev,
+		       "scsi: only %d (max_scsi_report_luns)"
 		       " of %d luns reported, try increasing"
-		       " max_scsi_report_luns.\n", devname,
+		       " max_scsi_report_luns.\n",
 		       max_scsi_report_luns, num_luns);
 		num_luns = max_scsi_report_luns;
 	}
@@ -1456,20 +1462,18 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
 		 * does not fit in lun.
 		 */
 		if (memcmp(&lunp->scsi_lun[sizeof(lun)], "\0\0\0\0", 4)) {
-			int i;
-
 			/*
 			 * Output an error displaying the LUN in byte order,
 			 * this differs from what linux would print for the
 			 * integer LUN value.
 			 */
-			printk(KERN_WARNING "scsi: %s lun 0x", devname);
-			data = (char *)lunp->scsi_lun;
-			for (i = 0; i < sizeof(struct scsi_lun); i++)
-				printk("%02x", data[i]);
-			printk(" has a LUN larger than currently supported.\n");
+			sdev_printk(KERN_WARNING, sdev,
+			       "scsi: %s lun 0x%08phN has a LUN larger "
+				    " than currently supported.",
+				    devname, lunp->scsi_lun);
 		} else if (lun > sdev->host->max_lun) {
-			printk(KERN_WARNING "scsi: %s lun%d has a LUN larger"
+			sdev_printk(KERN_WARNING, sdev,
+			       "scsi: %s lun%d has a LUN larger"
 			       " than allowed by the host adapter\n",
 			       devname, lun);
 		} else {
@@ -1483,8 +1487,8 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
 				 */
 				sdev_printk(KERN_ERR, sdev,
 					"Unexpected response"
-				        " from lun %d while scanning, scan"
-				        " aborted\n", lun);
+					" from lun %d while scanning, scan"
+					" aborted\n", lun);
 				break;
 			}
 		}
@@ -1743,8 +1747,7 @@ static struct async_scan_data *scsi_prep_async_scan(struct Scsi_Host *shost)
 		return NULL;
 
 	if (shost->async_scan) {
-		printk("%s called twice for host %d", __func__,
-				shost->host_no);
+		shost_printk(KERN_INFO, shost, "%s called twice", __func__);
 		dump_stack();
 		return NULL;
 	}
@@ -1797,8 +1800,7 @@ static void scsi_finish_async_scan(struct async_scan_data *data)
 	mutex_lock(&shost->scan_mutex);
 
 	if (!shost->async_scan) {
-		printk("%s called twice for host %d", __func__,
-				shost->host_no);
+		shost_printk(KERN_INFO, shost, "%s called twice", __func__);
 		dump_stack();
 		mutex_unlock(&shost->scan_mutex);
 		return;
-- 
1.7.4.2


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

* [PATCH 05/10] scsi: use buffer for print_opcode_name()
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (3 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 04/10] scsi: Use sdev_printk() for logging Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 06/10] scsi: use single printk call in scsi_print_command() Hannes Reinecke
                   ` (6 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

Instead of printing directly to syslog print_opcode_name() should
be using a private buffer to avoid linebreaks during printout.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c |   98 +++++++++++++++++++++++++++------------------
 1 files changed, 59 insertions(+), 39 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 76e4c03..b469798 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -204,9 +204,10 @@ static const char * get_sa_name(const struct value_name_pair * arr,
 }
 
 /* attempt to guess cdb length if cdb_len==0 . No trailing linefeed. */
-static void print_opcode_name(unsigned char * cdbp, int cdb_len)
+static int print_opcode_name(char *buf, int buf_len,
+			      unsigned char *cdbp, int cdb_len)
 {
-	int sa, len, cdb0;
+	int sa, len, cdb0, sz = 0;
 	const char * name;
 
 	cdb0 = cdbp[0];
@@ -214,101 +215,119 @@ static void print_opcode_name(unsigned char * cdbp, int cdb_len)
 	case VARIABLE_LENGTH_CMD:
 		len = scsi_varlen_cdb_length(cdbp);
 		if (len < 10) {
-			printk("short variable length command, "
-			       "len=%d ext_len=%d", len, cdb_len);
-			break;
+			sz = snprintf(buf, buf_len,
+				      "short variable length command, "
+				      "len=%d ext_len=%d", len, cdb_len);
+			return sz;
 		}
 		sa = (cdbp[8] << 8) + cdbp[9];
 		name = get_sa_name(variable_length_arr, VARIABLE_LENGTH_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 
 		if ((cdb_len > 0) && (len != cdb_len))
-			printk(", in_cdb_len=%d, ext_len=%d", len, cdb_len);
+			sz = snprintf(buf + sz, buf_len - sz,
+				      ", in_cdb_len=%d, ext_len=%d",
+				      len, cdb_len);
 
 		break;
 	case MAINTENANCE_IN:
 		sa = cdbp[1] & 0x1f;
 		name = get_sa_name(maint_in_arr, MAINT_IN_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 		break;
 	case MAINTENANCE_OUT:
 		sa = cdbp[1] & 0x1f;
 		name = get_sa_name(maint_out_arr, MAINT_OUT_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 		break;
 	case SERVICE_ACTION_IN_12:
 		sa = cdbp[1] & 0x1f;
 		name = get_sa_name(serv_in12_arr, SERV_IN12_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 		break;
 	case SERVICE_ACTION_OUT_12:
 		sa = cdbp[1] & 0x1f;
 		name = get_sa_name(serv_out12_arr, SERV_OUT12_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 		break;
 	case SERVICE_ACTION_IN_16:
 		sa = cdbp[1] & 0x1f;
 		name = get_sa_name(serv_in16_arr, SERV_IN16_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 		break;
 	case SERVICE_ACTION_OUT_16:
 		sa = cdbp[1] & 0x1f;
 		name = get_sa_name(serv_out16_arr, SERV_OUT16_SZ, sa);
 		if (name)
-			printk("%s", name);
+			sz = snprintf(buf, buf_len, "%s", name);
 		else
-			printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x, sa=0x%x",
+				      cdb0, sa);
 		break;
 	default:
 		if (cdb0 < 0xc0) {
 			name = cdb_byte0_names[cdb0];
 			if (name)
-				printk("%s", name);
+				sz = snprintf(buf, buf_len, "%s", name);
 			else
-				printk("cdb[0]=0x%x (reserved)", cdb0);
+				sz = snprintf(buf, buf_len,
+					      "cdb[0]=0x%x (reserved)", cdb0);
 		} else
-			printk("cdb[0]=0x%x (vendor)", cdb0);
+			sz = snprintf(buf, buf_len, "cdb[0]=0x%x (vendor)",
+				      cdb0);
 		break;
 	}
+	return sz;
 }
 
 #else /* ifndef CONFIG_SCSI_CONSTANTS */
 
-static void print_opcode_name(unsigned char * cdbp, int cdb_len)
+static int print_opcode_name(char *buf, int buf_len,
+			     unsigned char *cdbp, int cdb_len)
 {
-	int sa, len, cdb0;
+	int sa, len, cdb0, sz = 0;
 
 	cdb0 = cdbp[0];
+	sz = snprintf(buf, buf_len, "cdb[0]=0x%x", cdb0);
 	switch(cdb0) {
 	case VARIABLE_LENGTH_CMD:
 		len = scsi_varlen_cdb_length(cdbp);
 		if (len < 10) {
-			printk("short opcode=0x%x command, len=%d "
-			       "ext_len=%d", cdb0, len, cdb_len);
+			sz += snprintf(buf + sz, buf_size - sz,
+				       "short command, len=%d ext_len=%d",
+				       len, cdb_len);
 			break;
 		}
 		sa = (cdbp[8] << 8) + cdbp[9];
-		printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+		sz += snprintf(buf + sz, buf_len - sz, ", sa=0x%x", sa);
 		if (len != cdb_len)
-			printk(", in_cdb_len=%d, ext_len=%d", len, cdb_len);
+			sz += snprintf(buf + sz, buf_len - sz,
+				       ", in_cdb_len=%d, ext_len=%d",
+				       len, cdb_len);
 		break;
 	case MAINTENANCE_IN:
 	case MAINTENANCE_OUT:
@@ -317,23 +336,24 @@ static void print_opcode_name(unsigned char * cdbp, int cdb_len)
 	case SERVICE_ACTION_IN_16:
 	case SERVICE_ACTION_OUT_16:
 		sa = cdbp[1] & 0x1f;
-		printk("cdb[0]=0x%x, sa=0x%x", cdb0, sa);
+		sz += snprintf(buf + sz, buf_len - sz, ", sa=0x%x", sa);
 		break;
 	default:
-		if (cdb0 < 0xc0)
-			printk("cdb[0]=0x%x", cdb0);
-		else
-			printk("cdb[0]=0x%x (vendor)", cdb0);
+		if (cdb0 >= 0xc0)
+			sz += snprintf(buf + sz, buf_len - sz, " (vendor)");
 		break;
 	}
+	return sz;
 }
-#endif  
+#endif
 
 void __scsi_print_command(unsigned char *cdb)
 {
 	int k, len;
+	char cdb_str[64];
 
-	print_opcode_name(cdb, 0);
+	print_opcode_name(cdb_str, 64, cdb, 0);
+	pr_info("%s", cdb_str);
 	len = scsi_command_size(cdb);
 	/* print out all bytes in cdb */
 	for (k = 0; k < len; ++k) 
@@ -345,15 +365,15 @@ EXPORT_SYMBOL(__scsi_print_command);
 void scsi_print_command(struct scsi_cmnd *cmd)
 {
 	int k;
+	char cdb_str[64];
 
 	if (cmd->cmnd == NULL)
 		return;
 
-	scmd_printk(KERN_INFO, cmd, "CDB: ");
-	print_opcode_name(cmd->cmnd, cmd->cmd_len);
+	print_opcode_name(cdb_str, 64, cmd->cmnd, cmd->cmd_len);
+	scmd_printk(KERN_INFO, cmd, "CDB: %s:", cdb_str);
 
 	/* print out all bytes in cdb */
-	printk(":");
 	for (k = 0; k < cmd->cmd_len; ++k)
 		printk(" %02x", cmd->cmnd[k]);
 	printk("\n");
-- 
1.7.4.2


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

* [PATCH 06/10] scsi: use single printk call in scsi_print_command()
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (4 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 05/10] scsi: use buffer for print_opcode_name() Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 07/10] scsi: use buffer for scsi_show_result() Hannes Reinecke
                   ` (5 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

scsi_print_command is using several calls to printk(), causing
the output to be garbled. Modify it to use a single call to
printk().

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c |   71 +++++++++++++++++++++++++++++++++++++++------
 1 files changed, 61 insertions(+), 10 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index b469798..65367e8 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -349,34 +349,85 @@ static int print_opcode_name(char *buf, int buf_len,
 
 void __scsi_print_command(unsigned char *cdb)
 {
-	int k, len;
+	int k, len, rem, linelen;
 	char cdb_str[64];
+	char line[16 * 3 + 1];
 
 	print_opcode_name(cdb_str, 64, cdb, 0);
-	pr_info("%s", cdb_str);
 	len = scsi_command_size(cdb);
 	/* print out all bytes in cdb */
-	for (k = 0; k < len; ++k) 
-		printk(" %02x", cdb[k]);
-	printk("\n");
+	switch (len) {
+	case 6:
+		pr_info("%s %6ph\n", cdb_str, cdb);
+		break;
+	case 10:
+		pr_info("%s %10ph\n", cdb_str, cdb);
+		break;
+	case 12:
+		pr_info("%s %12ph\n", cdb_str, cdb);
+		break;
+	case 16:
+		pr_info("%s %16ph\n", cdb_str, cdb);
+		break;
+	default:
+		pr_info("%s\n", cdb_str);
+		rem = len;
+		for (k = 0; k < len; k += 16) {
+			linelen = min(rem, 16);
+			rem -= 16;
+
+			hex_dump_to_buffer(cdb + k, linelen, 16, 1,
+					   line, sizeof(line), false);
+			pr_info("%s\n", line);
+		}
+		break;
+	}
 }
 EXPORT_SYMBOL(__scsi_print_command);
 
 void scsi_print_command(struct scsi_cmnd *cmd)
 {
-	int k;
+	int k, rem, linelen;
 	char cdb_str[64];
+	char line[16 * 3 + 1];
 
 	if (cmd->cmnd == NULL)
 		return;
 
 	print_opcode_name(cdb_str, 64, cmd->cmnd, cmd->cmd_len);
-	scmd_printk(KERN_INFO, cmd, "CDB: %s:", cdb_str);
 
 	/* print out all bytes in cdb */
-	for (k = 0; k < cmd->cmd_len; ++k)
-		printk(" %02x", cmd->cmnd[k]);
-	printk("\n");
+	switch (cmd->cmd_len) {
+	case 6:
+		scmd_printk(KERN_INFO, cmd, "CDB: %s: %6ph\n",
+			    cdb_str, cmd->cmnd);
+		break;
+	case 10:
+		scmd_printk(KERN_INFO, cmd, "CDB: %s: %10ph\n",
+			    cdb_str, cmd->cmnd);
+		break;
+	case 12:
+		scmd_printk(KERN_INFO, cmd, "CDB: %s: %12ph\n",
+			    cdb_str, cmd->cmnd);
+		break;
+	case 16:
+		scmd_printk(KERN_INFO, cmd, "CDB: %s: %16ph\n",
+			    cdb_str, cmd->cmnd);
+		break;
+	default:
+		scmd_printk(KERN_INFO, cmd, "CDB: %s\n", cdb_str);
+		rem = cmd->cmd_len;
+		for (k = 0; k < cmd->cmd_len; k += 16) {
+			linelen = min(rem, 16);
+			rem -= 16;
+
+			hex_dump_to_buffer(cmd->cmnd + k, linelen, 16, 1,
+					   line, sizeof(line), false);
+			scmd_printk(KERN_INFO, cmd, "        %d: %s\n",
+				    k, line);
+		}
+		break;
+	}
 }
 EXPORT_SYMBOL(scsi_print_command);
 
-- 
1.7.4.2


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

* [PATCH 07/10] scsi: use buffer for scsi_show_result()
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (5 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 06/10] scsi: use single printk call in scsi_print_command() Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 08/10] scsi: open-code scsi_decode_sense_buffer() Hannes Reinecke
                   ` (4 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

scsi_show_result() should be printing the message into a supplied
buffer to avoid linebreaks during output.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c |   23 +++++++++++++----------
 drivers/scsi/sd.c        |    6 ++++--
 include/scsi/scsi_dbg.h  |    2 +-
 3 files changed, 18 insertions(+), 13 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 65367e8..ded16d9 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1502,32 +1502,35 @@ static const char * const driverbyte_table[]={
 "DRIVER_INVALID", "DRIVER_TIMEOUT", "DRIVER_HARD", "DRIVER_SENSE"};
 #define NUM_DRIVERBYTE_STRS ARRAY_SIZE(driverbyte_table)
 
-void scsi_show_result(int result)
+void scsi_show_result(char *buf, int buf_size, int result)
 {
 	int hb = host_byte(result);
 	int db = driver_byte(result);
 
-	printk("Result: hostbyte=%s driverbyte=%s\n",
-	       (hb < NUM_HOSTBYTE_STRS ? hostbyte_table[hb]     : "invalid"),
-	       (db < NUM_DRIVERBYTE_STRS ? driverbyte_table[db] : "invalid"));
+	snprintf(buf, buf_size,
+		"Result: hostbyte=%s driverbyte=%s\n",
+		(hb < NUM_HOSTBYTE_STRS ? hostbyte_table[hb]     : "invalid"),
+		(db < NUM_DRIVERBYTE_STRS ? driverbyte_table[db] : "invalid"));
 }
 
 #else
 
-void scsi_show_result(int result)
+void scsi_show_result(char *buf, int buf_size, int result)
 {
-	printk("Result: hostbyte=0x%02x driverbyte=0x%02x\n",
-	       host_byte(result), driver_byte(result));
+	snprintf(buf, buf_size,
+		 "Result: hostbyte=0x%02x driverbyte=0x%02x\n",
+		 host_byte(result), driver_byte(result));
 }
 
 #endif
 EXPORT_SYMBOL(scsi_show_result);
 
-
 void scsi_print_result(struct scsi_cmnd *cmd)
 {
-	scmd_printk(KERN_INFO, cmd, " ");
-	scsi_show_result(cmd->result);
+	char result_buf[70];
+
+	scsi_show_result(result_buf, 70, cmd->result);
+	scmd_printk(KERN_INFO, cmd, "%s", result_buf);
 }
 EXPORT_SYMBOL(scsi_print_result);
 
diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c
index 12f6fdf..f6165e6 100644
--- a/drivers/scsi/sd.c
+++ b/drivers/scsi/sd.c
@@ -3025,7 +3025,9 @@ static void sd_print_sense_hdr(struct scsi_disk *sdkp,
 
 static void sd_print_result(struct scsi_disk *sdkp, int result)
 {
-	sd_printk(KERN_INFO, sdkp, " ");
-	scsi_show_result(result);
+	char result_buf[70];
+
+	scsi_show_result(result_buf, 70, result);
+	sd_printk(KERN_INFO, sdkp, "%s", result_buf);
 }
 
diff --git a/include/scsi/scsi_dbg.h b/include/scsi/scsi_dbg.h
index e89844c..cc6abb4 100644
--- a/include/scsi/scsi_dbg.h
+++ b/include/scsi/scsi_dbg.h
@@ -15,7 +15,7 @@ extern void scsi_print_sense(char *, struct scsi_cmnd *);
 extern void __scsi_print_sense(const char *name,
 			       const unsigned char *sense_buffer,
 			       int sense_len);
-extern void scsi_show_result(int);
+extern void scsi_show_result(char *, int, int);
 extern void scsi_print_result(struct scsi_cmnd *);
 extern void scsi_print_status(unsigned char);
 extern const char *scsi_sense_key_string(unsigned char);
-- 
1.7.4.2


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

* [PATCH 08/10] scsi: open-code scsi_decode_sense_buffer()
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (6 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 07/10] scsi: use buffer for scsi_show_result() Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 09/10] scsi: decode descriptor sense Hannes Reinecke
                   ` (3 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

Pointless, and actually wrong as there is no point in trying
to decode invalid sense data.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c |   43 +++++++++++++++++--------------------------
 1 files changed, 17 insertions(+), 26 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index ded16d9..8bf2616 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1373,29 +1373,6 @@ scsi_cmd_print_sense_hdr(struct scsi_cmnd *scmd, const char *desc,
 EXPORT_SYMBOL(scsi_cmd_print_sense_hdr);
 
 static void
-scsi_decode_sense_buffer(const unsigned char *sense_buffer, int sense_len,
-		       struct scsi_sense_hdr *sshdr)
-{
-	int k, num, res;
-    
-	res = scsi_normalize_sense(sense_buffer, sense_len, sshdr);
-	if (0 == res) {
-		/* this may be SCSI-1 sense data */
-		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;
-	}
-}
-
-static void
 scsi_decode_sense_extras(const unsigned char *sense_buffer, int sense_len,
 			 struct scsi_sense_hdr *sshdr)
 {
@@ -1462,8 +1439,15 @@ void __scsi_print_sense(const char *name, const unsigned char *sense_buffer,
 {
 	struct scsi_sense_hdr sshdr;
 
+	if (!scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) {
+		/* this may be SCSI-1 sense data */
+		int num = (sense_len < 32) ? sense_len : 32;
+		pr_info("%s: Unrecognized sense data (in hex):", name);
+		print_hex_dump(KERN_INFO, "        ", DUMP_PREFIX_OFFSET,
+			       16, 1, sense_buffer, num, false);
+		return;
+	}
 	printk(KERN_INFO "%s: ", name);
-	scsi_decode_sense_buffer(sense_buffer, sense_len, &sshdr);
 	scsi_show_sense_hdr(&sshdr);
 	scsi_decode_sense_extras(sense_buffer, sense_len, &sshdr);
 	printk(KERN_INFO "%s: ", name);
@@ -1476,9 +1460,16 @@ void scsi_print_sense(char *name, struct scsi_cmnd *cmd)
 {
 	struct scsi_sense_hdr sshdr;
 
+	if (!scsi_normalize_sense(cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE,
+				  &sshdr)) {
+		scmd_printk(KERN_INFO, cmd,
+			    "Unrecognized sense data (in hex):");
+		print_hex_dump(KERN_INFO, "        ", DUMP_PREFIX_OFFSET,
+			       16, 1, cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE,
+			       false);
+		return;
+	}
 	scmd_printk(KERN_INFO, cmd, " ");
-	scsi_decode_sense_buffer(cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE,
-				 &sshdr);
 	scsi_show_sense_hdr(&sshdr);
 	scsi_decode_sense_extras(cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE,
 				 &sshdr);
-- 
1.7.4.2


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

* [PATCH 09/10] scsi: decode descriptor sense
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (7 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 08/10] scsi: open-code scsi_decode_sense_buffer() Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-12  8:33 ` [PATCH 10/10] scsi: use local buffer for decoding sense data Hannes Reinecke
                   ` (2 subsequent siblings)
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

Decode descriptor sense buffer to provide the same information as
we are already getting from fixed format sense.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c  |   79 +++++++++++++++------------------------------
 drivers/scsi/scsi_error.c |   43 +++++++++++++++++++++++-
 include/scsi/scsi_eh.h    |    8 +++-
 3 files changed, 73 insertions(+), 57 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index 8bf2616..df69ba3 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1376,61 +1376,34 @@ static void
 scsi_decode_sense_extras(const unsigned char *sense_buffer, int sense_len,
 			 struct scsi_sense_hdr *sshdr)
 {
-	int k, num, res;
-
-	if (sshdr->response_code < 0x72)
-	{
-		/* only decode extras for "fixed" format now */
-		char buff[80];
-		int blen, fixed_valid;
-		unsigned int info;
-
-		fixed_valid = sense_buffer[0] & 0x80;
-		info = ((sense_buffer[3] << 24) | (sense_buffer[4] << 16) |
-			(sense_buffer[5] << 8) | sense_buffer[6]);
-		res = 0;
-		memset(buff, 0, sizeof(buff));
-		blen = sizeof(buff) - 1;
-		if (fixed_valid)
-			res += snprintf(buff + res, blen - res,
-					"Info fld=0x%x", info);
-		if (sense_buffer[2] & 0x80) {
-			/* current command has read a filemark */
-			if (res > 0)
-				res += snprintf(buff + res, blen - res, ", ");
-			res += snprintf(buff + res, blen - res, "FMK");
-		}
-		if (sense_buffer[2] & 0x40) {
-			/* end-of-medium condition exists */
-			if (res > 0)
-				res += snprintf(buff + res, blen - res, ", ");
-			res += snprintf(buff + res, blen - res, "EOM");
-		}
-		if (sense_buffer[2] & 0x20) {
-			/* incorrect block length requested */
-			if (res > 0)
-				res += snprintf(buff + res, blen - res, ", ");
-			res += snprintf(buff + res, blen - res, "ILI");
-		}
-		if (res > 0)
-			printk("%s\n", buff);
-	} else if (sshdr->additional_length > 0) {
-		/* descriptor format with sense descriptors */
-		num = 8 + sshdr->additional_length;
-		num = (sense_len < num) ? sense_len : num;
-		printk("Descriptor sense data with sense descriptors "
-		       "(in hex):");
-		for (k = 0; k < num; ++k) {
-			if (0 == (k % 16)) {
-				printk("\n");
-				printk(KERN_INFO "        ");
-			}
-			printk("%02x ", sense_buffer[k]);
-		}
+	int res = 0;
+	char buff[80];
+	int blen = sense_len;
 
-		printk("\n");
-	}
+	if (sshdr->info)
+		res += snprintf(buff + res, blen - res,
+				"Info fld=0x%llx", sshdr->info);
 
+	if (sshdr->flags & SCSI_SENSE_FLAG_FMK) {
+		/* current command has read a filemark */
+		if (res > 0)
+			res += snprintf(buff + res, blen - res, ", ");
+		res += snprintf(buff + res, blen - res, "FMK");
+	}
+	if (sshdr->flags & SCSI_SENSE_FLAG_EOM) {
+		/* end-of-medium condition exists */
+		if (res > 0)
+			res += snprintf(buff + res, blen - res, ", ");
+		res += snprintf(buff + res, blen - res, "EOM");
+	}
+	if (sshdr->flags & SCSI_SENSE_FLAG_ILI) {
+		/* incorrect block length requested */
+		if (res > 0)
+			res += snprintf(buff + res, blen - res, ", ");
+		res += snprintf(buff + res, blen - res, "ILI");
+	}
+	if (res > 0)
+		pr_info("%s\n", buff);
 }
 
 /* Normalize and print sense buffer with name prefix */
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index f8d51c5..e8ff276 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -2086,7 +2086,7 @@ EXPORT_SYMBOL(scsi_reset_provider);
  *	1 if valid sense data information found, else 0;
  */
 int scsi_normalize_sense(const u8 *sense_buffer, int sb_len,
-                         struct scsi_sense_hdr *sshdr)
+			 struct scsi_sense_hdr *sshdr)
 {
 	if (!sense_buffer || !sb_len)
 		return 0;
@@ -2099,6 +2099,9 @@ int scsi_normalize_sense(const u8 *sense_buffer, int sb_len,
 		return 0;
 
 	if (sshdr->response_code >= 0x72) {
+		int i;
+		const char *sdesc;
+
 		/*
 		 * descriptor format
 		 */
@@ -2110,19 +2113,55 @@ int scsi_normalize_sense(const u8 *sense_buffer, int sb_len,
 			sshdr->ascq = sense_buffer[3];
 		if (sb_len > 7)
 			sshdr->additional_length = sense_buffer[7];
+		i = 0;
+		while ((i < sshdr->additional_length) && (i + 8 < sb_len)) {
+			sdesc = &sense_buffer[i + 8];
+			switch (sdesc[0]) {
+			case 0: /* Information */
+				if (!(sdesc[2] & 0x80))
+					break;
+				sshdr->info = (u64)sdesc[4] << 56 |
+					(u64)sdesc[5] << 48 |
+					(u64)sdesc[6] << 40 |
+					(u64)sdesc[7] << 32 |
+					(u64)sdesc[8] << 24 |
+					(u64)sdesc[9] << 16 |
+					(u64)sdesc[10] << 8 |
+					(u64)sdesc[11];
+				break;
+			case 3: /* Field replaceable unit */
+				sshdr->fru = sdesc[3];
+				break;
+			case 4: /* Stream commands */
+				sshdr->flags = sdesc[3] >> 4;
+				break;
+			case 5: /* Block commands */
+				sshdr->flags = sdesc[3] >> 4;
+			}
+			i += sdesc[1];
+		}
 	} else {
 		/*
 		 * fixed format
 		 */
-		if (sb_len > 2)
+		if (sb_len > 2) {
 			sshdr->sense_key = (sense_buffer[2] & 0xf);
+			sshdr->flags = (sense_buffer[2] >> 4);
+		}
 		if (sb_len > 7) {
+			if (sense_buffer[0] & 0x80)
+				sshdr->info = ((sense_buffer[3] << 24) |
+					       (sense_buffer[4] << 16) |
+					       (sense_buffer[5] << 8) |
+					       sense_buffer[6]);
 			sb_len = (sb_len < (sense_buffer[7] + 8)) ?
 					 sb_len : (sense_buffer[7] + 8);
 			if (sb_len > 12)
 				sshdr->asc = sense_buffer[12];
 			if (sb_len > 13)
 				sshdr->ascq = sense_buffer[13];
+			if (sb_len > 14)
+				sshdr->fru = sense_buffer[14];
 		}
 	}
 
diff --git a/include/scsi/scsi_eh.h b/include/scsi/scsi_eh.h
index 06a8790..3472448 100644
--- a/include/scsi/scsi_eh.h
+++ b/include/scsi/scsi_eh.h
@@ -21,10 +21,14 @@ struct scsi_sense_hdr {		/* See SPC-3 section 4.5 */
 	u8 sense_key;
 	u8 asc;
 	u8 ascq;
-	u8 byte4;
-	u8 byte5;
+	u8 flags;
+#define SCSI_SENSE_FLAG_FMK  0x8
+#define SCSI_SENSE_FLAG_EOM 0x4
+#define SCSI_SENSE_FLAG_ILI 0x2
+	u8 fru;
 	u8 byte6;
 	u8 additional_length;	/* always 0 for fixed sense format */
+	u64 info;
 };
 
 static inline int scsi_sense_valid(struct scsi_sense_hdr *sshdr)
-- 
1.7.4.2


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

* [PATCH 10/10] scsi: use local buffer for decoding sense data
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (8 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 09/10] scsi: decode descriptor sense Hannes Reinecke
@ 2012-10-12  8:33 ` Hannes Reinecke
  2012-10-15  0:19 ` [PATCH 00/10] scsi: avoid linebreaks in syslog output Mike Snitzer
  2013-12-20 13:25 ` Tomas Henzl
  11 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-12  8:33 UTC (permalink / raw)
  To: James Bottomley; +Cc: linux-scsi, Hannes Reinecke, Kay Sievers

Instead of printing directly to console we should be using
a local buffer for formatting sense data.
This will avoid garbled output.

Cc: Kay Sievers <kay@vrfy.org>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/constants.c |  102 +++++++++++++++++++++++++--------------------
 drivers/scsi/sd.c        |   10 +++--
 include/scsi/scsi_dbg.h  |    4 +-
 3 files changed, 65 insertions(+), 51 deletions(-)

diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c
index df69ba3..9115233 100644
--- a/drivers/scsi/constants.c
+++ b/drivers/scsi/constants.c
@@ -1299,49 +1299,52 @@ scsi_extd_sense_format(unsigned char asc, unsigned char ascq) {
 EXPORT_SYMBOL(scsi_extd_sense_format);
 
 void
-scsi_show_extd_sense(unsigned char asc, unsigned char ascq)
+scsi_show_extd_sense(char *buf, int buf_len,
+		     unsigned char asc, unsigned char ascq)
 {
-        const char *extd_sense_fmt = scsi_extd_sense_format(asc, ascq);
+	const char *extd_sense_fmt = scsi_extd_sense_format(asc, ascq);
+	int sz = 0;
 
 	if (extd_sense_fmt) {
 		if (strstr(extd_sense_fmt, "%x")) {
-			printk("Add. Sense: ");
-			printk(extd_sense_fmt, ascq);
+			sz = snprintf(buf, buf_len, "Add. Sense: ");
+			sz += snprintf(buf + sz, buf_len - sz,
+				       extd_sense_fmt, ascq);
 		} else
-			printk("Add. Sense: %s", extd_sense_fmt);
+			sz = snprintf(buf, buf_len, "Add. Sense: %s",
+				      extd_sense_fmt);
 	} else {
 		if (asc >= 0x80)
-			printk("<<vendor>> ASC=0x%x ASCQ=0x%x", asc,
-			       ascq);
-		if (ascq >= 0x80)
-			printk("ASC=0x%x <<vendor>> ASCQ=0x%x", asc,
-			       ascq);
+			snprintf(buf, buf_len, "<<vendor>> ASC=0x%x ASCQ=0x%x",
+				 asc, ascq);
+		else if (ascq >= 0x80)
+			snprintf(buf, buf_len, "ASC=0x%x <<vendor>> ASCQ=0x%x",
+				 asc, ascq);
 		else
-			printk("ASC=0x%x ASCQ=0x%x", asc, ascq);
+			snprintf(buf, buf_len, "ASC=0x%x ASCQ=0x%x", asc, ascq);
 	}
-
-	printk("\n");
 }
 EXPORT_SYMBOL(scsi_show_extd_sense);
 
 void
-scsi_show_sense_hdr(struct scsi_sense_hdr *sshdr)
+scsi_show_sense_hdr(char *buf, int buf_len, struct scsi_sense_hdr *sshdr)
 {
 	const char *sense_txt;
+	int sz;
 
 	sense_txt = scsi_sense_key_string(sshdr->sense_key);
 	if (sense_txt)
-		printk("Sense Key : %s ", sense_txt);
+		sz = snprintf(buf, buf_len, "Sense Key : %s ", sense_txt);
 	else
-		printk("Sense Key : 0x%x ", sshdr->sense_key);
+		sz = snprintf(buf, buf_len, "Sense Key : 0x%x ",
+			      sshdr->sense_key);
 
-	printk("%s", scsi_sense_is_deferred(sshdr) ? "[deferred] " :
-	       "[current] ");
+	sz += snprintf(buf + sz, buf_len - sz, "%s",
+		       scsi_sense_is_deferred(sshdr) ?
+		       "[deferred] " : "[current] ");
 
 	if (sshdr->response_code >= 0x72)
-		printk("[descriptor]");
-
-	printk("\n");
+		sz += snprintf(buf + sz, buf_len - sz, "[descriptor]");
 }
 EXPORT_SYMBOL(scsi_show_sense_hdr);
 
@@ -1351,10 +1354,12 @@ EXPORT_SYMBOL(scsi_show_sense_hdr);
 void
 scsi_print_sense_hdr(const char *name, struct scsi_sense_hdr *sshdr)
 {
-	printk(KERN_INFO "%s: ", name);
-	scsi_show_sense_hdr(sshdr);
-	printk(KERN_INFO "%s: ", name);
-	scsi_show_extd_sense(sshdr->asc, sshdr->ascq);
+	char sense_buf[128];
+
+	scsi_show_sense_hdr(sense_buf, 128, sshdr);
+	pr_info("%s: %s", name, sense_buf);
+	scsi_show_extd_sense(sense_buf, 128, sshdr->asc, sshdr->ascq);
+	pr_info("%s: %s", name, sense_buf);
 }
 EXPORT_SYMBOL(scsi_print_sense_hdr);
 
@@ -1365,20 +1370,21 @@ void
 scsi_cmd_print_sense_hdr(struct scsi_cmnd *scmd, const char *desc,
 			  struct scsi_sense_hdr *sshdr)
 {
-	scmd_printk(KERN_INFO, scmd, "%s: ", desc);
-	scsi_show_sense_hdr(sshdr);
-	scmd_printk(KERN_INFO, scmd, "%s: ", desc);
-	scsi_show_extd_sense(sshdr->asc, sshdr->ascq);
+	char sense_buf[128];
+
+	scsi_show_sense_hdr(sense_buf, 128, sshdr);
+	scmd_printk(KERN_INFO, scmd, "%s: %s", desc, sense_buf);
+	scsi_show_extd_sense(sense_buf, 128, sshdr->asc, sshdr->ascq);
+	scmd_printk(KERN_INFO, scmd, "%s: %s", desc, sense_buf);
 }
 EXPORT_SYMBOL(scsi_cmd_print_sense_hdr);
 
-static void
-scsi_decode_sense_extras(const unsigned char *sense_buffer, int sense_len,
+static int
+scsi_decode_sense_extras(char *buff, int buff_len,
 			 struct scsi_sense_hdr *sshdr)
 {
 	int res = 0;
-	char buff[80];
-	int blen = sense_len;
+	int blen = buff_len;
 
 	if (sshdr->info)
 		res += snprintf(buff + res, blen - res,
@@ -1402,8 +1408,7 @@ scsi_decode_sense_extras(const unsigned char *sense_buffer, int sense_len,
 			res += snprintf(buff + res, blen - res, ", ");
 		res += snprintf(buff + res, blen - res, "ILI");
 	}
-	if (res > 0)
-		pr_info("%s\n", buff);
+	return res;
 }
 
 /* Normalize and print sense buffer with name prefix */
@@ -1411,6 +1416,8 @@ void __scsi_print_sense(const char *name, const unsigned char *sense_buffer,
 			int sense_len)
 {
 	struct scsi_sense_hdr sshdr;
+	char sense_buf[128];
+	int len;
 
 	if (!scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) {
 		/* this may be SCSI-1 sense data */
@@ -1420,11 +1427,13 @@ void __scsi_print_sense(const char *name, const unsigned char *sense_buffer,
 			       16, 1, sense_buffer, num, false);
 		return;
 	}
+	scsi_show_sense_hdr(sense_buf, 128, &sshdr);
+	pr_info("%s: %s", name, sense_buf);
+	len = scsi_decode_sense_extras(sense_buf, 128, &sshdr);
+	if (len)
+		pr_info("%s: %s", name, sense_buf);
+	scsi_show_extd_sense(sense_buf, 128, sshdr.asc, sshdr.ascq);
 	printk(KERN_INFO "%s: ", name);
-	scsi_show_sense_hdr(&sshdr);
-	scsi_decode_sense_extras(sense_buffer, sense_len, &sshdr);
-	printk(KERN_INFO "%s: ", name);
-	scsi_show_extd_sense(sshdr.asc, sshdr.ascq);
 }
 EXPORT_SYMBOL(__scsi_print_sense);
 
@@ -1432,6 +1441,8 @@ EXPORT_SYMBOL(__scsi_print_sense);
 void scsi_print_sense(char *name, struct scsi_cmnd *cmd)
 {
 	struct scsi_sense_hdr sshdr;
+	char sense_buf[128];
+	int len;
 
 	if (!scsi_normalize_sense(cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE,
 				  &sshdr)) {
@@ -1442,12 +1453,13 @@ void scsi_print_sense(char *name, struct scsi_cmnd *cmd)
 			       false);
 		return;
 	}
-	scmd_printk(KERN_INFO, cmd, " ");
-	scsi_show_sense_hdr(&sshdr);
-	scsi_decode_sense_extras(cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE,
-				 &sshdr);
-	scmd_printk(KERN_INFO, cmd, " ");
-	scsi_show_extd_sense(sshdr.asc, sshdr.ascq);
+	scsi_show_sense_hdr(sense_buf, 128, &sshdr);
+	scmd_printk(KERN_INFO, cmd, "%s", sense_buf);
+	len = scsi_decode_sense_extras(sense_buf, 128, &sshdr);
+	if (len)
+		scmd_printk(KERN_INFO, cmd, "%s", sense_buf);
+	scsi_show_extd_sense(sense_buf, 128, sshdr.asc, sshdr.ascq);
+	scmd_printk(KERN_INFO, cmd, "%s", sense_buf);
 }
 EXPORT_SYMBOL(scsi_print_sense);
 
diff --git a/drivers/scsi/sd.c b/drivers/scsi/sd.c
index f6165e6..0c3d8e6 100644
--- a/drivers/scsi/sd.c
+++ b/drivers/scsi/sd.c
@@ -3017,10 +3017,12 @@ module_exit(exit_sd);
 static void sd_print_sense_hdr(struct scsi_disk *sdkp,
 			       struct scsi_sense_hdr *sshdr)
 {
-	sd_printk(KERN_INFO, sdkp, " ");
-	scsi_show_sense_hdr(sshdr);
-	sd_printk(KERN_INFO, sdkp, " ");
-	scsi_show_extd_sense(sshdr->asc, sshdr->ascq);
+	char sense_buf[128];
+
+	scsi_show_sense_hdr(sense_buf, 128, sshdr);
+	sd_printk(KERN_INFO, sdkp, "%s", sense_buf);
+	scsi_show_extd_sense(sense_buf, 128, sshdr->asc, sshdr->ascq);
+	sd_printk(KERN_INFO, sdkp, "%s", sense_buf);
 }
 
 static void sd_print_result(struct scsi_disk *sdkp, int result)
diff --git a/include/scsi/scsi_dbg.h b/include/scsi/scsi_dbg.h
index cc6abb4..301ce7d 100644
--- a/include/scsi/scsi_dbg.h
+++ b/include/scsi/scsi_dbg.h
@@ -6,8 +6,8 @@ struct scsi_sense_hdr;
 
 extern void scsi_print_command(struct scsi_cmnd *);
 extern void __scsi_print_command(unsigned char *);
-extern void scsi_show_extd_sense(unsigned char, unsigned char);
-extern void scsi_show_sense_hdr(struct scsi_sense_hdr *);
+extern void scsi_show_extd_sense(char *, int, unsigned char, unsigned char);
+extern void scsi_show_sense_hdr(char *, int, struct scsi_sense_hdr *);
 extern void scsi_print_sense_hdr(const char *, struct scsi_sense_hdr *);
 extern void scsi_cmd_print_sense_hdr(struct scsi_cmnd *, const char *,
 				     struct scsi_sense_hdr *);
-- 
1.7.4.2


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

* Re: [PATCH 01/10] sg: Use dev_printk
  2012-10-12  8:33 ` [PATCH 01/10] sg: Use dev_printk Hannes Reinecke
@ 2012-10-12 14:34   ` Douglas Gilbert
  0 siblings, 0 replies; 17+ messages in thread
From: Douglas Gilbert @ 2012-10-12 14:34 UTC (permalink / raw)
  To: Hannes Reinecke; +Cc: James Bottomley, linux-scsi, Kay Sievers

On 12-10-12 04:33 AM, Hannes Reinecke wrote:
> Every sg device has a reference to the underlying scsi device, so
> this patch adds dev_printk() macros to have the messages prefixed
> with the correct device.
>
> Before:
> [772330.437378] sg_open: dev=2, flags=0x8800
> [772330.475425] sg_add_sfp: sfp=0xffff880429d3e000
>
> After:
> [  409.399888] sr 2:0:0:0: [sg2] sg_open: flags=0x8800
> [  409.446029] sr 2:0:0:0: [sg2] sg_add_sfp: sfp=0xffff880425856000
>
> Cc: Kay Sievers <kay@vrfy.org>
> Cc: Doug Gilbert <dgilbert@interlog.com>
> Signed-off-by: Hannes Reinecke <hare@suse.de>

Acked-by: Douglas Gilbert <dgilbert@interlog.com>


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

* Re: [PATCH 00/10] scsi: avoid linebreaks in syslog output
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (9 preceding siblings ...)
  2012-10-12  8:33 ` [PATCH 10/10] scsi: use local buffer for decoding sense data Hannes Reinecke
@ 2012-10-15  0:19 ` Mike Snitzer
  2012-10-15  6:02   ` Hannes Reinecke
  2013-12-20 13:25 ` Tomas Henzl
  11 siblings, 1 reply; 17+ messages in thread
From: Mike Snitzer @ 2012-10-15  0:19 UTC (permalink / raw)
  To: Hannes Reinecke; +Cc: James Bottomley, linux-scsi

On Fri, Oct 12, 2012 at 4:33 AM, Hannes Reinecke <hare@suse.de> wrote:
> This patchset updates the SCSI midlayer to use dev_printk() instead
> of the simple printk(). The main objective here is to avoid line-breaks
> in syslog output; with the current state it's nearly impossible to match
> the output to the occurring device; under high load even the CDB will
> be split off into individual bytes, spread randomly across the lines.
> Which makes debugging via scsi_logging_level _really_ hard.
> In addition we'll be getting the syslog messages nicely prefixed with
> the device, which will make userspace logging daemons happy.
>
> Before:
> [  297.300605] sd 2:0:3:2: Send:
> [  297.300607] 0xffff8802348b0980
> [  297.300610] sd 2:0:3:2: CDB:
> [  297.300615] Test Unit Ready: 00 00 00 00 00 00
> [  297.300747] sd 2:0:3:2: Done:
> [  297.300750] 0xffff8802348b0980 SUCCESS
> [  297.300753] sd 2:0:3:2:
> [  297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK
> [  297.300758] sd 2:0:3:2: CDB:
> [  297.300764] Test Unit Ready: 00 00 00 00 00 00
> [  297.300766] sd 2:0:3:2:
> [  297.300769] Sense Key : Unit Attention [current]
> [  297.300771] Info fld=0x0
> [  297.300772] sd 2:0:3:2:
> [  297.300776] Add. Sense: Capacity data has changed
>
> After:
> [  636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0
> [  636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
> [  636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS
> [  636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
> [  636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
> [  636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current]
> [  637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed

I know there are a lot of changes here but shouldn't all this get
fixed in stable 3.5+?

Thanks for sorting all this out Hannes.

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

* Re: [PATCH 00/10] scsi: avoid linebreaks in syslog output
  2012-10-15  0:19 ` [PATCH 00/10] scsi: avoid linebreaks in syslog output Mike Snitzer
@ 2012-10-15  6:02   ` Hannes Reinecke
  0 siblings, 0 replies; 17+ messages in thread
From: Hannes Reinecke @ 2012-10-15  6:02 UTC (permalink / raw)
  To: Mike Snitzer; +Cc: James Bottomley, linux-scsi

On 10/15/2012 02:19 AM, Mike Snitzer wrote:
> On Fri, Oct 12, 2012 at 4:33 AM, Hannes Reinecke <hare@suse.de> wrote:
>> This patchset updates the SCSI midlayer to use dev_printk() instead
>> of the simple printk(). The main objective here is to avoid line-breaks
>> in syslog output; with the current state it's nearly impossible to match
>> the output to the occurring device; under high load even the CDB will
>> be split off into individual bytes, spread randomly across the lines.
>> Which makes debugging via scsi_logging_level _really_ hard.
>> In addition we'll be getting the syslog messages nicely prefixed with
>> the device, which will make userspace logging daemons happy.
>>
>> Before:
>> [  297.300605] sd 2:0:3:2: Send:
>> [  297.300607] 0xffff8802348b0980
>> [  297.300610] sd 2:0:3:2: CDB:
>> [  297.300615] Test Unit Ready: 00 00 00 00 00 00
>> [  297.300747] sd 2:0:3:2: Done:
>> [  297.300750] 0xffff8802348b0980 SUCCESS
>> [  297.300753] sd 2:0:3:2:
>> [  297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK
>> [  297.300758] sd 2:0:3:2: CDB:
>> [  297.300764] Test Unit Ready: 00 00 00 00 00 00
>> [  297.300766] sd 2:0:3:2:
>> [  297.300769] Sense Key : Unit Attention [current]
>> [  297.300771] Info fld=0x0
>> [  297.300772] sd 2:0:3:2:
>> [  297.300776] Add. Sense: Capacity data has changed
>>
>> After:
>> [  636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0
>> [  636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
>> [  636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS
>> [  636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
>> [  636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
>> [  636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current]
>> [  637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed
>
> I know there are a lot of changes here but shouldn't all this get
> fixed in stable 3.5+?
>

If you ask me, yes, of course.
I can easily post a v2 of the patchset (meanwhile I've got another
patch for st :-), Cc'ing stable with 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 00/10] scsi: avoid linebreaks in syslog output
  2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
                   ` (10 preceding siblings ...)
  2012-10-15  0:19 ` [PATCH 00/10] scsi: avoid linebreaks in syslog output Mike Snitzer
@ 2013-12-20 13:25 ` Tomas Henzl
  2013-12-20 13:31   ` Hannes Reinecke
  11 siblings, 1 reply; 17+ messages in thread
From: Tomas Henzl @ 2013-12-20 13:25 UTC (permalink / raw)
  To: Hannes Reinecke, James Bottomley; +Cc: linux-scsi

Hi Hannes, James,

I'm wondering what happened to this patch-set? I think it could
make parsing of the output for userspace programs much easier.
Are there some problems still to solve or is this just forgotten?

Thanks,
Tomas

On 10/12/2012 10:33 AM, Hannes Reinecke wrote:

> This patchset updates the SCSI midlayer to use dev_printk() instead
> of the simple printk(). The main objective here is to avoid line-breaks
> in syslog output; with the current state it's nearly impossible to match
> the output to the occurring device; under high load even the CDB will
> be split off into individual bytes, spread randomly across the lines.
> Which makes debugging via scsi_logging_level _really_ hard.
> In addition we'll be getting the syslog messages nicely prefixed with
> the device, which will make userspace logging daemons happy.
>
> Before:
> [  297.300605] sd 2:0:3:2: Send: 
> [  297.300607] 0xffff8802348b0980 
> [  297.300610] sd 2:0:3:2: CDB: 
> [  297.300615] Test Unit Ready: 00 00 00 00 00 00
> [  297.300747] sd 2:0:3:2: Done: 
> [  297.300750] 0xffff8802348b0980 SUCCESS
> [  297.300753] sd 2:0:3:2:  
> [  297.300755] Result: hostbyte=DID_OK driverbyte=DRIVER_OK
> [  297.300758] sd 2:0:3:2: CDB: 
> [  297.300764] Test Unit Ready: 00 00 00 00 00 00
> [  297.300766] sd 2:0:3:2:  
> [  297.300769] Sense Key : Unit Attention [current] 
> [  297.300771] Info fld=0x0
> [  297.300772] sd 2:0:3:2:  
> [  297.300776] Add. Sense: Capacity data has changed
>
> After:
> [  636.683556] sd 2:0:3:2: Send: 0xffff88043145eec0
> [  636.727856] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
> [  636.785330] sd 2:0:3:2: Done: 0xffff88043145eec0 SUCCESS
> [  636.838228] sd 2:0:3:2: Result: hostbyte=DID_OK driverbyte=DRIVER_OK
> [  636.899099] sd 2:0:3:2: CDB: Test Unit Ready: 00 00 00 00 00 00
> [  636.955905] sd 2:0:3:2: Sense Key : Unit Attention [current] 
> [  637.069179] sd 2:0:3:2: Add. Sense: Capacity data has changed
>
>
> Hannes Reinecke (10):
>   sg: Use dev_printk
>   sr: Use dev_printk()
>   scsi: Avoid linebreaks in syslog output
>   scsi: Use sdev_printk() for logging
>   scsi: use buffer for print_opcode_name()
>   scsi: use single printk call in scsi_print_command()
>   scsi: use buffer for scsi_show_result()
>   scsi: open-code scsi_decode_sense_buffer()
>   scsi: decode descriptor sense
>   scsi: use local buffer for decoding sense data
>
>  drivers/scsi/constants.c  |  406 +++++++++++++++++++++++++--------------------
>  drivers/scsi/scsi.c       |   54 ++++---
>  drivers/scsi/scsi_error.c |  190 ++++++++++++++-------
>  drivers/scsi/scsi_lib.c   |   13 +-
>  drivers/scsi/scsi_scan.c  |   68 ++++----
>  drivers/scsi/sd.c         |   16 +-
>  drivers/scsi/sg.c         |  187 ++++++++++++---------
>  drivers/scsi/sr.c         |   47 +++---
>  drivers/scsi/sr.h         |    4 +
>  include/scsi/scsi_dbg.h   |    6 +-
>  include/scsi/scsi_eh.h    |    8 +-
>  11 files changed, 588 insertions(+), 411 deletions(-)
>


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

* Re: [PATCH 00/10] scsi: avoid linebreaks in syslog output
  2013-12-20 13:25 ` Tomas Henzl
@ 2013-12-20 13:31   ` Hannes Reinecke
  2013-12-20 13:35     ` Tomas Henzl
  0 siblings, 1 reply; 17+ messages in thread
From: Hannes Reinecke @ 2013-12-20 13:31 UTC (permalink / raw)
  To: Tomas Henzl, James Bottomley; +Cc: linux-scsi

On 12/20/2013 02:25 PM, Tomas Henzl wrote:
> Hi Hannes, James,
> 
> I'm wondering what happened to this patch-set? I think it could
> make parsing of the output for userspace programs much easier.
> Are there some problems still to solve or is this just forgotten?
> 
Oh, no. Quite the contrary.
As James has now merged my previous patchsets I'm in the process of
updating this one, too.

It'll be part of a larger patchset having a per-device
scsi_logging_level; something I was wanting to have for a _LONG_
time now.

Currently I'm fiddling with sense code printing, so I won't be able
to send anything this year. But early next year I should have
something presentable.

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 00/10] scsi: avoid linebreaks in syslog output
  2013-12-20 13:31   ` Hannes Reinecke
@ 2013-12-20 13:35     ` Tomas Henzl
  0 siblings, 0 replies; 17+ messages in thread
From: Tomas Henzl @ 2013-12-20 13:35 UTC (permalink / raw)
  To: Hannes Reinecke, James Bottomley; +Cc: linux-scsi

On 12/20/2013 02:31 PM, Hannes Reinecke wrote:
> On 12/20/2013 02:25 PM, Tomas Henzl wrote:
>> Hi Hannes, James,
>>
>> I'm wondering what happened to this patch-set? I think it could
>> make parsing of the output for userspace programs much easier.
>> Are there some problems still to solve or is this just forgotten?
>>
> Oh, no. Quite the contrary.
> As James has now merged my previous patchsets I'm in the process of
> updating this one, too.
>
> It'll be part of a larger patchset having a per-device
> scsi_logging_level; something I was wanting to have for a _LONG_
> time now.
>
> Currently I'm fiddling with sense code printing, so I won't be able
> to send anything this year. But early next year I should have
> something presentable.

Great news! thanks.

>
> Cheers,
>
> Hannes


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

end of thread, other threads:[~2013-12-20 13:35 UTC | newest]

Thread overview: 17+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2012-10-12  8:33 [PATCH 00/10] scsi: avoid linebreaks in syslog output Hannes Reinecke
2012-10-12  8:33 ` [PATCH 01/10] sg: Use dev_printk Hannes Reinecke
2012-10-12 14:34   ` Douglas Gilbert
2012-10-12  8:33 ` [PATCH 02/10] sr: Use dev_printk() Hannes Reinecke
2012-10-12  8:33 ` [PATCH 03/10] scsi: Avoid linebreaks in syslog output Hannes Reinecke
2012-10-12  8:33 ` [PATCH 04/10] scsi: Use sdev_printk() for logging Hannes Reinecke
2012-10-12  8:33 ` [PATCH 05/10] scsi: use buffer for print_opcode_name() Hannes Reinecke
2012-10-12  8:33 ` [PATCH 06/10] scsi: use single printk call in scsi_print_command() Hannes Reinecke
2012-10-12  8:33 ` [PATCH 07/10] scsi: use buffer for scsi_show_result() Hannes Reinecke
2012-10-12  8:33 ` [PATCH 08/10] scsi: open-code scsi_decode_sense_buffer() Hannes Reinecke
2012-10-12  8:33 ` [PATCH 09/10] scsi: decode descriptor sense Hannes Reinecke
2012-10-12  8:33 ` [PATCH 10/10] scsi: use local buffer for decoding sense data Hannes Reinecke
2012-10-15  0:19 ` [PATCH 00/10] scsi: avoid linebreaks in syslog output Mike Snitzer
2012-10-15  6:02   ` Hannes Reinecke
2013-12-20 13:25 ` Tomas Henzl
2013-12-20 13:31   ` Hannes Reinecke
2013-12-20 13:35     ` Tomas Henzl

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).