public inbox for linux-scsi@vger.kernel.org
 help / color / mirror / Atom feed
* [PATCH] sdev_printk - scsi_device helper macro
@ 2004-01-19 21:55 Daniel Stekloff
  2004-01-22 19:44 ` [PATCH] sdev_printk for ULDs, example with sd Daniel Stekloff
  0 siblings, 1 reply; 5+ messages in thread
From: Daniel Stekloff @ 2004-01-19 21:55 UTC (permalink / raw)
  To: linux-scsi


Hello all,

I originally posted this patch for comments back in September:

http://marc.theaimsgroup.com/?l=linux-scsi&m=106487047707538&w=2

This patch is intended for the mid-layer and for LLDs, its purpose is:

1) Add consistency to printks. The macro enables a consistent format for 
scsi_device information. The format will help readability and will provide a 
means to automate log message responses. 

2) Identify a log message with a specific scsi_device.

3) Provide a single point for changing scsi_device information necessary for 
identifying the device. One could simply change the macro to change what 
scsi_device information is printed with printks rather than having to edit 
every single printk in the mid-layer and LLDs.

The patch isn't very invasive, merely adding a set of macros in scsi_device.h 
and then applying those macros to certain places in the mid-layer. The macros 
are very similar to the currently accepted and used dev_printk macros. 

I have made this patch against the scsi-misc-2.6 tree (had done to 2.7, but 
that disappeared). It should also apply to 2.6.1. 

All comments are welcome. 

Please apply.

Thanks,

Dan


PATCH FOLLOWS:
----------------------

diff -Nur --exclude=SCCS scsi-misc-2.6/include/scsi/scsi_device.h 
scsi-misc-2.6-sdevpk/include/scsi/scsi_device.h
--- scsi-misc-2.6/include/scsi/scsi_device.h	2004-01-19 11:30:55.000000000 
-0800
+++ scsi-misc-2.6-sdevpk/include/scsi/scsi_device.h	2004-01-19 
11:42:03.000000000 -0800
@@ -110,6 +110,23 @@
 #define	class_to_sdev(d)	\
 	container_of(d, struct scsi_device, sdev_classdev)
 
+#define sdev_printk(level, sdev, format, arg...) \
+	printk(level "scsi <%s>: " format , (sdev)->sdev_gendev.bus_id , ##arg)
+
+#ifdef DEBUG
+#define sdev_dbg(sdev, format, arg...)            \
+	sdev_printk(KERN_DEBUG , sdev , format , ## arg)
+#else
+#define sdev_dbg(sdev, format, arg...) do {} while (0)
+#endif
+
+#define sdev_err(sdev, format, arg...)            \
+	sdev_printk(KERN_ERR , sdev , format , ## arg)
+#define sdev_info(sdev, format, arg...)           \
+	sdev_printk(KERN_INFO , sdev , format , ## arg)
+#define sdev_warn(sdev, format, arg...)           \
+	sdev_printk(KERN_WARNING , sdev , format , ## arg)
+
 extern struct scsi_device *scsi_add_device(struct Scsi_Host *,
 		uint, uint, uint);
 extern void scsi_remove_device(struct scsi_device *);
diff -Nur --exclude=SCCS scsi-misc-2.6/drivers/scsi/constants.c 
scsi-misc-2.6-sdevpk/drivers/scsi/constants.c
--- scsi-misc-2.6/drivers/scsi/constants.c	2004-01-19 11:30:41.000000000 -0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/constants.c	2004-01-19 
11:42:03.000000000 -0800
@@ -1123,11 +1123,7 @@
 }
 
 void print_Scsi_Cmnd(struct scsi_cmnd *cmd) {
-    printk("scsi%d : destination target %d, lun %d\n", 
-	   cmd->device->host->host_no, 
-	   cmd->device->id, 
-	   cmd->device->lun);
-    printk("        command = ");
+    sdev_info(cmd->device, "        command = ");
     print_command(cmd->cmnd);
 }
 
diff -Nur --exclude=SCCS scsi-misc-2.6/drivers/scsi/scsi.c 
scsi-misc-2.6-sdevpk/drivers/scsi/scsi.c
--- scsi-misc-2.6/drivers/scsi/scsi.c	2004-01-19 11:30:42.000000000 -0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/scsi.c	2004-01-19 11:42:03.000000000 
-0800
@@ -388,9 +388,7 @@
 				       SCSI_LOG_MLQUEUE_BITS);
 		if (level > 1) {
 			sdev = cmd->device;
-			printk(KERN_INFO "scsi <%d:%d:%d:%d> send ",
-			       sdev->host->host_no, sdev->channel, sdev->id,
-			       sdev->lun);
+			sdev_info(sdev, "send ");
 			if (level > 2)
 				printk("0x%p ", cmd);
 			/*
@@ -434,9 +432,7 @@
 		if (((level > 0) && (cmd->result || disposition != SUCCESS)) ||
 		    (level > 1)) {
 			sdev = cmd->device;
-			printk(KERN_INFO "scsi <%d:%d:%d:%d> done ",
-			       sdev->host->host_no, sdev->channel, sdev->id,
-			       sdev->lun);
+			sdev_info(sdev, "done ");
 			if (level > 2)
 				printk("0x%p ", cmd);
 			/*
@@ -820,8 +816,9 @@
 	if (SCSI_SENSE_VALID(cmd))
 		cmd->result |= (DRIVER_SENSE << 24);
 
-	SCSI_LOG_MLCOMPLETE(4, printk("Notifying upper driver of completion "
-				"for device %d %x\n", sdev->id, cmd->result));
+	SCSI_LOG_MLCOMPLETE(4, sdev_info(sdev,
+				"Notifying upper driver of completion "
+				"for device with result %x\n", cmd->result));
 
 	cmd->owner = SCSI_OWNER_HIGHLEVEL;
 	cmd->state = SCSI_STATE_FINISHED;
@@ -902,10 +899,8 @@
 			sdev->simple_tags = 1;
 			break;
 		default:
-			printk(KERN_WARNING "(scsi%d:%d:%d:%d) "
-				"scsi_adjust_queue_depth, bad queue type, "
-				"disabled\n", sdev->host->host_no,
-				sdev->channel, sdev->id, sdev->lun); 
+			sdev_warn(sdev, "scsi_adjust_queue_depth,"
+				" bad queue type, disabled\n");
 		case 0:
 			sdev->ordered_tags = sdev->simple_tags = 0;
 			sdev->queue_depth = tags;
diff -Nur --exclude=SCCS scsi-misc-2.6/drivers/scsi/scsi_error.c 
scsi-misc-2.6-sdevpk/drivers/scsi/scsi_error.c
--- scsi-misc-2.6/drivers/scsi/scsi_error.c	2004-01-19 11:30:42.000000000 
-0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/scsi_error.c	2004-01-19 
11:42:03.000000000 -0800
@@ -221,12 +221,9 @@
 		}
 
 		if (cmd_cancel || cmd_failed) {
-			SCSI_LOG_ERROR_RECOVERY(3,
-				printk("%s: %d:%d:%d:%d cmds failed: %d,"
-				       " cancel: %d\n",
-				       __FUNCTION__, shost->host_no,
-				       sdev->channel, sdev->id, sdev->lun,
-				       cmd_failed, cmd_cancel));
+			SCSI_LOG_ERROR_RECOVERY(3, sdev_info(sdev, 
+					"%s: cmds failed: %d, cancel: %d\n",
+				       __FUNCTION__, cmd_failed, cmd_cancel));
 			cmd_cancel = 0;
 			cmd_failed = 0;
 			++devices_failed;
@@ -1059,13 +1056,8 @@
 
 	list_for_each_safe(lh, lh_sf, work_q) {
 		scmd = list_entry(lh, struct scsi_cmnd, eh_entry);
-		printk(KERN_INFO "scsi: Device offlined - not"
-		       		" ready after error recovery: host"
-				" %d channel %d id %d lun %d\n",
-				scmd->device->host->host_no,
-				scmd->device->channel,
-				scmd->device->id,
-				scmd->device->lun);
+		sdev_info(scmd->device, 
+			"Device offlined - not ready after error recovery\n");
 		scmd->device->online = FALSE;
 		if (scsi_eh_eflags_chk(scmd, SCSI_EH_CANCEL_CMD)) {
 			/*
@@ -1257,9 +1249,7 @@
 		return SUCCESS;
 
 	case RESERVATION_CONFLICT:
-		printk("scsi%d (%d,%d,%d) : reservation conflict\n",
-		       scmd->device->host->host_no, scmd->device->channel,
-		       scmd->device->id, scmd->device->lun);
+		sdev_info(scmd->device, "reservation conflict\n");
 		return SUCCESS; /* causes immediate i/o error */
 	default:
 		return FAILED;
diff -Nur --exclude=SCCS scsi-misc-2.6/drivers/scsi/scsi_lib.c 
scsi-misc-2.6-sdevpk/drivers/scsi/scsi_lib.c
--- scsi-misc-2.6/drivers/scsi/scsi_lib.c	2004-01-19 11:30:42.000000000 -0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/scsi_lib.c	2004-01-19 11:42:03.000000000 
-0800
@@ -806,9 +806,8 @@
 			break;
 		case MEDIUM_ERROR:
 		case VOLUME_OVERFLOW:
-			printk("scsi%d: ERROR on channel %d, id %d, lun %d, CDB: ",
-			       cmd->device->host->host_no, (int) cmd->device->channel,
-			       (int) cmd->device->id, (int) cmd->device->lun);
+			sdev_err(cmd->device, "ERROR on channel %d, CDB: ", 
+				cmd->device->channel);
 			print_command(cmd->data_cmnd);
 			print_sense("", cmd);
 			cmd = scsi_end_request(cmd, 0, block_sectors, 1);
@@ -827,11 +826,8 @@
 		return;
 	}
 	if (result) {
-		printk("SCSI error : <%d %d %d %d> return code = 0x%x\n",
-		       cmd->device->host->host_no,
-		       cmd->device->channel,
-		       cmd->device->id,
-		       cmd->device->lun, result);
+		sdev_err(cmd->device, "SCSI error : return code = 0x%x\n", 
+			result);
 
 		if (driver_byte(result) & DRIVER_SENSE)
 			print_sense("", cmd);
@@ -931,8 +927,7 @@
 		if(sdev->sdev_state == SDEV_DEL) {
 			/* Device is fully deleted, no commands
 			 * at all allowed down */
-			printk(KERN_ERR "scsi%d (%d:%d): rejecting I/O to dead device\n",
-			       sdev->host->host_no, sdev->id, sdev->lun);
+			sdev_err(sdev, "rejecting I/O to dead device\n");
 			return BLKPREP_KILL;
 		}
 		/* OK, we only allow special commands (i.e. not
@@ -963,8 +958,8 @@
 	} else if (req->flags & (REQ_CMD | REQ_BLOCK_PC)) {
 
 		if(unlikely(specials_only)) {
-			printk(KERN_ERR "scsi%d (%d:%d): rejecting I/O to device being removed\n",
-			       sdev->host->host_no, sdev->id, sdev->lun);
+			sdev_err(sdev, 
+				"rejecting I/O to device being removed\n");
 			return BLKPREP_KILL;
 		}
 			
@@ -977,8 +972,7 @@
 		 * it back online)
 		 */
 		if(!sdev->online) {
-			printk(KERN_ERR "scsi%d (%d:%d): rejecting I/O to offline device\n",
-			       sdev->host->host_no, sdev->id, sdev->lun);
+			sdev_err(sdev, "rejecting I/O to offline device\n");
 			return BLKPREP_KILL;
 		}
 		/*
@@ -1078,10 +1072,8 @@
 		 * unblock after device_blocked iterates to zero
 		 */
 		if (--sdev->device_blocked == 0) {
-			SCSI_LOG_MLQUEUE(3,
-				printk("scsi%d (%d:%d) unblocking device at"
-				       " zero depth\n", sdev->host->host_no,
-				       sdev->id, sdev->lun));
+			SCSI_LOG_MLQUEUE(3, sdev_info(sdev, 
+				"unblocking device at zero depth\n"));
 		} else {
 			blk_plug_device(q);
 			return 0;
@@ -1111,9 +1103,8 @@
 		 * unblock after host_blocked iterates to zero
 		 */
 		if (--shost->host_blocked == 0) {
-			SCSI_LOG_MLQUEUE(3,
-				printk("scsi%d unblocking host at zero depth\n",
-					shost->host_no));
+			SCSI_LOG_MLQUEUE(3, sdev_info(sdev, 
+				"unblocking host at zero depth\n"));
 		} else {
 			blk_plug_device(q);
 			return 0;
diff -Nur --exclude=SCCS scsi-misc-2.6/drivers/scsi/scsi_scan.c 
scsi-misc-2.6-sdevpk/drivers/scsi/scsi_scan.c
--- scsi-misc-2.6/drivers/scsi/scsi_scan.c	2004-01-19 11:30:42.000000000 -0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/scsi_scan.c	2004-01-19 
11:42:03.000000000 -0800
@@ -318,9 +318,7 @@
 
 	*bflags = 0;
  repeat_inquiry:
-	SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: INQUIRY to host %d"
-			" channel %d id %d lun %d\n", sdev->host->host_no,
-			sdev->channel, sdev->id, sdev->lun));
+	SCSI_LOG_SCAN_BUS(3, sdev_info(sdev, "scan: INQUIRY to host\n"));
 
 	memset(scsi_cmd, 0, 6);
 	scsi_cmd[0] = INQUIRY;
@@ -332,9 +330,10 @@
 	scsi_wait_req(sreq, (void *) scsi_cmd, (void *) inq_result, 36,
 		      SCSI_TIMEOUT + 4 * HZ, 3);
 
-	SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: 1st INQUIRY %s with"
-			" code 0x%x\n", sreq->sr_result ?
-			"failed" : "successful", sreq->sr_result));
+	SCSI_LOG_SCAN_BUS(3, sdev_info(sdev, 
+			"scan: 1st INQUIRY %s with code 0x%x\n", 
+			sreq->sr_result ? "failed" : "successful", 
+			sreq->sr_result));
 
 	if (sreq->sr_result) {
 		if ((driver_byte(sreq->sr_result) & DRIVER_SENSE) != 0 &&
@@ -380,14 +379,15 @@
 		scsi_wait_req(sreq, (void *) scsi_cmd,
 			      (void *) inq_result,
 			      possible_inq_resp_len, SCSI_TIMEOUT + 4 * HZ, 3);
-		SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: 2nd INQUIRY"
-				" %s with code 0x%x\n", sreq->sr_result ?
-				"failed" : "successful", sreq->sr_result));
+		SCSI_LOG_SCAN_BUS(3, sdev_info(sdev, 
+				"scan: 2nd INQUIRY %s with code 0x%x\n", 
+				sreq->sr_result ? "failed" : "successful", 
+				sreq->sr_result));
 		if (sreq->sr_result) {
 			/* if the longer inquiry has failed, flag the device
 			 * as only accepting 36 byte inquiries and retry the
 			 * 36 byte inquiry */
-			printk(KERN_INFO "scsi scan: %d byte inquiry failed"
+			sdev_info(sdev, "scan: %d byte inquiry failed"
 			       " with code %d.  Consider BLIST_INQUIRY_36 for"
 			       " this device\n", possible_inq_resp_len,
 			       sreq->sr_result);
@@ -512,7 +512,7 @@
 		sdev->writeable = 0;
 		break;
 	default:
-		printk(KERN_INFO "scsi: unknown device type %d\n", sdev->type);
+		sdev_info(sdev, "unknown device type %d\n", sdev->type);
 	}
 
 	print_inquiry(inq_result);
@@ -534,8 +534,9 @@
 	 * use up an sd slot.
 	 */
 	if (((inq_result[0] >> 5) & 7) == 1) {
-		SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO "scsi scan: peripheral"
-				" qualifier of 1, device offlined\n"));
+		SCSI_LOG_SCAN_BUS(3, sdev_info(sdev, 
+				"scan: peripheral qualifier of 1,"
+				" device offlined\n"));
 		sdev->online = FALSE;
 	}
 
@@ -599,7 +600,8 @@
 		if (!starget) {
 			starget = kmalloc(sizeof(*starget), GFP_ATOMIC);
 			if (!starget) {
-				printk(ALLOC_FAILURE_MSG, __FUNCTION__);
+				sdev_info(sdev, ALLOC_FAILURE_MSG, 
+					__FUNCTION__);
 				spin_unlock_irqrestore(sdev->host->host_lock,
 						       flags);
 				return SCSI_SCAN_NO_RESPONSE;
@@ -672,9 +674,8 @@
 	if (rescan) {
 		sdev = scsi_device_lookup(host, channel, id, lun);
 		if (sdev) {
-			SCSI_LOG_SCAN_BUS(3, printk(KERN_INFO
-				"scsi scan: device exists on <%d:%d:%d:%d>\n",
-				host->host_no, channel, id, lun));
+			SCSI_LOG_SCAN_BUS(3, sdev_info(sdev,
+						"scan: device found\n"));
 			if (sdevp)
 				*sdevp = sdev;
 			if (bflagsp)
@@ -888,7 +889,6 @@
 static int scsi_report_lun_scan(struct scsi_device *sdev, int bflags,
 				int rescan)
 {
-	char devname[64];
 	unsigned char scsi_cmd[MAX_COMMAND_SIZE];
 	unsigned int length;
 	unsigned int lun;
@@ -910,9 +910,6 @@
 	if (!sreq)
 		goto out;
 
-	sprintf(devname, "host %d channel %d id %d",
-		sdev->host->host_no, sdev->channel, sdev->id);
-
 	/*
 	 * Allocate enough to hold the header (the same size as one scsi_lun)
 	 * plus the max number of luns we are requesting.
@@ -960,15 +957,15 @@
 	 * 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_info(sdev, 
+				"scan: Sending REPORT LUNS (try %d)\n",
 				retries));
 		scsi_wait_req(sreq, scsi_cmd, lun_data, length,
 				SCSI_TIMEOUT + 4*HZ, 3);
-		SCSI_LOG_SCAN_BUS(3, printk (KERN_INFO "scsi scan: REPORT LUNS"
-				" %s (try %d) result 0x%x\n", sreq->sr_result
-				?  "failed" : "successful", retries,
-				sreq->sr_result));
+		SCSI_LOG_SCAN_BUS(3, sdev_info(sdev, 
+				"scan: REPORT LUNS %s (try %d) result 0x%x\n", 
+				sreq->sr_result	? "failed" : "successful", 
+				retries, sreq->sr_result));
 		if (sreq->sr_result == 0 ||
 		    sreq->sr_sense_buffer[2] != UNIT_ATTENTION)
 			break;
@@ -993,16 +990,13 @@
 
 	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_warn(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;
 	}
 
-	SCSI_LOG_SCAN_BUS(3, printk (KERN_INFO "scsi scan: REPORT LUN scan of"
-			" host %d channel %d id %d\n", sdev->host->host_no,
-			sdev->channel, sdev->id));
+	SCSI_LOG_SCAN_BUS(3, sdev_info(sdev, "scan: REPORT LUN scan\n"));
 
 	/*
 	 * Scan the luns in lun_data. The entry at offset 0 is really
@@ -1023,7 +1017,7 @@
 			 * this differs from what linux would print for the
 			 * integer LUN value.
 			 */
-			printk(KERN_WARNING "scsi: %s lun 0x", devname);
+			sdev_warn(sdev, "lun 0x");
 			data = (char *)lunp->scsi_lun;
 			for (i = 0; i < sizeof(struct scsi_lun); i++)
 				printk("%02x", data[i]);
@@ -1033,9 +1027,8 @@
 			 * LUN 0 has already been scanned.
 			 */
 		} else if (lun > sdev->host->max_lun) {
-			printk(KERN_WARNING "scsi: %s lun%d has a LUN larger"
-			       " than allowed by the host adapter\n",
-			       devname, lun);
+			sdev_warn(sdev, "lun%d has a LUN larger than allowed"
+				" by the host adapter\n", lun);
 		} else {
 			int res;
 
@@ -1045,9 +1038,8 @@
 				/*
 				 * Got some results, but now none, abort.
 				 */
-				printk(KERN_ERR "scsi: Unexpected response"
-				       " from %s lun %d while scanning, scan"
-				       " aborted\n", devname, lun);
+				sdev_err(sdev, "Unexpected response from lun %d"
+					" while scanning, scan aborted\n", lun);
 				break;
 			}
 		}
@@ -1062,7 +1054,7 @@
 	/*
 	 * We are out of memory, don't try scanning any further.
 	 */
-	printk(ALLOC_FAILURE_MSG, __FUNCTION__);
+	sdev_info(sdev, ALLOC_FAILURE_MSG, __FUNCTION__);
 	return 0;
 }
 #else
diff -Nur --exclude=SCCS scsi-misc-2.6/drivers/scsi/scsi_sysfs.c 
scsi-misc-2.6-sdevpk/drivers/scsi/scsi_sysfs.c
--- scsi-misc-2.6/drivers/scsi/scsi_sysfs.c	2004-01-19 11:30:42.000000000 
-0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/scsi_sysfs.c	2004-01-19 
11:42:03.000000000 -0800
@@ -353,13 +353,13 @@
 
 	error = device_add(&sdev->sdev_gendev);
 	if (error) {
-		printk(KERN_INFO "error 1\n");
+		sdev_info(sdev, "error 1\n");
 		return error;
 	}
 
 	error = class_device_add(&sdev->sdev_classdev);
 	if (error) {
-		printk(KERN_INFO "error 2\n");
+		sdev_info(sdev, "error 2\n");
 		goto clean_device;
 	}
 


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

* [PATCH] sdev_printk for ULDs, example with sd
  2004-01-19 21:55 [PATCH] sdev_printk - scsi_device helper macro Daniel Stekloff
@ 2004-01-22 19:44 ` Daniel Stekloff
  2004-01-22 20:08   ` James Bottomley
  0 siblings, 1 reply; 5+ messages in thread
From: Daniel Stekloff @ 2004-01-22 19:44 UTC (permalink / raw)
  To: James Bottomley, linux-scsi


Hi,

In my recent post concerning sdev_printk I mentioned sdev_printk was useful 
for the mid-layer and LLDs. The macro is also useful for Upper Level Drivers 
as well. He's a patch adding sdev_printk to sd. Sample output includes:

scsi <1:0:0:0>: SCSI device sda: 35548320 512-byte hdwr sectors (18201 MB)
scsi <1:0:0:0>: SCSI device sda: drive cache: write through
 sda: sda1 sda2 sda3 sda4 < sda5 >
scsi <1:0:0:0>: Attached scsi disk sda
scsi <1:0:1:0>: SCSI device sdb: 71096640 512-byte hdwr sectors (36401 MB)
scsi <1:0:1:0>: SCSI device sdb: drive cache: write through
 sdb: sdb1
scsi <1:0:1:0>: Attached scsi disk sdb


I know these macros aren't exciting. I know too that there's much more 
interesting things going on enhancing and instrumenting the SCSI subsystem. 
The macro also isn't perfect, it doesn't take into account multi-line printks 
and the prefix isn't configurable except by editing the macro.  I believe, 
however, that the sdev_printk macro is useful for the following reasons:

1) It provides consistency to SCSI log messages. Not only does it create the 
same format for displaying the scsi device information but the macro assists 
using logging levels KERN_INFO, etc. The standard format helps identify 
messages in the log stream that could help with automation and even simply 
reading the messages.

2) It provides a mechanism to easily identify the log message to a specific 
scsi device.

3) It provides a single point to change scsi device identification in the 
future. Should additional or different information be useful to identify scsi 
device's in log messages, someone could simply change the macro rather than a 
large number of individual printks.

All comments are welcome. If acceptable, please apply. This patch applies over 
my previous patch, which is against the latest scsi-misc-2.6.

Previous recent sdev_printk patch post:

http://marc.theaimsgroup.com/?l=linux-scsi&m=107454960106928&w=2


sd example patch follows:
----------------------------

--- scsi-misc-2.6-sdevpk-mid/include/scsi/scsi_device.h	2004-01-22 
11:14:38.925748984 -0800
+++ scsi-misc-2.6-sdevpk/include/scsi/scsi_device.h	2004-01-21 
16:54:38.000000000 -0800
@@ -124,6 +124,8 @@
 	sdev_printk(KERN_ERR , sdev , format , ## arg)
 #define sdev_info(sdev, format, arg...)           \
 	sdev_printk(KERN_INFO , sdev , format , ## arg)
+#define sdev_notice(sdev, format, arg...)           \
+	sdev_printk(KERN_NOTICE , sdev , format , ## arg)
 #define sdev_warn(sdev, format, arg...)           \
 	sdev_printk(KERN_WARNING , sdev , format , ## arg)
 
--- scsi-misc-2.6-sdevpk-mid/drivers/scsi/sd.c	2004-01-22 11:12:18.157149064 
-0800
+++ scsi-misc-2.6-sdevpk/drivers/scsi/sd.c	2004-01-21 17:06:50.000000000 -0800
@@ -217,14 +217,15 @@
 	block = SCpnt->request->sector;
 	this_count = SCpnt->request_bufflen >> 9;
 
-	SCSI_LOG_HLQUEUE(1, printk("sd_init_command: disk=%s, block=%llu, "
-			    "count=%d\n", disk->disk_name, (unsigned long long)block, 
this_count));
+	SCSI_LOG_HLQUEUE(1, sdev_info(sdp, "sd_init_command: disk=%s,"
+			" block=%llu, count=%d\n", disk->disk_name, 
+			(unsigned long long)block, this_count));
 
 	if (!sdp || !sdp->online ||
  	    block + SCpnt->request->nr_sectors > get_capacity(disk)) {
-		SCSI_LOG_HLQUEUE(2, printk("Finishing %ld sectors\n", 
+		SCSI_LOG_HLQUEUE(2, sdev_info(sdp, "Finishing %ld sectors\n", 
 				 SCpnt->request->nr_sectors));
-		SCSI_LOG_HLQUEUE(2, printk("Retry with 0x%p\n", SCpnt));
+		SCSI_LOG_HLQUEUE(2, sdev_info(sdp, "Retry with 0x%p\n", SCpnt));
 		return 0;
 	}
 
@@ -236,7 +237,7 @@
 		/* printk("SCSI disk has been changed. Prohibiting further I/O.\n"); */
 		return 0;
 	}
-	SCSI_LOG_HLQUEUE(2, printk("%s : block=%llu\n",
+	SCSI_LOG_HLQUEUE(2, sdev_info(sdp, "%s : block=%llu\n",
 				   disk->disk_name, (unsigned long long)block));
 
 	/*
@@ -252,7 +253,7 @@
 	 */
 	if (sdp->sector_size == 1024) {
 		if ((block & 1) || (SCpnt->request->nr_sectors & 1)) {
-			printk(KERN_ERR "sd: Bad block number requested");
+			sdev_err(sdp, "sd: Bad block number requested");
 			return 0;
 		} else {
 			block = block >> 1;
@@ -261,7 +262,7 @@
 	}
 	if (sdp->sector_size == 2048) {
 		if ((block & 3) || (SCpnt->request->nr_sectors & 3)) {
-			printk(KERN_ERR "sd: Bad block number requested");
+			sdev_err(sdp, "sd: Bad block number requested");
 			return 0;
 		} else {
 			block = block >> 2;
@@ -270,7 +271,7 @@
 	}
 	if (sdp->sector_size == 4096) {
 		if ((block & 7) || (SCpnt->request->nr_sectors & 7)) {
-			printk(KERN_ERR "sd: Bad block number requested");
+			sdev_err(sdp, "sd: Bad block number requested");
 			return 0;
 		} else {
 			block = block >> 3;
@@ -287,13 +288,13 @@
 		SCpnt->cmnd[0] = READ_6;
 		SCpnt->sc_data_direction = DMA_FROM_DEVICE;
 	} else {
-		printk(KERN_ERR "sd: Unknown command %lx\n", 
+		sdev_err(sdp, "sd: Unknown command %lx\n", 
 		       SCpnt->request->flags);
 /* overkill 	panic("Unknown sd command %lx\n", SCpnt->request->flags); */
 		return 0;
 	}
 
-	SCSI_LOG_HLQUEUE(2, printk("%s : %s %d/%ld 512 byte blocks.\n", 
+	SCSI_LOG_HLQUEUE(2, sdev_info(sdp, "%s : %s %d/%ld 512 byte blocks.\n", 
 		disk->disk_name, (rq_data_dir(SCpnt->request) == WRITE) ? 
 		"writing" : "reading", this_count, SCpnt->request->nr_sectors));
 
@@ -459,7 +460,8 @@
 	struct scsi_disk *sdkp = scsi_disk(disk);
 	struct scsi_device *sdev = sdkp->device;
 
-	SCSI_LOG_HLQUEUE(3, printk("sd_release: disk=%s\n", disk->disk_name));
+	SCSI_LOG_HLQUEUE(3, sdev_info(sdev, "sd_release: disk=%s\n", 
+				disk->disk_name));
 
 	if (!--sdkp->openers && sdev->removable) {
 		if (scsi_block_when_processing_errors(sdev))
@@ -526,7 +528,7 @@
 	struct scsi_device *sdp = scsi_disk(disk)->device;
 	int error;
     
-	SCSI_LOG_IOCTL(1, printk("sd_ioctl: disk=%s, cmd=0x%x\n",
+	SCSI_LOG_IOCTL(1, sdev_info(sdp, "sd_ioctl: disk=%s, cmd=0x%x\n",
 						disk->disk_name, cmd));
 
 	/*
@@ -582,7 +584,7 @@
 	struct scsi_device *sdp = sdkp->device;
 	int retval;
 
-	SCSI_LOG_HLQUEUE(3, printk("sd_media_changed: disk=%s\n",
+	SCSI_LOG_HLQUEUE(3, sdev_info(sdp, "sd_media_changed: disk=%s\n",
 						disk->disk_name));
 
 	if (!sdp->removable)
@@ -666,13 +668,14 @@
 	sector_t block_sectors = 1;
 	sector_t error_sector;
 #ifdef CONFIG_SCSI_LOGGING
-	SCSI_LOG_HLCOMPLETE(1, printk("sd_rw_intr: %s: res=0x%x\n", 
+	SCSI_LOG_HLCOMPLETE(1, sdev_info(SCpnt->device, 
+				"sd_rw_intr: %s: res=0x%x\n", 
 				SCpnt->request->rq_disk->disk_name, result));
 	if (0 != result) {
-		SCSI_LOG_HLCOMPLETE(1, printk("sd_rw_intr: sb[0,2,asc,ascq]"
-				"=%x,%x,%x,%x\n", SCpnt->sense_buffer[0],
-			SCpnt->sense_buffer[2], SCpnt->sense_buffer[12],
-			SCpnt->sense_buffer[13]));
+		SCSI_LOG_HLCOMPLETE(1, sdev_info(SCpnt->device,
+				"sd_rw_intr: sb[0,2,asc,ascq]=%x,%x,%x,%x\n", 
+			SCpnt->sense_buffer[0], SCpnt->sense_buffer[2], 
+			SCpnt->sense_buffer[12], SCpnt->sense_buffer[13]));
 	}
 #endif
 	/*
@@ -938,7 +941,7 @@
 	} while (the_result && retries);
 
 	if (the_result && !longrc) {
-		printk(KERN_NOTICE "%s : READ CAPACITY failed.\n"
+		sdev_notice(sdp, "%s : READ CAPACITY failed.\n"
 		       "%s : status=%x, message=%02x, host=%d, driver=%02x \n",
 		       diskname, diskname,
 		       status_byte(the_result),
@@ -949,7 +952,8 @@
 		if (driver_byte(the_result) & DRIVER_SENSE)
 			print_req_sense("sd", SRpnt);
 		else
-			printk("%s : sense not available. \n", diskname);
+			sdev_info(sdp, "%s : sense not available. \n", 
+				diskname);
 
 		/* Set dirty bit for removable devices if not ready -
 		 * sometimes drives will not report this properly. */
@@ -965,14 +969,14 @@
 		return;
 	} else if (the_result && longrc) {
 		/* READ CAPACITY(16) has been failed */
-		printk(KERN_NOTICE "%s : READ CAPACITY(16) failed.\n"
+		sdev_notice(sdp, "%s : READ CAPACITY(16) failed.\n"
 		       "%s : status=%x, message=%02x, host=%d, driver=%02x \n",
 		       diskname, diskname,
 		       status_byte(the_result),
 		       msg_byte(the_result),
 		       host_byte(the_result),
 		       driver_byte(the_result));
-		printk(KERN_NOTICE "%s : use 0xffffffff as device size\n",
+		sdev_notice(sdp, "%s : use 0xffffffff as device size\n",
 		       diskname);
 		
 		sdkp->capacity = 1 + (sector_t) 0xffffffff;		
@@ -985,12 +989,12 @@
 		if (buffer[0] == 0xff && buffer[1] == 0xff &&
 		    buffer[2] == 0xff && buffer[3] == 0xff) {
 			if(sizeof(sdkp->capacity) > 4) {
-				printk(KERN_NOTICE "%s : very big device. try to use"
-				       " READ CAPACITY(16).\n", diskname);
+				sdev_notice(sdp, "%s : very big device."
+				" try to use READ CAPACITY(16).\n", diskname);
 				longrc = 1;
 				goto repeat;
 			} else {
-				printk(KERN_ERR "%s: too big for kernel.  Assuming maximum 2Tb\n", 
diskname);
+				sdev_err(sdp, "%s: too big for kernel.  Assuming maximum 2Tb\n", 
diskname);
 			}
 		}
 		sdkp->capacity = 1 + (((sector_t)buffer[0] << 24) |
@@ -1014,7 +1018,7 @@
 got_data:
 	if (sector_size == 0) {
 		sector_size = 512;
-		printk(KERN_NOTICE "%s : sector size 0 reported, "
+		sdev_notice(sdp, "%s : sector size 0 reported, "
 		       "assuming 512.\n", diskname);
 	}
 
@@ -1023,7 +1027,7 @@
 	    sector_size != 2048 &&
 	    sector_size != 4096 &&
 	    sector_size != 256) {
-		printk(KERN_NOTICE "%s : unsupported sector size "
+		sdev_notice(sdp, "%s : unsupported sector size "
 		       "%d.\n", diskname, sector_size);
 		/*
 		 * The user might want to re-format the drive with
@@ -1051,7 +1055,7 @@
 		mb -= sz - 974;
 		sector_div(mb, 1950);
 
-		printk(KERN_NOTICE "SCSI device %s: "
+		sdev_notice(sdp, "SCSI device %s: "
 		       "%llu %d-byte hdwr sectors (%llu MB)\n",
 		       diskname, (unsigned long long)sdkp->capacity,
 		       hard_sector, (unsigned long long)mb);
@@ -1090,7 +1094,8 @@
 	struct scsi_mode_data data;
 
 	if (sdkp->device->skip_ms_page_3f) {
-		printk(KERN_NOTICE "%s: assuming Write Enabled\n", diskname);
+		sdev_notice(sdkp->device, "%s: assuming Write Enabled\n", 
+				diskname);
 		return;
 	}
 
@@ -1116,13 +1121,13 @@
 		res = sd_do_mode_sense(SRpnt, 0, 0x3F, buffer, 255, &data);
 
 	if (!scsi_status_is_good(res)) {
-		printk(KERN_WARNING
+		sdev_warn(sdkp->device,
 		       "%s: test WP failed, assume Write Enabled\n", diskname);
 	} else {
 		sdkp->write_prot = ((data.device_specific & 0x80) != 0);
-		printk(KERN_NOTICE "%s: Write Protect is %s\n", diskname,
+		sdev_notice(sdkp->device, "%s: Write Protect is %s\n", diskname,
 		       sdkp->write_prot ? "on" : "off");
-		printk(KERN_DEBUG "%s: Mode Sense: %02x %02x %02x %02x\n",
+		sdev_dbg(sdkp->device, "%s: Mode Sense: %02x %02x %02x %02x\n",
 		       diskname, buffer[0], buffer[1], buffer[2], buffer[3]);
 	}
 }
@@ -1181,7 +1186,7 @@
 
 		ct =  sdkp->RCD + 2*sdkp->WCE;
 
-		printk(KERN_NOTICE "SCSI device %s: drive cache: %s\n",
+		sdev_notice(sdkp->device, "SCSI device %s: drive cache: %s\n",
 		       diskname, types[ct]);
 
 		return;
@@ -1193,15 +1198,15 @@
 	     /* ASC 0x24 ASCQ 0x00: Invalid field in CDB */
 	     && SRpnt->sr_sense_buffer[12] == 0x24
 	     && SRpnt->sr_sense_buffer[13] == 0x00) {
-		printk(KERN_NOTICE "%s: cache data unavailable\n",
+		sdev_notice(sdkp->device, "%s: cache data unavailable\n",
 		       diskname);
 	} else {
-		printk(KERN_ERR "%s: asking for cache data failed\n",
+		sdev_err(sdkp->device, "%s: asking for cache data failed\n",
 		       diskname);
 	}
 
 defaults:
-	printk(KERN_ERR "%s: assuming drive cache: write through\n",
+	sdev_err(sdkp->device, "%s: assuming drive cache: write through\n",
 	       diskname);
 	sdkp->WCE = 0;
 	sdkp->RCD = 0;
@@ -1219,7 +1224,8 @@
 	struct scsi_request *sreq;
 	unsigned char *buffer;
 
-	SCSI_LOG_HLQUEUE(3, printk("sd_revalidate_disk: disk=%s\n", 
disk->disk_name));
+	SCSI_LOG_HLQUEUE(3, sdev_info(sdp, "sd_revalidate_disk: disk=%s\n", 
+					disk->disk_name));
 
 	/*
 	 * If the device is offline, don't try and read capacity or any
@@ -1230,14 +1236,14 @@
 
 	sreq = scsi_allocate_request(sdp, GFP_KERNEL);
 	if (!sreq) {
-		printk(KERN_WARNING "(sd_revalidate_disk:) Request allocation "
+		sdev_warn(sdp, "(sd_revalidate_disk:) Request allocation "
 		       "failure.\n");
 		goto out;
 	}
 
 	buffer = kmalloc(512, GFP_KERNEL | __GFP_DMA);
 	if (!buffer) {
-		printk(KERN_WARNING "(sd_revalidate_disk:) Memory allocation "
+		sdev_warn(sdp, "(sd_revalidate_disk:) Memory allocation "
 		       "failure.\n");
 		goto out_release_request;
 	}
@@ -1303,8 +1309,7 @@
 	if ((sdp->type != TYPE_DISK) && (sdp->type != TYPE_MOD))
 		goto out;
 
-	SCSI_LOG_HLQUEUE(3, printk("sd_attach: scsi device: <%d,%d,%d,%d>\n", 
-			 sdp->host->host_no, sdp->channel, sdp->id, sdp->lun));
+	SCSI_LOG_HLQUEUE(3, sdev_info(sdp, "sd_attach\n"));
 
 	error = -ENOMEM;
 	sdkp = kmalloc(sizeof(*sdkp), GFP_KERNEL);
@@ -1362,10 +1367,8 @@
 	dev_set_drvdata(dev, sdkp);
 	add_disk(gd);
 
-	printk(KERN_NOTICE "Attached scsi %sdisk %s at scsi%d, channel %d, "
-	       "id %d, lun %d\n", sdp->removable ? "removable " : "",
-	       gd->disk_name, sdp->host->host_no, sdp->channel,
-	       sdp->id, sdp->lun);
+	sdev_notice(sdp, "Attached scsi %sdisk %s\n", 
+		sdp->removable ? "removable " : "", gd->disk_name);
 
 	return 0;
 
@@ -1435,7 +1438,7 @@
 	if (!sdp->online || !sdkp->WCE)
 		return;
 
-	printk(KERN_NOTICE "Synchronizing SCSI cache for disk %s: ",
+	sdev_notice(sdp, "Synchronizing SCSI cache for disk %s: ",
 			sdkp->disk->disk_name);
 
 	sreq = scsi_allocate_request(sdp, GFP_KERNEL);




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

* Re: [PATCH] sdev_printk for ULDs, example with sd
  2004-01-22 19:44 ` [PATCH] sdev_printk for ULDs, example with sd Daniel Stekloff
