Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

[Patrick Mansfield]

On Tue, Apr 15, 2003 at 10:44:00PM +0200, Gert Vervoort wrote:

> The patch compiles and the warning messages are gone now.
> But, I still can't mount a zip disk.
> 
> Kernel messages after mounting a zip disk (mount -t ext2 /dev/sda1 
> /mnt/zip):
> 
> SCSI device sda: 196608 512-byte hdwr sectors (101 MB)
> sda: Write Protect is off
> sda: Mode Sense: 25 00 00 08
> sda: cache data unavailable
> sda: assuming drive cache: write through
> SCSI device sda: 196608 512-byte hdwr sectors (101 MB)
> sda: Write Protect is off
> sda: Mode Sense: 25 00 00 08
> sda: cache data unavailable
> sda: assuming drive cache: write through
>  sda:
> 
> The kernel messages are showing twice, does it try to mount the zip disk 
> two times?

It opens sd twice (AFAIK) - I think mount scans the block devices (an open
of sd) and then mounts (internal open). The code path in question is
probably via sd.c functions sd_media_changed and sd_revalidate_disk, and
the block_dev.c check_disk_change. sd_open calls check_disk_change.

This could be the same problem others are seeing with removable media
accessed via USB mass storage.

Can you dd to and from the media OK?

Can you capture output for the mount with scsi logging on?

It may or may not help track down what is happening.

If you haven't done much scsi, some scsi logging info:

Check that your .config has CONFIG_SCSI_LOGGING on.

Then do something like:

sync
sync
echo scsi log all > /proc/scsi/scsi 
mount /dev/sdw1 /mnt/sdw1
echo scsi log none > /proc/scsi/scsi
umount /mnt/sdw1

Turn off syslogd if you are logging to a scsi disk (and then you need a
serial line to capture output, and all printk's have to go to the
console), and sync if you are booted off scsi before turning on logging.
In either case, you could get a flood of messages.

-- Patrick Mansfield

Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

[Gert Vervoort]

>
>
>
>Can you capture output for the mount with scsi logging on?
>
>It may or may not help track down what is happening.
>
>If you haven't done much scsi, some scsi logging info:
>
>Check that your .config has CONFIG_SCSI_LOGGING on.
>
>Then do something like:
>
>sync
>sync
>echo scsi log all > /proc/scsi/scsi 
>mount /dev/sdw1 /mnt/sdw1
>  
>
scsi logging level set to 0xffffffff
sd_open: disk=sda
scsi_block_when_processing_errors: rtn: 1
sd_media_changed: disk=sda
scsi_block_when_processing_errors: rtn: 1
scsi_block_when_processing_errors: rtn: 1
Trying ioctl with scsi command 0
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 10000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = 00000000,
bufflen = 0, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command failed c7ea4060 2 busy=1 failed=0
bh?: old sense key No Sense
Non-extended sense class 0 code 0x0
Waking error handler thread
Error handler scsi_eh_0 waking up
scsi_eh_prt_fail_stats: 0:0:6:0 cmds failed: 1, cancel: 0
Total of 1 commands on 1 devices require eh work
scsi_eh_0: requesting sense for id: 6
scsi_add_timer: scmd: c7ea4060, time: 10000, (c0239f10)
scsi_eh_done scmd: c7ea4060 result: 0
scsi_send_eh_cmnd: scmd: c7ea4060, rtn:2002
scsi_send_eh_cmnd: scsi_eh_completed_normally 2002
sense requested for c7ea4060 result 2
Current bh?: sense key Unit Attention
Additional sense: Not ready to ready change, medium may have changed
scsi_eh_0: flush finish cmd: c7ea4060
Notifying upper driver of completion for device 6 8000002
scsi_restart_operations: waking up host to restart
Error handler scsi_eh_0 sleeping
Ioctl returned  0x8000002
IOCTL Releasing command
sd_init_onedisk: disk=sda
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 0, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 8, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
SCSI device sda: 196608 512-byte hdwr sectors (101 MB)
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 4, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
sda: Write Protect is off
sda: Mode Sense: 25 00 00 08
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 4, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command failed c7ea4060 2 busy=1 failed=0
bh?: old sense key No Sense
Non-extended sense class 0 code 0x0
Waking error handler thread
Error handler scsi_eh_0 waking up
scsi_eh_prt_fail_stats: 0:0:6:0 cmds failed: 1, cancel: 0
Total of 1 commands on 1 devices require eh work
scsi_eh_0: requesting sense for id: 6
scsi_add_timer: scmd: c7ea4060, time: 10000, (c0239f10)
scsi_eh_done scmd: c7ea4060 result: 0
scsi_send_eh_cmnd: scmd: c7ea4060, rtn:2002
scsi_send_eh_cmnd: scsi_eh_completed_normally 2002
sense requested for c7ea4060 result 2
Current bh?: sense key Illegal Request
Additional sense: Invalid field in cdb
scsi_eh_0: flush finish cmd: c7ea4060
Notifying upper driver of completion for device 6 8000002
scsi_restart_operations: waking up host to restart
Error handler scsi_eh_0 sleeping
sda: cache data unavailable
sda: assuming drive cache: write through
scsi_block_when_processing_errors: rtn: 1
Trying ioctl with scsi command 30
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 10000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = 00000000,
bufflen = 0, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
Ioctl returned  0x0
IOCTL Releasing command
sd_init_onedisk: disk=sda
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 0, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 8, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
SCSI device sda: 196608 512-byte hdwr sectors (101 MB)
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 4, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0
sda: Write Protect is off
sda: Mode Sense: 25 00 00 08
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea4060, time: 30000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea40b1, buffer = c0fffe00,
bufflen = 4, done = c023bb90)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
scsi_delete_timer: scmd: c7ea4060, rtn: 1
Command failed c7ea4060 2 busy=1 failed=0
bh?: old sense key No Sense
Non-extended sense class 0 code 0x0
Waking error handler thread
Error handler scsi_eh_0 waking up
scsi_eh_prt_fail_stats: 0:0:6:0 cmds failed: 1, cancel: 0
Total of 1 commands on 1 devices require eh work
scsi_eh_0: requesting sense for id: 6
scsi_add_timer: scmd: c7ea4060, time: 10000, (c0239f10)
scsi_eh_done scmd: c7ea4060 result: 0
scsi_send_eh_cmnd: scmd: c7ea4060, rtn:2002
scsi_send_eh_cmnd: scsi_eh_completed_normally 2002
sense requested for c7ea4060 result 2
Current bh?: sense key Illegal Request
Additional sense: Invalid field in cdb
scsi_eh_0: flush finish cmd: c7ea4060
Notifying upper driver of completion for device 6 8000002
scsi_restart_operations: waking up host to restart
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: c7ea41a0, time: 10000, (c0239cc0)
scsi_dispatch_cmnd (host = 0, channel = 0, target = 6, command = 
c7ea41f1, buffer = 00000000,
bufflen = 0, done = c023b0f0)
queuecommand : routine at c02417a0
leaving scsi_dispatch_cmnd()
Error handler scsi_eh_0 sleeping
sda: cache data unavailable
sda: assuming drive cache: write through
 sda:scsi_delete_timer: scmd: c7ea41a0, rtn: 1
