[regression/bisected] corrupt CD data after media change and delay

[regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 10797 bytes --]

	Hi all,

When mounting a CD/DVD more than 30 seconds after inserting it, and reading
from it, we get:

    attempt to access beyond end of device
    sr0: rw=0, want=371932, limit=371928
    Buffer I/O error on device sr0, logical block 92982
    attempt to access beyond end of device
    sr0: rw=0, want=371936, limit=371928
    Buffer I/O error on device sr0, logical block 92983
    attempt to access beyond end of device
    sr0: rw=0, want=371940, limit=371928
    Buffer I/O error on device sr0, logical block 92984
    attempt to access beyond end of device
    sr0: rw=0, want=371944, limit=371928
    Buffer I/O error on device sr0, logical block 92985
    attempt to access beyond end of device
    sr0: rw=0, want=371948, limit=371928
    Buffer I/O error on device sr0, logical block 92986
    ...

It can be reproduced on a PS3 with busybox userland using:

    # Insert first CD
    $ mount /dev/sr0 /mnt
    $ ls -R /mnt
    $ umount /mnt
    $ eject
    # Remove first CD

    # Insert second CD
    # Wait at least 30 seconds
    $ mount /dev/sr0 /mnt
    $ tar cf /dev/null /mnt

It does not happen when mounting the second CD within 30 seconds after
inserting it, which is consistent with

    #define SR_TIMEOUT     (30 * HZ)

I can't seem to reproduce it with a Debian or Fedora Core 6 userland.

The problem is present in 2.6.25.
2.6.24 is OK.

After bisecting, it seems to be introduced by

    commit 210ba1d1724f5c4ed87a2ab1a21ca861a915f734
    Author: James Bottomley <James.Bottomley@HansenPartnership.com>
    Date:   Sat Jan 5 10:39:51 2008 -0600

	[SCSI] sr: update to follow tray status correctly
	
	Based on an original patch from: David Martin <tasio@tasio.net>
	
	When trying to get the drive status via ioctl CDROM_DRIVE_STATUS, with
	no disk it gives CDS_TRAY_OPEN even if the tray is closed.
	
	ioctl works as expected with ide-cd driver.
	
	Gentoo bug report: http://bugs.gentoo.org/show_bug.cgi?id=196879
	
	Cc: Maarten Bressers <mbres@gentoo.org>
	Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

After reverting both 210ba1d1724f5c4ed87a2ab1a21ca861a915f734 and

    commit 38582a62ecd337de4212004c7d4844899dc57890
    Author: James Bottomley <James.Bottomley@HansenPartnership.com>
    Date:   Wed Feb 6 13:01:58 2008 -0600

	[SCSI] sr: fix test unit ready responses
	
	Commit 210ba1d1724f5c4ed87a2ab1a21ca861a915f734 updated sr.c to use
	the scsi_test_unit_ready() function.  Unfortunately, this has the
	wrong characteristic of eating NOT_READY returns which sr.c relies on
	for tray status.
	
	Fix by rolling an internal sr_test_unit_ready() that doesn't do this.
	
	Tested-by: Daniel Drake <dsd@gentoo.org>
	Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

(which reverse-depends on it), the problem goes away.

As I have not much of a clue about what's really going wrong, I added the debug
code below, and retried.

1. Mount first CD, read, unmount, eject:

    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    ISO 9660 Extensions: RRIP_1991A
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]


2. Mount second CD more than 30 seconds after insertion, try to read, unmount,
   eject:

    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    ISO 9660 Extensions: Microsoft Joliet Level 3
    ISO 9660 Extensions: RRIP_1991A
    attempt to access beyond end of device
    sr0: rw=0, want=371932, limit=371928
    Buffer I/O error on device sr0, logical block 92982
    attempt to access beyond end of device
    sr0: rw=0, want=371936, limit=371928
    Buffer I/O error on device sr0, logical block 92983
    [...]
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 367332
    __ratelimit: 76 messages suppressed
    ...
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 215608
    __ratelimit: 12 messages suppressed
    Buffer I/O error on device sr0, logical block 53902
    Buffer I/O error on device sr0, logical block 53903
    Buffer I/O error on device sr0, logical block 53904
    Buffer I/O error on device sr0, logical block 53905
    Buffer I/O error on device sr0, logical block 53906
    Buffer I/O error on device sr0, logical block 53907
    Buffer I/O error on device sr0, logical block 53908
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 215608
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 270656
    __ratelimit: 27 messages suppressed
    Buffer I/O error on device sr0, logical block 67664
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]


3. Mount second CD immediately after insertion, read, unmount, eject:

    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    ISO 9660 Extensions: Microsoft Joliet Level 3
    ISO 9660 Extensions: RRIP_1991A
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]


When running a Debian userland, I see some debug messages every few seconds.
Probably there's a deamon polling all drives with removable media, preventing
the problem from happening.

Is this a bug in the generic SCSI CD-ROM code, or does it merely expose a bug
in the ps3rom driver?

Thanks in advance!

Index: ps3-linux-2.6/drivers/scsi/sr.c
===================================================================
--- ps3-linux-2.6.orig/drivers/scsi/sr.c	2008-06-06 14:59:50.000000000 +0200
+++ ps3-linux-2.6/drivers/scsi/sr.c	2008-06-06 15:30:03.000000000 +0200
@@ -178,6 +178,8 @@ int sr_test_unit_ready(struct scsi_devic
 		the_result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL,
 					      0, sshdr, SR_TIMEOUT,
 					      retries--);
+		printk("+0+ the_result = 0x%x ", the_result);
+		scsi_show_sense_hdr(&sshdr);
 
 	} while (retries > 0 &&
 		 (!scsi_status_is_good(the_result) ||
Index: ps3-linux-2.6/drivers/scsi/sr_ioctl.c
===================================================================
--- ps3-linux-2.6.orig/drivers/scsi/sr_ioctl.c	2008-06-06 14:59:50.000000000 +0200
+++ ps3-linux-2.6/drivers/scsi/sr_ioctl.c	2008-06-06 15:04:28.000000000 +0200
@@ -306,23 +306,32 @@ int sr_drive_status(struct cdrom_device_
 		/* we have no changer support */
 		return -EINVAL;
 	}
-	if (0 == sr_test_unit_ready(cd->device, &sshdr))
+	if (0 == sr_test_unit_ready(cd->device, &sshdr)) {
+		printk("+1+ CDS_DISC_OK\n");
 		return CDS_DISC_OK;
+	}
+	scsi_show_sense_hdr(&sshdr);
 
 	if (!cdrom_get_media_event(cdi, &med)) {
-		if (med.media_present)
+		if (med.media_present) {
+			printk("+2+ CDS_DISC_OK\n");
 			return CDS_DISC_OK;
-		else if (med.door_open)
+		} else if (med.door_open) {
+			printk("+3+ CDS_TRAY_OPEN\n");
 			return CDS_TRAY_OPEN;
-		else
+		} else {
+			printk("+4+ CDS_NO_DISC\n");
 			return CDS_NO_DISC;
+		}
 	}
 
 	/*
 	 * 0x04 is format in progress .. but there must be a disc present!
 	 */
-	if (sshdr.sense_key == NOT_READY && sshdr.asc == 0x04)
+	if (sshdr.sense_key == NOT_READY && sshdr.asc == 0x04) {
+		printk("+5+ CDS_DISC_OK\n");
 		return CDS_DISC_OK;
+	}
 
 	/*
 	 * If not using Mt Fuji extended media tray reports,
@@ -331,11 +340,15 @@ int sr_drive_status(struct cdrom_device_
 	 */
 	if (scsi_sense_valid(&sshdr) &&
 	    /* 0x3a is medium not present */
-	    sshdr.asc == 0x3a)
+	    sshdr.asc == 0x3a) {
+		printk("+6+ CDS_NO_DISC\n");
 		return CDS_NO_DISC;
-	else
+	} else {
+		printk("+7+ CDS_TRAY_OPEN\n");
 		return CDS_TRAY_OPEN;
+	}
 
+	printk("+8+ CDS_DRIVE_NOT_READY\n");
 	return CDS_DRIVE_NOT_READY;
 }
 

With kind regards,
 
Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium
 
Phone:    +32 (0)2 700 8453	
Fax:      +32 (0)2 700 8622	
E-mail:   Geert.Uytterhoeven@sonycom.com	
Internet: http://www.sony-europe.com/
 	
Sony Technology and Software Centre Europe	
A division of Sony Service Centre (Europe) N.V.	
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium	
VAT BE 0413.825.160 · RPR Brussels	
Fortis 293-0376800-10 GEBA-BE-BB

[regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 10797 bytes --]

	Hi all,

When mounting a CD/DVD more than 30 seconds after inserting it, and reading
from it, we get:

    attempt to access beyond end of device
    sr0: rw=0, want=371932, limit=371928
    Buffer I/O error on device sr0, logical block 92982
    attempt to access beyond end of device
    sr0: rw=0, want=371936, limit=371928
    Buffer I/O error on device sr0, logical block 92983
    attempt to access beyond end of device
    sr0: rw=0, want=371940, limit=371928
    Buffer I/O error on device sr0, logical block 92984
    attempt to access beyond end of device
    sr0: rw=0, want=371944, limit=371928
    Buffer I/O error on device sr0, logical block 92985
    attempt to access beyond end of device
    sr0: rw=0, want=371948, limit=371928
    Buffer I/O error on device sr0, logical block 92986
    ...

It can be reproduced on a PS3 with busybox userland using:

    # Insert first CD
    $ mount /dev/sr0 /mnt
    $ ls -R /mnt
    $ umount /mnt
    $ eject
    # Remove first CD

    # Insert second CD
    # Wait at least 30 seconds
    $ mount /dev/sr0 /mnt
    $ tar cf /dev/null /mnt

It does not happen when mounting the second CD within 30 seconds after
inserting it, which is consistent with

    #define SR_TIMEOUT     (30 * HZ)

I can't seem to reproduce it with a Debian or Fedora Core 6 userland.

The problem is present in 2.6.25.
2.6.24 is OK.