@ 2004-01-22 20:08   ` James Bottomley
  2004-01-22 20:39     ` Daniel Stekloff
  2004-01-22 20:41     ` Mike Anderson
  0 siblings, 2 replies; 5+ messages in thread
From: James Bottomley @ 2004-01-22 20:08 UTC (permalink / raw)
  To: Daniel Stekloff; +Cc: SCSI Mailing List

On Thu, 2004-01-22 at 14:44, Daniel Stekloff wrote:
> In my recent post concerning sdev_printk I mentioned sdev_printk was useful 
> for the mid-layer and LLDs. The macro is also useful for Upper Level Drivers 
> as well. He's a patch adding sdev_printk to sd. Sample output includes:

Well, the thing about this is that it's a slippery slope that leads into
posix logging.  This recently came up in network as well (for
netdev_printk()):

http://marc.theaimsgroup.com/?t=107454443000004&r=1&w=2

The principle is sound, but I think the framework for doing it would
have to cross all subsystems and be nicely extensible.  I'd really like
to see us have some idea of the back end infrastructure before we do
something that we'll then have to change again.

James



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

* Re: [PATCH] sdev_printk for ULDs, example with sd
  2004-01-22 20:08   ` James Bottomley
@ 2004-01-22 20:39     ` Daniel Stekloff
  2004-01-22 20:41     ` Mike Anderson
  1 sibling, 0 replies; 5+ messages in thread
