All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCHv2 0/6] First batch of logging cleanup
@ 2014-06-25 14:39 Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 1/6] scsi: Implement sr_printk() Hannes Reinecke
                   ` (5 more replies)
  0 siblings, 6 replies; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Hi all,

this is the first patch of my SCSI logging cleanup.
The basic idea here is to use dev_printk() and friends
throughout the midlayer, so that any logging messages
are attached with the correct device information.

This patchset is relative to the core-for-3.17 git
tree from hch + my 64-bit LUN patchset.

Changes to v1:
- Rebase to apply after 64-bit LUN patchset

Hannes Reinecke (6):
  scsi: Implement sr_printk()
  scsi: Implement sg_printk()
  scsi: Implement ch_printk()
  scsi: Implement st_printk()
  scsi: use dev_printk() variants for ioctl
  scsi: use dev_printk variants where possible

 drivers/scsi/ch.c         |  14 +-
 drivers/scsi/hosts.c      |  15 +-
 drivers/scsi/scsi.c       |  18 +-
 drivers/scsi/scsi_error.c | 179 +++++++-------
 drivers/scsi/scsi_ioctl.c |  17 +-
 drivers/scsi/scsi_lib.c   |  22 +-
 drivers/scsi/scsi_scan.c  |  62 ++---
 drivers/scsi/sg.c         | 163 +++++++------
 drivers/scsi/sr.c         |  61 ++---
 drivers/scsi/sr.h         |   4 +
 drivers/scsi/sr_ioctl.c   |  26 +-
 drivers/scsi/sr_vendor.c  |  36 +--
 drivers/scsi/st.c         | 605 ++++++++++++++++++++++++----------------------
 13 files changed, 653 insertions(+), 569 deletions(-)

-- 
1.7.12.4


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

* [PATCH 1/6] scsi: Implement sr_printk()
  2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
@ 2014-06-25 14:39 ` Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 2/6] scsi: Implement sg_printk() Hannes Reinecke
                   ` (4 subsequent siblings)
  5 siblings, 0 replies; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Update the sr driver to use dev_printk() variants instead of
plain printk(); this will prefix logging messages with the
appropriate device.

Signed-off-by: Hannes Reinecke <hare@suse.de>
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
---
 drivers/scsi/sr.c        | 61 +++++++++++++++++++++++++-----------------------
 drivers/scsi/sr.h        |  4 ++++
 drivers/scsi/sr_ioctl.c  | 26 +++++++++++++--------
 drivers/scsi/sr_vendor.c | 36 ++++++++++++++--------------
 4 files changed, 70 insertions(+), 57 deletions(-)

diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c
index 93cbd36..a7ea27c 100644
--- a/drivers/scsi/sr.c
+++ b/drivers/scsi/sr.c
@@ -292,8 +292,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 {
@@ -322,7 +322,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);
+	scmd_printk(KERN_INFO, SCpnt, "done: %x\n", result);
 #endif
 
 	/*
@@ -398,13 +398,14 @@ static int sr_init_command(struct scsi_cmnd *SCpnt)
 	 * 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;
 	}
 
@@ -425,7 +426,8 @@ static int sr_init_command(struct scsi_cmnd *SCpnt)
 		if (!in_interrupt())
 			sr_set_blocklength(cd, 2048);
 		else
-			printk("sr: can't switch blocksize: in interrupt\n");
+			scmd_printk(KERN_INFO, SCpnt,
+				    "can't switch blocksize: in interrupt\n");
 	}
 
 	if (s_size != 512 && s_size != 1024 && s_size != 2048) {
@@ -438,7 +440,7 @@ static int sr_init_command(struct scsi_cmnd *SCpnt)
 			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;
@@ -475,11 +477,11 @@ static int sr_init_command(struct scsi_cmnd *SCpnt)
 	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) ?
+	SCSI_LOG_HLQUEUE(2, scmd_printk(KERN_INFO, SCpnt,
+					"%s %d/%u 512 byte blocks.\n",
+					(rq_data_dir(rq) == WRITE) ?
 					"writing" : "reading",
-				this_count, blk_rq_sectors(rq)));
+					this_count, blk_rq_sectors(rq)));
 
 	SCpnt->cmnd[1] = 0;
 	block = (unsigned int)blk_rq_pos(rq) / (s_size >> 9);
@@ -810,8 +812,8 @@ 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.", sector_size);
 			cd->capacity = 0;
 		}
 
@@ -853,7 +855,7 @@ static void get_capabilities(struct scsi_cd *cd)
 	/* allocate transfer buffer */
 	buffer = kmalloc(512, GFP_KERNEL | GFP_DMA);
 	if (!buffer) {
-		printk(KERN_ERR "sr: out of memory.\n");
+		sr_printk(KERN_ERR, cd, "out of memory.\n");
 		return;
 	}
 
@@ -872,7 +874,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;
 	}
 
@@ -881,22 +883,23 @@ 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,
-	       ((buffer[n + 14] << 8) + buffer[n + 15]) / 176,
-	       cd->cdi.speed,
-	       buffer[n + 3] & 0x01 ? "writer " : "", /* CD Writer */
-	       buffer[n + 3] & 0x20 ? "dvd-ram " : "",
-	       buffer[n + 2] & 0x02 ? "cd/rw " : "", /* can read rewriteable */
-	       buffer[n + 4] & 0x20 ? "xa/form2 " : "",	/* can read xa/from2 */
-	       buffer[n + 5] & 0x01 ? "cdda " : "", /* can read audio data */
-	       loadmech[buffer[n + 6] >> 5]);
+	sr_printk(KERN_INFO, cd,
+		  "scsi3-mmc drive: %dx/%dx %s%s%s%s%s%s\n",
+		  ((buffer[n + 14] << 8) + buffer[n + 15]) / 176,
+		  cd->cdi.speed,
+		  buffer[n + 3] & 0x01 ? "writer " : "", /* CD Writer */
+		  buffer[n + 3] & 0x20 ? "dvd-ram " : "",
+		  buffer[n + 2] & 0x02 ? "cd/rw " : "", /* can read rewriteable */
+		  buffer[n + 4] & 0x20 ? "xa/form2 " : "",	/* can read xa/from2 */
+		  buffer[n + 5] & 0x01 ? "cdda " : "", /* can read audio data */
+		  loadmech[buffer[n + 6] >> 5]);
 	if ((buffer[n + 6] >> 5) == 0)
 		/* caddy drives can't close tray... */
 		cd->cdi.mask |= CDC_CLOSE_TRAY;
 	if ((buffer[n + 2] & 0x8) == 0)
 		/* not a DVD drive */
 		cd->cdi.mask |= CDC_DVD;
-	if ((buffer[n + 3] & 0x20) == 0) 
+	if ((buffer[n + 3] & 0x20) == 0)
 		/* can't write DVD-RAM media */
 		cd->cdi.mask |= CDC_DVD_RAM;
 	if ((buffer[n + 3] & 0x10) == 0)
@@ -935,7 +938,7 @@ static void get_capabilities(struct scsi_cd *cd)
 
 /*
  * sr_packet() is the entry point for the generic commands generated
- * by the Uniform CD-ROM layer. 
+ * by the Uniform CD-ROM layer.
  */
 static int sr_packet(struct cdrom_device_info *cdi,
 		struct packet_command *cgc)
diff --git a/drivers/scsi/sr.h b/drivers/scsi/sr.h
index 37c8f6b..5334e98 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, cd, fmt, a...) \
+	sdev_printk(prefix, (cd)->device, "[%s] " fmt, \
+		    (cd)->cdi.name, ##a)
+
 int sr_do_ioctl(Scsi_CD *, struct packet_command *);
 
 int sr_lock_door(struct cdrom_device_info *, int);
diff --git a/drivers/scsi/sr_ioctl.c b/drivers/scsi/sr_ioctl.c
index a3911c3..6389fcf 100644
--- a/drivers/scsi/sr_ioctl.c
+++ b/drivers/scsi/sr_ioctl.c
@@ -36,7 +36,6 @@ module_param(xa_test, int, S_IRUGO | S_IWUSR);
  * the status of the unchecked_isa_dma flag in the host structure */
 #define SR_GFP_DMA(cd) (((cd)->device->host->unchecked_isa_dma) ? GFP_DMA : 0)
 
-
 static int sr_read_tochdr(struct cdrom_device_info *cdi,
 		struct cdrom_tochdr *tochdr)
 {
@@ -219,7 +218,8 @@ int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
 		case UNIT_ATTENTION:
 			SDev->changed = 1;
 			if (!cgc->quiet)
-				printk(KERN_INFO "%s: disc change detected.\n", cd->cdi.name);
+				sr_printk(KERN_INFO, cd,
+					  "disc change detected.\n");
 			if (retries++ < 10)
 				goto retry;
 			err = -ENOMEDIUM;
@@ -229,7 +229,8 @@ int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
 			    sshdr.ascq == 0x01) {
 				/* sense: Logical unit is in process of becoming ready */
 				if (!cgc->quiet)
-					printk(KERN_INFO "%s: CDROM not ready yet.\n", cd->cdi.name);
+					sr_printk(KERN_INFO, cd,
+						  "CDROM not ready yet.\n");
 				if (retries++ < 10) {
 					/* sleep 2 sec and try again */
 					ssleep(2);
@@ -241,7 +242,9 @@ int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
 				}
 			}
 			if (!cgc->quiet)
-				printk(KERN_INFO "%s: CDROM not ready.  Make sure there is a disc in the drive.\n", cd->cdi.name);
+				sr_printk(KERN_INFO, cd,
+					  "CDROM not ready.  Make sure there "
+					  "is a disc in the drive.\n");
 #ifdef DEBUG
 			scsi_print_sense_hdr("sr", &sshdr);
 #endif
@@ -259,7 +262,8 @@ int sr_do_ioctl(Scsi_CD *cd, struct packet_command *cgc)
 #endif
 			break;
 		default:
-			printk(KERN_ERR "%s: CDROM (ioctl) error, command: ", cd->cdi.name);
+			sr_printk(KERN_ERR, cd,
+				  "CDROM (ioctl) error, command: ");
 			__scsi_print_command(cgc->cmd);
 			scsi_print_sense_hdr("sr", &sshdr);
 			err = -EIO;
@@ -491,8 +495,8 @@ static int sr_read_cd(Scsi_CD *cd, unsigned char *dest, int lba, int format, int
 	struct packet_command cgc;
 
 #ifdef DEBUG
-	printk("%s: sr_read_cd lba=%d format=%d blksize=%d\n",
-	       cd->cdi.name, lba, format, blksize);
+	sr_printk(KERN_INFO, cd, "sr_read_cd lba=%d format=%d blksize=%d\n",
+		  lba, format, blksize);
 #endif
 
 	memset(&cgc, 0, sizeof(struct packet_command));
@@ -539,7 +543,8 @@ static int sr_read_sector(Scsi_CD *cd, int lba, int blksize, unsigned char *dest
 		if (-EDRIVE_CANT_DO_THIS != rc)
 			return rc;
 		cd->readcd_known = 0;
-		printk("CDROM does'nt support READ CD (0xbe) command\n");
+		sr_printk(KERN_INFO, cd,
+			  "CDROM does'nt support READ CD (0xbe) command\n");
 		/* fall & retry the other way */
 	}
 	/* ... if this fails, we switch the blocksize using MODE SELECT */
@@ -548,7 +553,8 @@ static int sr_read_sector(Scsi_CD *cd, int lba, int blksize, unsigned char *dest
 			return rc;
 	}
 #ifdef DEBUG
-	printk("%s: sr_read_sector lba=%d blksize=%d\n", cd->cdi.name, lba, blksize);
+	sr_printk(KERN_INFO, cd, "sr_read_sector lba=%d blksize=%d\n",
+		  lba, blksize);
 #endif
 
 	memset(&cgc, 0, sizeof(struct packet_command));
@@ -592,7 +598,7 @@ int sr_is_xa(Scsi_CD *cd)
 	}
 	kfree(raw_sector);
 #ifdef DEBUG
-	printk("%s: sr_is_xa: %d\n", cd->cdi.name, is_xa);
+	sr_printk(KERN_INFO, cd, "sr_is_xa: %d\n", is_xa);
 #endif
 	return is_xa;
 }
diff --git a/drivers/scsi/sr_vendor.c b/drivers/scsi/sr_vendor.c
index 92cc2ef..11a238c 100644
--- a/drivers/scsi/sr_vendor.c
+++ b/drivers/scsi/sr_vendor.c
@@ -123,7 +123,7 @@ int sr_set_blocklength(Scsi_CD *cd, int blocklength)
 		return -ENOMEM;
 
 #ifdef DEBUG
-	printk("%s: MODE SELECT 0x%x/%d\n", cd->cdi.name, density, blocklength);
+	sr_printk(KERN_INFO, cd, "MODE SELECT 0x%x/%d\n", density, blocklength);
 #endif
 	memset(&cgc, 0, sizeof(struct packet_command));
 	cgc.cmd[0] = MODE_SELECT;
@@ -144,8 +144,9 @@ int sr_set_blocklength(Scsi_CD *cd, int blocklength)
 	}
 #ifdef DEBUG
 	else
-		printk("%s: switching blocklength to %d bytes failed\n",
-		       cd->cdi.name, blocklength);
+		sr_printk(KERN_INFO, cd,
+			  "switching blocklength to %d bytes failed\n",
+			  blocklength);
 #endif
 	kfree(buffer);
 	return rc;
@@ -190,8 +191,8 @@ int sr_cd_check(struct cdrom_device_info *cdi)
 		if (rc != 0)
 			break;
 		if ((buffer[0] << 8) + buffer[1] < 0x0a) {
-			printk(KERN_INFO "%s: Hmm, seems the drive "
-			   "doesn't support multisession CD's\n", cd->cdi.name);
+			sr_printk(KERN_INFO, cd, "Hmm, seems the drive "
+			   "doesn't support multisession CD's\n");
 			no_multi = 1;
 			break;
 		}
@@ -218,9 +219,9 @@ int sr_cd_check(struct cdrom_device_info *cdi)
 			if (rc != 0)
 				break;
 			if (buffer[14] != 0 && buffer[14] != 0xb0) {
-				printk(KERN_INFO "%s: Hmm, seems the cdrom "
-				       "doesn't support multisession CD's\n",
-				       cd->cdi.name);
+				sr_printk(KERN_INFO, cd, "Hmm, seems the cdrom "
+					  "doesn't support multisession CD's\n");
+
 				no_multi = 1;
 				break;
 			}
@@ -245,9 +246,8 @@ int sr_cd_check(struct cdrom_device_info *cdi)
 			cgc.timeout = VENDOR_TIMEOUT;
 			rc = sr_do_ioctl(cd, &cgc);
 			if (rc == -EINVAL) {
-				printk(KERN_INFO "%s: Hmm, seems the drive "
-				       "doesn't support multisession CD's\n",
-				       cd->cdi.name);
+				sr_printk(KERN_INFO, cd, "Hmm, seems the drive "
+					  "doesn't support multisession CD's\n");
 				no_multi = 1;
 				break;
 			}
@@ -277,8 +277,8 @@ int sr_cd_check(struct cdrom_device_info *cdi)
 			break;
 		}
 		if ((rc = buffer[2]) == 0) {
-			printk(KERN_WARNING
-			       "%s: No finished session\n", cd->cdi.name);
+			sr_printk(KERN_WARNING, cd,
+				  "No finished session\n");
 			break;
 		}
 		cgc.cmd[0] = READ_TOC;	/* Read TOC */
@@ -301,9 +301,9 @@ int sr_cd_check(struct cdrom_device_info *cdi)
 
 	default:
 		/* should not happen */
-		printk(KERN_WARNING
-		   "%s: unknown vendor code (%i), not initialized ?\n",
-		       cd->cdi.name, cd->vendor);
+		sr_printk(KERN_WARNING, cd,
+			  "unknown vendor code (%i), not initialized ?\n",
+			  cd->vendor);
 		sector = 0;
 		no_multi = 1;
 		break;
@@ -321,8 +321,8 @@ int sr_cd_check(struct cdrom_device_info *cdi)
 
 #ifdef DEBUG
 	if (sector)
-		printk(KERN_DEBUG "%s: multisession offset=%lu\n",
-		       cd->cdi.name, sector);
+		sr_printk(KERN_DEBUG, cd, "multisession offset=%lu\n",
+			  sector);
 #endif
 	kfree(buffer);
 	return rc;
-- 
1.7.12.4


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

* [PATCH 2/6] scsi: Implement sg_printk()
  2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 1/6] scsi: Implement sr_printk() Hannes Reinecke
@ 2014-06-25 14:39 ` Hannes Reinecke
  2014-06-25 20:21   ` Douglas Gilbert
  2014-06-25 14:39 ` [PATCH 3/6] scsi: Implement ch_printk() Hannes Reinecke
                   ` (3 subsequent siblings)
  5 siblings, 1 reply; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Update the sg driver to use dev_printk() variants instead of
plain printk(); this will prefix logging messages with the
appropriate device.

Signed-off-by: Hannes Reinecke <hare@suse.de>
Acked-by: Doug Gilbert <dgilbert@interlog.com>
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
---
 drivers/scsi/sg.c | 163 +++++++++++++++++++++++++++++++-----------------------
 1 file changed, 95 insertions(+), 68 deletions(-)

diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c
index f27b70d..cb2a18e 100644
--- a/drivers/scsi/sg.c
+++ b/drivers/scsi/sg.c
@@ -199,11 +199,11 @@ 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_fd * sfp, Sg_scatter_hold * schp);
 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);
-static Sg_fd *sg_add_sfp(Sg_device * sdp, int dev);
+static Sg_fd *sg_add_sfp(Sg_device * sdp);
 static void sg_remove_sfp(struct kref *);
 static Sg_request *sg_get_rq_mark(Sg_fd * sfp, int pack_id);
 static Sg_request *sg_add_request(Sg_fd * sfp);
@@ -217,6 +217,10 @@ static void sg_device_destroy(struct kref *kref);
 #define SZ_SG_IOVEC sizeof(sg_iovec_t)
 #define SZ_SG_REQ_INFO sizeof(sg_req_info_t)
 
+#define sg_printk(prefix, sdp, fmt, a...) \
+	sdev_printk(prefix, (sdp)->device, "[%s] " fmt, \
+		    (sdp)->disk->disk_name, ##a)
+
 static int sg_allow_access(struct file *filp, unsigned char *cmd)
 {
 	struct sg_fd *sfp = filp->private_data;
@@ -275,13 +279,15 @@ 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));
 	if ((flags & O_EXCL) && (O_RDONLY == (flags & O_ACCMODE)))
 		return -EPERM; /* Can't lock it with read only access */
 	sdp = sg_get_dev(dev);
 	if (IS_ERR(sdp))
 		return PTR_ERR(sdp);
 
+	SCSI_LOG_TIMEOUT(3, sg_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 */
 	retval = scsi_device_get(sdp->device);
@@ -330,7 +336,7 @@ sg_open(struct inode *inode, struct file *filp)
 		q = sdp->device->request_queue;
 		sdp->sg_tablesize = queue_max_segments(q);
 	}
-	sfp = sg_add_sfp(sdp, dev);
+	sfp = sg_add_sfp(sdp);
 	if (IS_ERR(sfp)) {
 		retval = PTR_ERR(sfp);
 		goto out_undo;
@@ -369,7 +375,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, sg_printk(KERN_INFO, sdp, "sg_release\n"));
 
 	mutex_lock(&sdp->open_rel_lock);
 	scsi_autopm_put_device(sdp->device);
@@ -401,8 +407,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, sg_printk(KERN_INFO, sdp,
+				      "sg_read: count=%d\n", (int) count));
 
 	if (!access_ok(VERIFY_WRITE, buf, count))
 		return -EFAULT;
@@ -587,8 +593,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, sg_printk(KERN_INFO, sdp,
+				      "sg_write: count=%d\n", (int) count));
 	if (atomic_read(&sdp->detaching))
 		return -ENODEV;
 	if (!((filp->f_flags & O_NONBLOCK) ||
@@ -609,7 +615,8 @@ 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, sg_printk(KERN_INFO, sdp,
+					      "sg_write: queue full\n"));
 		return -EDOM;
 	}
 	buf += SZ_SG_HEADER;
@@ -622,7 +629,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, sg_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;
@@ -697,7 +704,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, sg_printk(KERN_INFO, sfp->parentdp,
+					      "sg_new_write: queue full\n"));
 		return -EDOM;
 	}
 	srp->sg_io_owned = sg_io_owned;
@@ -766,12 +774,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, sg_printk(KERN_INFO, sfp->parentdp,
+			"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, sg_printk(KERN_INFO, sfp->parentdp,
+			"sg_common_write: start_req err=%d\n", k));
 		sg_finish_rem_req(srp);
 		return k;	/* probably out of space --> ENOMEM */
 	}
@@ -845,8 +855,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, sg_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) {
@@ -898,7 +908,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, &sfp->reserve);
 				sg_build_reserve(sfp, val);
 			}
 		} else {
@@ -974,7 +984,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, &sfp->reserve);
 			sg_build_reserve(sfp, val);
 		}
 		return 0;
@@ -1197,8 +1207,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, sg_printk(KERN_INFO, sdp,
+				      "sg_poll: res=0x%x\n", (int) res));
 	return res;
 }
 
@@ -1210,8 +1220,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, sg_printk(KERN_INFO, sdp,
+				      "sg_fasync: mode=%d\n", mode));
 
 	return fasync_helper(fd, filp, mode, &sfp->async_qp);
 }
@@ -1230,8 +1240,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, sg_printk(KERN_INFO, sfp->parentdp,
+				      "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++) {
@@ -1266,8 +1277,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, sg_printk(KERN_INFO, sfp->parentdp,
+				      "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;
@@ -1329,8 +1341,9 @@ sg_rq_end_io(struct request *rq, int uptodate)
 	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, sg_printk(KERN_INFO, sdp,
+				      "sg_cmd_done: pack_id=%d, res=0x%x\n",
+				      srp->header.pack_id, result));
 	srp->header.resid = resid;
 	ms = jiffies_to_msecs(jiffies);
 	srp->header.duration = (ms > srp->header.duration) ?
@@ -1440,7 +1453,8 @@ sg_alloc(struct gendisk *disk, struct scsi_device *scsidp)
 	}
 	k = error;
 
-	SCSI_LOG_TIMEOUT(3, printk("sg_alloc: dev=%d \n", k));
+	SCSI_LOG_TIMEOUT(3, sdev_printk(KERN_INFO, scsidp,
+					"sg_alloc: dev=%d \n", k));
 	sprintf(disk->disk_name, "sg%d", k);
 	disk->first_minor = k;
 	sdp->disk = disk;
@@ -1560,8 +1574,7 @@ sg_device_destroy(struct kref *kref)
 	write_unlock_irqrestore(&sg_index_lock, flags);
 
 	SCSI_LOG_TIMEOUT(3,
-		printk("sg_device_destroy: %s\n",
-			sdp->disk->disk_name));
+		sg_printk(KERN_INFO, sdp, "sg_device_destroy\n"));
 
 	put_disk(sdp->disk);
 	kfree(sdp);
@@ -1583,8 +1596,8 @@ sg_remove_device(struct device *cl_dev, struct class_interface *cl_intf)
 	if (val > 1)
 		return; /* only want to do following once per device */
 
-	SCSI_LOG_TIMEOUT(3, printk("%s: %s\n", __func__,
-			 sdp->disk->disk_name));
+	SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp,
+				      "%s\n", __func__));
 
 	read_lock_irqsave(&sdp->sfd_lock, iflags);
 	list_for_each_entry(sfp, &sdp->sfds, sfd_siblings) {
@@ -1686,8 +1699,9 @@ sg_start_req(Sg_request *srp, unsigned char *cmd)
 	int rw = hp->dxfer_direction == SG_DXFER_TO_DEV ? WRITE : READ;
 	unsigned char *long_cmdp = NULL;
 
-	SCSI_LOG_TIMEOUT(4, printk(KERN_INFO "sg_start_req: dxfer_len=%d\n",
-				   dxfer_len));
+	SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sfp->parentdp,
+				      "sg_start_req: dxfer_len=%d\n",
+				      dxfer_len));
 
 	if (hp->cmd_len > BLK_MAX_CDB) {
 		long_cmdp = kzalloc(hp->cmd_len, GFP_KERNEL);
@@ -1785,7 +1799,9 @@ 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, sg_printk(KERN_INFO, sfp->parentdp,
+				      "sg_finish_rem_req: res_used=%d\n",
+				      (int) srp->res_used));
 	if (srp->rq) {
 		if (srp->bio)
 			ret = blk_rq_unmap_user(srp->bio);
@@ -1798,7 +1814,7 @@ 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(sfp, req_schp);
 
 	sg_remove_request(sfp, srp);
 
@@ -1832,8 +1848,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, sg_printk(KERN_INFO, sfp->parentdp,
+		"sg_build_indirect: buff_size=%d, blk_size=%d\n",
+		buff_size, blk_size));
 
 	/* N.B. ret_sz carried into this block ... */
 	mx_sc_elems = sg_build_sgat(schp, sfp, sg_tablesize);
@@ -1876,14 +1893,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, sg_printk(KERN_INFO, sfp->parentdp,
+				 "sg_build_indirect: k=%d, num=%d, ret_sz=%d\n",
+				 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, sg_printk(KERN_INFO, sfp->parentdp,
+			 "sg_build_indirect: k_use_sg=%d, rem_sz=%d\n",
+			 k, rem_sz));
 
 	schp->bufflen = blk_size;
 	if (rem_sz > 0)	/* must have failed */
@@ -1900,17 +1919,19 @@ out:
 }
 
 static void
-sg_remove_scat(Sg_scatter_hold * schp)
+sg_remove_scat(Sg_fd * sfp, Sg_scatter_hold * schp)
 {
-	SCSI_LOG_TIMEOUT(4, printk("sg_remove_scat: k_use_sg=%d\n", schp->k_use_sg));
+	SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sfp->parentdp,
+			 "sg_remove_scat: k_use_sg=%d\n", 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",
-				    k, schp->pages[k]));
+				SCSI_LOG_TIMEOUT(5,
+					sg_printk(KERN_INFO, sfp->parentdp,
+					"sg_remove_scat: k=%d, pg=0x%p\n",
+					k, schp->pages[k]));
 				__free_pages(schp->pages[k], schp->page_order);
 			}
 
@@ -1926,8 +1947,9 @@ 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, sg_printk(KERN_INFO, srp->parentfp->parentdp,
+			 "sg_read_oxfer: num_read_xfer=%d\n",
+			 num_read_xfer));
 	if ((!outp) || (num_read_xfer <= 0))
 		return 0;
 
@@ -1957,14 +1979,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, sg_printk(KERN_INFO, sfp->parentdp,
+			 "sg_build_reserve: req_size=%d\n", 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(sfp, schp);
 		req_size >>= 1;	/* divide by 2 */
 	} while (req_size > (PAGE_SIZE / 2));
 }
@@ -1977,7 +2000,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, sg_printk(KERN_INFO, sfp->parentdp,
+			 "sg_link_reserve: size=%d\n", size));
 	rem = size;
 
 	num = 1 << (PAGE_SHIFT + rsv_schp->page_order);
@@ -1995,7 +2019,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, sg_printk(KERN_INFO, sfp->parentdp,
+				 "sg_link_reserve: BAD size\n"));
 }
 
 static void
@@ -2003,8 +2028,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, sg_printk(KERN_INFO, srp->parentfp->parentdp,
+				      "sg_unlink_reserve: req->k_use_sg=%d\n",
+				      (int) req_schp->k_use_sg));
 	req_schp->k_use_sg = 0;
 	req_schp->bufflen = 0;
 	req_schp->pages = NULL;
@@ -2109,7 +2135,7 @@ sg_remove_request(Sg_fd * sfp, Sg_request * srp)
 }
 
 static Sg_fd *
-sg_add_sfp(Sg_device * sdp, int dev)
+sg_add_sfp(Sg_device * sdp)
 {
 	Sg_fd *sfp;
 	unsigned long iflags;
@@ -2138,15 +2164,18 @@ sg_add_sfp(Sg_device * sdp, int dev)
 	}
 	list_add_tail(&sfp->sfd_siblings, &sdp->sfds);
 	write_unlock_irqrestore(&sdp->sfd_lock, iflags);
-	SCSI_LOG_TIMEOUT(3, printk("sg_add_sfp: sfp=0x%p\n", sfp));
+	SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp,
+				      "sg_add_sfp: sfp=0x%p\n", sfp));
 	if (unlikely(sg_big_buff != def_reserved_size))
 		sg_big_buff = def_reserved_size;
 
 	bufflen = min_t(int, sg_big_buff,
 			max_sectors_bytes(sdp->device->request_queue));
 	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, sg_printk(KERN_INFO, sdp,
+				      "sg_add_sfp: bufflen=%d, k_use_sg=%d\n",
+				      sfp->reserve.bufflen,
+				      sfp->reserve.k_use_sg));
 
 	kref_get(&sdp->d_ref);
 	__module_get(THIS_MODULE);
@@ -2164,17 +2193,15 @@ sg_remove_sfp_usercontext(struct work_struct *work)
 		sg_finish_rem_req(sfp->headrp);
 
 	if (sfp->reserve.bufflen > 0) {
-		SCSI_LOG_TIMEOUT(6,
-			printk("sg_remove_sfp:    bufflen=%d, k_use_sg=%d\n",
+		SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp,
+				"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);
+		sg_remove_scat(sfp, &sfp->reserve);
 	}
 
-	SCSI_LOG_TIMEOUT(6,
-		printk("sg_remove_sfp: %s, sfp=0x%p\n",
-			sdp->disk->disk_name,
-			sfp));
+	SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp,
+			"sg_remove_sfp: sfp=0x%p\n", sfp));
 	kfree(sfp);
 
 	scsi_device_put(sdp->device);
-- 
1.7.12.4


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

* [PATCH 3/6] scsi: Implement ch_printk()
  2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 1/6] scsi: Implement sr_printk() Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 2/6] scsi: Implement sg_printk() Hannes Reinecke
@ 2014-06-25 14:39 ` Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 4/6] scsi: Implement st_printk() Hannes Reinecke
                   ` (2 subsequent siblings)
  5 siblings, 0 replies; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Update the ch driver to use dev_printk() variants instead of
plain printk(); this will prefix logging messages with the
appropriate device.

Signed-off-by: Hannes Reinecke <hare@suse.de>
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
---
 drivers/scsi/ch.c | 14 +++++++++-----
 1 file changed, 9 insertions(+), 5 deletions(-)

diff --git a/drivers/scsi/ch.c b/drivers/scsi/ch.c
index 2a32374..ba1c3bf 100644
--- a/drivers/scsi/ch.c
+++ b/drivers/scsi/ch.c
@@ -84,15 +84,19 @@ static const char * vendor_labels[CH_TYPES-4] = {
 };
 // module_param_string_array(vendor_labels, NULL, 0444);
 
+#define ch_printk(prefix, ch, fmt, a...) \
+	sdev_printk(prefix, (ch)->device, "[%s] " fmt, \
+		    (ch)->name, ##a)
+
 #define DPRINTK(fmt, arg...)						\
 do {									\
 	if (debug)							\
-		printk(KERN_DEBUG "%s: " fmt, ch->name, ##arg);		\
+		ch_printk(KERN_DEBUG, ch, fmt, ##arg);			\
 } while (0)
 #define VPRINTK(level, fmt, arg...)					\
 do {									\
 	if (verbose)							\
-		printk(level "%s: " fmt, ch->name, ##arg);		\
+		ch_printk(level, ch, fmt, ##arg);			\
 } while (0)
 
 /* ------------------------------------------------------------------- */
@@ -196,7 +200,7 @@ ch_do_scsi(scsi_changer *ch, unsigned char *cmd,
 		__scsi_print_command(cmd);
 	}
 
-        result = scsi_execute_req(ch->device, cmd, direction, buffer,
+	result = scsi_execute_req(ch->device, cmd, direction, buffer,
 				  buflength, &sshdr, timeout * HZ,
 				  MAX_RETRIES, NULL);
 
@@ -924,8 +928,8 @@ static int ch_probe(struct device *dev)
 				  MKDEV(SCSI_CHANGER_MAJOR, ch->minor), ch,
 				  "s%s", ch->name);
 	if (IS_ERR(class_dev)) {
-		printk(KERN_WARNING "ch%d: device_create failed\n",
-		       ch->minor);
+		sdev_printk(KERN_WARNING, sd, "ch%d: device_create failed\n",
+			    ch->minor);
 		ret = PTR_ERR(class_dev);
 		goto remove_idr;
 	}
-- 
1.7.12.4


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

* [PATCH 4/6] scsi: Implement st_printk()
  2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
                   ` (2 preceding siblings ...)
  2014-06-25 14:39 ` [PATCH 3/6] scsi: Implement ch_printk() Hannes Reinecke
@ 2014-06-25 14:39 ` Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 5/6] scsi: use dev_printk() variants for ioctl Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 6/6] scsi: use dev_printk variants where possible Hannes Reinecke
  5 siblings, 0 replies; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Update the st driver to use dev_printk() variants instead of