After bisecting, it seems to be introduced by

    commit 210ba1d1724f5c4ed87a2ab1a21ca861a915f734
    Author: James Bottomley <James.Bottomley@HansenPartnership.com>
    Date:   Sat Jan 5 10:39:51 2008 -0600

	[SCSI] sr: update to follow tray status correctly
	
	Based on an original patch from: David Martin <tasio@tasio.net>
	
	When trying to get the drive status via ioctl CDROM_DRIVE_STATUS, with
	no disk it gives CDS_TRAY_OPEN even if the tray is closed.
	
	ioctl works as expected with ide-cd driver.
	
	Gentoo bug report: http://bugs.gentoo.org/show_bug.cgi?id=196879
	
	Cc: Maarten Bressers <mbres@gentoo.org>
	Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

After reverting both 210ba1d1724f5c4ed87a2ab1a21ca861a915f734 and

    commit 38582a62ecd337de4212004c7d4844899dc57890
    Author: James Bottomley <James.Bottomley@HansenPartnership.com>
    Date:   Wed Feb 6 13:01:58 2008 -0600

	[SCSI] sr: fix test unit ready responses
	
	Commit 210ba1d1724f5c4ed87a2ab1a21ca861a915f734 updated sr.c to use
	the scsi_test_unit_ready() function.  Unfortunately, this has the
	wrong characteristic of eating NOT_READY returns which sr.c relies on
	for tray status.
	
	Fix by rolling an internal sr_test_unit_ready() that doesn't do this.
	
	Tested-by: Daniel Drake <dsd@gentoo.org>
	Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

(which reverse-depends on it), the problem goes away.

As I have not much of a clue about what's really going wrong, I added the debug
code below, and retried.

1. Mount first CD, read, unmount, eject:

    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    ISO 9660 Extensions: RRIP_1991A
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]


2. Mount second CD more than 30 seconds after insertion, try to read, unmount,
   eject:

    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    ISO 9660 Extensions: Microsoft Joliet Level 3
    ISO 9660 Extensions: RRIP_1991A
    attempt to access beyond end of device
    sr0: rw=0, want=371932, limit=371928
    Buffer I/O error on device sr0, logical block 92982
    attempt to access beyond end of device
    sr0: rw=0, want=371936, limit=371928
    Buffer I/O error on device sr0, logical block 92983
    [...]
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 367332
    __ratelimit: 76 messages suppressed
    ...
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 215608
    __ratelimit: 12 messages suppressed
    Buffer I/O error on device sr0, logical block 53902
    Buffer I/O error on device sr0, logical block 53903
    Buffer I/O error on device sr0, logical block 53904
    Buffer I/O error on device sr0, logical block 53905
    Buffer I/O error on device sr0, logical block 53906
    Buffer I/O error on device sr0, logical block 53907
    Buffer I/O error on device sr0, logical block 53908
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 215608
    sr 0:0:0:0: [sr0] Device not ready: Sense Key : 0x2 [current] 
    sr 0:0:0:0: [sr0] Device not ready: ASC=0x3a ASCQ=0x0
    end_request: I/O error, dev sr0, sector 270656
    __ratelimit: 27 messages suppressed
    Buffer I/O error on device sr0, logical block 67664
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]


3. Mount second CD immediately after insertion, read, unmount, eject:

    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
    Sense Key : 0x2 [current] 
    +5+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    ISO 9660 Extensions: Microsoft Joliet Level 3
    ISO 9660 Extensions: RRIP_1991A
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +1+ CDS_DISC_OK
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
    +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]


When running a Debian userland, I see some debug messages every few seconds.
Probably there's a deamon polling all drives with removable media, preventing
the problem from happening.

Is this a bug in the generic SCSI CD-ROM code, or does it merely expose a bug
in the ps3rom driver?

Thanks in advance!

Index: ps3-linux-2.6/drivers/scsi/sr.c
===================================================================
--- ps3-linux-2.6.orig/drivers/scsi/sr.c	2008-06-06 14:59:50.000000000 +0200
+++ ps3-linux-2.6/drivers/scsi/sr.c	2008-06-06 15:30:03.000000000 +0200
@@ -178,6 +178,8 @@ int sr_test_unit_ready(struct scsi_devic
 		the_result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL,
 					      0, sshdr, SR_TIMEOUT,
 					      retries--);
+		printk("+0+ the_result = 0x%x ", the_result);
+		scsi_show_sense_hdr(&sshdr);
 
 	} while (retries > 0 &&
 		 (!scsi_status_is_good(the_result) ||
Index: ps3-linux-2.6/drivers/scsi/sr_ioctl.c
===================================================================
--- ps3-linux-2.6.orig/drivers/scsi/sr_ioctl.c	2008-06-06 14:59:50.000000000 +0200
+++ ps3-linux-2.6/drivers/scsi/sr_ioctl.c	2008-06-06 15:04:28.000000000 +0200
@@ -306,23 +306,32 @@ int sr_drive_status(struct cdrom_device_
 		/* we have no changer support */
 		return -EINVAL;
 	}
-	if (0 == sr_test_unit_ready(cd->device, &sshdr))
+	if (0 == sr_test_unit_ready(cd->device, &sshdr)) {
+		printk("+1+ CDS_DISC_OK\n");
 		return CDS_DISC_OK;
+	}
+	scsi_show_sense_hdr(&sshdr);
 
 	if (!cdrom_get_media_event(cdi, &med)) {
-		if (med.media_present)
+		if (med.media_present) {
+			printk("+2+ CDS_DISC_OK\n");
 			return CDS_DISC_OK;
-		else if (med.door_open)
+		} else if (med.door_open) {
+			printk("+3+ CDS_TRAY_OPEN\n");
 			return CDS_TRAY_OPEN;
-		else
+		} else {
+			printk("+4+ CDS_NO_DISC\n");
 			return CDS_NO_DISC;
+		}
 	}
 
 	/*
 	 * 0x04 is format in progress .. but there must be a disc present!
 	 */
-	if (sshdr.sense_key == NOT_READY && sshdr.asc == 0x04)
+	if (sshdr.sense_key == NOT_READY && sshdr.asc == 0x04) {
+		printk("+5+ CDS_DISC_OK\n");
 		return CDS_DISC_OK;
+	}
 
 	/*
 	 * If not using Mt Fuji extended media tray reports,
@@ -331,11 +340,15 @@ int sr_drive_status(struct cdrom_device_
 	 */
 	if (scsi_sense_valid(&sshdr) &&
 	    /* 0x3a is medium not present */
-	    sshdr.asc == 0x3a)
+	    sshdr.asc == 0x3a) {
+		printk("+6+ CDS_NO_DISC\n");
 		return CDS_NO_DISC;
-	else
+	} else {
+		printk("+7+ CDS_TRAY_OPEN\n");
 		return CDS_TRAY_OPEN;
+	}
 
+	printk("+8+ CDS_DRIVE_NOT_READY\n");
 	return CDS_DRIVE_NOT_READY;
 }
 

With kind regards,
 
Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium
 
Phone:    +32 (0)2 700 8453	
Fax:      +32 (0)2 700 8622	
E-mail:   Geert.Uytterhoeven@sonycom.com	
Internet: http://www.sony-europe.com/
 	
Sony Technology and Software Centre Europe	
A division of Sony Service Centre (Europe) N.V.	
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium	
VAT BE 0413.825.160 · RPR Brussels	
Fortis 293-0376800-10 GEBA-BE-BB

