Re: __elv_add_request OOPS

Re: __elv_add_request OOPS

[Jens Axboe]

On 2011-05-24 06:29, Parag Warudkar wrote:
> 
> External DVD drive - connected when suspended, removed before resume.
> Results in NULL pointer dereference in __blk_add_request on resume.
> 
> *ffffffff811d6503:      48 89 58 08             mov    %rbx,0x8(%rax) |
> %ebx = ffff880131559020 <--- faulting instruction
> 
> 48 89 58 08 appears only in list_add :
> 
> static inline void list_add(struct list_head *new, struct list_head *head)
> {
>         __list_add(new, head, head->next);
> ffffffff81ac012c:       49 8b 04 24             mov    (%r12),%rax
> #ifndef CONFIG_DEBUG_LIST
> static inline void __list_add(struct list_head *new,
>                               struct list_head *prev,
>                               struct list_head *next)
> {
>         next->prev = new;
> ffffffff81ac0130:       48 89 58 08             mov    %rbx,0x8(%rax)
> 
> AFAICS list_add is only called from one place in __elv_add_request :
> 
>        switch (where) {
>         case ELEVATOR_INSERT_REQUEUE:
>         case ELEVATOR_INSERT_FRONT:
>                 rq->cmd_flags |= REQ_SOFTBARRIER;
>               **  list_add(&rq->queuelist, &q->queue_head);
>                 break;
> 
> Now, where is the patch? :)

You forgot to attach it?

This is clearly q == NULL, CC'ing James/linux-scsi. Oops left below.

> [18682.256362] BUG: unable to handle kernel NULL pointer dereference at 0000000000000008
> [18682.256535] IP: [<ffffffff811d6503>] __elv_add_request+0x1e3/0x270
> [18682.256603] PGD 0
> [18682.256632] Oops: 0002 [#1] SMP
> [18682.256686] CPU 2
> [18682.256714] Modules linked in: nls_utf8 udf crc_itu_t usb_storage cryptd aes_x86_64 aes_generic fuse parport_pc ppdev dm_crypt kvm_intel joydev kvm binfmt_misc snd_hda_codec_hdmi snd_hda_codec_realtek arc4 snd_hda_intel snd_hda_codec iwlagn snd_hwdep snd_pcm mac80211 snd_seq_midi snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd cfg80211 soundcore btusb uvcvideo snd_page_alloc bluetooth videodev v4l2_compat_ioctl32 psmouse ideapad_laptop serio_raw sparse_keymap lp intel_ips mac_hid parport ext4 mbcache jbd2 i915 ahci libahci libata drm_kms_helper drm i2c_algo_bit cfbcopyarea video cfbimgblt cfbfillrect atl1c
> [18682.257659]
> [18682.257685] Pid: 14069, comm: xdg-screensaver Not tainted 2.6.39+ #4 LENOVO 0876                            /Base Board Product Name
> [18682.257845] RIP: 0010:[<ffffffff811d6503>]  [<ffffffff811d6503>] __elv_add_request+0x1e3/0x270
> [18682.257964] RSP: 0018:ffff88009b3a19e8  EFLAGS: 00010006
> [18682.258056] RAX: 0000000000000000 RBX: ffff880131559020 RCX: 0000000000000001
> [18682.258152] RDX: 0000000000000001 RSI: ffff880131559020 RDI: ffff8801315f77d0
> [18682.258248] RBP: ffff88009b3a1a08 R08: ffffffff811e1000 R09: ffff8801315f77d0
> [18682.258343] R10: ffff8800b5085e40 R11: ffff8800b5085e40 R12: ffff8801315f77d0
> [18682.258437] R13: 0000000000000001 R14: 0000000000000001 R15: ffff8800b5085e40
> [18682.258529] FS:  0000000000000000(0000) GS:ffff880137c80000(0000) knlGS:0000000000000000
> [18682.258636] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [18682.258712] CR2: 0000000000000008 CR3: 0000000001a03000 CR4: 00000000000006e0
> [18682.258807] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [18682.258898] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> [18682.258994] Process xdg-screensaver (pid: 14069, threadinfo ffff88009b3a0000, task ffff8800aff096b0)
> [18682.259112] Stack:
> [18682.259140]  ffff8801315f77d0 ffff880131559020 0000000000000001 ffff88009b3a1c48
> [18682.259249]  ffff88009b3a1a38 ffffffff811e10a0 0000000000000000 ffff88009b3a1a48
> [18682.259354]  ffff880131559020 0000000000000000 ffff88009b3a1af8 ffffffff811e118e
> [18682.259460] Call Trace:
> [18682.259504]  [<ffffffff811e10a0>] blk_execute_rq_nowait+0x60/0xc0
> [18682.259587]  [<ffffffff811e118e>] blk_execute_rq+0x8e/0x130
> [18682.259668]  [<ffffffff812db5bc>] scsi_execute+0xfc/0x160
> [18682.259742]  [<ffffffff812dc18f>] scsi_execute_req+0xbf/0x130
> [18682.259821]  [<ffffffff812d5c71>] ioctl_internal_command.clone.4+0x61/0x1b0
> [18682.259914]  [<ffffffff812d5e3e>] scsi_set_medium_removal+0x7e/0xb0
> [18682.260000]  [<ffffffff812ecfa0>] sr_lock_door+0x20/0x30
> [18682.260075]  [<ffffffff812f9da7>] cdrom_release+0x147/0x270
> [18682.260153]  [<ffffffff812ebac8>] sr_block_release+0x38/0x60
> [18682.260233]  [<ffffffff811730ac>] __blkdev_put+0x16c/0x1b0
> [18682.260308]  [<ffffffff81173129>] blkdev_put+0x39/0x150
> [18682.260379]  [<ffffffff81173264>] blkdev_close+0x24/0x30
> [18682.260455]  [<ffffffff81140fba>] fput+0xea/0x220
> [18682.260521]  [<ffffffff8113d396>] filp_close+0x66/0x90
> [18682.260592]  [<ffffffff8105c117>] put_files_struct+0x87/0xf0
> [18682.260668]  [<ffffffff8105c244>] exit_files+0x54/0x70
> [18682.264275]  [<ffffffff8105c72b>] do_exit+0x16b/0x860
> [18682.267802]  [<ffffffff811f6c2a>] ? trace_hardirqs_off_thunk+0x3a/0x6c
> [18682.271512]  [<ffffffff8105d0e8>] do_group_exit+0x58/0xd0
> [18682.276948]  [<ffffffff8105d177>] sys_exit_group+0x17/0x20
> [18682.281121]  [<ffffffff81485d42>] system_call_fastpath+0x16/0x1b
> [18682.284603] Code: ff ff e9 90 fe ff ff 90 81 4b 40 00 08 00 00 48 89 df e8 c1 93 00 00 eb c1 0f 1f 80 00 00 00 00 81 4b 40 00 08 00 00 49 8b 04 24
> [18682.284903]  89 58 08 48 89 03 4c 89 63 08 49 89 1c 24 eb 9e 0f 1f 40 00
> [18682.290727] RIP  [<ffffffff811d6503>] __elv_add_request+0x1e3/0x270
> [18682.293189]  RSP <ffff88009b3a19e8>
> [18682.296075] CR2: 0000000000000008
> [18682.358582] ---[ end trace 82dd699fdeb50b72 ]---

-- 
Jens Axboe

[PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Tue, 24 May 2011, Jens Axboe wrote:

> On 2011-05-24 06:29, Parag Warudkar wrote:
> > 
> > External DVD drive - connected when suspended, removed before resume.
> > Results in NULL pointer dereference in __blk_add_request on resume.
> > 
> > *ffffffff811d6503:      48 89 58 08             mov    %rbx,0x8(%rax) |
> > %ebx = ffff880131559020 <--- faulting instruction
> > 
> > 48 89 58 08 appears only in list_add :
> > 
> > static inline void list_add(struct list_head *new, struct list_head *head)
> > {
> >         __list_add(new, head, head->next);
> > ffffffff81ac012c:       49 8b 04 24             mov    (%r12),%rax
> > #ifndef CONFIG_DEBUG_LIST
> > static inline void __list_add(struct list_head *new,
> >                               struct list_head *prev,
> >                               struct list_head *next)
> > {
> >         next->prev = new;
> > ffffffff81ac0130:       48 89 58 08             mov    %rbx,0x8(%rax)
> > 
> > AFAICS list_add is only called from one place in __elv_add_request :
> > 
> >        switch (where) {
> >         case ELEVATOR_INSERT_REQUEUE:
> >         case ELEVATOR_INSERT_FRONT:
> >                 rq->cmd_flags |= REQ_SOFTBARRIER;
> >               **  list_add(&rq->queuelist, &q->queue_head);
> >                 break;
> > 
> > Now, where is the patch? :)
> 
> You forgot to attach it?
> 
> This is clearly q == NULL [snip]

OK, I think this patch should do the trick.

Signed-off-by: Parag Warudkar <parag.lkml@gmail.com>
Reported-and-tested-by: Parag Warudkar <parag.lkml@gmail.com>
 
Check for device deletion before sending it a scsi command. This fixes an 
OOPS I was seeing during resume when the external dvd drive was removed 
while suspended.

diff --git a/drivers/scsi/scsi_ioctl.c b/drivers/scsi/scsi_ioctl.c
index d9564fb..cc4edbf 100644
--- a/drivers/scsi/scsi_ioctl.c
+++ b/drivers/scsi/scsi_ioctl.c
@@ -136,7 +136,7 @@ int scsi_set_medium_removal(struct scsi_device *sdev, char state)
 	char scsi_cmd[MAX_COMMAND_SIZE];
 	int ret;
 
-	if (!sdev->removable || !sdev->lockable)
+	if (!sdev->removable || !sdev->lockable || sdev->sdev_state == SDEV_DEL)
 	       return 0;
 
 	scsi_cmd[0] = ALLOW_MEDIUM_REMOVAL;

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Jens Axboe]

On 2011-05-25 03:41, Parag Warudkar wrote:
> 
> 
> On Tue, 24 May 2011, Jens Axboe wrote:
> 
>> On 2011-05-24 06:29, Parag Warudkar wrote:
>>>
>>> External DVD drive - connected when suspended, removed before resume.
>>> Results in NULL pointer dereference in __blk_add_request on resume.
>>>
>>> *ffffffff811d6503:      48 89 58 08             mov    %rbx,0x8(%rax) |
>>> %ebx = ffff880131559020 <--- faulting instruction
>>>
>>> 48 89 58 08 appears only in list_add :
>>>
>>> static inline void list_add(struct list_head *new, struct list_head *head)
>>> {
>>>         __list_add(new, head, head->next);
>>> ffffffff81ac012c:       49 8b 04 24             mov    (%r12),%rax
>>> #ifndef CONFIG_DEBUG_LIST
>>> static inline void __list_add(struct list_head *new,
>>>                               struct list_head *prev,
>>>                               struct list_head *next)
>>> {
>>>         next->prev = new;
>>> ffffffff81ac0130:       48 89 58 08             mov    %rbx,0x8(%rax)
>>>
>>> AFAICS list_add is only called from one place in __elv_add_request :
>>>
>>>        switch (where) {
>>>         case ELEVATOR_INSERT_REQUEUE:
>>>         case ELEVATOR_INSERT_FRONT:
>>>                 rq->cmd_flags |= REQ_SOFTBARRIER;
>>>               **  list_add(&rq->queuelist, &q->queue_head);
>>>                 break;
>>>
>>> Now, where is the patch? :)
>>
>> You forgot to attach it?
>>
>> This is clearly q == NULL [snip]
> 
> OK, I think this patch should do the trick.
> 
> Signed-off-by: Parag Warudkar <parag.lkml@gmail.com>
> Reported-and-tested-by: Parag Warudkar <parag.lkml@gmail.com>
>  
> Check for device deletion before sending it a scsi command. This fixes an 
> OOPS I was seeing during resume when the external dvd drive was removed 
> while suspended.
> 
> diff --git a/drivers/scsi/scsi_ioctl.c b/drivers/scsi/scsi_ioctl.c
> index d9564fb..cc4edbf 100644
> --- a/drivers/scsi/scsi_ioctl.c
> +++ b/drivers/scsi/scsi_ioctl.c
> @@ -136,7 +136,7 @@ int scsi_set_medium_removal(struct scsi_device *sdev, char state)
>  	char scsi_cmd[MAX_COMMAND_SIZE];
>  	int ret;
>  
> -	if (!sdev->removable || !sdev->lockable)
> +	if (!sdev->removable || !sdev->lockable || sdev->sdev_state == SDEV_DEL)
>  	       return 0;
>  
>  	scsi_cmd[0] = ALLOW_MEDIUM_REMOVAL;

While this will fix your particular oops, I don't think it's quite
right. It's fixing one particular piece of fall out from attempting to
talk to a removed device, it's not necessarily fixing the full class of
them. The other checks in scsi_set_medium_removal() aren't related to a
changing state of the device, they are capability checks.

-- 
Jens Axboe

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Wed, 25 May 2011, Jens Axboe wrote:

> While this will fix your particular oops, I don't think it's quite
> right. It's fixing one particular piece of fall out from attempting to
> talk to a removed device, it's not necessarily fixing the full class of
> them. The other checks in scsi_set_medium_removal() aren't related to a
> changing state of the device, they are capability checks.

Below patch pushes the check down to ioctl functions and hopefully should 
cover more ioctl-on-gone-device cases by returning -ENXIO if an attempt 
was made to submit request to a non-running device.

With this patch in place - instead of oopsing I now get a proper I/O error 
on resume.

AFAICT from my limited SCSI layer knowledge - these seem to be the right 
places to check. Would be interested in knowing if there are better/more 
complete ways to handle this but if they are going to take time IMHO it 
certainly doesn't hurt to keep the below patch in.

Signed-off-by: Parag Warudkar <parag.lkml@gmail.com>

diff --git a/drivers/scsi/scsi_ioctl.c b/drivers/scsi/scsi_ioctl.c
index d9564fb..c32cade 100644
--- a/drivers/scsi/scsi_ioctl.c
+++ b/drivers/scsi/scsi_ioctl.c
@@ -91,6 +91,10 @@ static int ioctl_internal_command(struct scsi_device *sdev, char *cmd,
 	int result;
 	struct scsi_sense_hdr sshdr;
 
+	if (!sdev || sdev->sdev_state == SDEV_DEL 
+		|| sdev->sdev_state > SDEV_QUIESCE)
+		return -ENXIO;
+
 	SCSI_LOG_IOCTL(1, printk("Trying ioctl with scsi command %d\n", *cmd));
 
 	result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL, 0,
@@ -195,8 +199,9 @@ int scsi_ioctl(struct scsi_device *sdev, int cmd, void __user *arg)
 {
 	char scsi_cmd[MAX_COMMAND_SIZE];
 
-	/* No idea how this happens.... */
-	if (!sdev)
+	/* No idea how !sdev happens.... */
+	if (!sdev || sdev->sdev_state == SDEV_DEL 
+		|| sdev->sdev_state > SDEV_QUIESCE)
 		return -ENXIO;
 
 	/*
@@ -288,6 +293,10 @@ int scsi_nonblockable_ioctl(struct scsi_device *sdev, int cmd,
 {
 	int val, result;
 
+	if (!sdev || sdev->sdev_state == SDEV_DEL 
+		|| sdev->sdev_state > SDEV_QUIESCE) 
+		return -ENXIO;
+
 	/* The first set of iocts may be executed even if we're doing
 	 * error processing, as long as the device was opened
 	 * non-blocking */

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 11:44 AM, Parag Warudkar <parag.lkml@gmail.com> wrote:
>
> Below patch pushes the check down to ioctl functions and hopefully should
> cover more ioctl-on-gone-device cases by returning -ENXIO if an attempt
> was made to submit request to a non-running device.

Can we please not duplicate complicated logic like that?

IOW, just make a helper function for it.

That said, isn't this all *exactly* what scsi_prep_state_check() is
supposed to check for? Why isn't that called, or if called, why isn't
it doing the right thing?

                     Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Jens Axboe]

On 2011-05-25 20:55, Linus Torvalds wrote:
> On Wed, May 25, 2011 at 11:44 AM, Parag Warudkar <parag.lkml@gmail.com> wrote:
>>
>> Below patch pushes the check down to ioctl functions and hopefully should
>> cover more ioctl-on-gone-device cases by returning -ENXIO if an attempt
>> was made to submit request to a non-running device.
> 
> Can we please not duplicate complicated logic like that?
> 
> IOW, just make a helper function for it.
> 
> That said, isn't this all *exactly* what scsi_prep_state_check() is
> supposed to check for? Why isn't that called, or if called, why isn't
> it doing the right thing?

This is before you get that far, it's actually oopsing on inserting the
request on sdev->sdev_queue that is now NULL. The prep state checking
happens when sr/sd pulls the request off the queue for processing.

-- 
Jens Axboe

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 12:02 PM, Jens Axboe <jaxboe@fusionio.com> wrote:
>
> This is before you get that far, it's actually oopsing on inserting the
> request on sdev->sdev_queue that is now NULL. The prep state checking
> happens when sr/sd pulls the request off the queue for processing.

Ok, please just add a "sdev_alive(sdev)" helper that checks for sdev
&& sdev->sdev_queue. Apparently the issue isn't "this device is
SDEV_DEL, so don't send commands". Apparently the issue is literally
"don't oops".

Or maybe the prep state checking could be moved earlier. It seems
stupid to have a "can I do this command" function that is run too late
to actually catch the problems..

                    Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Jens Axboe]

On 2011-05-25 21:13, Linus Torvalds wrote:
> On Wed, May 25, 2011 at 12:02 PM, Jens Axboe <jaxboe@fusionio.com> wrote:
>>
>> This is before you get that far, it's actually oopsing on inserting the
>> request on sdev->sdev_queue that is now NULL. The prep state checking
>> happens when sr/sd pulls the request off the queue for processing.
> 
> Ok, please just add a "sdev_alive(sdev)" helper that checks for sdev
> && sdev->sdev_queue. Apparently the issue isn't "this device is
> SDEV_DEL, so don't send commands". Apparently the issue is literally
> "don't oops".

Yep, will do.

> Or maybe the prep state checking could be moved earlier. It seems
> stupid to have a "can I do this command" function that is run too late
> to actually catch the problems..

I don't think we can move it earlier, we essentially have to do the
check at both ends. The "normal" IO path would see that the queue is
dead and error the IO, but this is an internal setup that sets up the
request and then adds it to the stored queue pointer. So it needs to
check this state one way or the other. I think the above fix with the
sdev_alive() will be good enough.

-- 
Jens Axboe

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Wed, 25 May 2011, Jens Axboe wrote:

> I don't think we can move it earlier, we essentially have to do the
> check at both ends. The "normal" IO path would see that the queue is
> dead and error the IO, but this is an internal setup that sets up the
> request and then adds it to the stored queue pointer. So it needs to
> check this state one way or the other. I think the above fix with the
> sdev_alive() will be good enough.
> 

If I understood it right we need checks in both places (kind of makes 
sense as the device could be gone *after* we checked in ioctl function and 
before the request queue was dereferenced). So here is the ioctl check 
with a helper function for state check that Linus asked for.

Signed-off-by: Parag Warudkar <parag.lkml@gmail.com>

diff --git a/drivers/scsi/scsi_ioctl.c b/drivers/scsi/scsi_ioctl.c
index d9564fb..8615e63 100644
--- a/drivers/scsi/scsi_ioctl.c
+++ b/drivers/scsi/scsi_ioctl.c
@@ -30,6 +30,13 @@
 
 #define MAX_BUF PAGE_SIZE
 
+static inline int sdev_early_check(struct scsi_device *sdev)
+{
+	if (!sdev || sdev->sdev_state == SDEV_DEL
+		|| sdev->sdev_state > SDEV_QUIESCE)
+		return -ENXIO;
+	return 0;
+}
 /**
  * ioctl_probe  --  return host identification
  * @host:	host to identify
@@ -91,6 +98,10 @@ static int ioctl_internal_command(struct scsi_device *sdev, char *cmd,
 	int result;
 	struct scsi_sense_hdr sshdr;
 
+	result = sdev_early_check(sdev);
+	if (result)
+		return result;
+
 	SCSI_LOG_IOCTL(1, printk("Trying ioctl with scsi command %d\n", *cmd));
 
 	result = scsi_execute_req(sdev, cmd, DMA_NONE, NULL, 0,
@@ -194,10 +205,11 @@ static int scsi_ioctl_get_pci(struct scsi_device *sdev, void __user *arg)
 int scsi_ioctl(struct scsi_device *sdev, int cmd, void __user *arg)
 {
 	char scsi_cmd[MAX_COMMAND_SIZE];
+	int result;
 
-	/* No idea how this happens.... */
-	if (!sdev)
-		return -ENXIO;
+	result = sdev_early_check(sdev);
+	if (result)
+		return result;
 
 	/*
 	 * If we are in the middle of error recovery, don't let anyone
@@ -288,6 +300,10 @@ int scsi_nonblockable_ioctl(struct scsi_device *sdev, int cmd,
 {
 	int val, result;
 
+	result = sdev_early_check(sdev);
+	if (result)
+		return result;
+
 	/* The first set of iocts may be executed even if we're doing
 	 * error processing, as long as the device was opened
 	 * non-blocking */

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 12:52 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
>
> +static inline int sdev_early_check(struct scsi_device *sdev)
> +{
> +       if (!sdev || sdev->sdev_state == SDEV_DEL
> +               || sdev->sdev_state > SDEV_QUIESCE)
> +               return -ENXIO;
> +       return 0;
> +}

Can somebody explain why it's those states, and nothing else?

Quite frankly, if it's about "don't oops on sdev->queue not existing",
then test for that. Not for some random and uncommented list of
states.

                          Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

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



On Wed, 25 May 2011, Linus Torvalds wrote:

> On Wed, May 25, 2011 at 12:52 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
> >
> > +static inline int sdev_early_check(struct scsi_device *sdev)
> > +{
> > +       if (!sdev || sdev->sdev_state == SDEV_DEL
> > +               || sdev->sdev_state > SDEV_QUIESCE)
> > +               return -ENXIO;
> > +       return 0;
> > +}
> 
> Can somebody explain why it's those states, and nothing else?
> 
> Quite frankly, if it's about "don't oops on sdev->queue not existing",
> then test for that. Not for some random and uncommented list of
> states.

List of states and what commands if any are accepeted for each state are 
explained in scsi_device.h enum definition of scsi_device_state : 

enum scsi_device_state {
        SDEV_CREATED = 1,       /* device created but not added to sysfs
                                 * Only internal commands allowed (for 
inq) */
        SDEV_RUNNING,           /* device properly configured
                                 * All commands allowed */
        SDEV_CANCEL,            /* beginning to delete device
                                 * Only error handler commands allowed */
        SDEV_DEL,               /* device deleted 
                                 * no commands allowed */
        SDEV_QUIESCE,           /* Device quiescent.  No block commands
                                 * will be accepted, only specials (which
                                 * originate in the mid-layer) */
        SDEV_OFFLINE,           /* Device offlined (by error handling or
                                 * user request */
        SDEV_BLOCK,             /* Device blocked by scsi lld.  No
                                 * scsi commands from user or midlayer
                                 * should be issued to the scsi
                                 * lld. */
        SDEV_CREATED_BLOCK,     /* same as above but for created devices 
*/
};

In this case - we check for cases where no commands are allowed and reject 
those right away, leaving prep_state_check to do filtering at lower level 
for which commands are allowed and which are not as the state permits.
 
Parag

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 1:18 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
>        SDEV_OFFLINE,           /* Device offlined (by error handling or
>                                 * user request */

So how do you fix the error or online it again? No chance it should
have commands passed to it to do that?

I don't know. My point is that I don't see why we should look at the
state at this point at all. We do that _later_.

                            Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

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



On Wed, 25 May 2011, Linus Torvalds wrote:

> On Wed, May 25, 2011 at 1:18 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
> >        SDEV_OFFLINE,           /* Device offlined (by error handling or
> >                                 * user request */
> 
> So how do you fix the error or online it again? No chance it should
> have commands passed to it to do that?

Yeah - that makes sense. By that logic, looks like we can only disallow 
for SDEV_DEL (if we decide to do that check here).

> I don't know. My point is that I don't see why we should look at the
> state at this point at all. We do that _later_.

If we can do it later, well and good. I just didn't think it would hurt to 
check upfront in ioctl if we are dealing with a dead device.

Parag

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[James Bottomley]

On Wed, 2011-05-25 at 16:42 -0400, Parag Warudkar wrote:
> Yeah - that makes sense. By that logic, looks like we can only disallow 
> for SDEV_DEL (if we decide to do that check here).

I don't think this is the root cause.  I think q is non-NULL but has
already been released, so we're just getting a NULL deref on the actual
list head.

Does this fix it?  It adds the refcounting at approximately the correct
places.  Of course, we'll now be trying elevator operations on an extant
queue but one whose elevator functions have been destroyed, so there are
probably additional state guards to place.

James

---

diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
index 58584dc..44e8ca3 100644
--- a/drivers/scsi/scsi_scan.c
+++ b/drivers/scsi/scsi_scan.c
@@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
 		kfree(sdev);
 		goto out;
 	}
-
+	blk_get_queue(sdev->request_queue);
 	sdev->request_queue->queuedata = sdev;
 	scsi_adjust_queue_depth(sdev, 0, sdev->host->cmd_per_lun);
 
diff --git a/drivers/scsi/scsi_sysfs.c b/drivers/scsi/scsi_sysfs.c
index e639125..e0bd3f7 100644
--- a/drivers/scsi/scsi_sysfs.c
+++ b/drivers/scsi/scsi_sysfs.c
@@ -322,6 +322,7 @@ static void scsi_device_dev_release_usercontext(struct work_struct *work)
 		kfree(evt);
 	}
 
+	blk_put_queue(sdev->request_queue);
 	/* NULL queue means the device can't be used */
 	sdev->request_queue = NULL;
 

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Wed, May 25, 2011 at 4:52 PM, James Bottomley
<James.Bottomley@hansenpartnership.com> wrote:
> On Wed, 2011-05-25 at 16:42 -0400, Parag Warudkar wrote:
>> Yeah - that makes sense. By that logic, looks like we can only disallow
>> for SDEV_DEL (if we decide to do that check here).
>
> I don't think this is the root cause.  I think q is non-NULL but has
> already been released, so we're just getting a NULL deref on the actual
> list head.
>
> Does this fix it?  It adds the refcounting at approximately the correct
> places.  Of course, we'll now be trying elevator operations on an extant
> queue but one whose elevator functions have been destroyed, so there are
> probably additional state guards to place.

[ Resend with URL - I got a bounce back from vger for attaching the OOPS JPEG ]

It doesn't seem to help. Machine locked up and I was dropped to text
console. I could only capture the oops by a camera.

OOPS available at below URLs [*]

Parag

[*] https://picasaweb.google.com/lh/photo/yccmqaz3xwumwjvecb-b0pTdDOYIfFRksMrZBIo-Inw?feat=directlink

[*] https://picasaweb.google.com/lh/photo/Lim6d3b8p7Lj4D3nHmkbFJTdDOYIfFRksMrZBIo-Inw?feat=directlink

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 4:00 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
>
> It doesn't seem to help. Machine locked up and I was dropped to text
> console. I could only capture the oops by a camera.

Hmm. That's a different oops. It is now in scsi_prep_state_check().

At the beginning of it too. You can't see the "Code: " line in the
pictures, but the only dereference I see there is "sdev" itself being
NULL. And %cr2 is 0x640, which would seem to agree (the 'sdev'
structure is absolutely disgustingly big, and sdev->sdev_state is
indeed at an offset in that region.

That 'sdev' comes from scsi_prep_fn() doing

    struct scsi_device *sdev = q->queuedata;

is that queuedata perhaps cleared even if the queue itself stays
around due to refcounts?

                       Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Wed, 25 May 2011, Linus Torvalds wrote:

> On Wed, May 25, 2011 at 4:00 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
> >
> > It doesn't seem to help. Machine locked up and I was dropped to text
> > console. I could only capture the oops by a camera.
> 
> Hmm. That's a different oops. It is now in scsi_prep_state_check().

Different at top but the call trace upto scsi_set_medium_removal is the 
same.

And since now we are upping the refcnt we keep the request queue around it 
was kind of expected that it won't oops on the request queue.

> 
> At the beginning of it too. You can't see the "Code: " line in the
> pictures, but the only dereference I see there is "sdev" itself being
> NULL. And %cr2 is 0x640, which would seem to agree (the 'sdev'
> structure is absolutely disgustingly big, and sdev->sdev_state is
> indeed at an offset in that region.
> 
> That 'sdev' comes from scsi_prep_fn() doing
> 
>     struct scsi_device *sdev = q->queuedata;
> 
> is that queuedata perhaps cleared even if the queue itself stays
> around due to refcounts?


So now the issue is with scsi_device refcnt?

Parag

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 4:45 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
>
> So now the issue is with scsi_device refcnt?

No, I'd guess that the problem is just that __scsi_remove_device()
sets queuedata to NULL. Afaik, both sdev and the queue actually stay
around.

That said, I don't have very high opinions of some of the SCSI code.
And that's me being polite. The thing is a overcomplicated mess of
indirection and pointers back-and-forth. The refcounting is crazy
and/or impossible, since the pointers really do go back-and-forth.

                       Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Linus Torvalds]

On Wed, May 25, 2011 at 5:35 PM, James Bottomley
<James.Bottomley@hansenpartnership.com> wrote:
>
> Jens, can you look at this, please ... would you prefer a separate DEAD
> test instead?  Incidentally, this is in addition to the other DEAD test
> you still haven't applied ...

Ugh.

Can you please just always set STOPPED at the same time you set DEAD?

                        Linus

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[James Bottomley]

On Wed, 2011-05-25 at 18:01 -0700, Linus Torvalds wrote:
> On Wed, May 25, 2011 at 5:35 PM, James Bottomley
> <James.Bottomley@hansenpartnership.com> wrote: > > Jens, can you look
> at this, please ... would you prefer a separate DEAD > test instead? 
> Incidentally, this is in addition to the other DEAD test > you still
> haven't applied ...
> 
> Ugh.
> 
> Can you please just always set STOPPED at the same time you set DEAD?

Well, Jens wondered the same thing in this thread:

http://marc.info/?l=linux-scsi&m=130632292705404

It's just an RFC patch to see if I can fix an oops ... how it's
ultimately implemented will be up to Jens.

James

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Wed, 25 May 2011, James Bottomley wrote:

> so, hopefully, applying this on top will now fix it.
> 

Yeah seems to be OK with that patch on top of the previous one - thanks.

Now I am left with 2 more unrelated suspend/resume issues to report.


Parag

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[James Bottomley]

On Wed, 2011-05-25 at 15:52 -0500, James Bottomley wrote:
> On Wed, 2011-05-25 at 16:42 -0400, Parag Warudkar wrote:
> > Yeah - that makes sense. By that logic, looks like we can only disallow 
> > for SDEV_DEL (if we decide to do that check here).
> 
> I don't think this is the root cause.  I think q is non-NULL but has
> already been released, so we're just getting a NULL deref on the actual
> list head.
> 
> Does this fix it?  It adds the refcounting at approximately the correct
> places.  Of course, we'll now be trying elevator operations on an extant
> queue but one whose elevator functions have been destroyed, so there are
> probably additional state guards to place.
> 
> James
> 
> ---
> 
> diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
> index 58584dc..44e8ca3 100644
> --- a/drivers/scsi/scsi_scan.c
> +++ b/drivers/scsi/scsi_scan.c
> @@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
>  		kfree(sdev);
>  		goto out;
>  	}
> -
> +	blk_get_queue(sdev->request_queue);

Apparently we can't do this because blk_[put|get]_queue aren't exported
for use in modules (and SCSI can be modular), so this caused a build
failure in linux-next.

James

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Jens Axboe]

On 2011-05-27 05:53, James Bottomley wrote:
> On Wed, 2011-05-25 at 15:52 -0500, James Bottomley wrote:
>> On Wed, 2011-05-25 at 16:42 -0400, Parag Warudkar wrote:
>>> Yeah - that makes sense. By that logic, looks like we can only disallow 
>>> for SDEV_DEL (if we decide to do that check here).
>>
>> I don't think this is the root cause.  I think q is non-NULL but has
>> already been released, so we're just getting a NULL deref on the actual
>> list head.
>>
>> Does this fix it?  It adds the refcounting at approximately the correct
>> places.  Of course, we'll now be trying elevator operations on an extant
>> queue but one whose elevator functions have been destroyed, so there are
>> probably additional state guards to place.
>>
>> James
>>
>> ---
>>
>> diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
>> index 58584dc..44e8ca3 100644
>> --- a/drivers/scsi/scsi_scan.c
>> +++ b/drivers/scsi/scsi_scan.c
>> @@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
>>  		kfree(sdev);
>>  		goto out;
>>  	}
>> -
>> +	blk_get_queue(sdev->request_queue);
> 
> Apparently we can't do this because blk_[put|get]_queue aren't exported
> for use in modules (and SCSI can be modular), so this caused a build
> failure in linux-next.

I'll just export them.

-- 
Jens Axboe

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[James Bottomley]

On Fri, 2011-05-27 at 07:43 +0200, Jens Axboe wrote: 
> On 2011-05-27 05:53, James Bottomley wrote:
> > On Wed, 2011-05-25 at 15:52 -0500, James Bottomley wrote:
> >> On Wed, 2011-05-25 at 16:42 -0400, Parag Warudkar wrote:
> >>> Yeah - that makes sense. By that logic, looks like we can only disallow 
> >>> for SDEV_DEL (if we decide to do that check here).
> >>
> >> I don't think this is the root cause.  I think q is non-NULL but has
> >> already been released, so we're just getting a NULL deref on the actual
> >> list head.
> >>
> >> Does this fix it?  It adds the refcounting at approximately the correct
> >> places.  Of course, we'll now be trying elevator operations on an extant
> >> queue but one whose elevator functions have been destroyed, so there are
> >> probably additional state guards to place.
> >>
> >> James
> >>
> >> ---
> >>
> >> diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
> >> index 58584dc..44e8ca3 100644
> >> --- a/drivers/scsi/scsi_scan.c
> >> +++ b/drivers/scsi/scsi_scan.c
> >> @@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
> >>  		kfree(sdev);
> >>  		goto out;
> >>  	}
> >> -
> >> +	blk_get_queue(sdev->request_queue);
> > 
> > Apparently we can't do this because blk_[put|get]_queue aren't exported
> > for use in modules (and SCSI can be modular), so this caused a build
> > failure in linux-next.
> 
> I'll just export them.

OK, if you're fine with that, how does this patch look?

I can take it through my rc-fixes tree (with your ack), since I'm a bit
late on the merge window now.

James

---

From: James Bottomley <James.Bottomley@HansenPartnership.com>
Subject: [PATCH] [SCSI] Fix oops caused by queue refcounting failure

In certain circumstances, we can get an oops from a torn down device.
Most notably this is from CD roms trying to call scsi_ioctl.  The root
cause of the problem is the fact that after scsi_remove_device() has
been called, the queue is fully torn down.  This is actually wrong
since the queue can be used until the sdev release function is called.
Therefore, we add an extra reference to the queue which is released in
sdev->release, so the queue always exists.

Also export blk_queue_get/blk_queue_put for the refcounting.

Reported-by: Parag Warudkar <parag.lkml@gmail.com>
Signed-off-by: James Bottomley <jbottomley@parallels.com>

diff --git a/block/blk-core.c b/block/blk-core.c
index 3fe00a1..1aa776c 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -345,6 +345,7 @@ void blk_put_queue(struct request_queue *q)
 {
 	kobject_put(&q->kobj);
 }
+EXPORT_SYMBOL_GPL(blk_put_queue);
 
 /*
  * Note: If a driver supplied the queue lock, it should not zap that lock
@@ -566,6 +567,7 @@ int blk_get_queue(struct request_queue *q)
 
 	return 1;
 }
+EXPORT_SYMBOL_GPL(blk_get_queue);
 
 static inline void blk_free_request(struct request_queue *q, struct request *rq)
 {
diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
index 58584dc..44e8ca3 100644
--- a/drivers/scsi/scsi_scan.c
+++ b/drivers/scsi/scsi_scan.c
@@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
 		kfree(sdev);
 		goto out;
 	}
-
+	blk_get_queue(sdev->request_queue);
 	sdev->request_queue->queuedata = sdev;
 	scsi_adjust_queue_depth(sdev, 0, sdev->host->cmd_per_lun);
 
diff --git a/drivers/scsi/scsi_sysfs.c b/drivers/scsi/scsi_sysfs.c
index e639125..e0bd3f7 100644
--- a/drivers/scsi/scsi_sysfs.c
+++ b/drivers/scsi/scsi_sysfs.c
@@ -322,6 +322,7 @@ static void scsi_device_dev_release_usercontext(struct work_struct *work)
 		kfree(evt);
 	}
 
+	blk_put_queue(sdev->request_queue);
 	/* NULL queue means the device can't be used */
 	sdev->request_queue = NULL;
 

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Jens Axboe]

On 2011-05-27 22:21, James Bottomley wrote:
> On Fri, 2011-05-27 at 07:43 +0200, Jens Axboe wrote: 
>> On 2011-05-27 05:53, James Bottomley wrote:
>>> On Wed, 2011-05-25 at 15:52 -0500, James Bottomley wrote:
>>>> On Wed, 2011-05-25 at 16:42 -0400, Parag Warudkar wrote:
>>>>> Yeah - that makes sense. By that logic, looks like we can only disallow 
>>>>> for SDEV_DEL (if we decide to do that check here).
>>>>
>>>> I don't think this is the root cause.  I think q is non-NULL but has
>>>> already been released, so we're just getting a NULL deref on the actual
>>>> list head.
>>>>
>>>> Does this fix it?  It adds the refcounting at approximately the correct
>>>> places.  Of course, we'll now be trying elevator operations on an extant
>>>> queue but one whose elevator functions have been destroyed, so there are
>>>> probably additional state guards to place.
>>>>
>>>> James
>>>>
>>>> ---
>>>>
>>>> diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
>>>> index 58584dc..44e8ca3 100644
>>>> --- a/drivers/scsi/scsi_scan.c
>>>> +++ b/drivers/scsi/scsi_scan.c
>>>> @@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
>>>>  		kfree(sdev);
>>>>  		goto out;
>>>>  	}
>>>> -
>>>> +	blk_get_queue(sdev->request_queue);
>>>
>>> Apparently we can't do this because blk_[put|get]_queue aren't exported
>>> for use in modules (and SCSI can be modular), so this caused a build
>>> failure in linux-next.
>>
>> I'll just export them.
> 
> OK, if you're fine with that, how does this patch look?

