Skip to contentSkip to conversation

Bug#733565: SIX messages per on boot console should be TWO

DISCUSSION Ben Hutchings 3 participants 5 messages Dec 30, 2013 – Jan 4, 2014 1 message not in the archive SCSI

lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): [email protected]

#1 lore raw

Control: reassign -1 src:linux 3.12.6-1

Quoted 20 lines · On Mon, 2013-12-30 at 07:13 +0800, [email protected] wrote:

Package: linux-image-3.12-1-686-pae

Currently any such devices as below that are attached during boot still produce the below SIX messages per device when they should only produce TWO:

# dmesg |egrep Caching\|Assuming
[    3.960663] sd 3:0:0:0: [sdb] No Caching mode page found
[    3.960701] sd 3:0:0:0: [sdb] Assuming drive cache: write through
[    3.978659] sd 3:0:0:0: [sdb] No Caching mode page found
[    3.978694] sd 3:0:0:0: [sdb] Assuming drive cache: write through
[    3.998652] sd 3:0:0:0: [sdb] No Caching mode page found
[    3.998689] sd 3:0:0:0: [sdb] Assuming drive cache: write through
[    4.174630] sd 2:0:0:2: [sde] No Caching mode page found
[    4.174669] sd 2:0:0:2: [sde] Assuming drive cache: write through
[    4.196628] sd 2:0:0:2: [sde] No Caching mode page found
[    4.196664] sd 2:0:0:2: [sde] Assuming drive cache: write through
[    4.220624] sd 2:0:0:2: [sde] No Caching mode page found
[    4.220661] sd 2:0:0:2: [sde] Assuming drive cache: write through
Quoted 2 lines

Please confirm that you also see the six messages right there on the console stderr.

I'm not seeing it at all here as my SSD apparently does implement the caching mode page.

I can see that it is emitted by sd_read_cache_type(), which is called by sd_revalidate_disk(), and that is apparently now called 3 times during probe. Which is quite ridiculous.

And I wonder whether this situation (no caching mode page) is really serious enough to deserve logging at ERR severity?

Ben.

Signature · 2 lines
Ben Hutchings
Logic doesn't apply to the real world. - Marvin Minsky
#2 lore raw
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line

"Ben" == Ben Hutchings <[email protected]> writes:

Ben> I can see that it is emitted by sd_read_cache_type(), which is Ben> called by sd_revalidate_disk(), and that is apparently now called 3 Ben> times during probe. Which is quite ridiculous.

We have to discover the basics of the disk before we can create the gendisk/block device/request queue. And some of the subsequent parameters we need can't be stored or acted upon until everything has been set up. So some questions we have to ask several times.

Ben> And I wonder whether this situation (no caching mode page) is Ben> really serious enough to deserve logging at ERR severity?

I guess we could extend the first_scan logic to cover the error case scenarios. But it is quite unusual for a device to not implement the caching mode page...

Signature · 1 line
Martin K. Petersen	Oracle Linux Engineering
#3 lore raw
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line

"MKP" == Martin K Petersen <[email protected]> writes:

MKP> We have to discover the basics of the disk before we can create the MKP> gendisk/block device/request queue. And some of the subsequent MKP> parameters we need can't be stored or acted upon until everything has MKP> been set up. So some questions we have to ask several times.

Perhaps the messages could be each differentiated so the user doesn't see them as something that looks like a bug and needs to be reported.

E.g., prefix/suffix with PHASE I CHECK, PHASE II CHECK, PHASE III CHECK. or FIRST CHECK, INTERMEDIATE CHECK, FINAL CHECK,
or CHECK 1, CHECK 2...
or INTERMEDIATE PROBE:, FINAL PROBE:, etc.

#4 lore raw
In reply to Martin K. Petersen
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line

"Martin" == Martin K Petersen <[email protected]> writes:

Martin> I guess we could extend the first_scan logic to cover the error Martin> case scenarios.

[SCSI] sd: Quiesce mode sense error messages

Messages about discovered disk properties are only printed once unless they are found to have changed. Errors encountered during mode sense, however, are printed every time we revalidate.

Quiesce mode sense errors so they are only printed during the first scan.

drivers/scsi/sd.c +22 -16
index 69725f7c32c1..14d601ed1956 100644
@@ -2283,7 +2283,7 @@ sd_read_write_protect_flag(struct scsi_disk *sdkp, unsigned char *buffer)
 
 	set_disk_ro(sdkp->disk, 0);
 	if (sdp->skip_ms_page_3f) {
-		sd_printk(KERN_NOTICE, sdkp, "Assuming Write Enabled\n");
+		sd_first_printk(KERN_NOTICE, sdkp, "Assuming Write Enabled\n");
 		return;
 	}
 