Re: [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> 	Hi all,
> 
> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> from it, we get:
> 
>     attempt to access beyond end of device
>     sr0: rw=0, want=371932, limit=371928
>     Buffer I/O error on device sr0, logical block 92982
>     attempt to access beyond end of device
>     sr0: rw=0, want=371936, limit=371928
>     Buffer I/O error on device sr0, logical block 92983
>     attempt to access beyond end of device
>     sr0: rw=0, want=371940, limit=371928
>     Buffer I/O error on device sr0, logical block 92984
>     attempt to access beyond end of device
>     sr0: rw=0, want=371944, limit=371928
>     Buffer I/O error on device sr0, logical block 92985
>     attempt to access beyond end of device
>     sr0: rw=0, want=371948, limit=371928
>     Buffer I/O error on device sr0, logical block 92986
>     ...
> 
> It can be reproduced on a PS3 with busybox userland using:
> 
>     # Insert first CD
>     $ mount /dev/sr0 /mnt
>     $ ls -R /mnt
>     $ umount /mnt
>     $ eject
>     # Remove first CD
> 
>     # Insert second CD
>     # Wait at least 30 seconds
>     $ mount /dev/sr0 /mnt
>     $ tar cf /dev/null /mnt
> 
> It does not happen when mounting the second CD within 30 seconds after
> inserting it, which is consistent with
> 
>     #define SR_TIMEOUT     (30 * HZ)
> 
> I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> 
> The problem is present in 2.6.25.
> 2.6.24 is OK.

Hmm ... how are you preventing HAL from automatically mounting the CD?

Also, in the two different situations, what does

cat /sys/block/sr0/size

(assuming your cd is sr0) give you?  My first theory is an incorrect
size propagating from something.

James

Re: [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> 	Hi all,
> 
> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> from it, we get:
> 
>     attempt to access beyond end of device
>     sr0: rw=0, want=371932, limit=371928
>     Buffer I/O error on device sr0, logical block 92982
>     attempt to access beyond end of device
>     sr0: rw=0, want=371936, limit=371928
>     Buffer I/O error on device sr0, logical block 92983
>     attempt to access beyond end of device
>     sr0: rw=0, want=371940, limit=371928
>     Buffer I/O error on device sr0, logical block 92984
>     attempt to access beyond end of device
>     sr0: rw=0, want=371944, limit=371928
>     Buffer I/O error on device sr0, logical block 92985
>     attempt to access beyond end of device
>     sr0: rw=0, want=371948, limit=371928
>     Buffer I/O error on device sr0, logical block 92986
>     ...
> 
> It can be reproduced on a PS3 with busybox userland using:
> 
>     # Insert first CD
>     $ mount /dev/sr0 /mnt
>     $ ls -R /mnt
>     $ umount /mnt
>     $ eject
>     # Remove first CD
> 
>     # Insert second CD
>     # Wait at least 30 seconds
>     $ mount /dev/sr0 /mnt
>     $ tar cf /dev/null /mnt
> 
> It does not happen when mounting the second CD within 30 seconds after
> inserting it, which is consistent with
> 
>     #define SR_TIMEOUT     (30 * HZ)
> 
> I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> 
> The problem is present in 2.6.25.
> 2.6.24 is OK.

Hmm ... how are you preventing HAL from automatically mounting the CD?

Also, in the two different situations, what does

cat /sys/block/sr0/size

(assuming your cd is sr0) give you?  My first theory is an incorrect
size propagating from something.

James

Re: [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 2477 bytes --]

On Fri, 6 Jun 2008, James Bottomley wrote:
> On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> > When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> > from it, we get:
> > 
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371932, limit=371928
> >     Buffer I/O error on device sr0, logical block 92982
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371936, limit=371928
> >     Buffer I/O error on device sr0, logical block 92983
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371940, limit=371928
> >     Buffer I/O error on device sr0, logical block 92984
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371944, limit=371928
> >     Buffer I/O error on device sr0, logical block 92985
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371948, limit=371928
> >     Buffer I/O error on device sr0, logical block 92986
> >     ...
> > 
> > It can be reproduced on a PS3 with busybox userland using:
> > 
> >     # Insert first CD
> >     $ mount /dev/sr0 /mnt
> >     $ ls -R /mnt
> >     $ umount /mnt
> >     $ eject
> >     # Remove first CD
> > 
> >     # Insert second CD
> >     # Wait at least 30 seconds
> >     $ mount /dev/sr0 /mnt
> >     $ tar cf /dev/null /mnt
> > 
> > It does not happen when mounting the second CD within 30 seconds after
> > inserting it, which is consistent with
> > 
> >     #define SR_TIMEOUT     (30 * HZ)
> > 
> > I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> > 
> > The problem is present in 2.6.25.
> > 2.6.24 is OK.
> 
> Hmm ... how are you preventing HAL from automatically mounting the CD?

By not running HAL?

> Also, in the two different situations, what does
> 
> cat /sys/block/sr0/size
> 
> (assuming your cd is sr0) give you?  My first theory is an incorrect
> size propagating from something.

I'll give that a try on Monday...

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 2477 bytes --]

On Fri, 6 Jun 2008, James Bottomley wrote:
> On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> > When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> > from it, we get:
> > 
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371932, limit=371928
> >     Buffer I/O error on device sr0, logical block 92982
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371936, limit=371928
> >     Buffer I/O error on device sr0, logical block 92983
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371940, limit=371928
> >     Buffer I/O error on device sr0, logical block 92984
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371944, limit=371928
> >     Buffer I/O error on device sr0, logical block 92985
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371948, limit=371928
> >     Buffer I/O error on device sr0, logical block 92986
> >     ...
> > 
> > It can be reproduced on a PS3 with busybox userland using:
> > 
> >     # Insert first CD
> >     $ mount /dev/sr0 /mnt
> >     $ ls -R /mnt
> >     $ umount /mnt
> >     $ eject
> >     # Remove first CD
> > 
> >     # Insert second CD
> >     # Wait at least 30 seconds
> >     $ mount /dev/sr0 /mnt
> >     $ tar cf /dev/null /mnt
> > 
> > It does not happen when mounting the second CD within 30 seconds after
> > inserting it, which is consistent with
> > 
> >     #define SR_TIMEOUT     (30 * HZ)
> > 
> > I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> > 
> > The problem is present in 2.6.25.
> > 2.6.24 is OK.
> 
> Hmm ... how are you preventing HAL from automatically mounting the CD?

By not running HAL?

> Also, in the two different situations, what does
> 
> cat /sys/block/sr0/size
> 
> (assuming your cd is sr0) give you?  My first theory is an incorrect
> size propagating from something.

I'll give that a try on Monday...

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3022 bytes --]

On Fri, 6 Jun 2008, James Bottomley wrote:
> On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> > When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> > from it, we get:
> > 
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371932, limit=371928
> >     Buffer I/O error on device sr0, logical block 92982
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371936, limit=371928
> >     Buffer I/O error on device sr0, logical block 92983
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371940, limit=371928
> >     Buffer I/O error on device sr0, logical block 92984
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371944, limit=371928
> >     Buffer I/O error on device sr0, logical block 92985
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371948, limit=371928
> >     Buffer I/O error on device sr0, logical block 92986
> >     ...
> > 
> > It can be reproduced on a PS3 with busybox userland using:
> > 
> >     # Insert first CD
> >     $ mount /dev/sr0 /mnt
> >     $ ls -R /mnt
> >     $ umount /mnt
> >     $ eject
> >     # Remove first CD
> > 
> >     # Insert second CD
> >     # Wait at least 30 seconds
> >     $ mount /dev/sr0 /mnt
> >     $ tar cf /dev/null /mnt
> > 
> > It does not happen when mounting the second CD within 30 seconds after
> > inserting it, which is consistent with
> > 
> >     #define SR_TIMEOUT     (30 * HZ)
> > 
> > I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> > 
> > The problem is present in 2.6.25.
> > 2.6.24 is OK.
> 
> Also, in the two different situations, what does
> 
> cat /sys/block/sr0/size
> 
> (assuming your cd is sr0) give you?  My first theory is an incorrect
> size propagating from something.

Nice first theory!

Initially /sys/block/sr0/size is 2097151.

After inserting the first CD, and mounting it, /sys/block/sr0/size is changed
to the size of the first CD (in 512 byte blocks).

After ejecting the first CD and inserting the second CD, the behavior is like
this:
  1. when immediately mounting the CD, /sys/block/sr0/size is updated to the
     size of the second CD,
  2. when waiting more than 30 seconds before mounting the CD,
     /sys/block/sr0/size is not updated, and keeps the old value.

Surprisingly, it doesn't behave like this when inserting the first CD.
/sys/block/sr0/size is always updated, whether I wait 30 seconds before
mounting it or not.

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3022 bytes --]

On Fri, 6 Jun 2008, James Bottomley wrote:
> On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> > When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> > from it, we get:
> > 
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371932, limit=371928
> >     Buffer I/O error on device sr0, logical block 92982
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371936, limit=371928
> >     Buffer I/O error on device sr0, logical block 92983
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371940, limit=371928
> >     Buffer I/O error on device sr0, logical block 92984
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371944, limit=371928
> >     Buffer I/O error on device sr0, logical block 92985
> >     attempt to access beyond end of device
> >     sr0: rw=0, want=371948, limit=371928
> >     Buffer I/O error on device sr0, logical block 92986
> >     ...
> > 
> > It can be reproduced on a PS3 with busybox userland using:
> > 
> >     # Insert first CD
> >     $ mount /dev/sr0 /mnt
> >     $ ls -R /mnt
> >     $ umount /mnt
> >     $ eject
> >     # Remove first CD
> > 
> >     # Insert second CD
> >     # Wait at least 30 seconds
> >     $ mount /dev/sr0 /mnt
> >     $ tar cf /dev/null /mnt
> > 
> > It does not happen when mounting the second CD within 30 seconds after
> > inserting it, which is consistent with
> > 
> >     #define SR_TIMEOUT     (30 * HZ)
> > 
> > I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> > 
> > The problem is present in 2.6.25.
> > 2.6.24 is OK.
> 
> Also, in the two different situations, what does
> 
> cat /sys/block/sr0/size
> 
> (assuming your cd is sr0) give you?  My first theory is an incorrect
> size propagating from something.

Nice first theory!

Initially /sys/block/sr0/size is 2097151.

After inserting the first CD, and mounting it, /sys/block/sr0/size is changed
to the size of the first CD (in 512 byte blocks).

After ejecting the first CD and inserting the second CD, the behavior is like
this:
  1. when immediately mounting the CD, /sys/block/sr0/size is updated to the
     size of the second CD,
  2. when waiting more than 30 seconds before mounting the CD,
     /sys/block/sr0/size is not updated, and keeps the old value.

Surprisingly, it doesn't behave like this when inserting the first CD.
/sys/block/sr0/size is always updated, whether I wait 30 seconds before
mounting it or not.

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3773 bytes --]

On Mon, 9 Jun 2008, Geert Uytterhoeven wrote:
> On Fri, 6 Jun 2008, James Bottomley wrote:
> > On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> > > When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> > > from it, we get:
> > > 
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371932, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92982
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371936, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92983
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371940, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92984
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371944, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92985
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371948, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92986
> > >     ...
> > > 
> > > It can be reproduced on a PS3 with busybox userland using:
> > > 
> > >     # Insert first CD
> > >     $ mount /dev/sr0 /mnt
> > >     $ ls -R /mnt
> > >     $ umount /mnt
> > >     $ eject
> > >     # Remove first CD
> > > 
> > >     # Insert second CD
> > >     # Wait at least 30 seconds
> > >     $ mount /dev/sr0 /mnt
> > >     $ tar cf /dev/null /mnt
> > > 
> > > It does not happen when mounting the second CD within 30 seconds after
> > > inserting it, which is consistent with
> > > 
> > >     #define SR_TIMEOUT     (30 * HZ)
> > > 
> > > I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> > > 
> > > The problem is present in 2.6.25.
> > > 2.6.24 is OK.
> > 
> > Also, in the two different situations, what does
> > 
> > cat /sys/block/sr0/size
> > 
> > (assuming your cd is sr0) give you?  My first theory is an incorrect
> > size propagating from something.
> 
> Nice first theory!
> 
> Initially /sys/block/sr0/size is 2097151.
> 
> After inserting the first CD, and mounting it, /sys/block/sr0/size is changed
> to the size of the first CD (in 512 byte blocks).
> 
> After ejecting the first CD and inserting the second CD, the behavior is like
> this:
>   1. when immediately mounting the CD, /sys/block/sr0/size is updated to the
>      size of the second CD,
>   2. when waiting more than 30 seconds before mounting the CD,
>      /sys/block/sr0/size is not updated, and keeps the old value.
> 
> Surprisingly, it doesn't behave like this when inserting the first CD.
> /sys/block/sr0/size is always updated, whether I wait 30 seconds before
> mounting it or not.

I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
So the problem is not PS3-specific.

Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
always stayed at the value for the first CD.

Note that Debian's tar is `smart' and optimizes `tar cf /dev/null' by never
reading the input files, so you have to e.g. pipe the resulting archive to
`cat > /dev/null' or so.

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3773 bytes --]