From: Daniel Stekloff @ 2004-01-22 20:39 UTC (permalink / raw)
  To: James Bottomley; +Cc: SCSI Mailing List

On Thursday 22 January 2004 12:08 pm, James Bottomley wrote:
> On Thu, 2004-01-22 at 14:44, Daniel Stekloff wrote:
> > In my recent post concerning sdev_printk I mentioned sdev_printk was
> > useful for the mid-layer and LLDs. The macro is also useful for Upper
> > Level Drivers as well. He's a patch adding sdev_printk to sd. Sample
> > output includes:
>
> Well, the thing about this is that it's a slippery slope that leads into
> posix logging.  This recently came up in network as well (for
> netdev_printk()):
>
> http://marc.theaimsgroup.com/?t=107454443000004&r=1&w=2
>
> The principle is sound, but I think the framework for doing it would
> have to cross all subsystems and be nicely extensible.  I'd really like
> to see us have some idea of the back end infrastructure before we do
> something that we'll then have to change again.
>
> James


Hi James,

Thank you for your comments. If you're referring to the Event Logging project, 
their logging infrastructure could plug into the dev macros without impacting 
driver or subsystem changes. They would only need to patch in where 
sdev_printk() is defined in scsi_device.h. The same is true for dev_printk in 
device.h and the proposed netdev_printk that the link refers to. Drivers 
wouldn't need to be changed and could continue to use the macros. We're 
really just building upon using the device structure and dev_printk macro.