plain printk(); this will prefix logging messages with the
appropriate device.

Signed-off-by: Hannes Reinecke <hare@suse.de>
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
---
 drivers/scsi/st.c | 605 ++++++++++++++++++++++++++++--------------------------
 1 file changed, 311 insertions(+), 294 deletions(-)

diff --git a/drivers/scsi/st.c b/drivers/scsi/st.c
index 14eb4b2..aff9689 100644
--- a/drivers/scsi/st.c
+++ b/drivers/scsi/st.c
@@ -58,11 +58,11 @@ static const char *verstr = "20101219";
    is defined and non-zero. */
 #define DEBUG 0
 
+#define ST_DEB_MSG  KERN_NOTICE
 #if DEBUG
 /* The message level for the debug messages is currently set to KERN_NOTICE
    so that people can easily see the messages. Later when the debugging messages
    in the drivers are more widely classified, this may be changed to KERN_DEBUG. */
-#define ST_DEB_MSG  KERN_NOTICE
 #define DEB(a) a
 #define DEBC(a) if (debugging) { a ; }
 #else
@@ -305,6 +305,15 @@ static inline char *tape_name(struct scsi_tape *tape)
 	return tape->disk->disk_name;
 }
 
+#define st_printk(prefix, t, fmt, a...) \
+	sdev_printk(prefix, (t)->device, "%s: " fmt, \
+		    tape_name(t), ##a)
+#ifdef DEBUG
+#define DEBC_printk(t, fmt, a...) \
+	if (debugging) { st_printk(ST_DEB_MSG, t, fmt, ##a ); }
+#else
+#define DEBC_printk(t, fmt, a...)
+#endif
 
 static void st_analyze_sense(struct st_request *SRpnt, struct st_cmdstatus *s)
 {
@@ -358,21 +367,20 @@ static int st_chk_result(struct scsi_tape *STp, struct st_request * SRpnt)
 	else
 		scode = 0;
 
-        DEB(
-        if (debugging) {
-                printk(ST_DEB_MSG "%s: Error: %x, cmd: %x %x %x %x %x %x\n",
-		       name, result,
-		       SRpnt->cmd[0], SRpnt->cmd[1], SRpnt->cmd[2],
-		       SRpnt->cmd[3], SRpnt->cmd[4], SRpnt->cmd[5]);
+	DEB(
+	if (debugging) {
+		st_printk(ST_DEB_MSG, STp,
+			    "Error: %x, cmd: %x %x %x %x %x %x\n", result,
+			    SRpnt->cmd[0], SRpnt->cmd[1], SRpnt->cmd[2],
+			    SRpnt->cmd[3], SRpnt->cmd[4], SRpnt->cmd[5]);
 		if (cmdstatp->have_sense)
 			 __scsi_print_sense(name, SRpnt->sense, SCSI_SENSE_BUFFERSIZE);
 	} ) /* end DEB */
 	if (!debugging) { /* Abnormal conditions for tape */
 		if (!cmdstatp->have_sense)
-			printk(KERN_WARNING
-			       "%s: Error %x (driver bt 0x%x, host bt 0x%x).\n",
-			       name, result, driver_byte(result),
-			       host_byte(result));
+			st_printk(KERN_WARNING, STp,
+			       "Error %x (driver bt 0x%x, host bt 0x%x).\n",
+			       result, driver_byte(result), host_byte(result));
 		else if (cmdstatp->have_sense &&
 			 scode != NO_SENSE &&
 			 scode != RECOVERED_ERROR &&
@@ -411,7 +419,7 @@ static int st_chk_result(struct scsi_tape *STp, struct st_request * SRpnt)
 		STp->recover_count++;
 		STp->recover_reg++;
 
-                DEB(
+		DEB(
 		if (debugging) {
 			if (SRpnt->cmd[0] == READ_6)
 				stp = "read";
@@ -419,8 +427,9 @@ static int st_chk_result(struct scsi_tape *STp, struct st_request * SRpnt)
 				stp = "write";
 			else
 				stp = "ioctl";
-			printk(ST_DEB_MSG "%s: Recovered %s error (%d).\n", name, stp,
-			       STp->recover_count);
+			st_printk(ST_DEB_MSG, STp,
+				  "Recovered %s error (%d).\n",
+				  stp, STp->recover_count);
 		} ) /* end DEB */
 
 		if (cmdstatp->flags == 0)
@@ -437,8 +446,8 @@ static struct st_request *st_allocate_request(struct scsi_tape *stp)
 	if (streq)
 		streq->stp = stp;
 	else {
-		DEBC(printk(KERN_ERR "%s: Can't get SCSI request.\n",
-			    tape_name(stp)););
+		st_printk(KERN_ERR, stp,
+			  "Can't get SCSI request.\n");
 		if (signal_pending(current))
 			stp->buffer->syscall_result = -EINTR;
 		else
@@ -525,8 +534,8 @@ st_do_scsi(struct st_request * SRpnt, struct scsi_tape * STp, unsigned char *cmd
 
 	/* if async, make sure there's no command outstanding */
 	if (!do_wait && ((STp->buffer)->last_SRpnt)) {
-		printk(KERN_ERR "%s: Async command already active.\n",
-		       tape_name(STp));
+		st_printk(KERN_ERR, STp,
+			  "Async command already active.\n");
 		if (signal_pending(current))
 			(STp->buffer)->syscall_result = (-EINTR);
 		else
@@ -597,12 +606,12 @@ static int write_behind_check(struct scsi_tape * STp)
 	if (!STbuffer->writing)
 		return 0;
 
-        DEB(
+	DEB(
 	if (STp->write_pending)
 		STp->nbr_waits++;
 	else
 		STp->nbr_finished++;
-        ) /* end DEB */
+	) /* end DEB */
 
 	wait_for_completion(&(STp->wait));
 	SRpnt = STbuffer->last_SRpnt;
@@ -639,8 +648,9 @@ static int write_behind_check(struct scsi_tape * STp)
 	STbuffer->writing = 0;
 
 	DEB(if (debugging && retval)
-	    printk(ST_DEB_MSG "%s: Async write error %x, return value %d.\n",
-		   tape_name(STp), STbuffer->cmdstat.midlevel_result, retval);) /* end DEB */
+		    st_printk(ST_DEB_MSG, STp,
+				"Async write error %x, return value %d.\n",
+				STbuffer->cmdstat.midlevel_result, retval);) /* end DEB */
 
 	return retval;
 }
@@ -662,8 +672,8 @@ static int cross_eof(struct scsi_tape * STp, int forward)
 		cmd[2] = cmd[3] = cmd[4] = 0xff;	/* -1 filemarks */
 	cmd[5] = 0;
 
-        DEBC(printk(ST_DEB_MSG "%s: Stepping over filemark %s.\n",
-		   tape_name(STp), forward ? "forward" : "backward"));
+	DEBC_printk(STp, "Stepping over filemark %s.\n",
+		    forward ? "forward" : "backward");
 
 	SRpnt = st_do_scsi(NULL, STp, cmd, 0, DMA_NONE,
 			   STp->device->request_queue->rq_timeout,
@@ -675,8 +685,9 @@ static int cross_eof(struct scsi_tape * STp, int forward)
 	SRpnt = NULL;
 
 	if ((STp->buffer)->cmdstat.midlevel_result != 0)
-		printk(KERN_ERR "%s: Stepping over filemark %s failed.\n",
-		   tape_name(STp), forward ? "forward" : "backward");
+		st_printk(KERN_ERR, STp,
+			  "Stepping over filemark %s failed.\n",
+			  forward ? "forward" : "backward");
 
 	return (STp->buffer)->syscall_result;
 }
@@ -699,8 +710,7 @@ static int st_flush_write_buffer(struct scsi_tape * STp)
 	if (STp->dirty == 1) {
 
 		transfer = STp->buffer->buffer_bytes;
-                DEBC(printk(ST_DEB_MSG "%s: Flushing %d bytes.\n",
-                               tape_name(STp), transfer));
+		DEBC_printk(STp, "Flushing %d bytes.\n", transfer);
 
 		memset(cmd, 0, MAX_COMMAND_SIZE);
 		cmd[0] = WRITE_6;
@@ -732,8 +742,7 @@ static int st_flush_write_buffer(struct scsi_tape * STp)
 					STps->drv_block += blks;
 				result = (-ENOSPC);
 			} else {
-				printk(KERN_ERR "%s: Error on flush.\n",
-                                       tape_name(STp));
+				st_printk(KERN_ERR, STp, "Error on flush.\n");
 				STps->drv_block = (-1);
 				result = (-EIO);
 			}
@@ -811,7 +820,6 @@ static int set_mode_densblk(struct scsi_tape * STp, struct st_modedef * STm)
 {
 	int set_it = 0;
 	unsigned long arg;
-	char *name = tape_name(STp);
 
 	if (!STp->density_changed &&
 	    STm->default_density >= 0 &&
@@ -830,9 +838,10 @@ static int set_mode_densblk(struct scsi_tape * STp, struct st_modedef * STm)
 		arg |= STp->block_size;
 	if (set_it &&
 	    st_int_ioctl(STp, SET_DENS_AND_BLK, arg)) {
-		printk(KERN_WARNING
-		       "%s: Can't set default block size to %d bytes and density %x.\n",
-		       name, STm->default_blksize, STm->default_density);
+		st_printk(KERN_WARNING, STp,
+			  "Can't set default block size to %d bytes "
+			  "and density %x.\n",
+			  STm->default_blksize, STm->default_density);
 		if (modes_defined)
 			return (-EINVAL);
 	}
@@ -844,12 +853,9 @@ static int set_mode_densblk(struct scsi_tape * STp, struct st_modedef * STm)
 static int do_door_lock(struct scsi_tape * STp, int do_lock)
 {
 	int retval, cmd;
-	DEB(char *name = tape_name(STp);)
-
 
 	cmd = do_lock ? SCSI_IOCTL_DOORLOCK : SCSI_IOCTL_DOORUNLOCK;
-	DEBC(printk(ST_DEB_MSG "%s: %socking drive door.\n", name,
-		    do_lock ? "L" : "Unl"));
+	DEBC_printk(STp, "%socking drive door.\n", do_lock ? "L" : "Unl");
 	retval = scsi_ioctl(STp->device, cmd, NULL);
 	if (!retval) {
 		STp->door_locked = do_lock ? ST_LOCKED_EXPLICIT : ST_UNLOCKED;
@@ -976,15 +982,14 @@ static int check_tape(struct scsi_tape *STp, struct file *filp)
 	struct st_request *SRpnt = NULL;
 	struct st_modedef *STm;
 	struct st_partstat *STps;
-	char *name = tape_name(STp);
 	struct inode *inode = file_inode(filp);
 	int mode = TAPE_MODE(inode);
 
 	STp->ready = ST_READY;
 
 	if (mode != STp->current_mode) {
-                DEBC(printk(ST_DEB_MSG "%s: Mode change from %d to %d.\n",
-			       name, STp->current_mode, mode));
+		DEBC_printk(STp, "Mode change from %d to %d.\n",
+			    STp->current_mode, mode);
 		new_session = 1;
 		STp->current_mode = mode;
 	}
@@ -1055,13 +1060,12 @@ static int check_tape(struct scsi_tape *STp, struct file *filp)
 			STp->min_block = ((STp->buffer)->b_data[4] << 8) |
 			    (STp->buffer)->b_data[5];
 			if ( DEB( debugging || ) !STp->inited)
-				printk(KERN_INFO
-                                       "%s: Block limits %d - %d bytes.\n", name,
-                                       STp->min_block, STp->max_block);
+				st_printk(KERN_INFO, STp,
+					  "Block limits %d - %d bytes.\n",
+					  STp->min_block, STp->max_block);
 		} else {
 			STp->min_block = STp->max_block = (-1);
-                        DEBC(printk(ST_DEB_MSG "%s: Can't read block limits.\n",
-                                       name));
+			DEBC_printk(STp, "Can't read block limits.\n");
 		}
 	}
 
@@ -1078,56 +1082,58 @@ static int check_tape(struct scsi_tape *STp, struct file *filp)
 	}
 
 	if ((STp->buffer)->syscall_result != 0) {
-                DEBC(printk(ST_DEB_MSG "%s: No Mode Sense.\n", name));
+		DEBC_printk(STp, "No Mode Sense.\n");
 		STp->block_size = ST_DEFAULT_BLOCK;	/* Educated guess (?) */
 		(STp->buffer)->syscall_result = 0;	/* Prevent error propagation */
 		STp->drv_write_prot = 0;
 	} else {
-                DEBC(printk(ST_DEB_MSG
-                            "%s: Mode sense. Length %d, medium %x, WBS %x, BLL %d\n",
-                            name,
-                            (STp->buffer)->b_data[0], (STp->buffer)->b_data[1],
-                            (STp->buffer)->b_data[2], (STp->buffer)->b_data[3]));
+		DEBC_printk(STp,"Mode sense. Length %d, "
+			    "medium %x, WBS %x, BLL %d\n",
+			    (STp->buffer)->b_data[0],
+			    (STp->buffer)->b_data[1],
+			    (STp->buffer)->b_data[2],
+			    (STp->buffer)->b_data[3]);
 
 		if ((STp->buffer)->b_data[3] >= 8) {
 			STp->drv_buffer = ((STp->buffer)->b_data[2] >> 4) & 7;
 			STp->density = (STp->buffer)->b_data[4];
 			STp->block_size = (STp->buffer)->b_data[9] * 65536 +
 			    (STp->buffer)->b_data[10] * 256 + (STp->buffer)->b_data[11];
-                        DEBC(printk(ST_DEB_MSG
-                                    "%s: Density %x, tape length: %x, drv buffer: %d\n",
-                                    name, STp->density, (STp->buffer)->b_data[5] * 65536 +
-                                    (STp->buffer)->b_data[6] * 256 + (STp->buffer)->b_data[7],
-                                    STp->drv_buffer));
+			DEBC_printk(STp, "Density %x, tape length: %x, "
+				    "drv buffer: %d\n",
+				    STp->density,
+				    (STp->buffer)->b_data[5] * 65536 +
+				    (STp->buffer)->b_data[6] * 256 +
+				    (STp->buffer)->b_data[7],
+				    STp->drv_buffer);
 		}
 		STp->drv_write_prot = ((STp->buffer)->b_data[2] & 0x80) != 0;
 		if (!STp->drv_buffer && STp->immediate_filemark) {
-			printk(KERN_WARNING
-			    "%s: non-buffered tape: disabling writing immediate filemarks\n",
-			    name);
+			st_printk(KERN_WARNING, STp,
+				  "non-buffered tape: disabling "
+				  "writing immediate filemarks\n");
 			STp->immediate_filemark = 0;
 		}
 	}
 	st_release_request(SRpnt);
 	SRpnt = NULL;
-        STp->inited = 1;
+	STp->inited = 1;
 
 	if (STp->block_size > 0)
 		(STp->buffer)->buffer_blocks =
-                        (STp->buffer)->buffer_size / STp->block_size;
+			(STp->buffer)->buffer_size / STp->block_size;
 	else
 		(STp->buffer)->buffer_blocks = 1;
 	(STp->buffer)->buffer_bytes = (STp->buffer)->read_pointer = 0;
 
-        DEBC(printk(ST_DEB_MSG
-                       "%s: Block size: %d, buffer size: %d (%d blocks).\n", name,
-		       STp->block_size, (STp->buffer)->buffer_size,
-		       (STp->buffer)->buffer_blocks));
+	DEBC_printk(STp, "Block size: %d, buffer size: %d (%d blocks).\n",
+		    STp->block_size, (STp->buffer)->buffer_size,
+		    (STp->buffer)->buffer_blocks);
 
 	if (STp->drv_write_prot) {
 		STp->write_prot = 1;
 
-                DEBC(printk(ST_DEB_MSG "%s: Write protected\n", name));
+		DEBC_printk(STp, "Write protected\n");
 
 		if (do_wait &&
 		    ((st_flags & O_ACCMODE) == O_WRONLY ||
@@ -1141,8 +1147,7 @@ static int check_tape(struct scsi_tape *STp, struct file *filp)
 		/* This code is reached when the device is opened for the first time
 		   after the driver has been initialized with tape in the drive and the
 		   partition support has been enabled. */
-                DEBC(printk(ST_DEB_MSG
-                            "%s: Updating partition number in status.\n", name));
+		DEBC_printk(STp, "Updating partition number in status.\n");
 		if ((STp->partition = find_partition(STp)) < 0) {
 			retval = STp->partition;
 			goto err_out;
@@ -1160,9 +1165,10 @@ static int check_tape(struct scsi_tape *STp, struct file *filp)
 
 		if (STp->default_drvbuffer != 0xff) {
 			if (st_int_ioctl(STp, MTSETDRVBUFFER, STp->default_drvbuffer))
-				printk(KERN_WARNING
-                                       "%s: Can't set default drive buffering to %d.\n",
-				       name, STp->default_drvbuffer);
+				st_printk(KERN_WARNING, STp,
+					  "Can't set default drive "
+					  "buffering to %d.\n",
+					  STp->default_drvbuffer);
 		}
 	}
 
@@ -1182,7 +1188,6 @@ static int st_open(struct inode *inode, struct file *filp)
 	struct scsi_tape *STp;
 	struct st_partstat *STps;
 	int dev = TAPE_NR(inode);
-	char *name;
 
 	/*
 	 * We really want to do nonseekable_open(inode, filp); here, but some
@@ -1196,13 +1201,12 @@ static int st_open(struct inode *inode, struct file *filp)
 	}
 
 	filp->private_data = STp;
-	name = tape_name(STp);
 
 	spin_lock(&st_use_lock);
 	if (STp->in_use) {
 		spin_unlock(&st_use_lock);
 		scsi_tape_put(STp);
-		DEB( printk(ST_DEB_MSG "%s: Device already in use.\n", name); )
+		DEBC_printk(STp, "Device already in use.\n");
 		return (-EBUSY);
 	}
 
@@ -1222,8 +1226,8 @@ static int st_open(struct inode *inode, struct file *filp)
 
 	/* See that we have at least a one page buffer available */
 	if (!enlarge_buffer(STp->buffer, PAGE_SIZE, STp->restr_dma)) {
-		printk(KERN_WARNING "%s: Can't allocate one page tape buffer.\n",
-		       name);
+		st_printk(KERN_WARNING, STp,
+			  "Can't allocate one page tape buffer.\n");
 		retval = (-EOVERFLOW);
 		goto err_out;
 	}
@@ -1279,7 +1283,6 @@ static int st_flush(struct file *filp, fl_owner_t id)
 	struct scsi_tape *STp = filp->private_data;
 	struct st_modedef *STm = &(STp->modes[STp->current_mode]);
 	struct st_partstat *STps = &(STp->ps[STp->partition]);
-	char *name = tape_name(STp);
 
 	if (file_count(filp) > 1)
 		return 0;
@@ -1292,24 +1295,25 @@ static int st_flush(struct file *filp, fl_owner_t id)
 
 	if (STp->can_partitions &&
 	    (result2 = switch_partition(STp)) < 0) {
-                DEBC(printk(ST_DEB_MSG
-                               "%s: switch_partition at close failed.\n", name));
+		DEBC_printk(STp, "switch_partition at close failed.\n");
 		if (result == 0)
 			result = result2;
 		goto out;
 	}
 
 	DEBC( if (STp->nbr_requests)
-		printk(KERN_DEBUG "%s: Number of r/w requests %d, dio used in %d, pages %d.\n",
-		       name, STp->nbr_requests, STp->nbr_dio, STp->nbr_pages));
+		st_printk(KERN_DEBUG, STp,
+			  "Number of r/w requests %d, dio used in %d, "
+			  "pages %d.\n", STp->nbr_requests, STp->nbr_dio,
+			  STp->nbr_pages));
 
 	if (STps->rw == ST_WRITING && !STp->pos_unknown) {
 		struct st_cmdstatus *cmdstatp = &STp->buffer->cmdstat;
 
-                DEBC(printk(ST_DEB_MSG "%s: Async write waits %d, finished %d.\n",
-                            name, STp->nbr_waits, STp->nbr_finished);
-		)
-
+#if DEBUG
+		DEBC_printk(STp, "Async write waits %d, finished %d.\n",
+			    STp->nbr_waits, STp->nbr_finished);
+#endif
 		memset(cmd, 0, MAX_COMMAND_SIZE);
 		cmd[0] = WRITE_FILEMARKS;
 		if (STp->immediate_filemark)
@@ -1343,13 +1347,13 @@ static int st_flush(struct file *filp, fl_owner_t id)
 		else { /* Write error */
 			st_release_request(SRpnt);
 			SRpnt = NULL;
-			printk(KERN_ERR "%s: Error on write filemark.\n", name);
+			st_printk(KERN_ERR, STp,
+				  "Error on write filemark.\n");
 			if (result == 0)
 				result = (-EIO);
 		}
 
-                DEBC(printk(ST_DEB_MSG "%s: Buffer flushed, %d EOF(s) written\n",
-                            name, cmd[4]));
+		DEBC_printk(STp, "Buffer flushed, %d EOF(s) written\n", cmd[4]);
 	} else if (!STp->rew_at_close) {
 		STps = &(STp->ps[STp->partition]);
 		if (!STm->sysv || STps->rw != ST_READING) {
@@ -1447,9 +1451,10 @@ static ssize_t rw_checks(struct scsi_tape *STp, struct file *filp, size_t count)
 	if (count == 0)
 		goto out;
 
-        DEB(
+	DEB(
 	if (!STp->in_use) {
-		printk(ST_DEB_MSG "%s: Incorrect device.\n", tape_name(STp));
+		st_printk(ST_DEB_MSG, STp,
+			  "Incorrect device.\n");
 		retval = (-EIO);
 		goto out;
 	} ) /* end DEB */
@@ -1519,8 +1524,9 @@ static int setup_buffering(struct scsi_tape *STp, const char __user *buf,
 
 		if (bufsize > STbp->buffer_size &&
 		    !enlarge_buffer(STbp, bufsize, STp->restr_dma)) {
-			printk(KERN_WARNING "%s: Can't allocate %d byte tape buffer.\n",
-			       tape_name(STp), bufsize);
+			st_printk(KERN_WARNING, STp,
+				  "Can't allocate %d byte tape buffer.\n",
+				  bufsize);
 			retval = (-EOVERFLOW);
 			goto out;
 		}
@@ -1563,7 +1569,6 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 	struct st_modedef *STm;
 	struct st_partstat *STps;
 	struct st_buffer *STbp;
-	char *name = tape_name(STp);
 
 	if (mutex_lock_interruptible(&STp->lock))
 		return -ERESTARTSYS;
@@ -1574,8 +1579,8 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 
 	/* Write must be integral number of blocks */
 	if (STp->block_size != 0 && (count % STp->block_size) != 0) {
-		printk(KERN_WARNING "%s: Write not multiple of tape block size.\n",
-		       name);
+		st_printk(KERN_WARNING, STp,
+			  "Write not multiple of tape block size.\n");
 		retval = (-EINVAL);
 		goto out;
 	}
@@ -1601,8 +1606,8 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 		if (STm->default_compression != ST_DONT_TOUCH &&
 		    !(STp->compression_changed)) {
 			if (st_compression(STp, (STm->default_compression == ST_YES))) {
-				printk(KERN_WARNING "%s: Can't set default compression.\n",
-				       name);
+				st_printk(KERN_WARNING, STp,
+					  "Can't set default compression.\n");
 				if (modes_defined) {
 					retval = (-EINVAL);
 					goto out;
@@ -1723,7 +1728,7 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 		if (STbp->syscall_result != 0) {
 			struct st_cmdstatus *cmdstatp = &STp->buffer->cmdstat;
 
-                        DEBC(printk(ST_DEB_MSG "%s: Error on write:\n", name));
+			DEBC_printk(STp, "Error on write:\n");
 			if (cmdstatp->have_sense && (cmdstatp->flags & SENSE_EOM)) {
 				scode = cmdstatp->sense_hdr.sense_key;
 				if (cmdstatp->remainder_valid)
@@ -1750,9 +1755,9 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 					if (STp->block_size == 0 ||
 					    undone > 0 || count == 0)
 						retval = (-ENOSPC); /* EOM within current request */
-                                        DEBC(printk(ST_DEB_MSG
-                                                       "%s: EOM with %d bytes unwritten.\n",
-						       name, (int)count));
+					DEBC_printk(STp, "EOM with %d "
+						    "bytes unwritten.\n",
+						    (int)count);
 				} else {
 					/* EOT within data buffered earlier (possible only
 					   in fixed block mode without direct i/o) */
@@ -1765,9 +1770,10 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 								STp->block_size;
 						}
 						STps->eof = ST_EOM_OK;
-						DEBC(printk(ST_DEB_MSG
-							    "%s: Retry write of %d bytes at EOM.\n",
-							    name, STp->buffer->buffer_bytes));
+						DEBC_printk(STp, "Retry "
+							    "write of %d "
+							    "bytes at EOM.\n",
+							    STp->buffer->buffer_bytes);
 						goto retry_write;
 					}
 					else {
@@ -1778,9 +1784,8 @@ st_write(struct file *filp, const char __user *buf, size_t count, loff_t * ppos)
 						STps->eof = ST_EOM_ERROR;
 						STps->drv_block = (-1); /* Too cautious? */
 						retval = (-EIO);	/* EOM for old data */
-						DEBC(printk(ST_DEB_MSG
-							    "%s: EOM with lost data.\n",
-							    name));
+						DEBC_printk(STp, "EOM with "
+							    "lost data.\n");
 					}
 				}
 			} else {
@@ -1839,7 +1844,6 @@ static long read_tape(struct scsi_tape *STp, long count,
 	struct st_partstat *STps;
 	struct st_buffer *STbp;
 	int retval = 0;
-	char *name = tape_name(STp);
 
 	if (count == 0)
 		return 0;
@@ -1891,12 +1895,12 @@ static long read_tape(struct scsi_tape *STp, long count,
 		struct st_cmdstatus *cmdstatp = &STp->buffer->cmdstat;
 
 		retval = 1;
-		DEBC(printk(ST_DEB_MSG "%s: Sense: %2x %2x %2x %2x %2x %2x %2x %2x\n",
-                            name,
-                            SRpnt->sense[0], SRpnt->sense[1],
-                            SRpnt->sense[2], SRpnt->sense[3],
-                            SRpnt->sense[4], SRpnt->sense[5],
-                            SRpnt->sense[6], SRpnt->sense[7]));
+		DEBC_printk(STp,
+			    "Sense: %2x %2x %2x %2x %2x %2x %2x %2x\n",
+			    SRpnt->sense[0], SRpnt->sense[1],
+			    SRpnt->sense[2], SRpnt->sense[3],
+			    SRpnt->sense[4], SRpnt->sense[5],
+			    SRpnt->sense[6], SRpnt->sense[7]);
 		if (cmdstatp->have_sense) {
 
 			if (cmdstatp->sense_hdr.sense_key == BLANK_CHECK)
@@ -1913,23 +1917,27 @@ static long read_tape(struct scsi_tape *STp, long count,
 					transfer = bytes;
 
 				if (cmdstatp->flags & SENSE_ILI) {	/* ILI */
-					if (STp->block_size == 0) {
-						if (transfer <= 0) {
-							if (transfer < 0)
-								printk(KERN_NOTICE
-								       "%s: Failed to read %d byte block with %d byte transfer.\n",
-								       name, bytes - transfer, bytes);
-							if (STps->drv_block >= 0)
-								STps->drv_block += 1;
-							STbp->buffer_bytes = 0;
-							return (-ENOMEM);
-						}
+					if (STp->block_size == 0 &&
+					    transfer < 0) {
+						st_printk(KERN_NOTICE, STp,
+							  "Failed to read %d "
+							  "byte block with %d "
+							  "byte transfer.\n",
+							  bytes - transfer,
+							  bytes);
+						if (STps->drv_block >= 0)
+							STps->drv_block += 1;
+						STbp->buffer_bytes = 0;
+						return (-ENOMEM);
+					} else if (STp->block_size == 0) {
 						STbp->buffer_bytes = bytes - transfer;
 					} else {
 						st_release_request(SRpnt);
 						SRpnt = *aSRpnt = NULL;
 						if (transfer == blks) {	/* We did not get anything, error */
-							printk(KERN_NOTICE "%s: Incorrect block size.\n", name);
+							st_printk(KERN_NOTICE, STp,
+								  "Incorrect "
+								  "block size.\n");
 							if (STps->drv_block >= 0)
 								STps->drv_block += blks - transfer + 1;
 							st_int_ioctl(STp, MTBSR, 1);
@@ -1938,9 +1946,11 @@ static long read_tape(struct scsi_tape *STp, long count,
 						/* We have some data, deliver it */
 						STbp->buffer_bytes = (blks - transfer) *
 						    STp->block_size;
-                                                DEBC(printk(ST_DEB_MSG
-                                                            "%s: ILI but enough data received %ld %d.\n",
-                                                            name, count, STbp->buffer_bytes));
+						DEBC_printk(STp, "ILI but "
+							    "enough data "
+							    "received %ld "
+							    "%d.\n", count,
+							    STbp->buffer_bytes);
 						if (STps->drv_block >= 0)
 							STps->drv_block += 1;
 						if (st_int_ioctl(STp, MTBSR, 1))
@@ -1956,9 +1966,9 @@ static long read_tape(struct scsi_tape *STp, long count,
 					else
 						STbp->buffer_bytes =
 						    bytes - transfer * STp->block_size;
-                                        DEBC(printk(ST_DEB_MSG
-                                                    "%s: EOF detected (%d bytes read).\n",
-                                                    name, STbp->buffer_bytes));
+					DEBC_printk(STp, "EOF detected (%d "
+						    "bytes read).\n",
+						    STbp->buffer_bytes);
 				} else if (cmdstatp->flags & SENSE_EOM) {
 					if (STps->eof == ST_FM)
 						STps->eof = ST_EOD_1;
@@ -1970,20 +1980,20 @@ static long read_tape(struct scsi_tape *STp, long count,
 						STbp->buffer_bytes =
 						    bytes - transfer * STp->block_size;
 
-                                        DEBC(printk(ST_DEB_MSG "%s: EOM detected (%d bytes read).\n",
-                                                    name, STbp->buffer_bytes));
+					DEBC_printk(STp, "EOM detected (%d "
+						    "bytes read).\n",
+						    STbp->buffer_bytes);
 				}
 			}
-			/* end of EOF, EOM, ILI test */ 
+			/* end of EOF, EOM, ILI test */
 			else {	/* nonzero sense key */
-                                DEBC(printk(ST_DEB_MSG
-                                            "%s: Tape error while reading.\n", name));
+				DEBC_printk(STp, "Tape error while reading.\n");
 				STps->drv_block = (-1);
 				if (STps->eof == ST_FM &&
 				    cmdstatp->sense_hdr.sense_key == BLANK_CHECK) {
-                                        DEBC(printk(ST_DEB_MSG
-                                                    "%s: Zero returned for first BLANK CHECK after EOF.\n",
-                                                    name));
+					DEBC_printk(STp, "Zero returned for "
+						    "first BLANK CHECK "
+						    "after EOF.\n");
 					STps->eof = ST_EOD_2;	/* First BLANK_CHECK after FM */
 				} else	/* Some other extended sense code */
 					retval = (-EIO);
@@ -1992,13 +2002,13 @@ static long read_tape(struct scsi_tape *STp, long count,
 			if (STbp->buffer_bytes < 0)  /* Caused by bogus sense data */
 				STbp->buffer_bytes = 0;
 		}
-		/* End of extended sense test */ 
+		/* End of extended sense test */
 		else {		/* Non-extended sense */
 			retval = STbp->syscall_result;
 		}
 
 	}
-	/* End of error handling */ 
+	/* End of error handling */
 	else {			/* Read successful */
 		STbp->buffer_bytes = bytes;
 		if (STp->sili) /* In fixed block mode residual is always zero here */
@@ -2028,7 +2038,6 @@ st_read(struct file *filp, char __user *buf, size_t count, loff_t * ppos)
 	struct st_modedef *STm;
 	struct st_partstat *STps;
 	struct st_buffer *STbp = STp->buffer;
-	DEB( char *name = tape_name(STp); )
 
 	if (mutex_lock_interruptible(&STp->lock))
 		return -ERESTARTSYS;
@@ -2053,11 +2062,12 @@ st_read(struct file *filp, char __user *buf, size_t count, loff_t * ppos)
 			goto out;
 		STps->rw = ST_READING;
 	}
-        DEB(
+	DEB(
 	if (debugging && STps->eof != ST_NOEOF)
-		printk(ST_DEB_MSG "%s: EOF/EOM flag up (%d). Bytes %d\n", name,
-		       STps->eof, STbp->buffer_bytes);
-        ) /* end DEB */
+		st_printk(ST_DEB_MSG, STp,
+			  "EOF/EOM flag up (%d). Bytes %d\n",
+			  STps->eof, STbp->buffer_bytes);
+	) /* end DEB */
 
 	retval = setup_buffering(STp, buf, count, 1);
 	if (retval)
@@ -2104,13 +2114,13 @@ st_read(struct file *filp, char __user *buf, size_t count, loff_t * ppos)
 
 		/* Move the data from driver buffer to user buffer */
 		if (STbp->buffer_bytes > 0) {
-                        DEB(
+			DEB(
 			if (debugging && STps->eof != ST_NOEOF)
-				printk(ST_DEB_MSG
-                                       "%s: EOF up (%d). Left %d, needed %d.\n", name,
-				       STps->eof, STbp->buffer_bytes,
-                                       (int)(count - total));
-                        ) /* end DEB */
+				st_printk(ST_DEB_MSG, STp,
+					  "EOF up (%d). Left %d, needed %d.\n",
+					  STps->eof, STbp->buffer_bytes,
+					  (int)(count - total));
+			) /* end DEB */
 			transfer = STbp->buffer_bytes < count - total ?
 			    STbp->buffer_bytes : count - total;
 			if (!do_dio) {
@@ -2166,26 +2176,30 @@ st_read(struct file *filp, char __user *buf, size_t count, loff_t * ppos)
 
 DEB(
 /* Set the driver options */
-static void st_log_options(struct scsi_tape * STp, struct st_modedef * STm, char *name)
+static void st_log_options(struct scsi_tape * STp, struct st_modedef * STm)
 {
 	if (debugging) {
-		printk(KERN_INFO
-		       "%s: Mode %d options: buffer writes: %d, async writes: %d, read ahead: %d\n",
-		       name, STp->current_mode, STm->do_buffer_writes, STm->do_async_writes,
-		       STm->do_read_ahead);
-		printk(KERN_INFO
-		       "%s:    can bsr: %d, two FMs: %d, fast mteom: %d, auto lock: %d,\n",
-		       name, STp->can_bsr, STp->two_fm, STp->fast_mteom, STp->do_auto_lock);
-		printk(KERN_INFO
-		       "%s:    defs for wr: %d, no block limits: %d, partitions: %d, s2 log: %d\n",
-		       name, STm->defaults_for_writes, STp->omit_blklims, STp->can_partitions,
-		       STp->scsi2_logical);
-		printk(KERN_INFO
-		       "%s:    sysv: %d nowait: %d sili: %d nowait_filemark: %d\n",
-		       name, STm->sysv, STp->immediate, STp->sili,
-		       STp->immediate_filemark);
-		printk(KERN_INFO "%s:    debugging: %d\n",
-		       name, debugging);
+		st_printk(KERN_INFO, STp,
+			  "Mode %d options: buffer writes: %d, "
+			  "async writes: %d, read ahead: %d\n",
+			  STp->current_mode, STm->do_buffer_writes,
+			  STm->do_async_writes, STm->do_read_ahead);
+		st_printk(KERN_INFO, STp,
+			  "    can bsr: %d, two FMs: %d, "
+			  "fast mteom: %d, auto lock: %d,\n",
+			  STp->can_bsr, STp->two_fm, STp->fast_mteom,
+			  STp->do_auto_lock);
+		st_printk(KERN_INFO, STp,
+			  "    defs for wr: %d, no block limits: %d, "
+			  "partitions: %d, s2 log: %d\n",
+			  STm->defaults_for_writes, STp->omit_blklims,
+			  STp->can_partitions, STp->scsi2_logical);
+		st_printk(KERN_INFO, STp,
+			  "    sysv: %d nowait: %d sili: %d "
+			  "nowait_filemark: %d\n",
+			  STm->sysv, STp->immediate, STp->sili,
+			  STp->immediate_filemark);
+		st_printk(KERN_INFO, STp, "    debugging: %d\n", debugging);
 	}
 }
 	)
@@ -2196,7 +2210,6 @@ static int st_set_options(struct scsi_tape *STp, long options)
 	int value;
 	long code;
 	struct st_modedef *STm;
-	char *name = tape_name(STp);
 	struct cdev *cd0, *cd1;
 	struct device *d0, *d1;
 
@@ -2212,9 +2225,8 @@ static int st_set_options(struct scsi_tape *STp, long options)
 		STm->devs[0]  = d0;
 		STm->devs[1]  = d1;
 		modes_defined = 1;
-                DEBC(printk(ST_DEB_MSG
-                            "%s: Initialized mode %d definition from mode 0\n",
-                            name, STp->current_mode));
+		DEBC_printk(STp, "Initialized mode %d definition from mode 0\n",
+			    STp->current_mode);
 	}
 
 	code = options & MT_ST_OPTIONS;
@@ -2236,7 +2248,7 @@ static int st_set_options(struct scsi_tape *STp, long options)
 		STm->sysv = (options & MT_ST_SYSV) != 0;
 		STp->sili = (options & MT_ST_SILI) != 0;
 		DEB( debugging = (options & MT_ST_DEBUGGING) != 0;
-		     st_log_options(STp, STm, name); )
+		     st_log_options(STp, STm); )
 	} else if (code == MT_ST_SETBOOLEANS || code == MT_ST_CLEARBOOLEANS) {
 		value = (code == MT_ST_SETBOOLEANS);
 		if ((options & MT_ST_BUFFER_WRITES) != 0)
@@ -2270,21 +2282,21 @@ static int st_set_options(struct scsi_tape *STp, long options)
 			STm->sysv = value;
 		if ((options & MT_ST_SILI) != 0)
 			STp->sili = value;
-                DEB(
+		DEB(
 		if ((options & MT_ST_DEBUGGING) != 0)
 			debugging = value;
-			st_log_options(STp, STm, name); )
+			st_log_options(STp, STm); )
 	} else if (code == MT_ST_WRITE_THRESHOLD) {
 		/* Retained for compatibility */
 	} else if (code == MT_ST_DEF_BLKSIZE) {
 		value = (options & ~MT_ST_OPTIONS);
 		if (value == ~MT_ST_OPTIONS) {
 			STm->default_blksize = (-1);
-			DEBC( printk(KERN_INFO "%s: Default block size disabled.\n", name));
+			DEBC_printk(STp, "Default block size disabled.\n");
 		} else {
 			STm->default_blksize = value;
-			DEBC( printk(KERN_INFO "%s: Default block size set to %d bytes.\n",
-			       name, STm->default_blksize));
+			DEBC_printk(STp,"Default block size set to "
+				    "%d bytes.\n", STm->default_blksize);
 			if (STp->ready == ST_READY) {
 				STp->blksize_changed = 0;
 				set_mode_densblk(STp, STm);
@@ -2294,13 +2306,13 @@ static int st_set_options(struct scsi_tape *STp, long options)
 		value = (options & ~MT_ST_OPTIONS);
 		if ((value & MT_ST_SET_LONG_TIMEOUT) != 0) {
 			STp->long_timeout = (value & ~MT_ST_SET_LONG_TIMEOUT) * HZ;
-			DEBC( printk(KERN_INFO "%s: Long timeout set to %d seconds.\n", name,
-			       (value & ~MT_ST_SET_LONG_TIMEOUT)));
+			DEBC_printk(STp, "Long timeout set to %d seconds.\n",
+				    (value & ~MT_ST_SET_LONG_TIMEOUT));
 		} else {
 			blk_queue_rq_timeout(STp->device->request_queue,
 					     value * HZ);
-			DEBC( printk(KERN_INFO "%s: Normal timeout set to %d seconds.\n",
-				name, value) );
+			DEBC_printk(STp, "Normal timeout set to %d seconds.\n",
+				    value);
 		}
 	} else if (code == MT_ST_SET_CLN) {
 		value = (options & ~MT_ST_OPTIONS) & 0xff;
@@ -2311,21 +2323,21 @@ static int st_set_options(struct scsi_tape *STp, long options)
 		STp->cln_mode = value;
 		STp->cln_sense_mask = (options >> 8) & 0xff;
 		STp->cln_sense_value = (options >> 16) & 0xff;
-		printk(KERN_INFO
-		       "%s: Cleaning request mode %d, mask %02x, value %02x\n",
-		       name, value, STp->cln_sense_mask, STp->cln_sense_value);
+		st_printk(KERN_INFO, STp,
+			  "Cleaning request mode %d, mask %02x, value %02x\n",
+			  value, STp->cln_sense_mask, STp->cln_sense_value);
 	} else if (code == MT_ST_DEF_OPTIONS) {
 		code = (options & ~MT_ST_CLEAR_DEFAULT);
 		value = (options & MT_ST_CLEAR_DEFAULT);
 		if (code == MT_ST_DEF_DENSITY) {
 			if (value == MT_ST_CLEAR_DEFAULT) {
 				STm->default_density = (-1);
-				DEBC( printk(KERN_INFO "%s: Density default disabled.\n",
-                                       name));
+				DEBC_printk(STp,
+					    "Density default disabled.\n");
 			} else {
 				STm->default_density = value & 0xff;
-				DEBC( printk(KERN_INFO "%s: Density default set to %x\n",
-				       name, STm->default_density));
+				DEBC_printk(STp, "Density default set to %x\n",
+					    STm->default_density);
 				if (STp->ready == ST_READY) {
 					STp->density_changed = 0;
 					set_mode_densblk(STp, STm);
@@ -2334,31 +2346,33 @@ static int st_set_options(struct scsi_tape *STp, long options)
 		} else if (code == MT_ST_DEF_DRVBUFFER) {
 			if (value == MT_ST_CLEAR_DEFAULT) {
 				STp->default_drvbuffer = 0xff;
-				DEBC( printk(KERN_INFO
-                                       "%s: Drive buffer default disabled.\n", name));
+				DEBC_printk(STp,
+					    "Drive buffer default disabled.\n");
 			} else {
 				STp->default_drvbuffer = value & 7;
-				DEBC( printk(KERN_INFO
-                                       "%s: Drive buffer default set to %x\n",
-				       name, STp->default_drvbuffer));
+				DEBC_printk(STp,
+					    "Drive buffer default set to %x\n",
+					    STp->default_drvbuffer);
 				if (STp->ready == ST_READY)
 					st_int_ioctl(STp, MTSETDRVBUFFER, STp->default_drvbuffer);
 			}
 		} else if (code == MT_ST_DEF_COMPRESSION) {
 			if (value == MT_ST_CLEAR_DEFAULT) {
 				STm->default_compression = ST_DONT_TOUCH;
-				DEBC( printk(KERN_INFO
-                                       "%s: Compression default disabled.\n", name));
+				DEBC_printk(STp,
+					    "Compression default disabled.\n");
 			} else {
 				if ((value & 0xff00) != 0) {
 					STp->c_algo = (value & 0xff00) >> 8;
-					DEBC( printk(KERN_INFO "%s: Compression algorithm set to 0x%x.\n",
-					       name, STp->c_algo));
+					DEBC_printk(STp, "Compression "
+						    "algorithm set to 0x%x.\n",
+						    STp->c_algo);
 				}
 				if ((value & 0xff) != 0xff) {
 					STm->default_compression = (value & 1 ? ST_YES : ST_NO);
-					DEBC( printk(KERN_INFO "%s: Compression default set to %x\n",
-					       name, (value & 1)));
+					DEBC_printk(STp, "Compression default "
+						    "set to %x\n",
+						    (value & 1));
 					if (STp->ready == ST_READY) {
 						STp->compression_changed = 0;
 						st_compression(STp, (STm->default_compression == ST_YES));
@@ -2473,7 +2487,6 @@ static int st_compression(struct scsi_tape * STp, int state)
 	int retval;
 	int mpoffs;  /* Offset to mode page start */
 	unsigned char *b_data = (STp->buffer)->b_data;
-	DEB( char *name = tape_name(STp); )
 
 	if (STp->ready != ST_READY)
 		return (-EIO);
@@ -2481,18 +2494,17 @@ static int st_compression(struct scsi_tape * STp, int state)
 	/* Read the current page contents */
 	retval = read_mode_page(STp, COMPRESSION_PAGE, 0);
 	if (retval) {
-                DEBC(printk(ST_DEB_MSG "%s: Compression mode page not supported.\n",
-                            name));
+		DEBC_printk(STp, "Compression mode page not supported.\n");
 		return (-EIO);
 	}
 
 	mpoffs = MODE_HEADER_LENGTH + b_data[MH_OFF_BDESCS_LENGTH];
-        DEBC(printk(ST_DEB_MSG "%s: Compression state is %d.\n", name,
-                    (b_data[mpoffs + CP_OFF_DCE_DCC] & DCE_MASK ? 1 : 0)));
+	DEBC_printk(STp, "Compression state is %d.\n",
+		    (b_data[mpoffs + CP_OFF_DCE_DCC] & DCE_MASK ? 1 : 0));
 
 	/* Check if compression can be changed */
 	if ((b_data[mpoffs + CP_OFF_DCE_DCC] & DCC_MASK) == 0) {
-                DEBC(printk(ST_DEB_MSG "%s: Compression not supported.\n", name));
+		DEBC_printk(STp, "Compression not supported.\n");
 		return (-EIO);
 	}
 
@@ -2510,11 +2522,10 @@ static int st_compression(struct scsi_tape * STp, int state)
 
 	retval = write_mode_page(STp, COMPRESSION_PAGE, 0);
 	if (retval) {
-                DEBC(printk(ST_DEB_MSG "%s: Compression change failed.\n", name));
+		DEBC_printk(STp, "Compression change failed.\n");
 		return (-EIO);
 	}
-        DEBC(printk(ST_DEB_MSG "%s: Compression state changed to %d.\n",
-		       name, state));
+	DEBC_printk(STp, "Compression state changed to %d.\n", state);
 
 	STp->compression_changed = 1;
 	return 0;
@@ -2525,7 +2536,6 @@ static int st_compression(struct scsi_tape * STp, int state)
 static int do_load_unload(struct scsi_tape *STp, struct file *filp, int load_code)
 {
 	int retval = (-EIO), timeout;
-	DEB( char *name = tape_name(STp); )
 	unsigned char cmd[MAX_COMMAND_SIZE];
 	struct st_partstat *STps;
 	struct st_request *SRpnt;
@@ -2546,9 +2556,9 @@ static int do_load_unload(struct scsi_tape *STp, struct file *filp, int load_cod
 	 */
 	if (load_code >= 1 + MT_ST_HPLOADER_OFFSET
 	    && load_code <= 6 + MT_ST_HPLOADER_OFFSET) {
-		DEBC(printk(ST_DEB_MSG "%s: Enhanced %sload slot %2d.\n",
-			    name, (cmd[4]) ? "" : "un",
-			    load_code - MT_ST_HPLOADER_OFFSET));
+		DEBC_printk(STp, " Enhanced %sload slot %2d.\n",
+			    (cmd[4]) ? "" : "un",
+			    load_code - MT_ST_HPLOADER_OFFSET);
 		cmd[3] = load_code - MT_ST_HPLOADER_OFFSET; /* MediaID field of C1553A */
 	}
 	if (STp->immediate) {
@@ -2560,9 +2570,9 @@ static int do_load_unload(struct scsi_tape *STp, struct file *filp, int load_cod
 
 	DEBC(
 		if (!load_code)
-		printk(ST_DEB_MSG "%s: Unloading tape.\n", name);
+			st_printk(ST_DEB_MSG, STp, "Unloading tape.\n");
 		else
-		printk(ST_DEB_MSG "%s: Loading tape.\n", name);
+			st_printk(ST_DEB_MSG, STp, "Loading tape.\n");
 		);
 
 	SRpnt = st_do_scsi(NULL, STp, cmd, 0, DMA_NONE,
@@ -2597,17 +2607,24 @@ static int do_load_unload(struct scsi_tape *STp, struct file *filp, int load_cod
 #if DEBUG
 #define ST_DEB_FORWARD  0
 #define ST_DEB_BACKWARD 1
-static void deb_space_print(char *name, int direction, char *units, unsigned char *cmd)
+static void deb_space_print(struct scsi_tape *STp, int direction, char *units, unsigned char *cmd)
 {
 	s32 sc;
 
+	if (!debugging)
+		return;
+
 	sc = cmd[2] & 0x80 ? 0xff000000 : 0;
 	sc |= (cmd[2] << 16) | (cmd[3] << 8) | cmd[4];
 	if (direction)
 		sc = -sc;
-	printk(ST_DEB_MSG "%s: Spacing tape %s over %d %s.\n", name,
-	       direction ? "backward" : "forward", sc, units);
+	st_printk(ST_DEB_MSG, STp, "Spacing tape %s over %d %s.\n",
+		  direction ? "backward" : "forward", sc, units);
 }
+#else
+#define ST_DEB_FORWARD  0
+#define ST_DEB_BACKWARD 1
+static void deb_space_print(struct scsi_tape *STp, int direction, char *units, unsigned char *cmd) {}
 #endif
 
 
@@ -2623,7 +2640,6 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 	struct st_partstat *STps;
 	int fileno, blkno, at_sm, undone;
 	int datalen = 0, direction = DMA_NONE;
-	char *name = tape_name(STp);
 
 	WARN_ON(STp->buffer->do_dio != 0);
 	if (STp->ready != ST_READY) {
@@ -2648,7 +2664,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[2] = (arg >> 16);
 		cmd[3] = (arg >> 8);
 		cmd[4] = arg;
-                DEBC(deb_space_print(name, ST_DEB_FORWARD, "filemarks", cmd);)
+		deb_space_print(STp, ST_DEB_FORWARD, "filemarks", cmd);
 		if (fileno >= 0)
 			fileno += arg;
 		blkno = 0;
@@ -2663,7 +2679,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[2] = (ltmp >> 16);
 		cmd[3] = (ltmp >> 8);
 		cmd[4] = ltmp;
-                DEBC(deb_space_print(name, ST_DEB_BACKWARD, "filemarks", cmd);)
+		deb_space_print(STp, ST_DEB_BACKWARD, "filemarks", cmd);
 		if (fileno >= 0)
 			fileno -= arg;
 		blkno = (-1);	/* We can't know the block number */
@@ -2675,7 +2691,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[2] = (arg >> 16);
 		cmd[3] = (arg >> 8);
 		cmd[4] = arg;
-                DEBC(deb_space_print(name, ST_DEB_FORWARD, "blocks", cmd);)
+		deb_space_print(STp, ST_DEB_FORWARD, "blocks", cmd);
 		if (blkno >= 0)
 			blkno += arg;
 		at_sm &= (arg == 0);
@@ -2687,7 +2703,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[2] = (ltmp >> 16);
 		cmd[3] = (ltmp >> 8);
 		cmd[4] = ltmp;
-                DEBC(deb_space_print(name, ST_DEB_BACKWARD, "blocks", cmd);)
+		deb_space_print(STp, ST_DEB_BACKWARD, "blocks", cmd);
 		if (blkno >= 0)
 			blkno -= arg;
 		at_sm &= (arg == 0);
@@ -2698,7 +2714,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[2] = (arg >> 16);
 		cmd[3] = (arg >> 8);
 		cmd[4] = arg;
-                DEBC(deb_space_print(name, ST_DEB_FORWARD, "setmarks", cmd);)
+		deb_space_print(STp, ST_DEB_FORWARD, "setmarks", cmd);
 		if (arg != 0) {
 			blkno = fileno = (-1);
 			at_sm = 1;
@@ -2711,7 +2727,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[2] = (ltmp >> 16);
 		cmd[3] = (ltmp >> 8);
 		cmd[4] = ltmp;
-                DEBC(deb_space_print(name, ST_DEB_BACKWARD, "setmarks", cmd);)
+		deb_space_print(STp, ST_DEB_BACKWARD, "setmarks", cmd);
 		if (arg != 0) {
 			blkno = fileno = (-1);
 			at_sm = 1;
@@ -2732,13 +2748,19 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		cmd[3] = (arg >> 8);
 		cmd[4] = arg;
 		timeout = STp->device->request_queue->rq_timeout;
-                DEBC(
-		     if (cmd_in != MTWSM)
-                               printk(ST_DEB_MSG "%s: Writing %d filemarks.\n", name,
-				 cmd[2] * 65536 + cmd[3] * 256 + cmd[4]);
-                     else
-				printk(ST_DEB_MSG "%s: Writing %d setmarks.\n", name,
-				 cmd[2] * 65536 + cmd[3] * 256 + cmd[4]);
+		DEBC(
+			if (cmd_in != MTWSM)
+				st_printk(ST_DEB_MSG, STp,
+					  "Writing %d filemarks.\n",
+					  cmd[2] * 65536 +
+					  cmd[3] * 256 +
+					  cmd[4]);
+			else
+				st_printk(ST_DEB_MSG, STp,
+					  "Writing %d setmarks.\n",
+					  cmd[2] * 65536 +
+					  cmd[3] * 256 +
+					  cmd[4]);
 		)
 		if (fileno >= 0)
 			fileno += arg;
@@ -2751,11 +2773,11 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 			cmd[1] = 1;	/* Don't wait for completion */
 			timeout = STp->device->request_queue->rq_timeout;
 		}
-                DEBC(printk(ST_DEB_MSG "%s: Rewinding tape.\n", name));
+		DEBC_printk(STp, "Rewinding tape.\n");
 		fileno = blkno = at_sm = 0;
 		break;
 	case MTNOP:
-                DEBC(printk(ST_DEB_MSG "%s: No op on tape.\n", name));
+		DEBC_printk(STp, "No op on tape.\n");
 		return 0;	/* Should do something ? */
 		break;
 	case MTRETEN:
@@ -2765,7 +2787,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 			timeout = STp->device->request_queue->rq_timeout;
 		}
 		cmd[4] = 3;
-                DEBC(printk(ST_DEB_MSG "%s: Retensioning tape.\n", name));
+		DEBC_printk(STp, "Retensioning tape.\n");
 		fileno = blkno = at_sm = 0;
 		break;
 	case MTEOM:
@@ -2783,8 +2805,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 			fileno = (-1);
 		cmd[0] = SPACE;
 		cmd[1] = 3;
-                DEBC(printk(ST_DEB_MSG "%s: Spacing to end of recorded medium.\n",
-                            name));
+		DEBC_printk(STp, "Spacing to end of recorded medium.\n");
 		blkno = -1;
 		at_sm = 0;
 		break;
@@ -2800,7 +2821,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		else
 			timeout = STp->long_timeout * 8;
 
-                DEBC(printk(ST_DEB_MSG "%s: Erasing tape.\n", name));
+		DEBC_printk(STp, "Erasing tape.\n");
 		fileno = blkno = at_sm = 0;
 		break;
 	case MTSETBLK:		/* Set block length */
@@ -2815,7 +2836,7 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		    STp->max_block > 0 &&
 		    ((arg & MT_ST_BLKSIZE_MASK) < STp->min_block ||
 		     (arg & MT_ST_BLKSIZE_MASK) > STp->max_block)) {
-			printk(KERN_WARNING "%s: Illegal block size.\n", name);
+			st_printk(KERN_WARNING, STp, "Illegal block size.\n");
 			return (-EINVAL);
 		}
 		cmd[0] = MODE_SELECT;
@@ -2848,21 +2869,21 @@ static int st_int_ioctl(struct scsi_tape *STp, unsigned int cmd_in, unsigned lon
 		(STp->buffer)->b_data[10] = (ltmp >> 8);
 		(STp->buffer)->b_data[11] = ltmp;
 		timeout = STp->device->request_queue->rq_timeout;
-                DEBC(
+		DEBC(
 			if (cmd_in == MTSETBLK || cmd_in == SET_DENS_AND_BLK)
-				printk(ST_DEB_MSG
-                                       "%s: Setting block size to %d bytes.\n", name,
-				       (STp->buffer)->b_data[9] * 65536 +
-				       (STp->buffer)->b_data[10] * 256 +
-				       (STp->buffer)->b_data[11]);
+				st_printk(ST_DEB_MSG, STp,
+					  "Setting block size to %d bytes.\n",
+					  (STp->buffer)->b_data[9] * 65536 +
+					  (STp->buffer)->b_data[10] * 256 +
+					  (STp->buffer)->b_data[11]);
 			if (cmd_in == MTSETDENSITY || cmd_in == SET_DENS_AND_BLK)
-				printk(ST_DEB_MSG
-                                       "%s: Setting density code to %x.\n", name,
-				       (STp->buffer)->b_data[4]);
+				st_printk(ST_DEB_MSG, STp,
+					  "Setting density code to %x.\n",
+					  (STp->buffer)->b_data[4]);
 			if (cmd_in == MTSETDRVBUFFER)
-				printk(ST_DEB_MSG
-                                       "%s: Setting drive buffer code to %d.\n", name,
-				    ((STp->buffer)->b_data[2] >> 4) & 7);
+				st_printk(ST_DEB_MSG, STp,
+					  "Setting drive buffer code to %d.\n",
+					  ((STp->buffer)->b_data[2] >> 4) & 7);
 		)
 		break;
 	default:
@@ -3019,7 +3040,6 @@ static int get_location(struct scsi_tape *STp, unsigned int *block, int *partiti
 	int result;
 	unsigned char scmd[MAX_COMMAND_SIZE];
 	struct st_request *SRpnt;
-	DEB( char *name = tape_name(STp); )
 
 	if (STp->ready != ST_READY)
 		return (-EIO);
@@ -3043,7 +3063,7 @@ static int get_location(struct scsi_tape *STp, unsigned int *block, int *partiti
 	    (STp->device->scsi_level >= SCSI_2 &&
 	     ((STp->buffer)->b_data[0] & 4) != 0)) {
 		*block = *partition = 0;
-                DEBC(printk(ST_DEB_MSG "%s: Can't read tape position.\n", name));
+		DEBC_printk(STp, " Can't read tape position.\n");
 		result = (-EIO);
 	} else {
 		result = 0;
@@ -3062,8 +3082,8 @@ static int get_location(struct scsi_tape *STp, unsigned int *block, int *partiti
 			    (STp->buffer)->b_data[1] == 0)	/* BOP of partition 0 */
 				STp->ps[0].drv_block = STp->ps[0].drv_file = 0;
 		}
-                DEBC(printk(ST_DEB_MSG "%s: Got tape pos. blk %d part %d.\n", name,
-                            *block, *partition));
+		DEBC_printk(STp, "Got tape pos. blk %d part %d.\n",
+			    *block, *partition);
 	}
 	st_release_request(SRpnt);
 	SRpnt = NULL;
@@ -3083,15 +3103,14 @@ static int set_location(struct scsi_tape *STp, unsigned int block, int partition
 	int timeout;
 	unsigned char scmd[MAX_COMMAND_SIZE];
 	struct st_request *SRpnt;
-	DEB( char *name = tape_name(STp); )
 
 	if (STp->ready != ST_READY)
 		return (-EIO);
 	timeout = STp->long_timeout;
 	STps = &(STp->ps[STp->partition]);
 
-        DEBC(printk(ST_DEB_MSG "%s: Setting block to %d and partition to %d.\n",
-                    name, block, partition));
+	DEBC_printk(STp, "Setting block to %d and partition to %d.\n",
+		    block, partition);
 	DEB(if (partition < 0)
 		return (-EIO); )
 
@@ -3105,9 +3124,9 @@ static int set_location(struct scsi_tape *STp, unsigned int block, int partition
 		else {
 			STps->last_block_valid = 1;
 			STps->last_block_visited = blk;
-                        DEBC(printk(ST_DEB_MSG
-                                    "%s: Visited block %d for partition %d saved.\n",
-                                    name, blk, STp->partition));
+			DEBC_printk(STp, "Visited block %d for "
+				    "partition %d saved.\n",
+				    blk, STp->partition);
 		}
 	}
 
@@ -3129,9 +3148,9 @@ static int set_location(struct scsi_tape *STp, unsigned int block, int partition
 		if (STp->partition != partition) {
 			scmd[1] |= 2;
 			scmd[8] = partition;
-                        DEBC(printk(ST_DEB_MSG
-                                    "%s: Trying to change partition from %d to %d\n",
-                                    name, STp->partition, partition));
+			DEBC_printk(STp, "Trying to change partition "
+				    "from %d to %d\n", STp->partition,
+				    partition);
 		}
 	}
 	if (STp->immediate) {
@@ -3222,7 +3241,6 @@ static int switch_partition(struct scsi_tape *STp)
 static int nbr_partitions(struct scsi_tape *STp)
 {
 	int result;
-	DEB( char *name = tape_name(STp); )
 
 	if (STp->ready != ST_READY)
 		return (-EIO);
@@ -3230,13 +3248,12 @@ static int nbr_partitions(struct scsi_tape *STp)
 	result = read_mode_page(STp, PART_PAGE, 1);
 
 	if (result) {
-                DEBC(printk(ST_DEB_MSG "%s: Can't read medium partition page.\n",
-                            name));
+		DEBC_printk(STp, "Can't read medium partition page.\n");
 		result = (-EIO);
 	} else {
 		result = (STp->buffer)->b_data[MODE_HEADER_LENGTH +
 					      PP_OFF_NBR_ADD_PARTS] + 1;
-                DEBC(printk(ST_DEB_MSG "%s: Number of partitions %d.\n", name, result));
+		DEBC_printk(STp, "Number of partitions %d.\n", result);
 	}
 
 	return result;
@@ -3264,21 +3281,20 @@ static int nbr_partitions(struct scsi_tape *STp)
  */
 static int partition_tape(struct scsi_tape *STp, int size)
 {
-	char *name = tape_name(STp);
 	int result;
 	int pgo, psd_cnt, psdo;
 	unsigned char *bp;
 
 	result = read_mode_page(STp, PART_PAGE, 0);
 	if (result) {
-		DEBC(printk(ST_DEB_MSG "%s: Can't read partition mode page.\n", name));
+		DEBC_printk(STp, "Can't read partition mode page.\n");
 		return result;
 	}
 	/* The mode page is in the buffer. Let's modify it and write it. */
 	bp = (STp->buffer)->b_data;
 	pgo = MODE_HEADER_LENGTH + bp[MH_OFF_BDESCS_LENGTH];
-	DEBC(printk(ST_DEB_MSG "%s: Partition page length is %d bytes.\n",
-		    name, bp[pgo + MP_OFF_PAGE_LENGTH] + 2));
+	DEBC_printk(STp, "Partition page length is %d bytes.\n",
+		    bp[pgo + MP_OFF_PAGE_LENGTH] + 2);
 
 	psd_cnt = (bp[pgo + MP_OFF_PAGE_LENGTH] + 2 - PART_PAGE_FIXED_LENGTH) / 2;
 	psdo = pgo + PART_PAGE_FIXED_LENGTH;
@@ -3288,25 +3304,23 @@ static int partition_tape(struct scsi_tape *STp, int size)
 	}
 	memset(bp + psdo, 0, bp[pgo + PP_OFF_NBR_ADD_PARTS] * 2);
 
-	DEBC(printk("%s: psd_cnt %d, max.parts %d, nbr_parts %d\n", name,
+	DEBC_printk(STp, "psd_cnt %d, max.parts %d, nbr_parts %d\n",
 		    psd_cnt, bp[pgo + PP_OFF_MAX_ADD_PARTS],
-		    bp[pgo + PP_OFF_NBR_ADD_PARTS]));
+		    bp[pgo + PP_OFF_NBR_ADD_PARTS]);
 
 	if (size <= 0) {
 		bp[pgo + PP_OFF_NBR_ADD_PARTS] = 0;
 		if (psd_cnt <= bp[pgo + PP_OFF_MAX_ADD_PARTS])
 		    bp[pgo + MP_OFF_PAGE_LENGTH] = 6;
-                DEBC(printk(ST_DEB_MSG "%s: Formatting tape with one partition.\n",
-                            name));
+		DEBC_printk(STp, "Formatting tape with one partition.\n");
 	} else {
 		bp[psdo] = (size >> 8) & 0xff;
 		bp[psdo + 1] = size & 0xff;
 		bp[pgo + 3] = 1;
 		if (bp[pgo + MP_OFF_PAGE_LENGTH] < 8)
 		    bp[pgo + MP_OFF_PAGE_LENGTH] = 8;
-                DEBC(printk(ST_DEB_MSG
-                            "%s: Formatting tape with two partitions (1 = %d MB).\n",
-                            name, size));
+		DEBC_printk(STp, "Formatting tape with two partitions "
+			    "(1 = %d MB).\n", size);
 	}
 	bp[pgo + PP_OFF_PART_UNITS] = 0;
 	bp[pgo + PP_OFF_RESERVED] = 0;
@@ -3314,7 +3328,7 @@ static int partition_tape(struct scsi_tape *STp, int size)
 
 	result = write_mode_page(STp, PART_PAGE, 1);
 	if (result) {
-		printk(KERN_INFO "%s: Partitioning of tape failed.\n", name);
+		st_printk(KERN_INFO, STp, "Partitioning of tape failed.\n");
 		result = (-EIO);
 	}
 
@@ -3332,15 +3346,14 @@ static long st_ioctl(struct file *file, unsigned int cmd_in, unsigned long arg)
 	struct scsi_tape *STp = file->private_data;
 	struct st_modedef *STm;
 	struct st_partstat *STps;
-	char *name = tape_name(STp);
 	void __user *p = (void __user *)arg;
 
 	if (mutex_lock_interruptible(&STp->lock))
 		return -ERESTARTSYS;
 
-        DEB(
+	DEB(
 	if (debugging && !STp->in_use) {
-		printk(ST_DEB_MSG "%s: Incorrect device.\n", name);
+		st_printk(ST_DEB_MSG, STp, "Incorrect device.\n");
 		retval = (-EIO);
 		goto out;
 	} ) /* end DEB */
@@ -3378,8 +3391,8 @@ static long st_ioctl(struct file *file, unsigned int cmd_in, unsigned long arg)
 		}
 
 		if (mtc.mt_op == MTSETDRVBUFFER && !capable(CAP_SYS_ADMIN)) {
-			printk(KERN_WARNING
-                               "%s: MTSETDRVBUFFER only allowed for root.\n", name);
+			st_printk(KERN_WARNING, STp,
+				  "MTSETDRVBUFFER only allowed for root.\n");
 			retval = (-EPERM);
 			goto out;
 		}
@@ -4087,7 +4100,8 @@ static int st_probe(struct device *dev)
 		return -ENODEV;
 	if ((stp = st_incompatible(SDp))) {
 		sdev_printk(KERN_INFO, SDp, "Found incompatible tape\n");
-		printk(KERN_INFO "st: The suggested driver is %s.\n", stp);
+		sdev_printk(KERN_INFO, SDp,
+			    "st: The suggested driver is %s.\n", stp);
 		return -ENODEV;
 	}
 
@@ -4096,20 +4110,23 @@ static int st_probe(struct device *dev)
 		i = st_max_sg_segs;
 	buffer = new_tape_buffer((SDp->host)->unchecked_isa_dma, i);
 	if (buffer == NULL) {
-		printk(KERN_ERR
-		       "st: Can't allocate new tape buffer. Device not attached.\n");
+		sdev_printk(KERN_ERR, SDp,
+			    "st: Can't allocate new tape buffer. "
+			    "Device not attached.\n");
 		goto out;
 	}
 
 	disk = alloc_disk(1);
 	if (!disk) {
-		printk(KERN_ERR "st: out of memory. Device not attached.\n");
+		sdev_printk(KERN_ERR, SDp,
+			    "st: out of memory. Device not attached.\n");
 		goto out_buffer_free;
 	}
 
 	tpnt = kzalloc(sizeof(struct scsi_tape), GFP_ATOMIC);
 	if (tpnt == NULL) {
-		printk(KERN_ERR "st: Can't allocate device descriptor.\n");
+		sdev_printk(KERN_ERR, SDp,
+			    "st: Can't allocate device descriptor.\n");
 		goto out_put_disk;
 	}
 	kref_init(&tpnt->kref);
-- 
1.7.12.4


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

* [PATCH 5/6] scsi: use dev_printk() variants for ioctl
  2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
                   ` (3 preceding siblings ...)
  2014-06-25 14:39 ` [PATCH 4/6] scsi: Implement st_printk() Hannes Reinecke
@ 2014-06-25 14:39 ` Hannes Reinecke
  2014-06-25 14:39 ` [PATCH 6/6] scsi: use dev_printk variants where possible Hannes Reinecke
  5 siblings, 0 replies; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Signed-off-by: Hannes Reinecke <hare@suse.de>
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
---
 drivers/scsi/scsi_ioctl.c | 17 +++++++++++------
 1 file changed, 11 insertions(+), 6 deletions(-)

diff --git a/drivers/scsi/scsi_ioctl.c b/drivers/scsi/scsi_ioctl.c
index d9564fb..1aaaf43 100644
--- a/drivers/scsi/scsi_ioctl.c
+++ b/drivers/scsi/scsi_ioctl.c
@@ -91,12 +91,14 @@ static int ioctl_internal_command(struct scsi_device *sdev, char *cmd,
 	int result;
 	struct scsi_sense_hdr sshdr;
 
-	SCSI_LOG_IOCTL(1, printk("Trying ioctl with scsi command %d\n", *cmd));
+	SCSI_LOG_IOCTL(1, sdev_printk(KERN_INFO, sdev,
+				      "Trying ioctl with scsi command %d\n", *cmd));
 
 	result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL, 0,
 				  &sshdr, timeout, retries, NULL);
 
-	SCSI_LOG_IOCTL(2, printk("Ioctl returned  0x%x\n", result));
+	SCSI_LOG_IOCTL(2, sdev_printk(KERN_INFO, sdev,
+				      "Ioctl returned  0x%x\n", result));
 
 	if ((driver_byte(result) & DRIVER_SENSE) &&
 	    (scsi_sense_valid(&sshdr))) {
@@ -105,9 +107,11 @@ static int ioctl_internal_command(struct scsi_device *sdev, char *cmd,
 			if (cmd[0] == ALLOW_MEDIUM_REMOVAL)
 				sdev->lockable = 0;
 			else
-				printk(KERN_INFO "ioctl_internal_command: "
-				       "ILLEGAL REQUEST asc=0x%x ascq=0x%x\n",
-				       sshdr.asc, sshdr.ascq);
+				sdev_printk(KERN_INFO, sdev,
+					    "ioctl_internal_command: "
+					    "ILLEGAL REQUEST "
+					    "asc=0x%x ascq=0x%x\n",
+					    sshdr.asc, sshdr.ascq);
 			break;
 		case NOT_READY:	/* This happens if there is no disc in drive */
 			if (sdev->removable)
@@ -127,7 +131,8 @@ static int ioctl_internal_command(struct scsi_device *sdev, char *cmd,
 		}
 	}
 
-	SCSI_LOG_IOCTL(2, printk("IOCTL Releasing command\n"));
+	SCSI_LOG_IOCTL(2, sdev_printk(KERN_INFO, sdev,
+				      "IOCTL Releasing command\n"));
 	return result;
 }
 
-- 
1.7.12.4


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

* [PATCH 6/6] scsi: use dev_printk variants where possible
  2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
                   ` (4 preceding siblings ...)
  2014-06-25 14:39 ` [PATCH 5/6] scsi: use dev_printk() variants for ioctl Hannes Reinecke
@ 2014-06-25 14:39 ` Hannes Reinecke
  5 siblings, 0 replies; 9+ messages in thread
From: Hannes Reinecke @ 2014-06-25 14:39 UTC (permalink / raw)
  To: James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi, Hannes Reinecke

Using dev_printk variants prefixes the logging message with
the originating device, which makes debugging easier.

Signed-off-by: Hannes Reinecke <hare@suse.de>
Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
Reviewed-by: Christoph Hellwig <hch@lst.de>
---
 drivers/scsi/hosts.c      |  15 ++--
 drivers/scsi/scsi.c       |  18 ++---
 drivers/scsi/scsi_error.c | 179 +++++++++++++++++++++++++---------------------
 drivers/scsi/scsi_lib.c   |  22 +++---
 drivers/scsi/scsi_scan.c  |  62 ++++++++--------
 5 files changed, 157 insertions(+), 139 deletions(-)

diff --git a/drivers/scsi/hosts.c b/drivers/scsi/hosts.c
index 3cbb57a..0632eee 100644
--- a/drivers/scsi/hosts.c
+++ b/drivers/scsi/hosts.c
@@ -204,12 +204,12 @@ int scsi_add_host_with_dma(struct Scsi_Host *shost, struct device *dev,
 	struct scsi_host_template *sht = shost->hostt;
 	int error = -EINVAL;
 
-	printk(KERN_INFO "scsi%d : %s\n", shost->host_no,
+	shost_printk(KERN_INFO, shost, "%s\n",
 			sht->info ? sht->info(shost) : sht->name);
 
 	if (!shost->can_queue) {
-		printk(KERN_ERR "%s: can_queue = 0 no longer supported\n",
-				sht->name);
+		shost_printk(KERN_ERR, shost,
+			     "can_queue = 0 no longer supported\n");
 		goto fail;
 	}
 
@@ -450,8 +450,9 @@ struct Scsi_Host *scsi_host_alloc(struct scsi_host_template *sht, int privsize)
 	shost->ehandler = kthread_run(scsi_error_handler, shost,
 			"scsi_eh_%d", shost->host_no);
 	if (IS_ERR(shost->ehandler)) {
-		printk(KERN_WARNING "scsi%d: error handler thread failed to spawn, error = %ld\n",
-			shost->host_no, PTR_ERR(shost->ehandler));
+		shost_printk(KERN_WARNING, shost,
+			"error handler thread failed to spawn, error = %ld\n",
+			PTR_ERR(shost->ehandler));
 		goto fail_kfree;
 	}
 
@@ -584,7 +585,7 @@ EXPORT_SYMBOL(scsi_is_host_device);
 int scsi_queue_work(struct Scsi_Host *shost, struct work_struct *work)
 {
 	if (unlikely(!shost->work_q)) {
-		printk(KERN_ERR
+		shost_printk(KERN_ERR, shost,
 			"ERROR: Scsi host '%s' attempted to queue scsi-work, "
 			"when no workqueue created.\n", shost->hostt->name);
 		dump_stack();
@@ -603,7 +604,7 @@ EXPORT_SYMBOL_GPL(scsi_queue_work);
 void scsi_flush_work(struct Scsi_Host *shost)
 {
 	if (!shost->work_q) {
-		printk(KERN_ERR
+		shost_printk(KERN_ERR, shost,
 			"ERROR: Scsi host '%s' attempted to flush scsi-work, "
 			"when no workqueue created.\n", shost->hostt->name);
 		dump_stack();
diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index bff351b..ce5b4e5 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -655,7 +655,7 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 
 	/* Check to see if the scsi lld made this device blocked. */
 	if (unlikely(scsi_device_blocked(cmd->device))) {
-		/* 
+		/*
 		 * in blocked state, the command is just put back on
 		 * the device queue.  The suspend state has already
 		 * blocked the queue so future requests should not
@@ -665,7 +665,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\n"));
 
 		/*
 		 * NOTE: rtn is still zero here because we don't need the
@@ -674,7 +675,7 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 		goto out;
 	}
 
-	/* 
+	/*
 	 * If SCSI-2 or lower, store the LUN value in cmnd.
 	 */
 	if (cmd->device->scsi_level <= SCSI_2 &&
@@ -690,8 +691,8 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 	 * length exceeds what the host adapter can handle.
 	 */
 	if (cmd->cmd_len > cmd->device->host->max_cmd_len) {
-		SCSI_LOG_MLQUEUE(3,
-			printk("queuecommand : command too long. "
+		SCSI_LOG_MLQUEUE(3, scmd_printk(KERN_INFO, cmd,
+			       "queuecommand : command too long. "
 			       "cdb_size=%d host->max_cmd_len=%d\n",
 			       cmd->cmd_len, cmd->device->host->max_cmd_len));
 		cmd->result = (DID_ABORT << 16);
@@ -715,14 +716,13 @@ int scsi_dispatch_cmd(struct scsi_cmnd *cmd)
 		    rtn != SCSI_MLQUEUE_TARGET_BUSY)
 			rtn = SCSI_MLQUEUE_HOST_BUSY;
 
-		scsi_queue_insert(cmd, rtn);
+		SCSI_LOG_MLQUEUE(3, scmd_printk(KERN_INFO, cmd,
+			"queuecommand : request rejected\n"));
 
-		SCSI_LOG_MLQUEUE(3,
-		    printk("queuecommand : request rejected\n"));
+		scsi_queue_insert(cmd, rtn);
 	}
 
  out:
-	SCSI_LOG_MLQUEUE(3, printk("leaving scsi_dispatch_cmnd()\n"));
 	return rtn;
 }
 
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index 4f36ae2..e4a5324 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -62,8 +62,8 @@ void scsi_eh_wakeup(struct Scsi_Host *shost)
 	if (shost->host_busy == shost->host_failed) {
 		trace_scsi_eh_wakeup(shost);
 		wake_up_process(shost->ehandler);
-		SCSI_LOG_ERROR_RECOVERY(5,
-				printk("Waking error handler thread\n"));
+		SCSI_LOG_ERROR_RECOVERY(5, shost_printk(KERN_INFO, shost,
+			"Waking error handler thread\n"));
 	}
 }
 
@@ -319,8 +319,8 @@ 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\n", __func__, online));
 
 	return online;
 }
@@ -365,8 +365,9 @@ static inline void scsi_eh_prt_fail_stats(struct Scsi_Host *shost,
 		}
 	}
 
-	SCSI_LOG_ERROR_RECOVERY(2, printk("Total of %d commands on %d"
-					  " devices require eh work\n",
+	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));
 }
 #endif
@@ -738,8 +739,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",
+	SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+			"%s scmd: %p result: %x\n",
 			__func__, scmd, scmd->result));
 
 	eh_action = scmd->device->host->eh_action;
@@ -758,8 +759,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",
-					  __func__));
+	SCSI_LOG_ERROR_RECOVERY(3,
+		shost_printk(KERN_INFO, host, "Snd Host RST\n"));
 
 	if (!hostt->eh_host_reset_handler)
 		return FAILED;
@@ -788,8 +789,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, scmd_printk(KERN_INFO, scmd,
+		"%s: Snd Bus RST\n", __func__));
 
 	if (!hostt->eh_bus_reset_handler)
 		return FAILED;
@@ -1036,8 +1037,8 @@ retry:
 
 	scsi_log_completion(scmd, rtn);
 
-	SCSI_LOG_ERROR_RECOVERY(3,
-		printk("%s: scmd: %p, timeleft: %ld\n",
+	SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+			"%s: scmd: %p, timeleft: %ld\n",
 			__func__, scmd, timeleft));
 
 	/*
@@ -1051,9 +1052,8 @@ retry:
 	 */
 	if (timeleft) {
 		rtn = scsi_eh_completed_normally(scmd);
-		SCSI_LOG_ERROR_RECOVERY(3,
-			printk("%s: scsi_eh_completed_normally %x\n",
-			       __func__, rtn));
+		SCSI_LOG_ERROR_RECOVERY(3, scmd_printk(KERN_INFO, scmd,
+			"%s: scsi_eh_completed_normally %x\n", __func__, rtn));
 
 		switch (rtn) {
 		case SUCCESS:
@@ -1177,9 +1177,9 @@ int scsi_eh_get_sense(struct list_head *work_q,
 		if (rtn != SUCCESS)
 			continue;
 
-		SCSI_LOG_ERROR_RECOVERY(3, printk("sense requested for %p"
-						  " result %x\n", scmd,
-						  scmd->result));
+		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));
 
 		rtn = scsi_decide_disposition(scmd);
@@ -1220,8 +1220,8 @@ retry_tur:
 	rtn = scsi_send_eh_cmnd(scmd, tur_command, 6,
 				scmd->device->eh_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\n", __func__, scmd, rtn));
 
 	switch (rtn) {
 	case NEEDS_RETRY:
@@ -1323,16 +1323,16 @@ static int scsi_eh_abort_cmds(struct list_head *work_q,
 					     __func__));
 			return list_empty(work_q);
 		}
-		SCSI_LOG_ERROR_RECOVERY(3, printk("%s: aborting cmd:"
-						  "0x%p\n", current->comm,
-						  scmd));
+		SCSI_LOG_ERROR_RECOVERY(3,
+			shost_printk(KERN_INFO, shost,
+				     "%s: aborting cmd: 0x%p\n",
+				     current->comm, scmd));
 		rtn = scsi_try_to_abort_cmd(shost->hostt, scmd);
 		if (rtn == FAILED) {
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: aborting"
-							  " cmd failed:"
-							  "0x%p\n",
-							  current->comm,
-							  scmd));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				shost_printk(KERN_INFO, shost,
+					     "%s: aborting cmd failed: 0x%p\n",
+					     current->comm, scmd));
 			list_splice_init(&check_list, work_q);
 			return list_empty(work_q);
 		}
@@ -1406,8 +1406,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,
+			shost_printk(KERN_INFO, shost,
+				     "%s: Sending START_UNIT to sdev: 0x%p\n",
+				     current->comm, sdev));
 
 		if (!scsi_eh_try_stu(stu_scmd)) {
 			if (!scsi_device_online(sdev) ||
@@ -1421,8 +1423,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));
+				shost_printk(KERN_INFO, shost,
+					     "%s: START_UNIT failed to sdev:"
+					     " 0x%p\n", current->comm, sdev));
 		}
 	}
 
@@ -1468,9 +1471,10 @@ 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:"
-						  " 0x%p\n", current->comm,
-						  sdev));
+		SCSI_LOG_ERROR_RECOVERY(3,
+			shost_printk(KERN_INFO, shost,
+				     "%s: Sending BDR sdev: 0x%p\n",
+				     current->comm, sdev));
 		rtn = scsi_try_bus_device_reset(bdr_scmd);
 		if (rtn == SUCCESS || rtn == FAST_IO_FAIL) {
 			if (!scsi_device_online(sdev) ||
@@ -1485,11 +1489,10 @@ static int scsi_eh_bus_device_reset(struct Scsi_Host *shost,
 				}
 			}
 		} else {
-			SCSI_LOG_ERROR_RECOVERY(3, printk("%s: BDR"
-							  " failed sdev:"
-							  "0x%p\n",
-							  current->comm,
-							   sdev));
+			SCSI_LOG_ERROR_RECOVERY(3,
+				shost_printk(KERN_INFO, shost,
+					     "%s: BDR failed sdev: 0x%p\n",
+					     current->comm, sdev));
 		}
 	}
 
@@ -1533,15 +1536,17 @@ 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,
+			shost_printk(KERN_INFO, shost,
+				     "%s: Sending target reset to target %d\n",
+				     current->comm, id));
 		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,
+				shost_printk(KERN_INFO, shost,
+					     "%s: Target reset failed"
+					     " target: %d\n",
+					     current->comm, id));
 		list_for_each_entry_safe(scmd, next, &tmp_list, eh_entry) {
 			if (scmd_id(scmd) != id)
 				continue;
@@ -1605,9 +1610,10 @@ 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,
+			shost_printk(KERN_INFO, shost,
+				     "%s: Sending BRST chan: %d\n",
+				     current->comm, channel));
 		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) {
@@ -1621,10 +1627,10 @@ 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,
+				shost_printk(KERN_INFO, shost,
+					     "%s: BRST failed chan: %d\n",
+					     current->comm, channel));
 		}
 	}
 	return scsi_eh_test_devices(&check_list, work_q, done_q, 0);
@@ -1635,7 +1641,8 @@ static int scsi_eh_bus_reset(struct Scsi_Host *shost,
  * @work_q:	list_head for processed commands.
  * @done_q:	list_head for processed commands.
  */
-static int scsi_eh_host_reset(struct list_head *work_q,
+static int scsi_eh_host_reset(struct Scsi_Host *shost,
+			      struct list_head *work_q,
 			      struct list_head *done_q)
 {
 	struct scsi_cmnd *scmd, *next;
@@ -1646,8 +1653,10 @@ 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,
+			shost_printk(KERN_INFO, shost,
+				     "%s: Sending HRST\n",
+				     current->comm));
 
 		rtn = scsi_try_host_reset(scmd);
 		if (rtn == SUCCESS) {
@@ -1657,9 +1666,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,
+				shost_printk(KERN_INFO, shost,
+					     "%s: HRST failed\n",
+					     current->comm));
 		}
 	}
 	return scsi_eh_test_devices(&check_list, work_q, done_q, 1);
@@ -1751,9 +1761,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"
-						  " as SUCCESS\n",
-						  __func__));
+		SCSI_LOG_ERROR_RECOVERY(5, scmd_printk(KERN_INFO, scmd,
+			"%s: device offline - report as SUCCESS\n", __func__));
 		return SUCCESS;
 	}
 
@@ -1999,8 +2008,7 @@ static void scsi_restart_operations(struct Scsi_Host *shost)
 	 * ioctls to queued block devices.
 	 */
 	SCSI_LOG_ERROR_RECOVERY(3,
-		printk("scsi_eh_%d waking up host to restart\n",
-		       shost->host_no));
+		shost_printk(KERN_INFO, shost, "waking up host to restart\n"));
 
 	spin_lock_irqsave(shost->host_lock, flags);
 	if (scsi_host_set_state(shost, SHOST_RUNNING))
@@ -2047,7 +2055,7 @@ void scsi_eh_ready_devs(struct Scsi_Host *shost,
 		if (!scsi_eh_bus_device_reset(shost, work_q, done_q))
 			if (!scsi_eh_target_reset(shost, work_q, done_q))
 				if (!scsi_eh_bus_reset(shost, work_q, done_q))
-					if (!scsi_eh_host_reset(work_q, done_q))
+					if (!scsi_eh_host_reset(shost, work_q, done_q))
 						scsi_eh_offline_sdevs(work_q,
 								      done_q);
 }
@@ -2066,10 +2074,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 {
 			/*
@@ -2079,9 +2087,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);
 		}
 	}
@@ -2157,17 +2166,19 @@ 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("scsi_eh_%d: sleeping\n",
-					shost->host_no));
+				shost_printk(KERN_INFO, shost,
+					     "scsi_eh_%d: sleeping\n",
+					     shost->host_no));
 			schedule();
 			continue;
 		}
 
 		__set_current_state(TASK_RUNNING);
 		SCSI_LOG_ERROR_RECOVERY(1,
-			printk("scsi_eh_%d: waking up %d/%d/%d\n",
-			       shost->host_no, shost->host_eh_scheduled,
-			       shost->host_failed, shost->host_busy));
+			shost_printk(KERN_INFO, shost,
+				     "scsi_eh_%d: waking up %d/%d/%d\n",
+				     shost->host_no, shost->host_eh_scheduled,
+				     shost->host_failed, shost->host_busy));
 
 		/*
 		 * We have a host that is failing for some reason.  Figure out
@@ -2201,7 +2212,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\n",
+			     shost->host_no));
 	shost->ehandler = NULL;
 	return 0;
 }
@@ -2362,8 +2375,8 @@ 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,
+			     "waking up host to restart after TMF\n"));
 
 	wake_up(&shost->host_wait);
 
diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index f7e3163..d5d22e4 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -95,8 +95,8 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, int unbusy)
 	struct request_queue *q = device->request_queue;
 	unsigned long flags;
 
-	SCSI_LOG_MLQUEUE(1,
-		 printk("Inserting command %p into mlqueue\n", cmd));
+	SCSI_LOG_MLQUEUE(1, scmd_printk(KERN_INFO, cmd,
+		"Inserting command %p into mlqueue\n", cmd));
 
 	/*
 	 * Set the appropriate busy bit for the device/host.
@@ -742,9 +742,9 @@ 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",
-				      blk_rq_sectors(req), good_bytes));
+	SCSI_LOG_HLCOMPLETE(1, scmd_printk(KERN_INFO, cmd,
+		"%u sectors total, %d bytes done.\n",
+		blk_rq_sectors(req), good_bytes));
 
 	/*
 	 * Recovered errors need reporting, but they're always treated
@@ -1343,8 +1343,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",
-					shost->host_no));
+				shost_printk(KERN_INFO, shost,
+					     "unblocking host at zero depth\n"));
 		} else {
 			return 0;
 		}
@@ -1453,7 +1453,7 @@ static void scsi_softirq_done(struct request *rq)
 			    wait_for/HZ);
 		disposition = SUCCESS;
 	}
-			
+
 	scsi_log_completion(cmd, disposition);
 
 	switch (disposition) {
@@ -1501,7 +1501,7 @@ static void scsi_request_fn(struct request_queue *q)
 		int rtn;
 		/*
 		 * get next queueable request.  We do this early to make sure
-		 * that the request is fully prepared even if we cannot 
+		 * that the request is fully prepared even if we cannot
 		 * accept it.
 		 */
 		req = blk_peek_request(q);
@@ -2139,9 +2139,9 @@ scsi_device_set_state(struct scsi_device *sdev, enum scsi_device_state state)
 	return 0;
 
  illegal:
-	SCSI_LOG_ERROR_RECOVERY(1, 
+	SCSI_LOG_ERROR_RECOVERY(1,
 				sdev_printk(KERN_ERR, sdev,
-					    "Illegal state transition %s->%s\n",
+					    "Illegal state transition %s->%s",
 					    scsi_device_state_name(oldstate),
 					    scsi_device_state_name(state))
 				);
diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
index 553e1c7..f12dca7 100644
--- a/drivers/scsi/scsi_scan.c
+++ b/drivers/scsi/scsi_scan.c
@@ -194,7 +194,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, "unlocking floptical drive\n");
 	scsi_cmd[0] = MODE_SENSE;
 	scsi_cmd[1] = 0;
 	scsi_cmd[2] = 0x2e;
@@ -596,8 +596,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) {
@@ -667,9 +667,10 @@ 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.  "
-				"Consider BLIST_INQUIRY_36 for this device\n",
-				try_inquiry_len);
+		sdev_printk(KERN_INFO, sdev,
+			    "scsi scan: %d byte inquiry failed.  "
+			    "Consider BLIST_INQUIRY_36 for this device\n",
+			    try_inquiry_len);
 
 		/* If this pass failed, the third pass goes back and transfers
 		 * the same amount as we successfully got in the first pass. */
@@ -702,8 +703,9 @@ 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),"
-				" using 36\n", sdev->inquiry_len);
+		sdev_printk(KERN_INFO, sdev,
+			    "scsi scan: INQUIRY result too short (%d),"
+			    " using 36\n", sdev->inquiry_len);
 		sdev->inquiry_len = 36;
 	}
 
@@ -822,7 +824,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\n",
+			    sdev->type);
 	}
 
 	if (sdev->type == TYPE_RBC || sdev->type == TYPE_ROM) {
@@ -1044,7 +1047,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)
@@ -1131,7 +1134,7 @@ 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"));
 		res = SCSI_SCAN_TARGET_PRESENT;
@@ -1185,8 +1188,8 @@ static void scsi_sequential_lun_scan(struct scsi_target *starget,
 	u64 sparse_lun, 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, starget_printk(KERN_INFO, starget,
+		"scsi scan: Sequential scan\n"));
 
 	max_dev_lun = min(max_scsi_luns, shost->max_lun);
 	/*
@@ -1431,17 +1434,19 @@ 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 to (try %d)\n",
 				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
-				?  "failed" : "successful", retries, result));
+		SCSI_LOG_SCAN_BUS(3, sdev_printk (KERN_INFO, sdev,
+				"scsi scan: REPORT LUNS"
+				" %s (try %d) result 0x%x\n",
+				result ?  "failed" : "successful",
+				retries, result));
 		if (result == 0)
 			break;
 		else if (scsi_sense_valid(&sshdr)) {
@@ -1467,10 +1472,11 @@ 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)"
-		       " of %d luns reported, try increasing"
-		       " max_scsi_report_luns.\n", devname,
-		       max_scsi_report_luns, num_luns);
+		sdev_printk(KERN_WARNING, sdev,
+			    "Only %d (max_scsi_report_luns)"
+			    " of %d luns reported, try increasing"
+			    " max_scsi_report_luns.\n",
+			    max_scsi_report_luns, num_luns);
 		num_luns = max_scsi_report_luns;
 	}
 
@@ -1485,9 +1491,9 @@ static int scsi_report_lun_scan(struct scsi_target *starget, int bflags,
 		lun = scsilun_to_int(lunp);
 
 		if (lun > sdev->host->max_lun) {
-			printk(KERN_WARNING "scsi: %s lun%llu has a LUN larger"
-			       " than allowed by the host adapter\n",
-			       devname, lun);
+			sdev_printk(KERN_WARNING, sdev,
+				    "lun%llu has a LUN larger than"
+				    " allowed by the host adapter\n", lun);
 		} else {
 			int res;
 
@@ -1765,8 +1771,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\n", __func__);
 		dump_stack();
 		return NULL;
 	}
@@ -1819,8 +1824,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\n", __func__);
 		dump_stack();
 		mutex_unlock(&shost->scan_mutex);
 		return;
-- 
1.7.12.4


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

* Re: [PATCH 2/6] scsi: Implement sg_printk()
  2014-06-25 14:39 ` [PATCH 2/6] scsi: Implement sg_printk() Hannes Reinecke
@ 2014-06-25 20:21   ` Douglas Gilbert
  2014-06-26  7:41     ` Christoph Hellwig
  0 siblings, 1 reply; 9+ messages in thread
From: Douglas Gilbert @ 2014-06-25 20:21 UTC (permalink / raw)
  To: Hannes Reinecke, James Bottomley
  Cc: Christoph Hellwig, Martin K. Petersen, linux-scsi

On 14-06-25 10:39 AM, Hannes Reinecke wrote:
> Update the sg driver to use dev_printk() variants instead of
> plain printk(); this will prefix logging messages with the
> appropriate device.
>
> Signed-off-by: Hannes Reinecke <hare@suse.de>
> Acked-by: Doug Gilbert <dgilbert@interlog.com>
^^^^^^^^^^^

A comment below as I believe you are going to make another
sweep through these printk()s in the future.

Doug Gilbert

> Reviewed-by: Martin K. Petersen <martin.petersen@oracle.com>
> Reviewed-by: Christoph Hellwig <hch@lst.de>
> ---
>   drivers/scsi/sg.c | 163 +++++++++++++++++++++++++++++++-----------------------
>   1 file changed, 95 insertions(+), 68 deletions(-)
>
> diff --git a/drivers/scsi/sg.c b/drivers/scsi/sg.c
> index f27b70d..cb2a18e 100644
> --- a/drivers/scsi/sg.c
> +++ b/drivers/scsi/sg.c
> @@ -199,11 +199,11 @@ 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_fd * sfp, Sg_scatter_hold * schp);
>   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);
> -static Sg_fd *sg_add_sfp(Sg_device * sdp, int dev);
> +static Sg_fd *sg_add_sfp(Sg_device * sdp);
>   static void sg_remove_sfp(struct kref *);
>   static Sg_request *sg_get_rq_mark(Sg_fd * sfp, int pack_id);
>   static Sg_request *sg_add_request(Sg_fd * sfp);
> @@ -217,6 +217,10 @@ static void sg_device_destroy(struct kref *kref);
>   #define SZ_SG_IOVEC sizeof(sg_iovec_t)
>   #define SZ_SG_REQ_INFO sizeof(sg_req_info_t)
>
> +#define sg_printk(prefix, sdp, fmt, a...) \
> +	sdev_printk(prefix, (sdp)->device, "[%s] " fmt, \
> +		    (sdp)->disk->disk_name, ##a)
> +
>   static int sg_allow_access(struct file *filp, unsigned char *cmd)
>   {
>   	struct sg_fd *sfp = filp->private_data;
> @@ -275,13 +279,15 @@ 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));
>   	if ((flags & O_EXCL) && (O_RDONLY == (flags & O_ACCMODE)))
>   		return -EPERM; /* Can't lock it with read only access */
>   	sdp = sg_get_dev(dev);
>   	if (IS_ERR(sdp))
>   		return PTR_ERR(sdp);
>
> +	SCSI_LOG_TIMEOUT(3, sg_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 */
>   	retval = scsi_device_get(sdp->device);
> @@ -330,7 +336,7 @@ sg_open(struct inode *inode, struct file *filp)
>   		q = sdp->device->request_queue;
>   		sdp->sg_tablesize = queue_max_segments(q);
>   	}
> -	sfp = sg_add_sfp(sdp, dev);
> +	sfp = sg_add_sfp(sdp);
>   	if (IS_ERR(sfp)) {
>   		retval = PTR_ERR(sfp);
>   		goto out_undo;
> @@ -369,7 +375,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, sg_printk(KERN_INFO, sdp, "sg_release\n"));
>
>   	mutex_lock(&sdp->open_rel_lock);
>   	scsi_autopm_put_device(sdp->device);
> @@ -401,8 +407,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, sg_printk(KERN_INFO, sdp,
> +				      "sg_read: count=%d\n", (int) count));
>
>   	if (!access_ok(VERIFY_WRITE, buf, count))
>   		return -EFAULT;
> @@ -587,8 +593,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, sg_printk(KERN_INFO, sdp,
> +				      "sg_write: count=%d\n", (int) count));
>   	if (atomic_read(&sdp->detaching))
>   		return -ENODEV;
>   	if (!((filp->f_flags & O_NONBLOCK) ||
> @@ -609,7 +615,8 @@ 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, sg_printk(KERN_INFO, sdp,
> +					      "sg_write: queue full\n"));
>   		return -EDOM;
>   	}
>   	buf += SZ_SG_HEADER;
> @@ -622,7 +629,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, sg_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;
> @@ -697,7 +704,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, sg_printk(KERN_INFO, sfp->parentdp,
> +					      "sg_new_write: queue full\n"));
>   		return -EDOM;
>   	}
>   	srp->sg_io_owned = sg_io_owned;
> @@ -766,12 +774,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, sg_printk(KERN_INFO, sfp->parentdp,
> +			"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, sg_printk(KERN_INFO, sfp->parentdp,
> +			"sg_common_write: start_req err=%d\n", k));
>   		sg_finish_rem_req(srp);
>   		return k;	/* probably out of space --> ENOMEM */
>   	}
> @@ -845,8 +855,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, sg_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) {
> @@ -898,7 +908,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, &sfp->reserve);
>   				sg_build_reserve(sfp, val);
>   			}
>   		} else {
> @@ -974,7 +984,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, &sfp->reserve);
>   			sg_build_reserve(sfp, val);
>   		}
>   		return 0;
> @@ -1197,8 +1207,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, sg_printk(KERN_INFO, sdp,
> +				      "sg_poll: res=0x%x\n", (int) res));
>   	return res;
>   }
>
> @@ -1210,8 +1220,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, sg_printk(KERN_INFO, sdp,
> +				      "sg_fasync: mode=%d\n", mode));
>
>   	return fasync_helper(fd, filp, mode, &sfp->async_qp);
>   }
> @@ -1230,8 +1240,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, sg_printk(KERN_INFO, sfp->parentdp,
> +				      "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++) {
> @@ -1266,8 +1277,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, sg_printk(KERN_INFO, sfp->parentdp,
> +				      "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;
> @@ -1329,8 +1341,9 @@ sg_rq_end_io(struct request *rq, int uptodate)
>   	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, sg_printk(KERN_INFO, sdp,
> +				      "sg_cmd_done: pack_id=%d, res=0x%x\n",
> +				      srp->header.pack_id, result));

That function used to be called sg_cmd_done() but
another hacker gave it a more reasonable name (?)
but neglected to fix the printk_s. There are other
examples, so now I prefer:

   SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sdp,
		   "%s: pack_id=%d, res=0x%x\n", __func__,
		   srp->header.pack_id, result));


Oh, and we really shouldn't be printing from this context but
it works and I have found it useful in debugging :-)

>   	srp->header.resid = resid;
>   	ms = jiffies_to_msecs(jiffies);
>   	srp->header.duration = (ms > srp->header.duration) ?
> @@ -1440,7 +1453,8 @@ sg_alloc(struct gendisk *disk, struct scsi_device *scsidp)
>   	}
>   	k = error;
>
> -	SCSI_LOG_TIMEOUT(3, printk("sg_alloc: dev=%d \n", k));
> +	SCSI_LOG_TIMEOUT(3, sdev_printk(KERN_INFO, scsidp,
> +					"sg_alloc: dev=%d \n", k));
>   	sprintf(disk->disk_name, "sg%d", k);
>   	disk->first_minor = k;
>   	sdp->disk = disk;
> @@ -1560,8 +1574,7 @@ sg_device_destroy(struct kref *kref)
>   	write_unlock_irqrestore(&sg_index_lock, flags);
>
>   	SCSI_LOG_TIMEOUT(3,
> -		printk("sg_device_destroy: %s\n",
> -			sdp->disk->disk_name));
> +		sg_printk(KERN_INFO, sdp, "sg_device_destroy\n"));
>
>   	put_disk(sdp->disk);
>   	kfree(sdp);
> @@ -1583,8 +1596,8 @@ sg_remove_device(struct device *cl_dev, struct class_interface *cl_intf)
>   	if (val > 1)
>   		return; /* only want to do following once per device */
>
> -	SCSI_LOG_TIMEOUT(3, printk("%s: %s\n", __func__,
> -			 sdp->disk->disk_name));
> +	SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp,
> +				      "%s\n", __func__));
>
>   	read_lock_irqsave(&sdp->sfd_lock, iflags);
>   	list_for_each_entry(sfp, &sdp->sfds, sfd_siblings) {
> @@ -1686,8 +1699,9 @@ sg_start_req(Sg_request *srp, unsigned char *cmd)
>   	int rw = hp->dxfer_direction == SG_DXFER_TO_DEV ? WRITE : READ;
>   	unsigned char *long_cmdp = NULL;
>
> -	SCSI_LOG_TIMEOUT(4, printk(KERN_INFO "sg_start_req: dxfer_len=%d\n",
> -				   dxfer_len));
> +	SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sfp->parentdp,
> +				      "sg_start_req: dxfer_len=%d\n",
> +				      dxfer_len));
>
>   	if (hp->cmd_len > BLK_MAX_CDB) {
>   		long_cmdp = kzalloc(hp->cmd_len, GFP_KERNEL);
> @@ -1785,7 +1799,9 @@ 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, sg_printk(KERN_INFO, sfp->parentdp,
> +				      "sg_finish_rem_req: res_used=%d\n",
> +				      (int) srp->res_used));
>   	if (srp->rq) {
>   		if (srp->bio)
>   			ret = blk_rq_unmap_user(srp->bio);
> @@ -1798,7 +1814,7 @@ 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(sfp, req_schp);
>
>   	sg_remove_request(sfp, srp);
>
> @@ -1832,8 +1848,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, sg_printk(KERN_INFO, sfp->parentdp,
> +		"sg_build_indirect: buff_size=%d, blk_size=%d\n",
> +		buff_size, blk_size));
>
>   	/* N.B. ret_sz carried into this block ... */
>   	mx_sc_elems = sg_build_sgat(schp, sfp, sg_tablesize);
> @@ -1876,14 +1893,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, sg_printk(KERN_INFO, sfp->parentdp,
> +				 "sg_build_indirect: k=%d, num=%d, ret_sz=%d\n",
> +				 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, sg_printk(KERN_INFO, sfp->parentdp,
> +			 "sg_build_indirect: k_use_sg=%d, rem_sz=%d\n",
> +			 k, rem_sz));
>
>   	schp->bufflen = blk_size;
>   	if (rem_sz > 0)	/* must have failed */
> @@ -1900,17 +1919,19 @@ out:
>   }
>
>   static void
> -sg_remove_scat(Sg_scatter_hold * schp)
> +sg_remove_scat(Sg_fd * sfp, Sg_scatter_hold * schp)
>   {
> -	SCSI_LOG_TIMEOUT(4, printk("sg_remove_scat: k_use_sg=%d\n", schp->k_use_sg));
> +	SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sfp->parentdp,
> +			 "sg_remove_scat: k_use_sg=%d\n", 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",
> -				    k, schp->pages[k]));
> +				SCSI_LOG_TIMEOUT(5,
> +					sg_printk(KERN_INFO, sfp->parentdp,
> +					"sg_remove_scat: k=%d, pg=0x%p\n",
> +					k, schp->pages[k]));
>   				__free_pages(schp->pages[k], schp->page_order);
>   			}
>
> @@ -1926,8 +1947,9 @@ 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, sg_printk(KERN_INFO, srp->parentfp->parentdp,
> +			 "sg_read_oxfer: num_read_xfer=%d\n",
> +			 num_read_xfer));
>   	if ((!outp) || (num_read_xfer <= 0))
>   		return 0;
>
> @@ -1957,14 +1979,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, sg_printk(KERN_INFO, sfp->parentdp,
> +			 "sg_build_reserve: req_size=%d\n", 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(sfp, schp);
>   		req_size >>= 1;	/* divide by 2 */
>   	} while (req_size > (PAGE_SIZE / 2));
>   }
> @@ -1977,7 +2000,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, sg_printk(KERN_INFO, sfp->parentdp,
> +			 "sg_link_reserve: size=%d\n", size));
>   	rem = size;
>
>   	num = 1 << (PAGE_SHIFT + rsv_schp->page_order);
> @@ -1995,7 +2019,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, sg_printk(KERN_INFO, sfp->parentdp,
> +				 "sg_link_reserve: BAD size\n"));
>   }
>
>   static void
> @@ -2003,8 +2028,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, sg_printk(KERN_INFO, srp->parentfp->parentdp,
> +				      "sg_unlink_reserve: req->k_use_sg=%d\n",
> +				      (int) req_schp->k_use_sg));
>   	req_schp->k_use_sg = 0;
>   	req_schp->bufflen = 0;
>   	req_schp->pages = NULL;
> @@ -2109,7 +2135,7 @@ sg_remove_request(Sg_fd * sfp, Sg_request * srp)
>   }
>
>   static Sg_fd *
> -sg_add_sfp(Sg_device * sdp, int dev)
> +sg_add_sfp(Sg_device * sdp)
>   {
>   	Sg_fd *sfp;
>   	unsigned long iflags;
> @@ -2138,15 +2164,18 @@ sg_add_sfp(Sg_device * sdp, int dev)
>   	}
>   	list_add_tail(&sfp->sfd_siblings, &sdp->sfds);
>   	write_unlock_irqrestore(&sdp->sfd_lock, iflags);
> -	SCSI_LOG_TIMEOUT(3, printk("sg_add_sfp: sfp=0x%p\n", sfp));
> +	SCSI_LOG_TIMEOUT(3, sg_printk(KERN_INFO, sdp,
> +				      "sg_add_sfp: sfp=0x%p\n", sfp));
>   	if (unlikely(sg_big_buff != def_reserved_size))
>   		sg_big_buff = def_reserved_size;
>
>   	bufflen = min_t(int, sg_big_buff,
>   			max_sectors_bytes(sdp->device->request_queue));
>   	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, sg_printk(KERN_INFO, sdp,
> +				      "sg_add_sfp: bufflen=%d, k_use_sg=%d\n",
> +				      sfp->reserve.bufflen,
> +				      sfp->reserve.k_use_sg));
>
>   	kref_get(&sdp->d_ref);
>   	__module_get(THIS_MODULE);
> @@ -2164,17 +2193,15 @@ sg_remove_sfp_usercontext(struct work_struct *work)
>   		sg_finish_rem_req(sfp->headrp);
>
>   	if (sfp->reserve.bufflen > 0) {
> -		SCSI_LOG_TIMEOUT(6,
> -			printk("sg_remove_sfp:    bufflen=%d, k_use_sg=%d\n",
> +		SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp,
> +				"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);
> +		sg_remove_scat(sfp, &sfp->reserve);
>   	}
>
> -	SCSI_LOG_TIMEOUT(6,
> -		printk("sg_remove_sfp: %s, sfp=0x%p\n",
> -			sdp->disk->disk_name,
> -			sfp));
> +	SCSI_LOG_TIMEOUT(6, sg_printk(KERN_INFO, sdp,
> +			"sg_remove_sfp: sfp=0x%p\n", sfp));
>   	kfree(sfp);
>
>   	scsi_device_put(sdp->device);
>


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

* Re: [PATCH 2/6] scsi: Implement sg_printk()
  2014-06-25 20:21   ` Douglas Gilbert
@ 2014-06-26  7:41     ` Christoph Hellwig
  0 siblings, 0 replies; 9+ messages in thread
From: Christoph Hellwig @ 2014-06-26  7:41 UTC (permalink / raw)
  To: Douglas Gilbert
  Cc: Hannes Reinecke, James Bottomley, Christoph Hellwig,
	Martin K. Petersen, linux-scsi

On Wed, Jun 25, 2014 at 04:21:19PM -0400, Douglas Gilbert wrote:
> That function used to be called sg_cmd_done() but
> another hacker gave it a more reasonable name (?)
> but neglected to fix the printk_s. There are other
> examples, so now I prefer:
> 
>   SCSI_LOG_TIMEOUT(4, sg_printk(KERN_INFO, sdp,
> 		   "%s: pack_id=%d, res=0x%x\n", __func__,
> 		   srp->header.pack_id, result));
> 
> 
> Oh, and we really shouldn't be printing from this context but
> it works and I have found it useful in debugging :-)

printk from irq context isn't a problem at all.  And just send me the
one liner to use __func__ againat the core-for-3.17 tree.


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

end of thread, other threads:[~2014-06-26  7:42 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-06-25 14:39 [PATCHv2 0/6] First batch of logging cleanup Hannes Reinecke
2014-06-25 14:39 ` [PATCH 1/6] scsi: Implement sr_printk() Hannes Reinecke
2014-06-25 14:39 ` [PATCH 2/6] scsi: Implement sg_printk() Hannes Reinecke
2014-06-25 20:21   ` Douglas Gilbert
2014-06-26  7:41     ` Christoph Hellwig
2014-06-25 14:39 ` [PATCH 3/6] scsi: Implement ch_printk() Hannes Reinecke
2014-06-25 14:39 ` [PATCH 4/6] scsi: Implement st_printk() Hannes Reinecke
2014-06-25 14:39 ` [PATCH 5/6] scsi: use dev_printk() variants for ioctl Hannes Reinecke
2014-06-25 14:39 ` [PATCH 6/6] scsi: use dev_printk variants where possible Hannes Reinecke

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