On Mon, 9 Jun 2008, Geert Uytterhoeven wrote:
> On Fri, 6 Jun 2008, James Bottomley wrote:
> > On Fri, 2008-06-06 at 16:06 +0200, Geert Uytterhoeven wrote:
> > > When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> > > from it, we get:
> > > 
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371932, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92982
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371936, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92983
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371940, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92984
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371944, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92985
> > >     attempt to access beyond end of device
> > >     sr0: rw=0, want=371948, limit=371928
> > >     Buffer I/O error on device sr0, logical block 92986
> > >     ...
> > > 
> > > It can be reproduced on a PS3 with busybox userland using:
> > > 
> > >     # Insert first CD
> > >     $ mount /dev/sr0 /mnt
> > >     $ ls -R /mnt
> > >     $ umount /mnt
> > >     $ eject
> > >     # Remove first CD
> > > 
> > >     # Insert second CD
> > >     # Wait at least 30 seconds
> > >     $ mount /dev/sr0 /mnt
> > >     $ tar cf /dev/null /mnt
> > > 
> > > It does not happen when mounting the second CD within 30 seconds after
> > > inserting it, which is consistent with
> > > 
> > >     #define SR_TIMEOUT     (30 * HZ)
> > > 
> > > I can't seem to reproduce it with a Debian or Fedora Core 6 userland.
> > > 
> > > The problem is present in 2.6.25.
> > > 2.6.24 is OK.
> > 
> > Also, in the two different situations, what does
> > 
> > cat /sys/block/sr0/size
> > 
> > (assuming your cd is sr0) give you?  My first theory is an incorrect
> > size propagating from something.
> 
> Nice first theory!
> 
> Initially /sys/block/sr0/size is 2097151.
> 
> After inserting the first CD, and mounting it, /sys/block/sr0/size is changed
> to the size of the first CD (in 512 byte blocks).
> 
> After ejecting the first CD and inserting the second CD, the behavior is like
> this:
>   1. when immediately mounting the CD, /sys/block/sr0/size is updated to the
>      size of the second CD,
>   2. when waiting more than 30 seconds before mounting the CD,
>      /sys/block/sr0/size is not updated, and keeps the old value.
> 
> Surprisingly, it doesn't behave like this when inserting the first CD.
> /sys/block/sr0/size is always updated, whether I wait 30 seconds before
> mounting it or not.

I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
So the problem is not PS3-specific.

Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
always stayed at the value for the first CD.

Note that Debian's tar is `smart' and optimizes `tar cf /dev/null' by never
reading the input files, so you have to e.g. pipe the resulting archive to
`cat > /dev/null' or so.

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Mon, 2008-06-09 at 15:54 +0200, Geert Uytterhoeven wrote:
> I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
> Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
> So the problem is not PS3-specific.
> 
> Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
> when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
> always stayed at the value for the first CD.
> 
> Note that Debian's tar is `smart' and optimizes `tar cf /dev/null' by never
> reading the input files, so you have to e.g. pipe the resulting archive to
> `cat > /dev/null' or so.

Well, we have the taxonomy.  It's something to do with the media change
trigger.  Could you try getting the output of this patch and correlate
the prints with your success and failure cases?

Thanks,

James

---

diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c
index 7ee86d4..2b58772 100644
--- a/drivers/scsi/sr.c
+++ b/drivers/scsi/sr.c
@@ -212,6 +212,8 @@ static int sr_media_change(struct cdrom_device_info *cdi, int slot)
 	if (retval || (scsi_sense_valid(sshdr) &&
 		       /* 0x3a is medium not present */
 		       sshdr->asc == 0x3a)) {
+		printk("+10+ the result = 0x%x, skip size update ", retval);
+		scsi_show_sense_hdr(&sshdr);
 		/* Media not present or unable to test, unit probably not
 		 * ready. This usually means there is no disc in the drive.
 		 * Mark as changed, and we will figure it out later once
@@ -232,7 +234,7 @@ static int sr_media_change(struct cdrom_device_info *cdi, int slot)
 		sr_cd_check(cdi);
 		get_sectorsize(cd);
 	}
-
+	printk("+11+ Return forcing update is %d\n", retval);
 out:
 	/* Notify userspace, that media has changed. */
 	if (retval != cd->previous_state)

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Mon, 2008-06-09 at 15:54 +0200, Geert Uytterhoeven wrote:
> I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
> Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
> So the problem is not PS3-specific.
> 
> Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
> when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
> always stayed at the value for the first CD.
> 
> Note that Debian's tar is `smart' and optimizes `tar cf /dev/null' by never
> reading the input files, so you have to e.g. pipe the resulting archive to
> `cat > /dev/null' or so.

Well, we have the taxonomy.  It's something to do with the media change
trigger.  Could you try getting the output of this patch and correlate
the prints with your success and failure cases?

Thanks,

James

---

diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c
index 7ee86d4..2b58772 100644
--- a/drivers/scsi/sr.c
+++ b/drivers/scsi/sr.c
@@ -212,6 +212,8 @@ static int sr_media_change(struct cdrom_device_info *cdi, int slot)
 	if (retval || (scsi_sense_valid(sshdr) &&
 		       /* 0x3a is medium not present */
 		       sshdr->asc == 0x3a)) {
+		printk("+10+ the result = 0x%x, skip size update ", retval);
+		scsi_show_sense_hdr(&sshdr);
 		/* Media not present or unable to test, unit probably not
 		 * ready. This usually means there is no disc in the drive.
 		 * Mark as changed, and we will figure it out later once
@@ -232,7 +234,7 @@ static int sr_media_change(struct cdrom_device_info *cdi, int slot)
 		sr_cd_check(cdi);
 		get_sectorsize(cd);
 	}
-
+	printk("+11+ Return forcing update is %d\n", retval);
 out:
 	/* Notify userspace, that media has changed. */
 	if (retval != cd->previous_state)

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 4662 bytes --]

	Hi James,

On Mon, 9 Jun 2008, James Bottomley wrote:
> On Mon, 2008-06-09 at 15:54 +0200, Geert Uytterhoeven wrote:
> > I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
> > Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
> > So the problem is not PS3-specific.
> > 
> > Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
> > when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
> > always stayed at the value for the first CD.
> 
> Well, we have the taxonomy.  It's something to do with the media change
> trigger.  Could you try getting the output of this patch and correlate
> the prints with your success and failure cases?

Sure!

Inserting first CD, mounting:

| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 1
                                ^
				OK

| ISO 9660 Extensions: RRIP_1991A

Unmounting first CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Ejecting first CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Inserting second CD, mounting after 30 seconds:

| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0
                                ^
				Not updated!
| ISO 9660 Extensions: Microsoft Joliet Level 3
| ISO 9660 Extensions: RRIP_1991A

=> failed!

Unmounting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Ejecting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Inserting second CD, mounting immediately:

| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| Sense Key : 0x2 [current] 
| +5+ CDS_DISC_OK
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| Sense Key : 0x2 [current] 
| +5+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 1
                                ^
				OK

| ISO 9660 Extensions: Microsoft Joliet Level 3
| ISO 9660 Extensions: RRIP_1991A

=> success!

Unmounting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Ejecting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 4662 bytes --]

	Hi James,

On Mon, 9 Jun 2008, James Bottomley wrote:
> On Mon, 2008-06-09 at 15:54 +0200, Geert Uytterhoeven wrote:
> > I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
> > Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
> > So the problem is not PS3-specific.
> > 
> > Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
> > when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
> > always stayed at the value for the first CD.
> 
> Well, we have the taxonomy.  It's something to do with the media change
> trigger.  Could you try getting the output of this patch and correlate
> the prints with your success and failure cases?

Sure!

Inserting first CD, mounting:

| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 1
                                ^
				OK

| ISO 9660 Extensions: RRIP_1991A

Unmounting first CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Ejecting first CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Inserting second CD, mounting after 30 seconds:

| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0
                                ^
				Not updated!
| ISO 9660 Extensions: Microsoft Joliet Level 3
| ISO 9660 Extensions: RRIP_1991A

=> failed!

Unmounting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Ejecting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Inserting second CD, mounting immediately:

| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| Sense Key : 0x2 [current] 
| +5+ CDS_DISC_OK
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
| Sense Key : 0x2 [current] 
| +5+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 1
                                ^
				OK

| ISO 9660 Extensions: Microsoft Joliet Level 3
| ISO 9660 Extensions: RRIP_1991A

=> success!

Unmounting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Ejecting second CD:

| +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3226 bytes --]

	Hi James,

On Mon, 9 Jun 2008, James Bottomley wrote:
> My best guess is that it's something to do with eaten UNIT_ATTENTION
> keys.  I theorise that in the successful case, they get processed in
> scsi_io_completion which sets the changed bit.  In the delay case, the
> unit attention is eaten by sr_test_unit_ready so the changed bit is
> always kept at zero.  If this is the case, then the patch below should
> fix it.  If not, we're back to more debugging ...

Yep, that fixed it. Thanks!

Inserting first CD, mounting:

| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| Sense Key : 0x2 [current] 
| +5+ CDS_DISC_OK
| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| Sense Key : 0x2 [current] 
| +5+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 1
                                ^
				OK

| ISO 9660 Extensions: RRIP_1991A

Unmounting first CD:

| +0+ the_result = 0x0 (sdev->changed = 0)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 0)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 0)
| Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 0

Inserting second CD, mounting after 30 seconds:

| +0+ the_result = 0x8000002 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +1+ CDS_DISC_OK
| +0+ the_result = 0x0 (sdev->changed = 1)
| Sense Key : 0x0 [current] [descriptor]
| +11+ Return forcing update is 1
                                ^
				OK!

| ISO 9660 Extensions: Microsoft Joliet Level 3
| ISO 9660 Extensions: RRIP_1991A

=> success!

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

[resend, managed to drop linux-scsi first time around]

On Mon, 2008-06-09 at 17:27 +0200, Geert Uytterhoeven wrote:
> 	Hi James,
> 
> On Mon, 9 Jun 2008, James Bottomley wrote:
> > On Mon, 2008-06-09 at 15:54 +0200, Geert Uytterhoeven wrote:
> > > I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
> > > Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
> > > So the problem is not PS3-specific.
> > > 
> > > Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
> > > when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
> > > always stayed at the value for the first CD.
> > 
> > Well, we have the taxonomy.  It's something to do with the media change
> > trigger.  Could you try getting the output of this patch and correlate
> > the prints with your success and failure cases?
> 
> Sure!
> 
> Inserting first CD, mounting:
> 
> | +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 1
>                                 ^
> 				OK
> 
> | ISO 9660 Extensions: RRIP_1991A
> 
> Unmounting first CD:
> 
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 0
> 
> Ejecting first CD:
> 
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 0
> 
> Inserting second CD, mounting after 30 seconds:
> 
> | +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 0
>                                 ^
> 				Not updated!
> | ISO 9660 Extensions: Microsoft Joliet Level 3
> | ISO 9660 Extensions: RRIP_1991A
> 
> => failed!

Great!  confirms the theory of the what but doesn't tell us how this is
happening.

My best guess is that it's something to do with eaten UNIT_ATTENTION
keys.  I theorise that in the successful case, they get processed in
scsi_io_completion which sets the changed bit.  In the delay case, the
unit attention is eaten by sr_test_unit_ready so the changed bit is
always kept at zero.  If this is the case, then the patch below should
fix it.  If not, we're back to more debugging ...

James

---

diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c
index 7ee86d4..c82df8b 100644
--- a/drivers/scsi/sr.c
+++ b/drivers/scsi/sr.c
@@ -178,6 +178,9 @@ int sr_test_unit_ready(struct scsi_device *sdev, struct scsi_sense_hdr *sshdr)
 		the_result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL,
 					      0, sshdr, SR_TIMEOUT,
 					      retries--);
+		if (scsi_sense_valid(sshdr) &&
+		    sshdr->sense_key == UNIT_ATTENTION)
+			sdev->changed = 1;
 
 	} while (retries > 0 &&
 		 (!scsi_status_is_good(the_result) ||

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Tue, 2008-06-10 at 17:11 +0200, Geert Uytterhoeven wrote:
> 	Hi James,
> 
> On Mon, 9 Jun 2008, James Bottomley wrote:
> > My best guess is that it's something to do with eaten UNIT_ATTENTION
> > keys.  I theorise that in the successful case, they get processed in
> > scsi_io_completion which sets the changed bit.  In the delay case, the
> > unit attention is eaten by sr_test_unit_ready so the changed bit is
> > always kept at zero.  If this is the case, then the patch below should
> > fix it.  If not, we're back to more debugging ...
> 
> Yep, that fixed it. Thanks!

OK, will add to rc-fixes and ask for stable backport; thanks.

James


> Inserting first CD, mounting:
> 
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | Sense Key : 0x2 [current] 
> | +5+ CDS_DISC_OK
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | Sense Key : 0x2 [current] 
> | +5+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 1
>                                 ^
> 				OK
> 
> | ISO 9660 Extensions: RRIP_1991A
> 
> Unmounting first CD:
> 
> | +0+ the_result = 0x0 (sdev->changed = 0)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 0)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 0)
> | Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 0
> 
> Inserting second CD, mounting after 30 seconds:
> 
> | +0+ the_result = 0x8000002 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +1+ CDS_DISC_OK
> | +0+ the_result = 0x0 (sdev->changed = 1)
> | Sense Key : 0x0 [current] [descriptor]
> | +11+ Return forcing update is 1
>                                 ^
> 				OK!
> 
> | ISO 9660 Extensions: Microsoft Joliet Level 3
> | ISO 9660 Extensions: RRIP_1991A
> 
> => success!
> 
> With kind regards,
> 
> Geert Uytterhoeven
> Software Architect
> 
> Sony Techsoft Centre
> The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium
> 
> Phone:    +32 (0)2 700 8453
> Fax:      +32 (0)2 700 8622
> E-mail:   Geert.Uytterhoeven@sonycom.com
> Internet: http://www.sony-europe.com/
> 
> Sony Technology and Software Centre Europe
> A division of Sony Service Centre (Europe) N.V.
> Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
> VAT BE 0413.825.160 · RPR Brussels
> Fortis 293-0376800-10 GEBA-BE-BB

--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Boaz Harrosh]

James Bottomley wrote:
> [resend, managed to drop linux-scsi first time around]
> 
> On Mon, 2008-06-09 at 17:27 +0200, Geert Uytterhoeven wrote:
>> 	Hi James,
>>
>> On Mon, 9 Jun 2008, James Bottomley wrote:
>>> On Mon, 2008-06-09 at 15:54 +0200, Geert Uytterhoeven wrote:
>>>> I managed to reproduce it on my laptop (Core 2 Duo, SATA DVD-RAM, running
>>>> Ubuntu 8.04 for amd64), by booting Debian's 2.6.25 kernel into recovery mode.
>>>> So the problem is not PS3-specific.
>>>>
>>>> Worse, I never got an updated /sys/block/sr0/size for the second CD, not even
>>>> when mounting it ASAP (which is ca. 15-20 seconds after inserting it).  It
>>>> always stayed at the value for the first CD.
>>> Well, we have the taxonomy.  It's something to do with the media change
>>> trigger.  Could you try getting the output of this patch and correlate
>>> the prints with your success and failure cases?
>> Sure!
>>
>> Inserting first CD, mounting:
>>
>> | +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +11+ Return forcing update is 1
>>                                 ^
>> 				OK
>>
>> | ISO 9660 Extensions: RRIP_1991A
>>
>> Unmounting first CD:
>>
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +11+ Return forcing update is 0
>>
>> Ejecting first CD:
>>
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +11+ Return forcing update is 0
>>
>> Inserting second CD, mounting after 30 seconds:
>>
>> | +0+ the_result = 0x8000002 Sense Key : 0x0 [current] [descriptor]
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +1+ CDS_DISC_OK
>> | +0+ the_result = 0x0 Sense Key : 0x0 [current] [descriptor]
>> | +11+ Return forcing update is 0
>>                                 ^
>> 				Not updated!
>> | ISO 9660 Extensions: Microsoft Joliet Level 3
>> | ISO 9660 Extensions: RRIP_1991A
>>
>> => failed!
> 
> Great!  confirms the theory of the what but doesn't tell us how this is
> happening.
> 
> My best guess is that it's something to do with eaten UNIT_ATTENTION
> keys.  I theorise that in the successful case, they get processed in
> scsi_io_completion which sets the changed bit.  In the delay case, the
> unit attention is eaten by sr_test_unit_ready so the changed bit is
> always kept at zero.  If this is the case, then the patch below should
> fix it.  If not, we're back to more debugging ...
> 
> James
> 
> ---
> 
> diff --git a/drivers/scsi/sr.c b/drivers/scsi/sr.c
> index 7ee86d4..c82df8b 100644
> --- a/drivers/scsi/sr.c
> +++ b/drivers/scsi/sr.c
> @@ -178,6 +178,9 @@ int sr_test_unit_ready(struct scsi_device *sdev, struct scsi_sense_hdr *sshdr)
>  		the_result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL,
>  					      0, sshdr, SR_TIMEOUT,
>  					      retries--);
> +		if (scsi_sense_valid(sshdr) &&
> +		    sshdr->sense_key == UNIT_ATTENTION)
> +			sdev->changed = 1;
>  
>  	} while (retries > 0 &&
>  		 (!scsi_status_is_good(the_result) ||
> 
> 

I think, I recall that, any issued command, not only unit_ready, might be appended
with UNIT_ATTENTION sense. So maybe as a deeper fix (with lots of testing) we want 
to add this logic into the scsi_check_sense() processing. But I'm not sure either way.

Boaz

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Tue, 2008-06-10 at 18:49 +0300, Boaz Harrosh wrote:
> I think, I recall that, any issued command, not only unit_ready, might be appended
> with UNIT_ATTENTION sense. So maybe as a deeper fix (with lots of testing) we want 
> to add this logic into the scsi_check_sense() processing. But I'm not sure either way.

We do .. it's in scsi_io_completion().  The problem is that by design
internally issued commands bypass this, so the problem was that the
internally issued command wasn't doing the correct update.

James

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Boaz Harrosh]

James Bottomley wrote:
> On Tue, 2008-06-10 at 18:49 +0300, Boaz Harrosh wrote:
>> I think, I recall that, any issued command, not only unit_ready, might be appended
>> with UNIT_ATTENTION sense. So maybe as a deeper fix (with lots of testing) we want 
>> to add this logic into the scsi_check_sense() processing. But I'm not sure either way.
> 
> We do .. it's in scsi_io_completion().  The problem is that by design
> internally issued commands bypass this, so the problem was that the
> internally issued command wasn't doing the correct update.
> 
> James
> 
> 

Yes, I was just staring at that code. It looks like this hunk could be move up
to before the completion, since with BLOCK_PC commands we always complete the
all command length, hence the code will never get there.

Should I attempt a fix, or could you do it?

Boaz

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Tue, 2008-06-10 at 19:12 +0300, Boaz Harrosh wrote:
> James Bottomley wrote:
> > On Tue, 2008-06-10 at 18:49 +0300, Boaz Harrosh wrote:
> >> I think, I recall that, any issued command, not only unit_ready, might be appended
> >> with UNIT_ATTENTION sense. So maybe as a deeper fix (with lots of testing) we want 
> >> to add this logic into the scsi_check_sense() processing. But I'm not sure either way.
> > 
> > We do .. it's in scsi_io_completion().  The problem is that by design
> > internally issued commands bypass this, so the problem was that the
> > internally issued command wasn't doing the correct update.
> > 
> > James
> > 
> > 
> 
> Yes, I was just staring at that code. It looks like this hunk could be move up
> to before the completion, since with BLOCK_PC commands we always complete the
> all command length, hence the code will never get there.
> 
> Should I attempt a fix, or could you do it?

Like I said, we deliberately let them see this, so moving the code would
be the wrong thing to do.

James

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 862 bytes --]

On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> from it, we get:

Apparently the fix didn't make it to all the CCed lists...

http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 862 bytes --]

On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> from it, we get:

Apparently the fix didn't make it to all the CCed lists...

http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
<Geert.Uytterhoeven@sonycom.com> wrote:
> On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>> from it, we get:
>
> Apparently the fix didn't make it to all the CCed lists...
>
> http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0

Oh, that's in mainline ? I still have the problem of having to
 insert DVD / try accessing it and get errors / eject / re-insert
 and then it magically works... the messages have changed
 from what they were as reported here

http://bugzilla.kernel.org/show_bug.cgi?id=10116

 (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:

Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
hostbyte=0x00 driverbyte=0x08
Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38

here I eject and reinsert the disc, and:

Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found

 lo and behold, no problem.

This does not, alas, happen every time. It might be at the first
 DVD access after booting the laptop, but I haven't investigated
 in this detail yet.

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
<Geert.Uytterhoeven@sonycom.com> wrote:
> On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>> from it, we get:
>
> Apparently the fix didn't make it to all the CCed lists...
>
> http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0

Oh, that's in mainline ? I still have the problem of having to
 insert DVD / try accessing it and get errors / eject / re-insert
 and then it magically works... the messages have changed
 from what they were as reported here

http://bugzilla.kernel.org/show_bug.cgi?id=10116

 (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:

Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
hostbyte=0x00 driverbyte=0x08
Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38

here I eject and reinsert the disc, and:

Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found

 lo and behold, no problem.

This does not, alas, happen every time. It might be at the first
 DVD access after booting the laptop, but I haven't investigated
 in this detail yet.

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 2975 bytes --]

On Wed, 18 Jun 2008, Alessandro Suardi wrote:
> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
> <Geert.Uytterhoeven@sonycom.com> wrote:
> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> >> from it, we get:
> >
> > Apparently the fix didn't make it to all the CCed lists...
> >
> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
> 
> Oh, that's in mainline ? I still have the problem of having to

Not yet, it's in the scsi-rc-fixes-2.6 tree.

>  insert DVD / try accessing it and get errors / eject / re-insert
>  and then it magically works... the messages have changed
>  from what they were as reported here
> 
> http://bugzilla.kernel.org/show_bug.cgi?id=10116
> 
>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
> 
> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
> hostbyte=0x00 driverbyte=0x08
> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
> 
> here I eject and reinsert the disc, and:
> 
> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
> 
>  lo and behold, no problem.
> 
> This does not, alas, happen every time. It might be at the first
>  DVD access after booting the laptop, but I haven't investigated
>  in this detail yet.

Does /sys/block/sr0/size reflect the correct size of the DVD?

Did you try applying the patch?

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 2975 bytes --]

On Wed, 18 Jun 2008, Alessandro Suardi wrote:
> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
> <Geert.Uytterhoeven@sonycom.com> wrote:
> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> >> from it, we get:
> >
> > Apparently the fix didn't make it to all the CCed lists...
> >
> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
> 
> Oh, that's in mainline ? I still have the problem of having to

Not yet, it's in the scsi-rc-fixes-2.6 tree.

>  insert DVD / try accessing it and get errors / eject / re-insert
>  and then it magically works... the messages have changed
>  from what they were as reported here
> 
> http://bugzilla.kernel.org/show_bug.cgi?id=10116
> 
>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
> 
> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
> hostbyte=0x00 driverbyte=0x08
> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
> 
> here I eject and reinsert the disc, and:
> 
> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
> 
>  lo and behold, no problem.
> 
> This does not, alas, happen every time. It might be at the first
>  DVD access after booting the laptop, but I haven't investigated
>  in this detail yet.

Does /sys/block/sr0/size reflect the correct size of the DVD?

Did you try applying the patch?

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
<Geert.Uytterhoeven@sonycom.com> wrote:
> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
>> <Geert.Uytterhoeven@sonycom.com> wrote:
>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>> >> from it, we get:
>> >
>> > Apparently the fix didn't make it to all the CCed lists...
>> >
>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
>>
>> Oh, that's in mainline ? I still have the problem of having to
>
> Not yet, it's in the scsi-rc-fixes-2.6 tree.
>
>>  insert DVD / try accessing it and get errors / eject / re-insert
>>  and then it magically works... the messages have changed
>>  from what they were as reported here
>>
>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
>>
>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
>>
>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
>> hostbyte=0x00 driverbyte=0x08
>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
>>
>> here I eject and reinsert the disc, and:
>>
>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
>>
>>  lo and behold, no problem.
>>
>> This does not, alas, happen every time. It might be at the first
>>  DVD access after booting the laptop, but I haven't investigated
>>  in this detail yet.
>
> Does /sys/block/sr0/size reflect the correct size of the DVD?
>
> Did you try applying the patch?

ATM I'm away from home (as usual), I'll post back when
 I have the info you asked for and tried applying the
 above patch. Thanks !

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
<Geert.Uytterhoeven@sonycom.com> wrote:
> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
>> <Geert.Uytterhoeven@sonycom.com> wrote:
>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>> >> from it, we get:
>> >
>> > Apparently the fix didn't make it to all the CCed lists...
>> >
>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
>>
>> Oh, that's in mainline ? I still have the problem of having to
>
> Not yet, it's in the scsi-rc-fixes-2.6 tree.
>
>>  insert DVD / try accessing it and get errors / eject / re-insert
>>  and then it magically works... the messages have changed
>>  from what they were as reported here
>>
>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
>>
>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
>>
>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
>> hostbyte=0x00 driverbyte=0x08
>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
>>
>> here I eject and reinsert the disc, and:
>>
>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
>>
>>  lo and behold, no problem.
>>
>> This does not, alas, happen every time. It might be at the first
>>  DVD access after booting the laptop, but I haven't investigated
>>  in this detail yet.
>
> Does /sys/block/sr0/size reflect the correct size of the DVD?
>
> Did you try applying the patch?

ATM I'm away from home (as usual), I'll post back when
 I have the info you asked for and tried applying the
 above patch. Thanks !

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

[dropped David Martin from CC: list as I get permanent delivery errors]

On Wed, Jun 18, 2008 at 2:15 PM, Alessandro Suardi
<alessandro.suardi@gmail.com> wrote:
> On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
> <Geert.Uytterhoeven@sonycom.com> wrote:
>> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
>>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
>>> <Geert.Uytterhoeven@sonycom.com> wrote:
>>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>>> >> from it, we get:
>>> >
>>> > Apparently the fix didn't make it to all the CCed lists...
>>> >
>>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
>>>
>>> Oh, that's in mainline ? I still have the problem of having to
>>
>> Not yet, it's in the scsi-rc-fixes-2.6 tree.
>>
>>>  insert DVD / try accessing it and get errors / eject / re-insert
>>>  and then it magically works... the messages have changed
>>>  from what they were as reported here
>>>
>>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
>>>
>>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
>>>
>>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
>>> hostbyte=0x00 driverbyte=0x08
>>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
>>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
>>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
>>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
>>>
>>> here I eject and reinsert the disc, and:
>>>
>>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
>>>
>>>  lo and behold, no problem.
>>>
>>> This does not, alas, happen every time. It might be at the first
>>>  DVD access after booting the laptop, but I haven't investigated
>>>  in this detail yet.
>>
>> Does /sys/block/sr0/size reflect the correct size of the DVD?
>>
>> Did you try applying the patch?
>
> ATM I'm away from home (as usual), I'll post back when
>  I have the info you asked for and tried applying the
>  above patch. Thanks !

Sigh. I haven't been able to reproduce the problem once since
 I posted this. Will keep trying...

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3715 bytes --]

On Sat, 21 Jun 2008, Alessandro Suardi wrote:
> On Wed, Jun 18, 2008 at 2:15 PM, Alessandro Suardi
> <alessandro.suardi@gmail.com> wrote:
> > On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
> > <Geert.Uytterhoeven@sonycom.com> wrote:
> >> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
> >>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
> >>> <Geert.Uytterhoeven@sonycom.com> wrote:
> >>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
> >>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> >>> >> from it, we get:
> >>> >
> >>> > Apparently the fix didn't make it to all the CCed lists...
> >>> >
> >>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
> >>>
> >>> Oh, that's in mainline ? I still have the problem of having to
> >>
> >> Not yet, it's in the scsi-rc-fixes-2.6 tree.
> >>
> >>>  insert DVD / try accessing it and get errors / eject / re-insert
> >>>  and then it magically works... the messages have changed
> >>>  from what they were as reported here
> >>>
> >>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
> >>>
> >>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
> >>>
> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
> >>> hostbyte=0x00 driverbyte=0x08
> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
> >>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
> >>>
> >>> here I eject and reinsert the disc, and:
> >>>
> >>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
> >>>
> >>>  lo and behold, no problem.
> >>>
> >>> This does not, alas, happen every time. It might be at the first
> >>>  DVD access after booting the laptop, but I haven't investigated
> >>>  in this detail yet.
> >>
> >> Does /sys/block/sr0/size reflect the correct size of the DVD?
> >>
> >> Did you try applying the patch?
> >
> > ATM I'm away from home (as usual), I'll post back when
> >  I have the info you asked for and tried applying the
> >  above patch. Thanks !
> 
> Sigh. I haven't been able to reproduce the problem once since
>  I posted this. Will keep trying...

Perhaps because the fix is now in mainline?

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Geert Uytterhoeven]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 3715 bytes --]

On Sat, 21 Jun 2008, Alessandro Suardi wrote:
> On Wed, Jun 18, 2008 at 2:15 PM, Alessandro Suardi
> <alessandro.suardi@gmail.com> wrote:
> > On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
> > <Geert.Uytterhoeven@sonycom.com> wrote:
> >> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
> >>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
> >>> <Geert.Uytterhoeven@sonycom.com> wrote:
> >>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
> >>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
> >>> >> from it, we get:
> >>> >
> >>> > Apparently the fix didn't make it to all the CCed lists...
> >>> >
> >>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
> >>>
> >>> Oh, that's in mainline ? I still have the problem of having to
> >>
> >> Not yet, it's in the scsi-rc-fixes-2.6 tree.
> >>
> >>>  insert DVD / try accessing it and get errors / eject / re-insert
> >>>  and then it magically works... the messages have changed
> >>>  from what they were as reported here
> >>>
> >>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
> >>>
> >>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
> >>>
> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
> >>> hostbyte=0x00 driverbyte=0x08
> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
> >>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
> >>>
> >>> here I eject and reinsert the disc, and:
> >>>
> >>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
> >>>
> >>>  lo and behold, no problem.
> >>>
> >>> This does not, alas, happen every time. It might be at the first
> >>>  DVD access after booting the laptop, but I haven't investigated
> >>>  in this detail yet.
> >>
> >> Does /sys/block/sr0/size reflect the correct size of the DVD?
> >>
> >> Did you try applying the patch?
> >
> > ATM I'm away from home (as usual), I'll post back when
> >  I have the info you asked for and tried applying the
> >  above patch. Thanks !
> 
> Sigh. I haven't been able to reproduce the problem once since
>  I posted this. Will keep trying...

Perhaps because the fix is now in mainline?

With kind regards,

Geert Uytterhoeven
Software Architect

Sony Techsoft Centre
The Corporate Village · Da Vincilaan 7-D1 · B-1935 Zaventem · Belgium

Phone:    +32 (0)2 700 8453
Fax:      +32 (0)2 700 8622
E-mail:   Geert.Uytterhoeven@sonycom.com
Internet: http://www.sony-europe.com/

Sony Technology and Software Centre Europe
A division of Sony Service Centre (Europe) N.V.
Registered office: Technologielaan 7 · B-1840 Londerzeel · Belgium
VAT BE 0413.825.160 · RPR Brussels
Fortis 293-0376800-10 GEBA-BE-BB

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Sun, Jun 22, 2008 at 10:18 AM, Geert Uytterhoeven
<Geert.Uytterhoeven@sonycom.com> wrote:
> On Sat, 21 Jun 2008, Alessandro Suardi wrote:
>> On Wed, Jun 18, 2008 at 2:15 PM, Alessandro Suardi
>> <alessandro.suardi@gmail.com> wrote:
>> > On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
>> > <Geert.Uytterhoeven@sonycom.com> wrote:
>> >> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
>> >>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
>> >>> <Geert.Uytterhoeven@sonycom.com> wrote:
>> >>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>> >>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>> >>> >> from it, we get:
>> >>> >
>> >>> > Apparently the fix didn't make it to all the CCed lists...
>> >>> >
>> >>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
>> >>>
>> >>> Oh, that's in mainline ? I still have the problem of having to
>> >>
>> >> Not yet, it's in the scsi-rc-fixes-2.6 tree.
>> >>
>> >>>  insert DVD / try accessing it and get errors / eject / re-insert
>> >>>  and then it magically works... the messages have changed
>> >>>  from what they were as reported here
>> >>>
>> >>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
>> >>>
>> >>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
>> >>>
>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
>> >>> hostbyte=0x00 driverbyte=0x08
>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
>> >>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
>> >>>
>> >>> here I eject and reinsert the disc, and:
>> >>>
>> >>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
>> >>>
>> >>>  lo and behold, no problem.
>> >>>
>> >>> This does not, alas, happen every time. It might be at the first
>> >>>  DVD access after booting the laptop, but I haven't investigated
>> >>>  in this detail yet.
>> >>
>> >> Does /sys/block/sr0/size reflect the correct size of the DVD?
>> >>
>> >> Did you try applying the patch?
>> >
>> > ATM I'm away from home (as usual), I'll post back when
>> >  I have the info you asked for and tried applying the
>> >  above patch. Thanks !
>>
>> Sigh. I haven't been able to reproduce the problem once since
>>  I posted this. Will keep trying...
>
> Perhaps because the fix is now in mainline?

Eh, that may be a reason :)

I'm indeed tracking mainline and haven't reproduced with
 at least six different discs in -rc7.

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Sun, Jun 22, 2008 at 3:14 PM, Alessandro Suardi
<alessandro.suardi@gmail.com> wrote:
> On Sun, Jun 22, 2008 at 10:18 AM, Geert Uytterhoeven
> <Geert.Uytterhoeven@sonycom.com> wrote:
>> On Sat, 21 Jun 2008, Alessandro Suardi wrote:
>>> On Wed, Jun 18, 2008 at 2:15 PM, Alessandro Suardi
>>> <alessandro.suardi@gmail.com> wrote:
>>> > On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
>>> > <Geert.Uytterhoeven@sonycom.com> wrote:
>>> >> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
>>> >>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
>>> >>> <Geert.Uytterhoeven@sonycom.com> wrote:
>>> >>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>>> >>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>>> >>> >> from it, we get:
>>> >>> >
>>> >>> > Apparently the fix didn't make it to all the CCed lists...
>>> >>> >
>>> >>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
>>> >>>
>>> >>> Oh, that's in mainline ? I still have the problem of having to
>>> >>
>>> >> Not yet, it's in the scsi-rc-fixes-2.6 tree.
>>> >>
>>> >>>  insert DVD / try accessing it and get errors / eject / re-insert
>>> >>>  and then it magically works... the messages have changed
>>> >>>  from what they were as reported here
>>> >>>
>>> >>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
>>> >>>
>>> >>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
>>> >>>
>>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
>>> >>> hostbyte=0x00 driverbyte=0x08
>>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
>>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
>>> >>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
>>> >>>
>>> >>> here I eject and reinsert the disc, and:
>>> >>>
>>> >>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
>>> >>>
>>> >>>  lo and behold, no problem.
>>> >>>
>>> >>> This does not, alas, happen every time. It might be at the first
>>> >>>  DVD access after booting the laptop, but I haven't investigated
>>> >>>  in this detail yet.
>>> >>
>>> >> Does /sys/block/sr0/size reflect the correct size of the DVD?
>>> >>
>>> >> Did you try applying the patch?
>>> >
>>> > ATM I'm away from home (as usual), I'll post back when
>>> >  I have the info you asked for and tried applying the
>>> >  above patch. Thanks !
>>>
>>> Sigh. I haven't been able to reproduce the problem once since
>>>  I posted this. Will keep trying...
>>
>> Perhaps because the fix is now in mainline?
>
> Eh, that may be a reason :)
>
> I'm indeed tracking mainline and haven't reproduced with
>  at least six different discs in -rc7.