Outdated :-)

I already merged the export addition:

commit d86e0e83b32bc84600adb0b6ea1fce389b266682
Author: Jens Axboe <jaxboe@fusionio.com>
Date:   Fri May 27 07:44:43 2011 +0200

    block: export blk_{get,put}_queue()

> I can take it through my rc-fixes tree (with your ack), since I'm a bit
> late on the merge window now.

Only the SCSI bit remains, so add at will. You can add my acked-by to
that standalone, if you wish.

-- 
Jens Axboe

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Torsten Hilbrich]

[-- Attachment #1: Type: text/plain, Size: 4506 bytes --]

Am 27.05.2011 22:21, schrieb James Bottomley:

> diff --git a/drivers/scsi/scsi_scan.c b/drivers/scsi/scsi_scan.c
> index 58584dc..44e8ca3 100644
> --- a/drivers/scsi/scsi_scan.c
> +++ b/drivers/scsi/scsi_scan.c
> @@ -297,7 +297,7 @@ static struct scsi_device *scsi_alloc_sdev(struct scsi_target *starget,
>  		kfree(sdev);
>  		goto out;
>  	}
> -
> +	blk_get_queue(sdev->request_queue);
>  	sdev->request_queue->queuedata = sdev;
>  	scsi_adjust_queue_depth(sdev, 0, sdev->host->cmd_per_lun);
>  
> diff --git a/drivers/scsi/scsi_sysfs.c b/drivers/scsi/scsi_sysfs.c
> index e639125..e0bd3f7 100644
> --- a/drivers/scsi/scsi_sysfs.c
> +++ b/drivers/scsi/scsi_sysfs.c
> @@ -322,6 +322,7 @@ static void scsi_device_dev_release_usercontext(struct work_struct *work)
>  		kfree(evt);
>  	}
>  
> +	blk_put_queue(sdev->request_queue);
>  	/* NULL queue means the device can't be used */
>  	sdev->request_queue = NULL;