@@ -2315,7 +2315,7 @@ sd_read_write_protect_flag(struct scsi_disk *sdkp, unsigned char *buffer)
 	}
 
 	if (!scsi_status_is_good(res)) {
-		sd_printk(KERN_WARNING, sdkp,
+		sd_first_printk(KERN_WARNING, sdkp,
 			  "Test WP failed, assume Write Enabled\n");
 	} else {
 		sdkp->write_prot = ((data.device_specific & 0x80) != 0);
@@ -2383,7 +2383,8 @@ sd_read_cache_type(struct scsi_disk *sdkp, unsigned char *buffer)
 	if (!data.header_length) {
 		modepage = 6;
 		first_len = 0;
-		sd_printk(KERN_ERR, sdkp, "Missing header in MODE_SENSE response\n");
+		sd_first_printk(KERN_ERR, sdkp,
+				"Missing header in MODE_SENSE response\n");
 	}
 
 	/* that went OK, now ask for the proper length */
@@ -2396,7 +2397,7 @@ sd_read_cache_type(struct scsi_disk *sdkp, unsigned char *buffer)
 	if (len < 3)
 		goto bad_sense;
 	else if (len > SD_BUF_SIZE) {
-		sd_printk(KERN_NOTICE, sdkp, "Truncating mode parameter "
+		sd_first_printk(KERN_NOTICE, sdkp, "Truncating mode parameter "
 			  "data from %d to %d bytes\n", len, SD_BUF_SIZE);
 		len = SD_BUF_SIZE;
 	}
@@ -2419,8 +2420,9 @@ sd_read_cache_type(struct scsi_disk *sdkp, unsigned char *buffer)
 				/* We're interested only in the first 3 bytes.
 				 */
 				if (len - offset <= 2) {
-					sd_printk(KERN_ERR, sdkp, "Incomplete "
-						  "mode parameter data\n");
+					sd_first_printk(KERN_ERR, sdkp,
+						"Incomplete mode parameter "
+							"data\n");
 					goto defaults;
 				} else {
 					modepage = page_code;
@@ -2434,14 +2436,15 @@ sd_read_cache_type(struct scsi_disk *sdkp, unsigned char *buffer)
 				else if (!spf && len - offset > 1)
 					offset += 2 + buffer[offset+1];
 				else {
-					sd_printk(KERN_ERR, sdkp, "Incomplete "
-						  "mode parameter data\n");
+					sd_first_printk(KERN_ERR, sdkp,
+							"Incomplete mode "
+							"parameter data\n");
 					goto defaults;
 				}
 			}
 		}
 
-		sd_printk(KERN_ERR, sdkp, "No Caching mode page found\n");
+		sd_first_printk(KERN_ERR, sdkp, "No Caching mode page found\n");
 		goto defaults;
 
 	Page_found:
@@ -2455,7 +2458,7 @@ sd_read_cache_type(struct scsi_disk *sdkp, unsigned char *buffer)
 
 		sdkp->DPOFUA = (data.device_specific & 0x10) != 0;
 		if (sdkp->DPOFUA && !sdkp->device->use_10_for_rw) {
-			sd_printk(KERN_NOTICE, sdkp,
+			sd_first_printk(KERN_NOTICE, sdkp,
 				  "Uses READ/WRITE(6), disabling FUA\n");
 			sdkp->DPOFUA = 0;
 		}
@@ -2477,16 +2480,19 @@ bad_sense:
 	    sshdr.sense_key == ILLEGAL_REQUEST &&
 	    sshdr.asc == 0x24 && sshdr.ascq == 0x0)
 		/* Invalid field in CDB */
-		sd_printk(KERN_NOTICE, sdkp, "Cache data unavailable\n");
+		sd_first_printk(KERN_NOTICE, sdkp, "Cache data unavailable\n");
 	else
-		sd_printk(KERN_ERR, sdkp, "Asking for cache data failed\n");
+		sd_first_printk(KERN_ERR, sdkp,
+				"Asking for cache data failed\n");
 
 defaults:
 	if (sdp->wce_default_on) {
-		sd_printk(KERN_NOTICE, sdkp, "Assuming drive cache: write back\n");
+		sd_first_printk(KERN_NOTICE, sdkp,
+				"Assuming drive cache: write back\n");
 		sdkp->WCE = 1;
 	} else {
-		sd_printk(KERN_ERR, sdkp, "Assuming drive cache: write through\n");
+		sd_first_printk(KERN_ERR, sdkp,
+				"Assuming drive cache: write through\n");
 		sdkp->WCE = 0;
 	}
 	sdkp->RCD = 0;
@@ -2515,7 +2521,7 @@ static void sd_read_app_tag_own(struct scsi_disk *sdkp, unsigned char *buffer)
 
 	if (!scsi_status_is_good(res) || !data.header_length ||
 	    data.length < 6) {
-		sd_printk(KERN_WARNING, sdkp,
+		sd_first_printk(KERN_WARNING, sdkp,
 			  "getting Control mode page failed, assume no ATO\n");
 
 		if (scsi_sense_valid(&sshdr))
@@ -2527,7 +2533,7 @@ static void sd_read_app_tag_own(struct scsi_disk *sdkp, unsigned char *buffer)
 	offset = data.header_length + data.block_descriptor_length;
 
 	if ((buffer[offset] & 0x3f) != 0x0a) {
-		sd_printk(KERN_ERR, sdkp, "ATO Got wrong page\n");
+		sd_first_printk(KERN_ERR, sdkp, "ATO Got wrong page\n");
 		return;
 	}
 
drivers/scsi/sd.h +5 -0
index 26895ff247c5..59956e9a5b80 100644
@@ -104,6 +104,11 @@ static inline struct scsi_disk *scsi_disk(struct gendisk *disk)
 		    (sdsk)->disk->disk_name, ##a) :			\
 	sdev_printk(prefix, (sdsk)->device, fmt, ##a)
 
+#define sd_first_printk(prefix,sdsk, fmt, a...)				\
+	do {								\
+	if ((sdkp)->first_scan) sd_printk(prefix, sdsk, fmt, ##a);	\
+	} while (0)
+
 static inline int scsi_medium_access_command(struct scsi_cmnd *scmd)
 {
 	switch (scmd->cmnd[0]) {
#5 lore raw
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line
Quoted 1 line

"MKP" == Martin K Petersen <[email protected]> writes:

MKP> [SCSI] sd: Quiesce mode sense error messages
Thanks!