Command finished 1 0 0x0
Notifying upper driver of completion for device 6 0



   Gert

Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

[Gert Vervoort]

>
>
>
>Can you dd to and from the media OK?
>  
>
Same effect as mount, now dd is stuck in the "D" state, dd if=/dev/sda 
of=/tmp/kw:

[root@viper root]# ps -ax |grep dd
  985 tty1     D      0:00 dd if /dev/sda of /tmp/kw
 1041 tty2     S      0:00 grep dd
[root@viper root]#


   Gert

Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

[Patrick Mansfield]

On Wed, Apr 16, 2003 at 07:52:15PM +0200, Gert Vervoort wrote:

> bh?: old sense key No Sense
> Non-extended sense class 0 code 0x0
> Waking error handler thread
> Error handler scsi_eh_0 waking up
> scsi_eh_prt_fail_stats: 0:0:6:0 cmds failed: 1, cancel: 0
> Total of 1 commands on 1 devices require eh work
> scsi_eh_0: requesting sense for id: 6
> scsi_add_timer: scmd: c7ea4060, time: 10000, (c0239f10)
> scsi_eh_done scmd: c7ea4060 result: 0
> scsi_send_eh_cmnd: scmd: c7ea4060, rtn:2002
> scsi_send_eh_cmnd: scsi_eh_completed_normally 2002
> sense requested for c7ea4060 result 2
> Current bh?: sense key Unit Attention
> Additional sense: Not ready to ready change, medium may have changed

The ppa driver did not do auto-sense, so we run the error handler
to get the sense code.

There was a missing call to scsi_queue_next_request for door locking (the
ioctl in the scsi log output, ALLOW_MEDIUM_REMOVAL value 30, or 0x1e),
Mike A posted this patch to linux-scsi in response to some debugging leg
work of Alan Stern, does this fix your problem?

Not sure if it patches clean against 2.5.67, but it's pretty simple.

DESC
The patch adds a call to scsi_queue_next_request from scsi_release_request. It
also removes a call in scsi_eh_lock_done to scsi_put_command.
scsi_release_request will do a call to scsi_put_command if needed.
EDESC


 drivers/scsi/scsi.c       |    2 ++
 drivers/scsi/scsi_error.c |    4 ----
 2 files changed, 2 insertions(+), 4 deletions(-)

diff -puN drivers/scsi/scsi.c~scsi-release-req drivers/scsi/scsi.c
--- sysfs-bleed-2.5/drivers/scsi/scsi.c~scsi-release-req	Mon Apr 14 15:34:14 2003
+++ sysfs-bleed-2.5-andmike/drivers/scsi/scsi.c	Mon Apr 14 15:34:14 2003
@@ -224,8 +224,10 @@ void scsi_release_request(Scsi_Request *
 {
 	if( req->sr_command != NULL )
 	{
+    		request_queue_t *q = req->sr_device->request_queue;
 		scsi_put_command(req->sr_command);
 		req->sr_command = NULL;
+		scsi_queue_next_request(q, NULL);
 	}
 
 	kfree(req);
diff -puN drivers/scsi/scsi_error.c~scsi-release-req drivers/scsi/scsi_error.c
--- sysfs-bleed-2.5/drivers/scsi/scsi_error.c~scsi-release-req	Mon Apr 14 15:34:14 2003
+++ sysfs-bleed-2.5-andmike/drivers/scsi/scsi_error.c	Mon Apr 14 15:34:14 2003
@@ -1334,10 +1334,6 @@ static void scsi_eh_lock_done(struct scs
 {
 	struct scsi_request *sreq = scmd->sc_request;
 
-	scmd->sc_request = NULL;
-	sreq->sr_command = NULL;
-
-	scsi_put_command(scmd);
 	scsi_release_request(sreq);
 }

Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

[Gert Vervoort]

  Patrick Mansfield wrote:

>There was a missing call to scsi_queue_next_request for door locking (the
>ioctl in the scsi log output, ALLOW_MEDIUM_REMOVAL value 30, or 0x1e),
>Mike A posted this patch to linux-scsi in response to some debugging leg
>work of Alan Stern, does this fix your problem?
>
>  
>
Yes, this fixes the problem. So far, the zip disk seems to work normal 
(mount/umount, eject a disk, reading from disk).

>Not sure if it patches clean against 2.5.67, but it's pretty simple.
>  
>
The following workaround is needed to make the patch compile  (otherwise 
the linker complains about scsi_queue_next_request not being defined):

--- scsi_lib.c.1        2003-04-16 21:23:37.000000000 +0200
+++ scsi_lib.c  2003-04-16 21:23:46.000000000 +0200
@@ -351,7 +351,7 @@
  *             permutations grows as 2**N, and if too many more special 
cases
  *             get added, we start to get screwed.
  */
-static void scsi_queue_next_request(request_queue_t *q, struct 
scsi_cmnd *cmd)
+/*static*/ void scsi_queue_next_request(request_queue_t *q, struct 
scsi_cmnd *cmd)
 {
        struct scsi_device *sdev, *sdev2;
        struct Scsi_Host *shost;


    Gert

>DESC
>The patch adds a call to scsi_queue_next_request from scsi_release_request. It
>also removes a call in scsi_eh_lock_done to scsi_put_command.
>scsi_release_request will do a call to scsi_put_command if needed.
>EDESC
>
>
> drivers/scsi/scsi.c       |    2 ++
> drivers/scsi/scsi_error.c |    4 ----
> 2 files changed, 2 insertions(+), 4 deletions(-)
>
>diff -puN drivers/scsi/scsi.c~scsi-release-req drivers/scsi/scsi.c
>--- sysfs-bleed-2.5/drivers/scsi/scsi.c~scsi-release-req	Mon Apr 14 15:34:14 2003
>+++ sysfs-bleed-2.5-andmike/drivers/scsi/scsi.c	Mon Apr 14 15:34:14 2003
>@@ -224,8 +224,10 @@ void scsi_release_request(Scsi_Request *
> {
> 	if( req->sr_command != NULL )
> 	{
>+    		request_queue_t *q = req->sr_device->request_queue;
> 		scsi_put_command(req->sr_command);
> 		req->sr_command = NULL;
>+		scsi_queue_next_request(q, NULL);
> 	}
> 
> 	kfree(req);
>diff -puN drivers/scsi/scsi_error.c~scsi-release-req drivers/scsi/scsi_error.c
>--- sysfs-bleed-2.5/drivers/scsi/scsi_error.c~scsi-release-req	Mon Apr 14 15:34:14 2003
>+++ sysfs-bleed-2.5-andmike/drivers/scsi/scsi_error.c	Mon Apr 14 15:34:14 2003
>@@ -1334,10 +1334,6 @@ static void scsi_eh_lock_done(struct scs
> {
> 	struct scsi_request *sreq = scmd->sc_request;
> 
>-	scmd->sc_request = NULL;
>-	sreq->sr_command = NULL;
>-
>-	scsi_put_command(scmd);
> 	scsi_release_request(sreq);
> }
>
>.
>
>  
>

Re: [PATCH] Re: 2.5.67: ppa driver & preempt == oops

[Mike Anderson]

Gert Vervoort [gert.vervoort@hccnet.nl] wrote:
> The following workaround is needed to make the patch compile  (otherwise 
> the linker complains about scsi_queue_next_request not being defined):
> 
> --- scsi_lib.c.1        2003-04-16 21:23:37.000000000 +0200
> +++ scsi_lib.c  2003-04-16 21:23:46.000000000 +0200
> @@ -351,7 +351,7 @@
>  *             permutations grows as 2**N, and if too many more special 
> cases
>  *             get added, we start to get screwed.
>  */
> -static void scsi_queue_next_request(request_queue_t *q, struct 
> scsi_cmnd *cmd)
> +/*static*/ void scsi_queue_next_request(request_queue_t *q, struct 
> scsi_cmnd *cmd)
> {
>        struct scsi_device *sdev, *sdev2;
>        struct Scsi_Host *shost;

The static removal is present already in bk current.

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