I did some testing with this patch (using 3.0rc2 for reproducing it upstream, but the same behaviour
with 2.6.39 and e73e079bf128d68284efedeba1fbbc18d78610f9 applied).

ext2 and ext3 FS on the USB sticks are working fine, however I get the following oops when performing
the same test with the CDROM part of a sandisk cruzer:

general protection fault: 0000 [#1] SMP 
CPU 1 
Modules linked in:

Pid: 1978, comm: umount Not tainted 3.0.0-rc2 #41 LENOVO 20077KG/20077KG
RIP: 0010:[<ffffffff81244590>]  [<ffffffff81244590>] elv_may_queue+0x10/0x20
RSP: 0018:ffff88007be17aa8  EFLAGS: 00010097
RAX: 6b6b6b6b6b6b6b6b RBX: ffff88007bc628c0 RCX: 0000000000000010
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88007bc628c0
RBP: ffff88007be17aa8 R08: 0000000000000000 R09: ffff88007bc6f340
R10: ffff88007be17d08 R11: ffff88007be061c8 R12: 0000000000000000
R13: 0000000000000001 R14: 0000000000000000 R15: ffff88007bc6f340
FS:  00007f5f4ba89740(0000) GS:ffff88007fd00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5f4b12a355 CR3: 000000007be2f000 CR4: 00000000000006a0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process umount (pid: 1978, threadinfo ffff88007be16000, task ffff88007cceb7b0)
Stack:
 ffff88007be17b08 ffffffff8124b3ce ffff88007d19f5f8 ffff88007bd90188
 ffff880000000010 ffffffff810f52a6 ffff88007be17b08 ffff88007bc628c0
 0000000000000000 0000000000000010 ffff88007be17d08 ffff88007bc6f340
Call Trace:
 [<ffffffff8124b3ce>] get_request+0x3e/0x380
 [<ffffffff810f52a6>] ? kfree_debugcheck+0x16/0x40
 [<ffffffff8124b739>] get_request_wait+0x29/0x190
 [<ffffffff8124bc0d>] blk_get_request+0x6d/0x80
 [<ffffffff8149a258>] scsi_execute+0x48/0x160
 [<ffffffff8149a491>] ? scsi_execute_req+0x61/0x110
 [<ffffffff8149a4d7>] scsi_execute_req+0xa7/0x110
 [<ffffffff81493e0d>] T.752+0x4d/0x110
 [<ffffffff810f5d68>] ? cache_free_debugcheck+0x198/0x250
 [<ffffffff81493f36>] scsi_set_medium_removal+0x66/0x90
 [<ffffffff81135c6a>] ? fsnotify_clear_marks_by_inode+0x2a/0xf0
 [<ffffffff814d4670>] sr_lock_door+0x20/0x30
 [<ffffffff816d05a7>] cdrom_release+0x137/0x250
 [<ffffffff810f5d68>] ? cache_free_debugcheck+0x198/0x250
 [<ffffffff811de45c>] ? isofs_destroy_inode+0x1c/0x20
 [<ffffffff814d3a08>] sr_block_release+0x38/0x60
 [<ffffffff81130cac>] __blkdev_put+0x16c/0x1b0
 [<ffffffff81130d21>] blkdev_put+0x31/0x130
 [<ffffffff810ffc3d>] kill_block_super+0x4d/0x80
 [<ffffffff811003d5>] deactivate_locked_super+0x45/0x60
 [<ffffffff8110100a>] deactivate_super+0x4a/0x70
 [<ffffffff8111a98a>] mntput_no_expire+0x12a/0x1a0
 [<ffffffff8111afb8>] sys_umount+0x78/0x3b0
 [<ffffffff819cd3ab>] system_call_fastpath+0x16/0x1b
Code: 66 66 66 90 48 8b 47 18 48 8b 00 48 8b 40 68 48 85 c0 74 05 48 89 f7 ff d0 c9 c3 55 48 89 e5 66 66 66 66 90 48 8b 47 18 48 8b 00 
 8b 50 70 31 c0 48 85 d2 74 02 ff d2 c9 c3 90 55 48 89 e5 66 
RIP  [<ffffffff81244590>] elv_may_queue+0x10/0x20
 RSP <ffff88007be17aa8>
---[ end trace a59ceb38f50c5e0c ]---

Steps to reproduce:

1. mount /dev/sr0 /mnt # Mount fails
2. umount /mnt # Message about not being mounted
3. mount /dev/sr0 /mnt # [sr0] messages appears in kernel log
4. remove USB stick # USB disconnect message
5. umount /mnt # above error message

I mount the /dev/sr0 in /mnt and remove it before calling umount. I had to repeat the mount as it seemed to fail the first time (calling umount /mnt in-between). The second mount succeeded with some errors reported by the sr0.

Full logs attached as text file.

	Torsten


[-- Attachment #2: screenlog.0 --]
[-- Type: text/plain, Size: 51967 bytes --]

Linux version 3.0.0-rc2 (thilbrich@sn-be111) (gcc version 4.4.3 (Ubuntu 4.4.3-4ubuntu5) ) #41 SMP Tue Jun 7 13:06:34 CEST 2011
Command line: BOOT_IMAGE=/bzImage-ipsec-test root=/dev/sda1 ro single init=/bin/bash console=ttyS0,115200 console=tty0 loglevel=7
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009f000 (usable)
 BIOS-e820: 000000000009f000 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000d2000 - 00000000000d4000 (reserved)
 BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000007fed0000 (usable)
 BIOS-e820: 000000007fed0000 - 000000007fedf000 (ACPI data)
 BIOS-e820: 000000007fedf000 - 000000007ff00000 (ACPI NVS)
 BIOS-e820: 000000007ff00000 - 0000000080000000 (reserved)
 BIOS-e820: 00000000f0000000 - 00000000f4000000 (reserved)
 BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
 BIOS-e820: 00000000fed00000 - 00000000fed00400 (reserved)
 BIOS-e820: 00000000fed14000 - 00000000fed1a000 (reserved)
 BIOS-e820: 00000000fed1c000 - 00000000fed90000 (reserved)
 BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
 BIOS-e820: 00000000ff800000 - 0000000100000000 (reserved)
NX (Execute Disable) protection: active
DMI present.
No AGP bridge found
last_pfn = 0x7fed0 max_arch_pfn = 0x400000000
x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
found SMP MP-table at [ffff8800000f6810] f6810
init_memory_mapping: 0000000000000000-000000007fed0000
ACPI: RSDP 00000000000f67e0 00024 (v02 LENOVO)
ACPI: XSDT 000000007fed13c7 0008C (v01 LENOVO TP-79    00002180  LTP 00000000)
ACPI: FACP 000000007fed1500 000F4 (v03 LENOVO TP-79    00002180 LNVO 00000001)
ACPI Warning: 32/64X length mismatch in Gpe1Block: 0/32 (20110413/tbfadt-529)
ACPI Warning: Optional field Gpe1Block has zero address or length: 0x000000000000102C/0x0 (20110413/tbfadt-560)
ACPI: DSDT 000000007fed185e 0D3C2 (v01 LENOVO TP-79    00002180 MSFT 0100000E)
ACPI: FACS 000000007fef4000 00040
ACPI: SSDT 000000007fed16b4 001AA (v01 LENOVO TP-79    00002180 MSFT 0100000E)
ACPI: ECDT 000000007fedec20 00052 (v01 LENOVO TP-79    00002180 LNVO 00000001)
ACPI: TCPA 000000007fedec72 00032 (v02 LENOVO TP-79    00002180 LNVO 00000001)
ACPI: APIC 000000007fedeca4 00068 (v01 LENOVO TP-79    00002180 LNVO 00000001)
ACPI: MCFG 000000007feded0c 0003C (v01 LENOVO TP-79    00002180 LNVO 00000001)
ACPI: HPET 000000007feded48 00038 (v01 LENOVO TP-79    00002180 LNVO 00000001)
ACPI: SLIC 000000007fedee62 00176 (v01 LENOVO TP-79    00002180  LTP 00000000)
ACPI: BOOT 000000007fedefd8 00028 (v01 LENOVO TP-79    00002180  LTP 00000001)
ACPI: SSDT 000000007fef2697 0025F (v01 LENOVO TP-79    00002180 INTL 20050513)
ACPI: SSDT 000000007fef28f6 000A6 (v01 LENOVO TP-79    00002180 INTL 20050513)
ACPI: SSDT 000000007fef299c 004F7 (v01 LENOVO TP-79    00002180 INTL 20050513)
ACPI: SSDT 000000007fef2e93 001D8 (v01 LENOVO TP-79    00002180 INTL 20050513)
No NUMA configuration found
Faking a node at 0000000000000000-000000007fed0000
Initmem setup node 0 0000000000000000-000000007fed0000
  NODE_DATA [000000007fec7000 - 000000007fecbfff]
Zone PFN ranges:
  DMA      0x00000010 -> 0x00001000
  DMA32    0x00001000 -> 0x00100000
  Normal   empty
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
    0: 0x00000010 -> 0x0000009f
    0: 0x00000100 -> 0x0007fed0
ACPI: PM-Timer IO Port: 0x1008
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, version 32, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
Using ACPI (MADT) for SMP configuration information
ACPI: HPET id: 0x8086a201 base: 0xfed00000
SMP: Allowing 2 CPUs, 0 hotplug CPUs
PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
PM: Registered nosave memory: 00000000000a0000 - 00000000000d2000
PM: Registered nosave memory: 00000000000d2000 - 00000000000d4000
PM: Registered nosave memory: 00000000000d4000 - 00000000000dc000
PM: Registered nosave memory: 00000000000dc000 - 0000000000100000
Allocating PCI resources starting at 80000000 (gap: 80000000:70000000)
setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:2 nr_node_ids:1
PERCPU: Embedded 25 pages/cpu @ffff88007fc00000 s70336 r8192 d23872 u1048576
Built 1 zonelists in Node order, mobility grouping on.  Total pages: 516702
Policy zone: DMA32
Kernel command line: BOOT_IMAGE=/bzImage-ipsec-test root=/dev/sda1 ro single init=/bin/bash console=ttyS0,115200 console=tty0 loglevel=7
PID hash table entries: 4096 (order: 3, 32768 bytes)
Checking aperture...
No AGP bridge found
Memory: 2045612k/2095936k available (10053k kernel code, 452k absent, 49872k reserved, 7108k data, 920k init)
Hierarchical RCU implementation.
NR_IRQS:4352 nr_irqs:512 16
Extended CMOS year: 2000
Console: colour VGA+ 80x25
console [tty0] enabled
console [ttyS0] enabled
Fast TSC calibration using PIT
Detected 2161.314 MHz processor.
Calibrating delay loop (skipped), value calculated using timer frequency.. 4322.62 BogoMIPS (lpj=2161314)
pid_max: default: 32768 minimum: 301
Security Framework initialized
Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
Mount-cache hash table entries: 256
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 0
using mwait in idle threads.
ACPI: Core revision 20110413
ftrace: allocating 33379 entries in 131 pages
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
CPU0: Intel(R) Core(TM)2 CPU         T7400  @ 2.16GHz stepping 06
Performance Events: PEBS fmt0-, Core2 events, Intel PMU driver.
PEBS disabled due to CPU errata.
... version:                2
... bit width:              40
... generic registers:      2
... value mask:             000000ffffffffff
... max period:             000000007fffffff
... fixed-purpose events:   3
... event mask:             0000000700000003
Booting Node   0, Processors  #1 Ok.
TSC synchronization [CPU#0 -> CPU#1]:
Measured 669123 cycles TSC warp between CPUs, turning off TSC clock.
Marking TSC unstable due to check_tsc_sync_source failed
Brought up 2 CPUs
Total of 2 processors activated (8644.94 BogoMIPS).
kworker/u:0 used greatest stack depth: 6048 bytes left
PM: Registering ACPI NVS region at 7fedf000 (135168 bytes)
NET: Registered protocol family 16
kworker/u:0 used greatest stack depth: 5664 bytes left
ACPI FADT declares the system doesn't support PCIe ASPM, so disable it
ACPI: bus type pci registered
PCI: MMCONFIG for domain 0000 [bus 00-3f] at [mem 0xf0000000-0xf3ffffff] (base 0xf0000000)
PCI: MMCONFIG at [mem 0xf0000000-0xf3ffffff] reserved in E820
PCI: Using configuration type 1 for base access
bio: create slab <bio-0> at 0
ACPI: EC: EC description table is found, configuring boot EC
ACPI: SSDT 000000007fef1d36 00282 (v01  PmRef  Cpu0Ist 00000100 INTL 20050513)
ACPI: Dynamic OEM Table Load:
ACPI: SSDT           (null) 00282 (v01  PmRef  Cpu0Ist 00000100 INTL 20050513)
ACPI: SSDT 000000007fef203d 0065A (v01  PmRef  Cpu0Cst 00000100 INTL 20050513)
ACPI: Dynamic OEM Table Load:
ACPI: SSDT           (null) 0065A (v01  PmRef  Cpu0Cst 00000100 INTL 20050513)
ACPI: SSDT 000000007fef1c6e 000C8 (v01  PmRef  Cpu1Ist 00000100 INTL 20050513)
ACPI: Dynamic OEM Table Load:
ACPI: SSDT           (null) 000C8 (v01  PmRef  Cpu1Ist 00000100 INTL 20050513)
ACPI: SSDT 000000007fef1fb8 00085 (v01  PmRef  Cpu1Cst 00000100 INTL 20050513)
ACPI: Dynamic OEM Table Load:
ACPI: SSDT           (null) 00085 (v01  PmRef  Cpu1Cst 00000100 INTL 20050513)
ACPI: Interpreter enabled
ACPI: (supports S0 S3 S4 S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: Power Resource [PUBS] (on)
ACPI: EC: GPE = 0x1c, I/O: command/status = 0x66, data = 0x62
ACPI: ACPI Dock Station Driver: 3 docks/bays found
PCI: Ignoring host bridge windows from ACPI; if necessary, use "pci=use_crs" and report a bug
ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
pci 0000:00:1f.0: quirk: [io  0x1000-0x107f] claimed by ICH6 ACPI/GPIO/TCO
pci 0000:00:1f.0: quirk: [io  0x1180-0x11bf] claimed by ICH6 GPIO
pci 0000:00:1f.0: ICH7 LPC Generic IO decode 1 PIO at 1600 (mask 007f)
pci 0000:00:1f.0: ICH7 LPC Generic IO decode 2 PIO at 15e0 (mask 000f)
pci 0000:00:1f.0: ICH7 LPC Generic IO decode 3 PIO at 1680 (mask 001f)
pci 0000:00:01.0: PCI bridge to [bus 01-01]
pci 0000:00:1c.0: PCI bridge to [bus 02-02]
pci 0000:00:1c.1: PCI bridge to [bus 03-03]
pci 0000:00:1c.2: PCI bridge to [bus 04-0b]
pci 0000:00:1c.3: PCI bridge to [bus 0c-13]
pci 0000:00:1e.0: PCI bridge to [bus 15-18] (subtractive decode)
 pci0000:00: Requesting ACPI _OSC control (0x1d)
 pci0000:00: ACPI _OSC control (0x1d) granted
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 9 10 *11)
vgaarb: device added: PCI:0000:01:00.0,decodes=io+mem,owns=io+mem,locks=none
vgaarb: loaded
vgaarb: bridge control possible 0000:01:00.0
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
wmi: Mapper loaded
Advanced Linux Sound Architecture Driver Version 1.0.24.
PCI: Using ACPI for IRQ routing
cfg80211: Calling CRDA to update world regulatory domain
NetLabel: Initializing
NetLabel:  domain hash size = 128
NetLabel:  protocols = UNLABELED CIPSOv4
NetLabel:  unlabeled traffic allowed by default
HPET: 3 timers in total, 0 timers will be used for per-cpu timer
Switching to clocksource hpet
Switched to NOHz mode on CPU #0
Switched to NOHz mode on CPU #1
pnp: PnP ACPI init
ACPI: bus type pnp registered
system 00:00: [mem 0x00000000-0x0009ffff] could not be reserved
system 00:00: [mem 0x000c0000-0x000c3fff] could not be reserved
system 00:00: [mem 0x000c4000-0x000c7fff] could not be reserved
system 00:00: [mem 0x000c8000-0x000cbfff] could not be reserved
system 00:00: [mem 0x000cc000-0x000cffff] could not be reserved
system 00:00: [mem 0x000d0000-0x000d3fff] could not be reserved
system 00:00: [mem 0x000dc000-0x000dffff] could not be reserved
system 00:00: [mem 0x000e0000-0x000e3fff] could not be reserved
system 00:00: [mem 0x000e4000-0x000e7fff] could not be reserved
system 00:00: [mem 0x000e8000-0x000ebfff] could not be reserved
system 00:00: [mem 0x000ec000-0x000effff] could not be reserved
system 00:00: [mem 0x000f0000-0x000fffff] could not be reserved
system 00:00: [mem 0x00100000-0x7fffffff] could not be reserved
system 00:00: [mem 0xfec00000-0xfed3ffff] could not be reserved
system 00:00: [mem 0xfed41000-0xffffffff] could not be reserved
system 00:02: [io  0x164e-0x164f] has been reserved
system 00:02: [io  0x1000-0x107f] has been reserved
system 00:02: [io  0x1180-0x11bf] has been reserved
system 00:02: [io  0x0800-0x080f] has been reserved
system 00:02: [io  0x15e0-0x15ef] has been reserved
system 00:02: [io  0x1600-0x165f] could not be reserved
system 00:02: [mem 0xf0000000-0xf3ffffff] has been reserved
system 00:02: [mem 0xfed1c000-0xfed1ffff] has been reserved
system 00:02: [mem 0xfed14000-0xfed17fff] has been reserved
system 00:02: [mem 0xfed18000-0xfed18fff] has been reserved
system 00:02: [mem 0xfed19000-0xfed19fff] has been reserved
pnp: PnP ACPI: found 13 devices
ACPI: ACPI bus type pnp unregistered
pci 0000:00:1c.0: BAR 15: assigned [mem 0x80000000-0x801fffff 64bit pref]
pci 0000:01:00.0: BAR 6: assigned [mem 0xee120000-0xee13ffff pref]
pci 0000:00:01.0: PCI bridge to [bus 01-01]
pci 0000:00:01.0:   bridge window [io  0x2000-0x2fff]
pci 0000:00:01.0:   bridge window [mem 0xee100000-0xee1fffff]
pci 0000:00:01.0:   bridge window [mem 0xd0000000-0xdfffffff 64bit pref]
pci 0000:00:1c.0: PCI bridge to [bus 02-02]
pci 0000:00:1c.0:   bridge window [io  0x3000-0x3fff]
pci 0000:00:1c.0:   bridge window [mem 0xee000000-0xee0fffff]
pci 0000:00:1c.0:   bridge window [mem 0x80000000-0x801fffff 64bit pref]
pci 0000:00:1c.1: PCI bridge to [bus 03-03]
pci 0000:00:1c.1:   bridge window [io  0x4000-0x5fff]
pci 0000:00:1c.1:   bridge window [mem 0xec000000-0xedffffff]
pci 0000:00:1c.1:   bridge window [mem 0xe4000000-0xe40fffff 64bit pref]
pci 0000:00:1c.2: PCI bridge to [bus 04-0b]
pci 0000:00:1c.2:   bridge window [io  0x6000-0x7fff]
pci 0000:00:1c.2:   bridge window [mem 0xe8000000-0xe9ffffff]
pci 0000:00:1c.2:   bridge window [mem 0xe4100000-0xe41fffff 64bit pref]
pci 0000:00:1c.3: PCI bridge to [bus 0c-13]
pci 0000:00:1c.3:   bridge window [io  0x8000-0x9fff]
pci 0000:00:1c.3:   bridge window [mem 0xea000000-0xebffffff]
pci 0000:00:1c.3:   bridge window [mem 0xe4200000-0xe42fffff 64bit pref]
pci 0000:15:00.0: BAR 15: assigned [mem 0xe0000000-0xe3ffffff pref]
pci 0000:15:00.0: BAR 16: assigned [mem 0x84000000-0x87ffffff]
pci 0000:15:00.0: BAR 13: assigned [io  0xa000-0xa0ff]
pci 0000:15:00.0: BAR 14: assigned [io  0xa400-0xa4ff]
pci 0000:15:00.0: CardBus bridge to [bus 16-17]
pci 0000:15:00.0:   bridge window [io  0xa000-0xa0ff]
pci 0000:15:00.0:   bridge window [io  0xa400-0xa4ff]
pci 0000:15:00.0:   bridge window [mem 0xe0000000-0xe3ffffff pref]
pci 0000:15:00.0:   bridge window [mem 0x84000000-0x87ffffff]
pci 0000:00:1e.0: PCI bridge to [bus 15-18]
pci 0000:00:1e.0:   bridge window [io  0xa000-0xdfff]
pci 0000:00:1e.0:   bridge window [mem 0xe4300000-0xe7ffffff]
pci 0000:00:1e.0:   bridge window [mem 0xe0000000-0xe3ffffff 64bit pref]
pci 0000:00:01.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
pci 0000:00:1c.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
pci 0000:00:1c.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
pci 0000:00:1c.2: PCI INT C -> GSI 22 (level, low) -> IRQ 22
pci 0000:00:1c.3: PCI INT D -> GSI 23 (level, low) -> IRQ 23
pci 0000:00:1e.0: enabling device (0005 -> 0007)
pci 0000:15:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
NET: Registered protocol family 2
IP route cache hash table entries: 65536 (order: 7, 524288 bytes)
TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
TCP: Hash tables configured (established 262144 bind 65536)
TCP reno registered
UDP hash table entries: 1024 (order: 3, 32768 bytes)
UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
NET: Registered protocol family 1
RPC: Registered named UNIX socket transport module.
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
Simple Boot Flag at 0x35 set to 0x1
squashfs: version 4.0 (2009/01/31) Phillip Lougher
msgmni has been set to 3995
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
uvesafb: failed to execute /sbin/v86d
uvesafb: make sure that the v86d helper is installed and executable
uvesafb: Getting VBE info block failed (eax=0x4f00, err=-2)
uvesafb: vbe_init() failed with -22
uvesafb: probe of uvesafb.0 failed with error -22
ACPI: Deprecated procfs I/F for AC is loaded, please retry with CONFIG_ACPI_PROCFS_POWER cleared
ACPI: AC Adapter [AC] (on-line)
input: Lid Switch as /devices/LNXSYSTM:00/device:00/PNP0C0D:00/input/input0
ACPI: Lid Switch [LID]
input: Sleep Button as /devices/LNXSYSTM:00/device:00/PNP0C0E:00/input/input1
ACPI: Sleep Button [SLPB]
input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input2
ACPI: Power Button [PWRF]
acpi device:06: registered as cooling_device0
input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/device:05/LNXVIDEO:01/input/input3
ACPI: Video Device [VID1] (multi-head: yes  rom: no  post: no)
thermal LNXTHERM:00: registered as thermal_zone0
ACPI: Thermal Zone [THM0] (63 C)
thermal LNXTHERM:01: registered as thermal_zone1
ACPI: Thermal Zone [THM1] (63 C)
ACPI: Deprecated procfs I/F for battery is loaded, please retry with CONFIG_ACPI_PROCFS_POWER cleared
ACPI: Battery Slot [BAT0] (battery present)
Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:0a: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Initializing Nozomi driver 2.1d
lp: driver loaded but no devices found
Non-volatile memory driver v1.3
intel_rng: FWH not detected
Linux agpgart interface v0.103
[drm] Initialized drm 1.1.0 20060810
[drm] radeon defaulting to kernel modesetting.
[drm] radeon kernel modesetting enabled.
radeon 0000:01:00.0: power state changed by ACPI to D0
radeon 0000:01:00.0: power state changed by ACPI to D0
radeon 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[drm] initializing kernel modesetting (RV530 0x1002:0x71D4).
[drm] register mmio base: 0xEE100000
[drm] register mmio size: 65536
ATOM BIOS: Lenovo
[drm] Generation 2 PCI interface, using max accessible memory
radeon 0000:01:00.0: VRAM: 256M 0x0000000000000000 - 0x000000000FFFFFFF (256M used)
radeon 0000:01:00.0: GTT: 512M 0x0000000010000000 - 0x000000002FFFFFFF
[drm] Supports vblank timestamp caching Rev 1 (10.10.2010).
[drm] Driver supports precise vblank timestamp query.
radeon 0000:01:00.0: radeon: using MSI.
[drm] radeon: irq initialized.
[drm] Detected VRAM RAM=256M, BAR=256M
[drm] RAM width 128bits DDR
[TTM] Zone  kernel: Available graphics memory: 1022806 kiB.
[TTM] Initializing pool allocator.
[drm] radeon: 256M of VRAM memory ready
[drm] radeon: 512M of GTT memory ready.
[drm] GART: num cpu pages 131072, num gpu pages 131072
[drm] radeon: 1 quad pipes, 2 z pipes initialized.
[drm] PCIE GART of 512M enabled (table at 0x00040000).
radeon 0000:01:00.0: WB enabled
[drm] Loading R500 Microcode
[drm] radeon: ring at 0x0000000010001000
[drm] ring test succeeded in 10 usecs
[drm] radeon: ib pool ready.
[drm] ib test succeeded in 0 usecs
[drm] Radeon Display Connectors
[drm] Connector 0:
[drm]   VGA
[drm]   DDC: 0x7e40 0x7e40 0x7e44 0x7e44 0x7e48 0x7e48 0x7e4c 0x7e4c
[drm]   Encoders:
[drm]     CRT1: INTERNAL_KLDSCP_DAC1
[drm] Connector 1:
[drm]   LVDS
[drm]   DDC: 0x7e60 0x7e60 0x7e64 0x7e64 0x7e68 0x7e68 0x7e6c 0x7e6c
[drm]   Encoders:
[drm]     LCD1: INTERNAL_LVTM1
[drm] Connector 2:
[drm]   DVI-I
[drm]   HPD1
[drm]   DDC: 0x7e50 0x7e50 0x7e54 0x7e54 0x7e58 0x7e58 0x7e5c 0x7e5c
[drm]   Encoders:
[drm]     DFP1: INTERNAL_KLDSCP_TMDS1
[drm] radeon: power management initialized
[drm] fb mappable at 0xD00C0000
[drm] vram apper at 0xD0000000
[drm] size 5914624
[drm] fb depth is 24
[drm]    pitch is 5632
fbcon: radeondrmfb (fb0) is primary device
Console: switching to colour frame buffer device 175x65
fb0: radeondrmfb frame buffer device
drm: registered panic notifier
[drm] Initialized radeon 2.10.0 20080528 for 0000:01:00.0 on minor 0
drm/i810 does not support SMP
[drm:i915_init] *ERROR* drm/i915 can't work without intel_agp module!
parport_pc 00:0b: activated
parport_pc 00:0b: reported by Plug and Play ACPI
parport0: PC-style at 0x3bc, irq 7 [PCSPP(,...)]
lp0: using parport0 (interrupt-driven).
floppy0: no floppy controllers found
brd: module loaded
loop: module loaded
HP CISS Driver (v 3.6.26)
Uniform Multi-Platform E-IDE driver
piix 0000:00:1f.1: IDE controller (0x8086:0x27df rev 0x02)
pci 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
piix 0000:00:1f.1: IDE port disabled
piix 0000:00:1f.1: not 100% native mode: will probe irqs later
    ide0: BM-DMA at 0x1880-0x1887
hda: HL-DT-ST DVDRAM GSA-4083N, ATAPI CD/DVD-ROM drive
hda: UDMA/33 mode selected
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
ide_generic: please use "probe_mask=0x3f" module parameter for probing all legacy ISA IDE ports
ide-gd driver 1.18
ide-cd driver 5.00
ide-cd: hda: ATAPI 24X DVD-ROM DVD-R/RAM CD-R/RW drive, 2048kB Cache
cdrom: Uniform CD-ROM driver Revision: 3.20
megaraid cmm: 2.20.2.7 (Release Date: Sun Jul 16 00:01:03 EST 2006)
megaraid: 2.20.5.1 (Release Date: Thu Nov 16 15:32:35 EST 2006)
ahci 0000:00:1f.2: PCI INT B -> GSI 16 (level, low) -> IRQ 16
ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 1.5 Gbps 0x1 impl SATA mode
ahci 0000:00:1f.2: flags: 64bit ncq pm led clo pio slum part 
scsi0 : ahci
scsi1 : ahci
scsi2 : ahci
scsi3 : ahci
ata1: SATA max UDMA/133 abar m1024@0xee404400 port 0xee404500 irq 46
ata2: DUMMY
ata3: DUMMY
ata4: DUMMY
e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
e1000: Copyright (c) 1999-2006 Intel Corporation.
e1000e: Intel(R) PRO/1000 Network Driver - 1.3.10-k2
e1000e: Copyright(c) 1999 - 2011 Intel Corporation.
e1000e 0000:02:00.0: Disabling ASPM L0s L1
e1000e 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
e1000e 0000:02:00.0: eth0: (PCI Express:2.5GT/s:Width x1) 00:1a:6b:6d:52:3a
e1000e 0000:02:00.0: eth0: Intel(R) PRO/1000 Network Connection
e1000e 0000:02:00.0: eth0: MAC: 2, PHY: 2, PBA No: 005301-003
Atheros(R) L2 Ethernet Driver - version 2.2.3
Copyright (c) 2007 Atheros Corporation.
pcnet32: pcnet32.c:v1.35 21.Apr.2008 tsbogend@alpha.franken.de
e100: Intel(R) PRO/100 Network Driver, 3.5.24-k2-NAPI
e100: Copyright(c) 1999-2006 Intel Corporation
sky2: driver version 1.28
PPP generic driver version 2.4.2
PPP Deflate Compression module registered
PPP BSD Compression module registered
pegasus: v0.6.14 (2006/09/27), Pegasus/Pegasus II USB Ethernet driver
usbcore: registered new interface driver pegasus
hso: drivers/net/usb/hso.c: Option Wireless
usbcore: registered new interface driver hso
usbcore: registered new interface driver asix
usbcore: registered new interface driver cdc_ether
usbcore: registered new interface driver net1080
usbcore: registered new interface driver cdc_subset
usbcore: registered new interface driver zaurus
cdc_ncm: 01-June-2011
usbcore: registered new interface driver cdc_ncm
ipw2100: Intel(R) PRO/Wireless 2100 Network Driver, git-1.2.2
ipw2100: Copyright(c) 2003-2006 Intel Corporation
ipw2200: Intel(R) PRO/Wireless 2200/2915 Network Driver, 1.2.2kmprq
ipw2200: Copyright(c) 2003-2006 Intel Corporation
libipw: 802.11 data/management/control stack, git-1.1.13
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
libipw: Copyright (C) 2004-2005 Intel Corporation <jketreno@linux.intel.com>
ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
airo(): Probing for PCI adapters
ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
airo(): Finished probing for PCI adapters
Loaded prism54 driver, version 1.2
ata1.00: ATA-7: HITACHI HTS541612J9SA00  3H, SB3IC7UP, max UDMA/100
ata1.00: 234441648 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
usbcore: registered new interface driver zd1211rw
usbcore: registered new interface driver rtl8187
usbcore: registered new interface driver zd1201
iwlagn: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:
iwlagn: Copyright(c) 2003-2011 Intel Corporation
iwl4965: Intel(R) Wireless WiFi 4965 driver for Linux, in-tree:
iwl4965: Copyright(c) 2003-2011 Intel Corporation
iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux, in-tree:s
iwl3945: Copyright(c) 2003-2011 Intel Corporation
iwl3945 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
iwl3945 0000:03:00.0: Tunable channels: 13 802.11bg, 23 802.11a channels
iwl3945 0000:03:00.0: Detected Intel Wireless WiFi Link 3945ABG
ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
usbcore: registered new interface driver rt73usb
ata1.00: configured for UDMA/100
scsi 0:0:0:0: Direct-Access     ATA      HITACHI HTS54161 SB3I PQ: 0 ANSI: 5
console [netcon0] enabled
netconsole: network logging started
sd 0:0:0:0: [sda] 234441648 512-byte logical blocks: (120 GB/111 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
yenta_cardbus 0000:15:00.0: CardBus bridge found [17aa:2012]
yenta_cardbus 0000:15:00.0: Using INTVAL to route CSC interrupts to PCI
yenta_cardbus 0000:15:00.0: Routing CardBus interrupts to PCI
yenta_cardbus 0000:15:00.0: TI: mfunc 0x01d01002, devctl 0x64
 sda: sda1 sda2 sda3 sda4 < sda5 sda6 >
sd 0:0:0:0: [sda] Attached SCSI disk
yenta_cardbus 0000:15:00.0: ISA IRQ mask 0x0c78, PCI irq 16
yenta_cardbus 0000:15:00.0: Socket status: 30000007
yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge window: [io  0xa000-0xdfff]
yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge window: [mem 0xe4300000-0xe7ffffff]
pcmcia_socket pcmcia_socket0: cs: memory probe 0xe4300000-0xe7ffffff: excluding 0xe4300000-0xe46cffff
yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge window: [mem 0xe0000000-0xe3ffffff 64bit pref]
pcmcia_socket pcmcia_socket0: cs: memory probe 0xe0000000-0xe3ffffff: excluding 0xe0000000-0xe3ffffff
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
ehci_hcd 0000:00:1d.7: EHCI Host Controller
ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1
ehci_hcd 0000:00:1d.7: using broken periodic workaround
ehci_hcd 0000:00:1d.7: debug port 1
ehci_hcd 0000:00:1d.7: irq 19, io mem 0xee404000
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: Product: EHCI Host Controller
usb usb1: Manufacturer: Linux 3.0.0-rc2 ehci_hcd
usb usb1: SerialNumber: 0000:00:1d.7
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 8 ports detected
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
uhci_hcd: USB Universal Host Controller Interface driver
uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
uhci_hcd 0000:00:1d.0: UHCI Host Controller
uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1d.0: irq 16, io base 0x00001800
usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb2: Product: UHCI Host Controller
usb usb2: Manufacturer: Linux 3.0.0-rc2 uhci_hcd
usb usb2: SerialNumber: 0000:00:1d.0
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
uhci_hcd 0000:00:1d.1: UHCI Host Controller
uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:1d.1: irq 17, io base 0x00001820
usb usb3: New USB device found, idVendor=1d6b, idProduct=0001
usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb3: Product: UHCI Host Controller
usb usb3: Manufacturer: Linux 3.0.0-rc2 uhci_hcd
usb usb3: SerialNumber: 0000:00:1d.1
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
uhci_hcd 0000:00:1d.2: UHCI Host Controller
uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:1d.2: irq 18, io base 0x00001840
usb usb4: New USB device found, idVendor=1d6b, idProduct=0001
usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb4: Product: UHCI Host Controller
usb usb4: Manufacturer: Linux 3.0.0-rc2 uhci_hcd
usb usb4: SerialNumber: 0000:00:1d.2
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 19 (level, low) -> IRQ 19
uhci_hcd 0000:00:1d.3: UHCI Host Controller
uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 5
uhci_hcd 0000:00:1d.3: irq 19, io base 0x00001860
usb usb5: New USB device found, idVendor=1d6b, idProduct=0001
usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb5: Product: UHCI Host Controller
usb usb5: Manufacturer: Linux 3.0.0-rc2 uhci_hcd
usb usb5: SerialNumber: 0000:00:1d.3
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 2 ports detected
usbcore: registered new interface driver cdc_acm
cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
usbcore: registered new interface driver usblp
usbcore: registered new interface driver cdc_wdm
Initializing USB Mass Storage driver...
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
usbcore: registered new interface driver libusual
usbcore: registered new interface driver ums-datafab
usbcore: registered new interface driver ums-freecom
usbcore: registered new interface driver ums-isd200
usbcore: registered new interface driver ums-jumpshot
usbcore: registered new interface driver ums-sddr09
usbcore: registered new interface driver ums-sddr55
usbcore: registered new interface driver ums-usbat
usbcore: registered new interface driver usbserial
USB Serial support registered for generic
usb 1-6: new high speed USB device number 3 using ehci_hcd
usb 1-6: New USB device found, idVendor=04b3, idProduct=4485
usb 1-6: New USB device strings: Mfr=0, Product=0, SerialNumber=0
hub 1-6:1.0: USB hub found
hub 1-6:1.0: 4 ports detected
usb 2-2: new full speed USB device number 2 using uhci_hcd
usb 2-2: New USB device found, idVendor=0d46, idProduct=3003
usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 2-2: Product: KAAN SIM III
usb 2-2: Manufacturer: KOBIL
usb 2-2: SerialNumber: K_000000000
usb 5-1: new full speed USB device number 2 using uhci_hcd
usb 5-1: New USB device found, idVendor=0a5c, idProduct=2110
usb 5-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 5-1: Product: BCM2045B
usb 5-1: Manufacturer: Broadcom Corp
usb 5-2: new full speed USB device number 3 using uhci_hcd
usb 5-2: New USB device found, idVendor=0483, idProduct=2016
usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 5-2: Product: Biometric Coprocessor
usb 5-2: Manufacturer: STMicroelectronics
usbcore: registered new interface driver usbserial_generic
usbserial: USB Serial Driver core
USB Serial support registered for Keyspan - (without firmware)
USB Serial support registered for Keyspan 1 port adapter
USB Serial support registered for Keyspan 2 port adapter
USB Serial support registered for Keyspan 4 port adapter
usbcore: registered new interface driver keyspan
keyspan: v1.1.5:Keyspan USB to Serial Converter Driver
USB Serial support registered for GSM modem (1-port)
usbcore: registered new interface driver option
option: v0.7.2:USB Driver for GSM modems
USB Serial support registered for Qualcomm USB modem
usbcore: registered new interface driver qcserial
USB Serial support registered for Sierra USB modem
usbcore: registered new interface driver sierra
sierra: v.1.7.16:USB Driver for Sierra Wireless USB modems
i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mousedev: PS/2 mouse device common for all mice
rtc_cmos 00:07: RTC can wake from S4
rtc_cmos 00:07: rtc core: registered rtc_cmos as rtc0
rtc0: alarms up to one month, y3k, 114 bytes nvram, hpet irqs
i801_smbus 0000:00:1f.3: PCI INT A -> GSI 23 (level, low) -> IRQ 23
iTCO_wdt: Intel TCO WatchDog Timer Driver v1.06
iTCO_wdt: Found a ICH7-M or ICH7-U TCO device (Version=2, TCOBASE=0x1060)
iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
md: linear personality registered for level -1
input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input4
device-mapper: ioctl: 4.20.0-ioctl (2011-02-02) initialised: dm-devel@redhat.com
cpuidle: using governor ladder
cpuidle: using governor menu
usbcore: registered new interface driver usbhid
usbhid: USB HID core driver
dell_wmi: No known WMI GUID found
thinkpad_acpi: ThinkPad ACPI Extras v0.24
thinkpad_acpi: http://ibm-acpi.sf.net/
thinkpad_acpi: ThinkPad BIOS 79ETD8WW (2.18 ), EC 79HT50WW-1.07
thinkpad_acpi: Lenovo ThinkPad T60p, model 20077KG
thinkpad_acpi: WARNING: Outdated ThinkPad BIOS/EC firmware
thinkpad_acpi: WARNING: This firmware may be missing critical bug fixes and/or important features
thinkpad_acpi: detected a 8-level brightness capable ThinkPad
thinkpad_acpi: radio switch found; radios are enabled
thinkpad_acpi: rfkill switch tpacpi_bluetooth_sw: radio is unblocked
thinkpad_acpi: Standard ACPI backlight interface available, not loading native one
thinkpad_acpi: Console audio control enabled, mode: monitor (read only)
input: ThinkPad Extra Buttons as /devices/platform/thinkpad_acpi/input/input5
hdaps: inverting axis (3) readings
hdaps: LENOVO ThinkPad T60 detected
input: hdaps as /devices/platform/hdaps/input/input6
hdaps: driver successfully loaded
fujitsu_laptop: driver 0.6.0 successfully loaded
HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
hda_intel: probe_mask set to 0x1 for device 17aa:2010
ALSA device list:
  #0: Dummy 1
  #1: HDA Intel at 0xee400000 irq 49
  #29: ThinkPad Console Audio Control at EC reg 0x30, fw 79HT50WW-1.07
Netfilter messages via NETLINK v0.30.
nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
ctnetlink v0.93: registering with nfnetlink.
ip_tables: (C) 2000-2006 Netfilter Core Team
arp_tables: (C) 2002 David S. Miller
TCP cubic registered
NET: Registered protocol family 17
lib80211: common routines for IEEE802.11 drivers
Registering the dns_resolver key type
registered taskstats version 1
IBM TrackPoint firmware: 0x0e, buttons: 3/3
input: TPPS/2 IBM TrackPoint as /devices/platform/i8042/serio1/input/input7
md: Waiting for all devices to be available before autodetect
md: If you don't use raid, use raid=noautodetect
md: Autodetecting RAID arrays.
md: Scanned 0 and added 0 devices.
md: autorun ...
md: ... autorun DONE.
EXT3-fs (sda1): error: couldn't mount because of unsupported optional features (240)
EXT2-fs (sda1): error: couldn't mount because of unsupported optional features (240)
EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
VFS: Mounted root (ext4 filesystem) readonly on device 8:1.
Freeing unused kernel memory: 920k freed
Write protecting the kernel read-only data: 16384k
Freeing unused kernel memory: 164k freed
Freeing unused kernel memory: 1404k freed
groups used greatest stack depth: 4656 bytes left
bash used greatest stack depth: 4488 bytes left
EXT4-fs (sda1): re-mounted. Opts: errors=remount-ro
mount used greatest stack depth: 4232 bytes left
usb 1-5: new high speed USB device number 6 using ehci_hcd
usb 1-5: New USB device found, idVendor=0781, idProduct=5406
usb 1-5: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 1-5: Product: U3 Cruzer Micro
usb 1-5: Manufacturer: SanDisk
usb 1-5: SerialNumber: 0774231405811B9E
scsi4 : usb-storage 1-5:1.0
scsi 4:0:0:0: Direct-Access     SanDisk  Cruzer           7.01 PQ: 0 ANSI: 0 CCS
sd 4:0:0:0: [sdb] 3907583 512-byte logical blocks: (2.00 GB/1.86 GiB)
scsi 4:0:0:1: CD-ROM            SanDisk  Cruzer           7.01 PQ: 0 ANSI: 0
sd 4:0:0:0: [sdb] Write Protect is off
sd 4:0:0:0: [sdb] No Caching mode page present
sd 4:0:0:0: [sdb] Assuming drive cache: write through
sr0: scsi3-mmc drive: 48x/48x tray
sd 4:0:0:0: [sdb] No Caching mode page present
sd 4:0:0:0: [sdb] Assuming drive cache: write through
 sdb: sdb1 sdb3
sd 4:0:0:0: [sdb] No Caching mode page present
sd 4:0:0:0: [sdb] Assuming drive cache: write through
sd 4:0:0:0: [sdb] Attached SCSI removable disk
usb 1-5: USB disconnect, device number 6
usb 1-5: new high speed USB device number 7 using ehci_hcd
usb 1-5: New USB device found, idVendor=0781, idProduct=5406
usb 1-5: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 1-5: Product: U3 Cruzer Micro
usb 1-5: Manufacturer: SanDisk
usb 1-5: SerialNumber: 0774231405811B9E
scsi5 : usb-storage 1-5:1.0
scsi 5:0:0:0: Direct-Access     SanDisk  Cruzer           7.01 PQ: 0 ANSI: 0 CCS
sd 5:0:0:0: [sdb] 3907583 512-byte logical blocks: (2.00 GB/1.86 GiB)
scsi 5:0:0:1: CD-ROM            SanDisk  Cruzer           7.01 PQ: 0 ANSI: 0
sd 5:0:0:0: [sdb] Write Protect is off
sd 5:0:0:0: [sdb] No Caching mode page present
sd 5:0:0:0: [sdb] Assuming drive cache: write through
sr0: scsi3-mmc drive: 48x/48x tray
sd 5:0:0:0: [sdb] No Caching mode page present
sd 5:0:0:0: [sdb] Assuming drive cache: write through
 sdb: sdb1 sdb3
sd 5:0:0:0: [sdb] No Caching mode page present
sd 5:0:0:0: [sdb] Assuming drive cache: write through
sd 5:0:0:0: [sdb] Attached SCSI removable disk
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f c0 00 00 02 00
end_request: I/O error, dev sr0, sector 130816
Buffer I/O error on device sr0, logical block 32704
Buffer I/O error on device sr0, logical block 32705
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f c0 00 00 02 00
end_request: I/O error, dev sr0, sector 130816
Buffer I/O error on device sr0, logical block 32704
Buffer I/O error on device sr0, logical block 32705
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fa 00 00 02 00
end_request: I/O error, dev sr0, sector 131048
Buffer I/O error on device sr0, logical block 32762
Buffer I/O error on device sr0, logical block 32763
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fa 00 00 02 00
end_request: I/O error, dev sr0, sector 131048
Buffer I/O error on device sr0, logical block 32762
Buffer I/O error on device sr0, logical block 32763
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
Buffer I/O error on device sr0, logical block 32766
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
Buffer I/O error on device sr0, logical block 32766
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f ee 00 00 02 00
end_request: I/O error, dev sr0, sector 131000
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fc 00 00 02 00
end_request: I/O error, dev sr0, sector 131056
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fc 00 00 02 00
end_request: I/O error, dev sr0, sector 131056
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f c0 00 00 02 00
end_request: I/O error, dev sr0, sector 130816
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f c0 00 00 02 00
end_request: I/O error, dev sr0, sector 130816
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fa 00 00 02 00
end_request: I/O error, dev sr0, sector 131048
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fa 00 00 02 00
end_request: I/O error, dev sr0, sector 131048
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f ee 00 00 02 00
end_request: I/O error, dev sr0, sector 131000
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fc 00 00 02 00
end_request: I/O error, dev sr0, sector 131056
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fe 00 00 01 00
end_request: I/O error, dev sr0, sector 131064
sr 5:0:0:1: [sr0] Unhandled sense code
sr 5:0:0:1: [sr0]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
sr 5:0:0:1: [sr0]  Sense Key : Hardware Error [current] 
sr 5:0:0:1: [sr0]  Add. Sense: No additional sense information
sr 5:0:0:1: [sr0] CDB: Read(10): 28 00 00 00 7f fc 00 00 02 00
end_request: I/O error, dev sr0, sector 131056
usb 1-5: USB disconnect, device number 7
general protection fault: 0000 [#1] SMP 
CPU 1 
Modules linked in:

Pid: 1978, comm: umount Not tainted 3.0.0-rc2 #41 LENOVO 20077KG/20077KG
RIP: 0010:[<ffffffff81244590>]  [<ffffffff81244590>] elv_may_queue+0x10/0x20
RSP: 0018:ffff88007be17aa8  EFLAGS: 00010097
RAX: 6b6b6b6b6b6b6b6b RBX: ffff88007bc628c0 RCX: 0000000000000010
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88007bc628c0
RBP: ffff88007be17aa8 R08: 0000000000000000 R09: ffff88007bc6f340
R10: ffff88007be17d08 R11: ffff88007be061c8 R12: 0000000000000000
R13: 0000000000000001 R14: 0000000000000000 R15: ffff88007bc6f340
FS:  00007f5f4ba89740(0000) GS:ffff88007fd00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5f4b12a355 CR3: 000000007be2f000 CR4: 00000000000006a0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process umount (pid: 1978, threadinfo ffff88007be16000, task ffff88007cceb7b0)
Stack:
 ffff88007be17b08 ffffffff8124b3ce ffff88007d19f5f8 ffff88007bd90188
 ffff880000000010 ffffffff810f52a6 ffff88007be17b08 ffff88007bc628c0
 0000000000000000 0000000000000010 ffff88007be17d08 ffff88007bc6f340
Call Trace:
 [<ffffffff8124b3ce>] get_request+0x3e/0x380
 [<ffffffff810f52a6>] ? kfree_debugcheck+0x16/0x40
 [<ffffffff8124b739>] get_request_wait+0x29/0x190
 [<ffffffff8124bc0d>] blk_get_request+0x6d/0x80
 [<ffffffff8149a258>] scsi_execute+0x48/0x160
 [<ffffffff8149a491>] ? scsi_execute_req+0x61/0x110
 [<ffffffff8149a4d7>] scsi_execute_req+0xa7/0x110
 [<ffffffff81493e0d>] T.752+0x4d/0x110
 [<ffffffff810f5d68>] ? cache_free_debugcheck+0x198/0x250
 [<ffffffff81493f36>] scsi_set_medium_removal+0x66/0x90
 [<ffffffff81135c6a>] ? fsnotify_clear_marks_by_inode+0x2a/0xf0
 [<ffffffff814d4670>] sr_lock_door+0x20/0x30
 [<ffffffff816d05a7>] cdrom_release+0x137/0x250
 [<ffffffff810f5d68>] ? cache_free_debugcheck+0x198/0x250
 [<ffffffff811de45c>] ? isofs_destroy_inode+0x1c/0x20
 [<ffffffff814d3a08>] sr_block_release+0x38/0x60
 [<ffffffff81130cac>] __blkdev_put+0x16c/0x1b0
 [<ffffffff81130d21>] blkdev_put+0x31/0x130
 [<ffffffff810ffc3d>] kill_block_super+0x4d/0x80
 [<ffffffff811003d5>] deactivate_locked_super+0x45/0x60
 [<ffffffff8110100a>] deactivate_super+0x4a/0x70
 [<ffffffff8111a98a>] mntput_no_expire+0x12a/0x1a0
 [<ffffffff8111afb8>] sys_umount+0x78/0x3b0
 [<ffffffff819cd3ab>] system_call_fastpath+0x16/0x1b
Code: 66 66 66 90 48 8b 47 18 48 8b 00 48 8b 40 68 48 85 c0 74 05 48 89 f7 ff d0 c9 c3 55 48 89 e5 66 66 66 66 90 48 8b 47 18 48 8b 00 
 8b 50 70 31 c0 48 85 d2 74 02 ff d2 c9 c3 90 55 48 89 e5 66 
RIP  [<ffffffff81244590>] elv_may_queue+0x10/0x20
 RSP <ffff88007be17aa8>
---[ end trace a59ceb38f50c5e0c ]---
kworker/u:0 used greatest stack depth: 3952 bytes left

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[James Bottomley]

On Wed, 2011-05-25 at 13:03 -0700, Linus Torvalds wrote:
> On Wed, May 25, 2011 at 12:52 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
> >
> > +static inline int sdev_early_check(struct scsi_device *sdev)
> > +{
> > +       if (!sdev || sdev->sdev_state == SDEV_DEL
> > +               || sdev->sdev_state > SDEV_QUIESCE)
> > +               return -ENXIO;
> > +       return 0;
> > +}
> 
> Can somebody explain why it's those states, and nothing else?

The states are definitely wrong.  QUIESCE shouldn't cause an error.

Can we back up a bit.  I agree with Jens that sdev->request_queue looks
to be NULL, but that *only* happens in the final sdev release, so this
must be a refcounting problem higher up the stack.  Something is holding
an unrefcounted pointer to the sdev.

James

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[Parag Warudkar]

On Wed, 25 May 2011, James Bottomley wrote:

> On Wed, 2011-05-25 at 13:03 -0700, Linus Torvalds wrote:
> > On Wed, May 25, 2011 at 12:52 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
> > >
> > > +static inline int sdev_early_check(struct scsi_device *sdev)
> > > +{
> > > +       if (!sdev || sdev->sdev_state == SDEV_DEL
> > > +               || sdev->sdev_state > SDEV_QUIESCE)
> > > +               return -ENXIO;
> > > +       return 0;
> > > +}
> > 
> > Can somebody explain why it's those states, and nothing else?
> 
> The states are definitely wrong.  QUIESCE shouldn't cause an error.
> 
QUIESCE is not causing an error above - > QUIESCE is which per the 
documentation is correct.

Parag

Re: [PATCH] SCSI IOCTL: Check for device deletion [was Re: __elv_add_request OOPS]

[James Bottomley]

On Wed, 2011-05-25 at 16:22 -0400, Parag Warudkar wrote:
> 
> On Wed, 25 May 2011, James Bottomley wrote:
> 
> > On Wed, 2011-05-25 at 13:03 -0700, Linus Torvalds wrote:
> > > On Wed, May 25, 2011 at 12:52 PM, Parag Warudkar <parag.lkml@gmail.com> wrote:
> > > >
> > > > +static inline int sdev_early_check(struct scsi_device *sdev)
> > > > +{
> > > > +       if (!sdev || sdev->sdev_state == SDEV_DEL
> > > > +               || sdev->sdev_state > SDEV_QUIESCE)
> > > > +               return -ENXIO;
> > > > +       return 0;
> > > > +}
> > > 
> > > Can somebody explain why it's those states, and nothing else?
> > 
> > The states are definitely wrong.  QUIESCE shouldn't cause an error.
> > 
> QUIESCE is not causing an error above - > QUIESCE is which per the 
> documentation is correct.

BLOCK means a similar thing.

James

Re: __elv_add_request OOPS

[James Bottomley]

On Tue, 2011-05-24 at 12:44 +0200, Jens Axboe wrote:
> On 2011-05-24 06:29, Parag Warudkar wrote:
> > 
> > External DVD drive - connected when suspended, removed before resume.
> > Results in NULL pointer dereference in __blk_add_request on resume.
> > 
> > *ffffffff811d6503:      48 89 58 08             mov    %rbx,0x8(%rax) |
> > %ebx = ffff880131559020 <--- faulting instruction
> > 
> > 48 89 58 08 appears only in list_add :
> > 
> > static inline void list_add(struct list_head *new, struct list_head *head)
> > {
> >         __list_add(new, head, head->next);
> > ffffffff81ac012c:       49 8b 04 24             mov    (%r12),%rax
> > #ifndef CONFIG_DEBUG_LIST
> > static inline void __list_add(struct list_head *new,
> >                               struct list_head *prev,
> >                               struct list_head *next)
> > {
> >         next->prev = new;
> > ffffffff81ac0130:       48 89 58 08             mov    %rbx,0x8(%rax)
> > 
> > AFAICS list_add is only called from one place in __elv_add_request :
> > 
> >        switch (where) {
> >         case ELEVATOR_INSERT_REQUEUE:
> >         case ELEVATOR_INSERT_FRONT:
> >                 rq->cmd_flags |= REQ_SOFTBARRIER;
> >               **  list_add(&rq->queuelist, &q->queue_head);
> >                 break;
> > 
> > Now, where is the patch? :)
> 
> You forgot to attach it?
> 
> This is clearly q == NULL, CC'ing James/linux-scsi. Oops left below.

Something strange is going on here.  the q can't have been NULL when we
called blk_get_request() in scsi_execute() otherwise we'd have oopsed on
q->queue_lock, so it's not as simple as sdev->request_queue being NULL.

James


> > [18682.256362] BUG: unable to handle kernel NULL pointer dereference at 0000000000000008
> > [18682.256535] IP: [<ffffffff811d6503>] __elv_add_request+0x1e3/0x270
> > [18682.256603] PGD 0
> > [18682.256632] Oops: 0002 [#1] SMP
> > [18682.256686] CPU 2
> > [18682.256714] Modules linked in: nls_utf8 udf crc_itu_t usb_storage cryptd aes_x86_64 aes_generic fuse parport_pc ppdev dm_crypt kvm_intel joydev kvm binfmt_misc snd_hda_codec_hdmi snd_hda_codec_realtek arc4 snd_hda_intel snd_hda_codec iwlagn snd_hwdep snd_pcm mac80211 snd_seq_midi snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd cfg80211 soundcore btusb uvcvideo snd_page_alloc bluetooth videodev v4l2_compat_ioctl32 psmouse ideapad_laptop serio_raw sparse_keymap lp intel_ips mac_hid parport ext4 mbcache jbd2 i915 ahci libahci libata drm_kms_helper drm i2c_algo_bit cfbcopyarea video cfbimgblt cfbfillrect atl1c
> > [18682.257659]
> > [18682.257685] Pid: 14069, comm: xdg-screensaver Not tainted 2.6.39+ #4 LENOVO 0876                            /Base Board Product Name
> > [18682.257845] RIP: 0010:[<ffffffff811d6503>]  [<ffffffff811d6503>] __elv_add_request+0x1e3/0x270
> > [18682.257964] RSP: 0018:ffff88009b3a19e8  EFLAGS: 00010006
> > [18682.258056] RAX: 0000000000000000 RBX: ffff880131559020 RCX: 0000000000000001
> > [18682.258152] RDX: 0000000000000001 RSI: ffff880131559020 RDI: ffff8801315f77d0
> > [18682.258248] RBP: ffff88009b3a1a08 R08: ffffffff811e1000 R09: ffff8801315f77d0
> > [18682.258343] R10: ffff8800b5085e40 R11: ffff8800b5085e40 R12: ffff8801315f77d0
> > [18682.258437] R13: 0000000000000001 R14: 0000000000000001 R15: ffff8800b5085e40
> > [18682.258529] FS:  0000000000000000(0000) GS:ffff880137c80000(0000) knlGS:0000000000000000
> > [18682.258636] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [18682.258712] CR2: 0000000000000008 CR3: 0000000001a03000 CR4: 00000000000006e0
> > [18682.258807] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > [18682.258898] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > [18682.258994] Process xdg-screensaver (pid: 14069, threadinfo ffff88009b3a0000, task ffff8800aff096b0)
> > [18682.259112] Stack:
> > [18682.259140]  ffff8801315f77d0 ffff880131559020 0000000000000001 ffff88009b3a1c48
> > [18682.259249]  ffff88009b3a1a38 ffffffff811e10a0 0000000000000000 ffff88009b3a1a48
> > [18682.259354]  ffff880131559020 0000000000000000 ffff88009b3a1af8 ffffffff811e118e
> > [18682.259460] Call Trace:
> > [18682.259504]  [<ffffffff811e10a0>] blk_execute_rq_nowait+0x60/0xc0
> > [18682.259587]  [<ffffffff811e118e>] blk_execute_rq+0x8e/0x130
> > [18682.259668]  [<ffffffff812db5bc>] scsi_execute+0xfc/0x160
> > [18682.259742]  [<ffffffff812dc18f>] scsi_execute_req+0xbf/0x130
> > [18682.259821]  [<ffffffff812d5c71>] ioctl_internal_command.clone.4+0x61/0x1b0
> > [18682.259914]  [<ffffffff812d5e3e>] scsi_set_medium_removal+0x7e/0xb0
> > [18682.260000]  [<ffffffff812ecfa0>] sr_lock_door+0x20/0x30
> > [18682.260075]  [<ffffffff812f9da7>] cdrom_release+0x147/0x270
> > [18682.260153]  [<ffffffff812ebac8>] sr_block_release+0x38/0x60
> > [18682.260233]  [<ffffffff811730ac>] __blkdev_put+0x16c/0x1b0
> > [18682.260308]  [<ffffffff81173129>] blkdev_put+0x39/0x150
> > [18682.260379]  [<ffffffff81173264>] blkdev_close+0x24/0x30
> > [18682.260455]  [<ffffffff81140fba>] fput+0xea/0x220
> > [18682.260521]  [<ffffffff8113d396>] filp_close+0x66/0x90
> > [18682.260592]  [<ffffffff8105c117>] put_files_struct+0x87/0xf0
> > [18682.260668]  [<ffffffff8105c244>] exit_files+0x54/0x70
> > [18682.264275]  [<ffffffff8105c72b>] do_exit+0x16b/0x860
> > [18682.267802]  [<ffffffff811f6c2a>] ? trace_hardirqs_off_thunk+0x3a/0x6c
> > [18682.271512]  [<ffffffff8105d0e8>] do_group_exit+0x58/0xd0
> > [18682.276948]  [<ffffffff8105d177>] sys_exit_group+0x17/0x20
> > [18682.281121]  [<ffffffff81485d42>] system_call_fastpath+0x16/0x1b
> > [18682.284603] Code: ff ff e9 90 fe ff ff 90 81 4b 40 00 08 00 00 48 89 df e8 c1 93 00 00 eb c1 0f 1f 80 00 00 00 00 81 4b 40 00 08 00 00 49 8b 04 24
> > [18682.284903]  89 58 08 48 89 03 4c 89 63 08 49 89 1c 24 eb 9e 0f 1f 40 00
> > [18682.290727] RIP  [<ffffffff811d6503>] __elv_add_request+0x1e3/0x270
> > [18682.293189]  RSP <ffff88009b3a19e8>
> > [18682.296075] CR2: 0000000000000008
> > [18682.358582] ---[ end trace 82dd699fdeb50b72 ]---
>