Just had the symptoms again in -rc9-git9 :(

Relevant part of dmesg:

<mount -r /cdrom, access file with gmplayer>

SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
ISO 9660 Extensions: Microsoft Joliet Level 3
ISO 9660 Extensions: RRIP_1991A
SELinux: initialized (dev sr0, type iso9660), uses genfs_contexts
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
Buffer I/O error on device sr0, logical block 2110628
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
Buffer I/O error on device sr0, logical block 2110629
attempt to access beyond end of device
sr0: rw=0, want=8442524, limit=2097151
Buffer I/O error on device sr0, logical block 2110630
attempt to access beyond end of device
sr0: rw=0, want=8442528, limit=2097151
Buffer I/O error on device sr0, logical block 2110631
attempt to access beyond end of device
sr0: rw=0, want=8442532, limit=2097151
Buffer I/O error on device sr0, logical block 2110632
attempt to access beyond end of device
sr0: rw=0, want=8442536, limit=2097151
Buffer I/O error on device sr0, logical block 2110633
attempt to access beyond end of device
sr0: rw=0, want=8442540, limit=2097151
Buffer I/O error on device sr0, logical block 2110634
attempt to access beyond end of device
sr0: rw=0, want=8442544, limit=2097151
Buffer I/O error on device sr0, logical block 2110635
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
Buffer I/O error on device sr0, logical block 2110628
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
Buffer I/O error on device sr0, logical block 2110629
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442516, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=8442520, limit=2097151

<here I eject, reinsert and remount the DVD>

UDF-fs: No VRS found
ISO 9660 Extensions: Microsoft Joliet Level 3
ISO 9660 Extensions: RRIP_1991A
SELinux: initialized (dev sr0, type iso9660), uses genfs_contexts

<now works fine>

Have to say that I didn't wait N seconds in the beginning,
 but just rather

 - plop cdrom in
 - close tray
 - mount -r /cdrom while disc is still spinning

Unfortunately I only have this after eject/remount:

[asuardi@sandman ~]$ cat /sys/block/sr0/size
9133120

Final note, as I said earlier in the thread, this is definitely
 an occurrence of first device access after boot - as I just
 rebooted:

[asuardi@sandman ~]$ uptime
 23:25:28 up 17 min,  6 users,  load average: 0.09, 0.18, 0.15
[asuardi@sandman ~]$ uname -a
Linux sandman 2.6.26-rc9-git9 #7 Fri Jul 11 21:59:15 CEST 2008 i686
i686 i386 GNU/Linux

Thanks,

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Fri, Jul 11, 2008 at 11:25 PM, Alessandro Suardi
<alessandro.suardi@gmail.com> wrote:
> On Sun, Jun 22, 2008 at 3:14 PM, Alessandro Suardi
> <alessandro.suardi@gmail.com> wrote:
>> On Sun, Jun 22, 2008 at 10:18 AM, Geert Uytterhoeven
>> <Geert.Uytterhoeven@sonycom.com> wrote:
>>> On Sat, 21 Jun 2008, Alessandro Suardi wrote:
>>>> On Wed, Jun 18, 2008 at 2:15 PM, Alessandro Suardi
>>>> <alessandro.suardi@gmail.com> wrote:
>>>> > On Wed, Jun 18, 2008 at 1:13 PM, Geert Uytterhoeven
>>>> > <Geert.Uytterhoeven@sonycom.com> wrote:
>>>> >> On Wed, 18 Jun 2008, Alessandro Suardi wrote:
>>>> >>> On Fri, Jun 13, 2008 at 7:33 PM, Geert Uytterhoeven
>>>> >>> <Geert.Uytterhoeven@sonycom.com> wrote:
>>>> >>> > On Fri, 6 Jun 2008, Geert Uytterhoeven wrote:
>>>> >>> >> When mounting a CD/DVD more than 30 seconds after inserting it, and reading
>>>> >>> >> from it, we get:
>>>> >>> >
>>>> >>> > Apparently the fix didn't make it to all the CCed lists...
>>>> >>> >
>>>> >>> > http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Fjejb%2Fscsi-rc-fixes-2.6.git;a=commitdiff_plain;h=d1daeabf0da5bfa1943272ce508e2ba785730bf0
>>>> >>>
>>>> >>> Oh, that's in mainline ? I still have the problem of having to
>>>> >>
>>>> >> Not yet, it's in the scsi-rc-fixes-2.6 tree.
>>>> >>
>>>> >>>  insert DVD / try accessing it and get errors / eject / re-insert
>>>> >>>  and then it magically works... the messages have changed
>>>> >>>  from what they were as reported here
>>>> >>>
>>>> >>> http://bugzilla.kernel.org/show_bug.cgi?id=10116
>>>> >>>
>>>> >>>  (see comments #8 and #9) to these ones, in 2.6.26-rc6-git4:
>>>> >>>
>>>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Result:
>>>> >>> hostbyte=0x00 driverbyte=0x08
>>>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] Sense Key : 0x3 [current]
>>>> >>> Jun 17 22:38:43 sandman kernel: sr 1:0:0:0: [sr0] ASC=0x11 ASCQ=0x0
>>>> >>> Jun 17 22:38:43 sandman kernel: end_request: I/O error, dev sr0, sector 232
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 29
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 30
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 31
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 32
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 33
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 34
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 35
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 36
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 37
>>>> >>> Jun 17 22:38:43 sandman kernel: Buffer I/O error on device sr0, logical block 38
>>>> >>>
>>>> >>> here I eject and reinsert the disc, and:
>>>> >>>
>>>> >>> Jun 17 22:39:10 sandman kernel: UDF-fs: No VRS found
>>>> >>>
>>>> >>>  lo and behold, no problem.
>>>> >>>
>>>> >>> This does not, alas, happen every time. It might be at the first
>>>> >>>  DVD access after booting the laptop, but I haven't investigated
>>>> >>>  in this detail yet.
>>>> >>
>>>> >> Does /sys/block/sr0/size reflect the correct size of the DVD?
>>>> >>
>>>> >> Did you try applying the patch?
>>>> >
>>>> > ATM I'm away from home (as usual), I'll post back when
>>>> >  I have the info you asked for and tried applying the
>>>> >  above patch. Thanks !
>>>>
>>>> Sigh. I haven't been able to reproduce the problem once since
>>>>  I posted this. Will keep trying...
>>>
>>> Perhaps because the fix is now in mainline?
>>
>> Eh, that may be a reason :)
>>
>> I'm indeed tracking mainline and haven't reproduced with
>>  at least six different discs in -rc7.
>
> Just had the symptoms again in -rc9-git9 :(
>
> Relevant part of dmesg:
>
> <mount -r /cdrom, access file with gmplayer>
>
> SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
> ISO 9660 Extensions: Microsoft Joliet Level 3
> ISO 9660 Extensions: RRIP_1991A
> SELinux: initialized (dev sr0, type iso9660), uses genfs_contexts
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> Buffer I/O error on device sr0, logical block 2110628
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> Buffer I/O error on device sr0, logical block 2110629
> attempt to access beyond end of device
> sr0: rw=0, want=8442524, limit=2097151
> Buffer I/O error on device sr0, logical block 2110630
> attempt to access beyond end of device
> sr0: rw=0, want=8442528, limit=2097151
> Buffer I/O error on device sr0, logical block 2110631
> attempt to access beyond end of device
> sr0: rw=0, want=8442532, limit=2097151
> Buffer I/O error on device sr0, logical block 2110632
> attempt to access beyond end of device
> sr0: rw=0, want=8442536, limit=2097151
> Buffer I/O error on device sr0, logical block 2110633
> attempt to access beyond end of device
> sr0: rw=0, want=8442540, limit=2097151
> Buffer I/O error on device sr0, logical block 2110634
> attempt to access beyond end of device
> sr0: rw=0, want=8442544, limit=2097151
> Buffer I/O error on device sr0, logical block 2110635
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> Buffer I/O error on device sr0, logical block 2110628
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> Buffer I/O error on device sr0, logical block 2110629
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442516, limit=2097151
> attempt to access beyond end of device
> sr0: rw=0, want=8442520, limit=2097151
>
> <here I eject, reinsert and remount the DVD>
>
> UDF-fs: No VRS found
> ISO 9660 Extensions: Microsoft Joliet Level 3
> ISO 9660 Extensions: RRIP_1991A
> SELinux: initialized (dev sr0, type iso9660), uses genfs_contexts
>
> <now works fine>
>
> Have to say that I didn't wait N seconds in the beginning,
>  but just rather
>
>  - plop cdrom in
>  - close tray
>  - mount -r /cdrom while disc is still spinning
>
> Unfortunately I only have this after eject/remount:
>
> [asuardi@sandman ~]$ cat /sys/block/sr0/size
> 9133120
>
> Final note, as I said earlier in the thread, this is definitely
>  an occurrence of first device access after boot - as I just
>  rebooted:
>
> [asuardi@sandman ~]$ uptime
>  23:25:28 up 17 min,  6 users,  load average: 0.09, 0.18, 0.15
> [asuardi@sandman ~]$ uname -a
> Linux sandman 2.6.26-rc9-git9 #7 Fri Jul 11 21:59:15 CEST 2008 i686
> i686 i386 GNU/Linux

And yet again, in 2.6.26-rc9-git10 freshly compiled/booted,
 when trying to access the Fedora9 DVD to install a bunch
 of packages needed to build SDLmame...

SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
ISO 9660 Extensions: Microsoft Joliet Level 3
ISO 9660 Extensions: RRIP_1991A
SELinux: initialized (dev sr0, type iso9660), uses genfs_contexts
attempt to access beyond end of device
sr0: rw=0, want=3291924, limit=2097151
Buffer I/O error on device sr0, logical block 822980
attempt to access beyond end of device
sr0: rw=0, want=3291928, limit=2097151
Buffer I/O error on device sr0, logical block 822981
attempt to access beyond end of device
sr0: rw=0, want=3291932, limit=2097151
Buffer I/O error on device sr0, logical block 822982
attempt to access beyond end of device
sr0: rw=0, want=3291936, limit=2097151
Buffer I/O error on device sr0, logical block 822983
attempt to access beyond end of device
sr0: rw=0, want=3291940, limit=2097151
Buffer I/O error on device sr0, logical block 822984
attempt to access beyond end of device
sr0: rw=0, want=3291944, limit=2097151
Buffer I/O error on device sr0, logical block 822985
attempt to access beyond end of device
sr0: rw=0, want=3291948, limit=2097151
Buffer I/O error on device sr0, logical block 822986
attempt to access beyond end of device
sr0: rw=0, want=3291952, limit=2097151
Buffer I/O error on device sr0, logical block 822987
attempt to access beyond end of device
sr0: rw=0, want=3291924, limit=2097151
Buffer I/O error on device sr0, logical block 822980
attempt to access beyond end of device
sr0: rw=0, want=3291928, limit=2097151
Buffer I/O error on device sr0, logical block 822981
attempt to access beyond end of device
sr0: rw=0, want=3291924, limit=2097151
attempt to access beyond end of device
sr0: rw=0, want=3291928, limit=2097151
[asuardi@sandman sdlmame0126]$ h | grep siz
  958  cat /sys/block/sr0/size
 1031  h | grep siz
[asuardi@sandman sdlmame0126]$ !958
cat /sys/block/sr0/size
6993536

<eject, remount DVD>

[asuardi@sandman sdlmame0126]$ !mount
mount -r /cdrom
[asuardi@sandman sdlmame0126]$ cat /sys/block/sr0/size
6993536

<now everything works fine>

Possibly a new bug then - since size is always the same ?

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Sat, 2008-07-12 at 14:08 +0200, Alessandro Suardi wrote:
> On Fri, Jul 11, 2008 at 11:25 PM, Alessandro Suardi
> sr0: rw=0, want=3291928, limit=2097151
> [asuardi@sandman sdlmame0126]$ h | grep siz
>   958  cat /sys/block/sr0/size
>  1031  h | grep siz
> [asuardi@sandman sdlmame0126]$ !958
> cat /sys/block/sr0/size
> 6993536
> 
> <eject, remount DVD>
> 
> [asuardi@sandman sdlmame0126]$ !mount
> mount -r /cdrom
> [asuardi@sandman sdlmame0126]$ cat /sys/block/sr0/size
> 6993536
> 
> <now everything works fine>
> 
> Possibly a new bug then - since size is always the same ?

It looks like a re-manifestation of Geert's bug.

You said everything worked in -rc7, and there actually have been no sr
changes at all between then and now, so I'm a bit confused as to how it
could reappear.  Could you try a bisection search for it (first
re-verify -rc7 is OK, just in case that's a false negative).

Thanks,

James

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[James Bottomley]

On Sat, 2008-07-12 at 14:08 +0200, Alessandro Suardi wrote:
> On Fri, Jul 11, 2008 at 11:25 PM, Alessandro Suardi
> sr0: rw=0, want=3291928, limit=2097151
> [asuardi@sandman sdlmame0126]$ h | grep siz
>   958  cat /sys/block/sr0/size
>  1031  h | grep siz
> [asuardi@sandman sdlmame0126]$ !958
> cat /sys/block/sr0/size
> 6993536
> 
> <eject, remount DVD>
> 
> [asuardi@sandman sdlmame0126]$ !mount
> mount -r /cdrom
> [asuardi@sandman sdlmame0126]$ cat /sys/block/sr0/size
> 6993536
> 
> <now everything works fine>
> 
> Possibly a new bug then - since size is always the same ?

It looks like a re-manifestation of Geert's bug.

You said everything worked in -rc7, and there actually have been no sr
changes at all between then and now, so I'm a bit confused as to how it
could reappear.  Could you try a bisection search for it (first
re-verify -rc7 is OK, just in case that's a false negative).

Thanks,

James

Re: [Cbe-oss-dev] [regression/bisected] corrupt CD data after media change and delay

[Alessandro Suardi]

On Sun, Jul 13, 2008 at 3:33 PM, James Bottomley
<James.Bottomley@hansenpartnership.com> wrote:
> On Sat, 2008-07-12 at 14:08 +0200, Alessandro Suardi wrote:
>> On Fri, Jul 11, 2008 at 11:25 PM, Alessandro Suardi
>> sr0: rw=0, want=3291928, limit=2097151
>> [asuardi@sandman sdlmame0126]$ h | grep siz
>>   958  cat /sys/block/sr0/size
>>  1031  h | grep siz
>> [asuardi@sandman sdlmame0126]$ !958
>> cat /sys/block/sr0/size
>> 6993536
>>
>> <eject, remount DVD>
>>
>> [asuardi@sandman sdlmame0126]$ !mount
>> mount -r /cdrom
>> [asuardi@sandman sdlmame0126]$ cat /sys/block/sr0/size
>> 6993536
>>
>> <now everything works fine>
>>
>> Possibly a new bug then - since size is always the same ?
>
> It looks like a re-manifestation of Geert's bug.
>
> You said everything worked in -rc7, and there actually have been no sr
> changes at all between then and now, so I'm a bit confused as to how it
> could reappear.  Could you try a bisection search for it (first
> re-verify -rc7 is OK, just in case that's a false negative).

I have been away a few days - I'll try this weekend rebuilding
 older kernels (I save religiously my .configs for every kernel
 I built in the last, um, five years at least) and give the reboot/
 DVD mount/access sequence a go...

The good news is that in 2.6.26-git4, -git9, -git10 I have been
 unable to reproduce the issue a single time. Still, I'm willing
 to make a bit more effort in trying to reproduce.

--alessandro

 "Give me love / Or give me hate
 Give me anything that's not just ok"

 (Sophia, 'Weightless')