I'm not sure why different macros for different subsystems is an issue, the 
different macros take advantage of specific subsystem information. The 
sdev_printk gives benefit of working with the scsi_device structure and 
prints information to identify a scsi device. The dev_printk macro could be 
used in the mid-layer in some situations, but there are places in scsi_scan.c 
where the device->driver struct hasn't been initialized, which would make 
dev_printk unusable at those points.

I'm not sure of other infrastructures in the works. 

Thanks,

Dan



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

* Re: [PATCH] sdev_printk for ULDs, example with sd
  2004-01-22 20:08   ` James Bottomley
  2004-01-22 20:39     ` Daniel Stekloff
@ 2004-01-22 20:41     ` Mike Anderson
  1 sibling, 0 replies; 5+ messages in thread
From: Mike Anderson @ 2004-01-22 20:41 UTC (permalink / raw)
  To: James Bottomley; +Cc: Daniel Stekloff, SCSI Mailing List

James Bottomley [James.Bottomley@steeleye.com] wrote:
> On Thu, 2004-01-22 at 14:44, Daniel Stekloff wrote:
> > In my recent post concerning sdev_printk I mentioned sdev_printk was useful 
> > for the mid-layer and LLDs. The macro is also useful for Upper Level Drivers 
> > as well. He's a patch adding sdev_printk to sd. Sample output includes:
> 
> Well, the thing about this is that it's a slippery slope that leads into
> posix logging.  This recently came up in network as well (for
> netdev_printk()):
> 
> http://marc.theaimsgroup.com/?t=107454443000004&r=1&w=2
> 
> The principle is sound, but I think the framework for doing it would
> have to cross all subsystems and be nicely extensible.  I'd really like
> to see us have some idea of the back end infrastructure before we do
> something that we'll then have to change again.
> 

I thought after passed discussions that dev_printk was the support to
build on? It should be extensible to a limit as the struct device is
passed in as a argument.

At least for some of the LLDDs that have implemented it I find it more
consistent when I load and unload modules to get the dev_printk type
message from the driver.

-andmike
--
Michael Anderson
andmike@us.ibm.com


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

end of thread, other threads:[~2004-01-22 20:43 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2004-01-19 21:55 [PATCH] sdev_printk - scsi_device helper macro Daniel Stekloff
2004-01-22 19:44 ` [PATCH] sdev_printk for ULDs, example with sd Daniel Stekloff
2004-01-22 20:08   ` James Bottomley
2004-01-22 20:39     ` Daniel Stekloff
2004-01-22 20:41     ` Mike Anderson

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox