2008-10-30 03:20:08

by Tejun Heo

[permalink] [raw]
Subject: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

Block queue supports two usage models - one where block driver peeks
at the front of queue using elv_next_request(), processes it and
finishes it and the other where block driver peeks at the front of
queue, dequeue the request using blkdev_dequeue_request() and finishes
it. The latter is more flexible as it allows the driver to process
multiple commands concurrently.

These two inconsistent usage models affect the block layer
implementation confusing. For some, elv_next_request() is considered
the issue point while others consider blkdev_dequeue_request() the
issue point.

Till now the inconsistency mostly affect only accounting, so it didn't
really break anything seriously; however, with block layer timeout,
this inconsistency hits hard. Block layer considers
elv_next_request() the issue point and adds timer but SCSI layer
thinks it was just peeking and when the request can't process the
command right away, it's just left there without further processing.
This makes the request dangling on the timer list and, when the timer
goes off, the request which the SCSI layer and below think is still on
the block queue ends up in the EH queue, causing various problems - EH
hang (failed count goes over busy count and EH never wakes up),
WARN_ON() and oopses as low level driver trying to handle the unknown
command, etc. depending on the timing.

As SCSI midlayer is the only user of block layer timer at the moment,
moving blk_add_timer() to elv_dequeue_request() fixes the problem;
however, this two usage models definitely need to be cleaned up in the
future.

Signed-off-by: Tejun Heo <[email protected]>
---
block/elevator.c | 12 ++++++------
1 file changed, 6 insertions(+), 6 deletions(-)

Index: work/block/elevator.c
===================================================================
--- work.orig/block/elevator.c
+++ work/block/elevator.c
@@ -773,12 +773,6 @@ struct request *elv_next_request(struct
*/
rq->cmd_flags |= REQ_STARTED;
blk_add_trace_rq(q, rq, BLK_TA_ISSUE);
-
- /*
- * We are now handing the request to the hardware,
- * add the timeout handler
- */
- blk_add_timer(rq);
}

if (!q->boundary_rq || q->boundary_rq == rq) {
@@ -850,6 +844,12 @@ void elv_dequeue_request(struct request_
*/
if (blk_account_rq(rq))
q->in_flight++;
+
+ /*
+ * We are now handing the request to the hardware, add the
+ * timeout handler.
+ */
+ blk_add_timer(rq);
}
EXPORT_SYMBOL(elv_dequeue_request);


2008-10-30 07:31:23

by Jens Axboe

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

On Thu, Oct 30 2008, Tejun Heo wrote:
> Block queue supports two usage models - one where block driver peeks
> at the front of queue using elv_next_request(), processes it and
> finishes it and the other where block driver peeks at the front of
> queue, dequeue the request using blkdev_dequeue_request() and finishes
> it. The latter is more flexible as it allows the driver to process
> multiple commands concurrently.
>
> These two inconsistent usage models affect the block layer
> implementation confusing. For some, elv_next_request() is considered
> the issue point while others consider blkdev_dequeue_request() the
> issue point.
>
> Till now the inconsistency mostly affect only accounting, so it didn't
> really break anything seriously; however, with block layer timeout,
> this inconsistency hits hard. Block layer considers
> elv_next_request() the issue point and adds timer but SCSI layer
> thinks it was just peeking and when the request can't process the
> command right away, it's just left there without further processing.
> This makes the request dangling on the timer list and, when the timer
> goes off, the request which the SCSI layer and below think is still on
> the block queue ends up in the EH queue, causing various problems - EH
> hang (failed count goes over busy count and EH never wakes up),
> WARN_ON() and oopses as low level driver trying to handle the unknown
> command, etc. depending on the timing.
>
> As SCSI midlayer is the only user of block layer timer at the moment,
> moving blk_add_timer() to elv_dequeue_request() fixes the problem;
> however, this two usage models definitely need to be cleaned up in the
> future.
>
> Signed-off-by: Tejun Heo <[email protected]>
> ---
> block/elevator.c | 12 ++++++------
> 1 file changed, 6 insertions(+), 6 deletions(-)
>
> Index: work/block/elevator.c
> ===================================================================
> --- work.orig/block/elevator.c
> +++ work/block/elevator.c
> @@ -773,12 +773,6 @@ struct request *elv_next_request(struct
> */
> rq->cmd_flags |= REQ_STARTED;
> blk_add_trace_rq(q, rq, BLK_TA_ISSUE);
> -
> - /*
> - * We are now handing the request to the hardware,
> - * add the timeout handler
> - */
> - blk_add_timer(rq);
> }
>
> if (!q->boundary_rq || q->boundary_rq == rq) {
> @@ -850,6 +844,12 @@ void elv_dequeue_request(struct request_
> */
> if (blk_account_rq(rq))
> q->in_flight++;
> +
> + /*
> + * We are now handing the request to the hardware, add the
> + * timeout handler.
> + */
> + blk_add_timer(rq);
> }
> EXPORT_SYMBOL(elv_dequeue_request);

That's actually a pretty dumb error, I'm surprised it hasn't reared its
ugly face in more ways. Presumably because the timeout is usually so
long, that we'll get to actually issuing and completing it within the
normal timeout anyway.

Thanks, applied!

--
Jens Axboe

2008-10-30 07:55:45

by Tejun Heo

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

Jens Axboe wrote:
> That's actually a pretty dumb error, I'm surprised it hasn't reared its
> ugly face in more ways. Presumably because the timeout is usually so
> long, that we'll get to actually issuing and completing it within the
> normal timeout anyway.

Heh... it showed its ugly face in many different ways while I was
playing with PMP connected via a very long eSATA cable.

Thanks. :-)

--
tejun

2008-10-30 08:00:24

by Jens Axboe

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

On Thu, Oct 30 2008, Tejun Heo wrote:
> Jens Axboe wrote:
> > That's actually a pretty dumb error, I'm surprised it hasn't reared its
> > ugly face in more ways. Presumably because the timeout is usually so
> > long, that we'll get to actually issuing and completing it within the
> > normal timeout anyway.
>
> Heh... it showed its ugly face in many different ways while I was
> playing with PMP connected via a very long eSATA cable.

Ah :-)

If we had it wired up for eg the old IDE drivers, it would have shown up
quite quickly as well I think.

--
Jens Axboe

2008-10-30 09:28:00

by Mike Anderson

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

Jens Axboe <[email protected]> wrote:
> On Thu, Oct 30 2008, Tejun Heo wrote:
> > Jens Axboe wrote:
> > > That's actually a pretty dumb error, I'm surprised it hasn't reared its
> > > ugly face in more ways. Presumably because the timeout is usually so
> > > long, that we'll get to actually issuing and completing it within the
> > > normal timeout anyway.
> >
> > Heh... it showed its ugly face in many different ways while I was
> > playing with PMP connected via a very long eSATA cable.
>
> Ah :-)
>
> If we had it wired up for eg the old IDE drivers, it would have shown up
> quite quickly as well I think.

I am getting errors now and my system will not boot up. The system is
connected to storage with active / passive paths. If we are doing a
BLKPREP_KILL we will call elv_dequeue_request which will add the
timer for the request we are killing.

The attached patch is a quick patch to work around my issue, but we
probably need something better. I would like to run some short timeout
testing on it for a while (though that previously did not catch Tejun's
issue). I will look at this more tomorrow unless someone beats me to it.

-andmike
--
Michael Anderson
[email protected]

1.) Dmesg
[ 35.104483] Buffer I/O error on device sda, logical block 0
[ 35.104493] ------------[ cut here ]------------
[ 35.104496] WARNING: at
/home/data/xbuild/source/linux-2.6_work/lib/list_debug.c:30
__list_add+0x6e/0x87()
[ 35.104499] list_add corruption. prev->next should be next
(ffff88007c5be568), but was ffff88007bd3ce88. (prev=ffff88007bd3ce88).
[ 35.104501] Modules linked in: sd_mod(+) usbcore(+) dm_snapshot dm_mod
edd ext3 jbd fan mptsas mptscsih mptbase scsi_transport_sas lpfc
scsi_transport_fc scsi_dh_rdac scsi_dh scsi_mod thermal processor
[ 35.104512] Pid: 1168, comm: modprobe Not tainted
2.6.28-rc2-00044-g9678cc9 #1
[ 35.104514] Call Trace:
[ 35.104521] [<ffffffff8023a368>] warn_slowpath+0xae/0xd5
[ 35.104527] [<ffffffff80256daf>] ? trace_hardirqs_off+0xd/0xf
[ 35.104531] [<ffffffff8025ad17>] ? __lock_acquire+0x1541/0x155d
[ 35.104537] [<ffffffff80457e17>] ? printk+0x67/0x70
[ 35.104542] [<ffffffff80335106>] ? __ratelimit+0xb6/0xc0
[ 35.104546] [<ffffffff80387d9e>] ? mix_pool_bytes_extract+0x13e/0x14d
[ 35.104549] [<ffffffff80256daf>] ? trace_hardirqs_off+0xd/0xf
[ 35.104553] [<ffffffff8045acb9>] ? _spin_unlock_irqrestore+0x38/0x47
[ 35.104556] [<ffffffff8033b96b>] __list_add+0x6e/0x87
[ 35.104561] [<ffffffff80327c6a>] blk_add_timer+0x99/0xe4
[ 35.104564] [<ffffffff803219d4>] elv_dequeue_request+0x53/0x55
[ 35.104567] [<ffffffff80323395>] end_that_request_last+0x4b/0x1e5
[ 35.104570] [<ffffffff80323610>] __blk_end_request+0x3c/0x45
[ 35.104572] [<ffffffff80321b9c>] elv_next_request+0x1c6/0x234
[ 35.104576] [<ffffffff80243777>] ? lock_timer_base+0x26/0x4a
[ 35.104608] [<ffffffffa0028d0a>] scsi_request_fn+0x93/0x510 [scsi_mod]
[ 35.104611] [<ffffffff80323e02>] __generic_unplug_device+0x27/0x2c
[ 35.104614] [<ffffffff80323e2b>] blk_start_queueing+0x24/0x26
[ 35.104617] [<ffffffff8032ec40>] cfq_insert_request+0x333/0x352
[ 35.104620] [<ffffffff80321dff>] elv_insert+0x1f5/0x29e
[ 35.104622] [<ffffffff80321f3e>] __elv_add_request+0x96/0x9f
[ 35.104625] [<ffffffff803249d6>] __make_request+0x405/0x46e
[ 35.104628] [<ffffffff80258eed>] ? trace_hardirqs_on_caller+0xf9/0x124
[ 35.104631] [<ffffffff8032306b>] generic_make_request+0x3a6/0x3e9
[ 35.104635] [<ffffffff8027c1e3>] ? mempool_alloc+0x5b/0x113
[ 35.104638] [<ffffffff80323161>] submit_bio+0xb3/0xbc
[ 35.104643] [<ffffffff802c650f>] submit_bh+0xea/0x10e
[ 35.104647] [<ffffffff802c98a3>] block_read_full_page+0x273/0x292
[ 35.104650] [<ffffffff802cb011>] ? blkdev_get_block+0x0/0x5d
[ 35.104652] [<ffffffff80279dd3>] ? __lock_page+0x63/0x6a
[ 35.104656] [<ffffffff802cc502>] blkdev_readpage+0x13/0x15
[ 35.104658] [<ffffffff8027a454>] read_cache_page_async+0x118/0x143
[ 35.104661] [<ffffffff802cc4ef>] ? blkdev_readpage+0x0/0x15
[ 35.104663] [<ffffffff8027a48d>] read_cache_page+0xe/0x46
[ 35.104668] [<ffffffff802f03a0>] read_dev_sector+0x2e/0x93
[ 35.104671] [<ffffffff802f411f>] read_lba+0x5b/0xb3
[ 35.104674] [<ffffffff80258f25>] ? trace_hardirqs_on+0xd/0xf
[ 35.104677] [<ffffffff802f43cb>] efi_partition+0x9f/0x5f8
[ 35.104679] [<ffffffff80258f25>] ? trace_hardirqs_on+0xd/0xf
[ 35.104682] [<ffffffff80258eed>] ? trace_hardirqs_on_caller+0xf9/0x124
[ 35.104686] [<ffffffff802f0bb2>] rescan_partitions+0x159/0x2e1
[ 35.104693] [<ffffffffa01a047a>] ? sd_open+0xcd/0x18d [sd_mod]
[ 35.104695] [<ffffffff802cbf4b>] __blkdev_get+0x1ff/0x2cf
[ 35.104699] [<ffffffff80332697>] ? kobject_put+0x47/0x4b
[ 35.104701] [<ffffffff802cc026>] blkdev_get+0xb/0xd
[ 35.104704] [<ffffffff802f04e5>] register_disk+0xe0/0x145
[ 35.104707] [<ffffffff80329280>] add_disk+0xc0/0x124
[ 35.104711] [<ffffffffa01a1fa8>] sd_probe+0x2c6/0x39e [sd_mod]
[ 35.104715] [<ffffffff802f6c1e>] ? sysfs_create_link+0xe/0x10
[ 35.104719] [<ffffffff803ad9f2>] driver_probe_device+0xc0/0x16e
[ 35.104721] [<ffffffff803adb02>] __driver_attach+0x62/0x8c
[ 35.104724] [<ffffffff803adaa0>] ? __driver_attach+0x0/0x8c
[ 35.104726] [<ffffffff803ad269>] bus_for_each_dev+0x52/0x8c
[ 35.104729] [<ffffffff803ad83a>] driver_attach+0x1c/0x1e
[ 35.104731] [<ffffffff803acb2a>] bus_add_driver+0xba/0x207
[ 35.104734] [<ffffffff803adcf6>] driver_register+0xab/0x12b
[ 35.104749] [<ffffffffa002dcbc>] scsi_register_driver+0x11/0x13
[scsi_mod]
[ 35.104752] [<ffffffffa01ac0a4>] init_sd+0xa4/0xff [sd_mod]
[ 35.104756] [<ffffffffa01ac000>] ? init_sd+0x0/0xff [sd_mod]
[ 35.104760] [<ffffffff80209058>] _stext+0x58/0x138
[ 35.104763] [<ffffffff80256daf>] ? trace_hardirqs_off+0xd/0xf
[ 35.104766] [<ffffffff8045acb9>] ? _spin_unlock_irqrestore+0x38/0x47
[ 35.104769] [<ffffffff80233a6c>] ? try_to_wake_up+0x186/0x198
[ 35.104772] [<ffffffff80258f25>] ? trace_hardirqs_on+0xd/0xf
[ 35.104775] [<ffffffff80258eed>] ? trace_hardirqs_on_caller+0xf9/0x124
[ 35.104780] [<ffffffff802642a7>] sys_init_module+0xab/0x1bc
[ 35.104783] [<ffffffff8020be9b>] system_call_fastpath+0x16/0x1b
[ 35.104785] ---[ end trace 08ddd733955d992c ]---
[

2.) Patch

>From 698916fcee612e84ecce89f27ea66dd5f21bc351 Mon Sep 17 00:00:00 2001
From: Mike Anderson <[email protected]>
Date: Thu, 30 Oct 2008 02:16:20 -0700
Subject: [PATCH 1/1] blk: move blk_delete_timer call in end_that_request_last

Move the calling blk_delete_timer to later in end_that_request_last to
address an issue where blkdev_dequeue_request may have add a timer for the
request.

Signed-off-by: Mike Anderson <[email protected]>
---
block/blk-core.c | 4 ++--
1 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/block/blk-core.c b/block/blk-core.c
index c3df30c..10e8a64 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -1770,8 +1770,6 @@ static void end_that_request_last(struct request *req, int error)
{
struct gendisk *disk = req->rq_disk;

- blk_delete_timer(req);
-
if (blk_rq_tagged(req))
blk_queue_end_tag(req->q, req);

@@ -1781,6 +1779,8 @@ static void end_that_request_last(struct request *req, int error)
if (unlikely(laptop_mode) && blk_fs_request(req))
laptop_io_completion();

+ blk_delete_timer(req);
+
/*
* Account IO completion. bar_rq isn't accounted as a normal
* IO on queueing nor completion. Accounting the containing
--
1.5.6.5

2008-10-30 09:34:32

by Tejun Heo

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

Mike Anderson wrote:
> Jens Axboe <[email protected]> wrote:
>> On Thu, Oct 30 2008, Tejun Heo wrote:
>>> Jens Axboe wrote:
>>>> That's actually a pretty dumb error, I'm surprised it hasn't reared its
>>>> ugly face in more ways. Presumably because the timeout is usually so
>>>> long, that we'll get to actually issuing and completing it within the
>>>> normal timeout anyway.
>>> Heh... it showed its ugly face in many different ways while I was
>>> playing with PMP connected via a very long eSATA cable.
>> Ah :-)
>>
>> If we had it wired up for eg the old IDE drivers, it would have shown up
>> quite quickly as well I think.
>
> I am getting errors now and my system will not boot up. The system is
> connected to storage with active / passive paths. If we are doing a
> BLKPREP_KILL we will call elv_dequeue_request which will add the
> timer for the request we are killing.
>
> The attached patch is a quick patch to work around my issue, but we
> probably need something better. I would like to run some short timeout
> testing on it for a while (though that previously did not catch Tejun's
> issue). I will look at this more tomorrow unless someone beats me to it.

Aieee... I'm now trying to clean up the command fetch/completion
interface. Please give me a day or two. I'll clean it all up.

Thanks.

--
tejun

2008-10-30 09:51:47

by Tejun Heo

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

Mike Anderson wrote:
> From: Mike Anderson <[email protected]>
> Date: Thu, 30 Oct 2008 02:16:20 -0700
> Subject: [PATCH 1/1] blk: move blk_delete_timer call in end_that_request_last
>
> Move the calling blk_delete_timer to later in end_that_request_last to
> address an issue where blkdev_dequeue_request may have add a timer for the
> request.
>
> Signed-off-by: Mike Anderson <[email protected]>

This patch definitely is necessary.

Acked-by: Tejun Heo <[email protected]>

Thanks.

--
tejun

2008-10-30 11:16:16

by Jens Axboe

[permalink] [raw]
Subject: Re: [PATCH] block: add timer on blkdev_dequeue_request() not elv_next_request()

On Thu, Oct 30 2008, Mike Anderson wrote:
> Jens Axboe <[email protected]> wrote:
> > On Thu, Oct 30 2008, Tejun Heo wrote:
> > > Jens Axboe wrote:
> > > > That's actually a pretty dumb error, I'm surprised it hasn't reared its
> > > > ugly face in more ways. Presumably because the timeout is usually so
> > > > long, that we'll get to actually issuing and completing it within the
> > > > normal timeout anyway.
> > >
> > > Heh... it showed its ugly face in many different ways while I was
> > > playing with PMP connected via a very long eSATA cable.
> >
> > Ah :-)
> >
> > If we had it wired up for eg the old IDE drivers, it would have shown up
> > quite quickly as well I think.
>
> I am getting errors now and my system will not boot up. The system is
> connected to storage with active / passive paths. If we are doing a
> BLKPREP_KILL we will call elv_dequeue_request which will add the
> timer for the request we are killing.
>
> The attached patch is a quick patch to work around my issue, but we
> probably need something better. I would like to run some short timeout
> testing on it for a while (though that previously did not catch Tejun's
> issue). I will look at this more tomorrow unless someone beats me to it.
>
> -andmike
> --
> Michael Anderson
> [email protected]
>
> 1.) Dmesg
> [ 35.104483] Buffer I/O error on device sda, logical block 0
> [ 35.104493] ------------[ cut here ]------------
> [ 35.104496] WARNING: at
> /home/data/xbuild/source/linux-2.6_work/lib/list_debug.c:30
> __list_add+0x6e/0x87()
> [ 35.104499] list_add corruption. prev->next should be next
> (ffff88007c5be568), but was ffff88007bd3ce88. (prev=ffff88007bd3ce88).
> [ 35.104501] Modules linked in: sd_mod(+) usbcore(+) dm_snapshot dm_mod
> edd ext3 jbd fan mptsas mptscsih mptbase scsi_transport_sas lpfc
> scsi_transport_fc scsi_dh_rdac scsi_dh scsi_mod thermal processor
> [ 35.104512] Pid: 1168, comm: modprobe Not tainted
> 2.6.28-rc2-00044-g9678cc9 #1
> [ 35.104514] Call Trace:
> [ 35.104521] [<ffffffff8023a368>] warn_slowpath+0xae/0xd5
> [ 35.104527] [<ffffffff80256daf>] ? trace_hardirqs_off+0xd/0xf
> [ 35.104531] [<ffffffff8025ad17>] ? __lock_acquire+0x1541/0x155d
> [ 35.104537] [<ffffffff80457e17>] ? printk+0x67/0x70
> [ 35.104542] [<ffffffff80335106>] ? __ratelimit+0xb6/0xc0
> [ 35.104546] [<ffffffff80387d9e>] ? mix_pool_bytes_extract+0x13e/0x14d
> [ 35.104549] [<ffffffff80256daf>] ? trace_hardirqs_off+0xd/0xf
> [ 35.104553] [<ffffffff8045acb9>] ? _spin_unlock_irqrestore+0x38/0x47
> [ 35.104556] [<ffffffff8033b96b>] __list_add+0x6e/0x87
> [ 35.104561] [<ffffffff80327c6a>] blk_add_timer+0x99/0xe4
> [ 35.104564] [<ffffffff803219d4>] elv_dequeue_request+0x53/0x55
> [ 35.104567] [<ffffffff80323395>] end_that_request_last+0x4b/0x1e5
> [ 35.104570] [<ffffffff80323610>] __blk_end_request+0x3c/0x45
> [ 35.104572] [<ffffffff80321b9c>] elv_next_request+0x1c6/0x234
> [ 35.104576] [<ffffffff80243777>] ? lock_timer_base+0x26/0x4a
> [ 35.104608] [<ffffffffa0028d0a>] scsi_request_fn+0x93/0x510 [scsi_mod]
> [ 35.104611] [<ffffffff80323e02>] __generic_unplug_device+0x27/0x2c
> [ 35.104614] [<ffffffff80323e2b>] blk_start_queueing+0x24/0x26
> [ 35.104617] [<ffffffff8032ec40>] cfq_insert_request+0x333/0x352
> [ 35.104620] [<ffffffff80321dff>] elv_insert+0x1f5/0x29e
> [ 35.104622] [<ffffffff80321f3e>] __elv_add_request+0x96/0x9f
> [ 35.104625] [<ffffffff803249d6>] __make_request+0x405/0x46e
> [ 35.104628] [<ffffffff80258eed>] ? trace_hardirqs_on_caller+0xf9/0x124
> [ 35.104631] [<ffffffff8032306b>] generic_make_request+0x3a6/0x3e9
> [ 35.104635] [<ffffffff8027c1e3>] ? mempool_alloc+0x5b/0x113
> [ 35.104638] [<ffffffff80323161>] submit_bio+0xb3/0xbc
> [ 35.104643] [<ffffffff802c650f>] submit_bh+0xea/0x10e
> [ 35.104647] [<ffffffff802c98a3>] block_read_full_page+0x273/0x292
> [ 35.104650] [<ffffffff802cb011>] ? blkdev_get_block+0x0/0x5d
> [ 35.104652] [<ffffffff80279dd3>] ? __lock_page+0x63/0x6a
> [ 35.104656] [<ffffffff802cc502>] blkdev_readpage+0x13/0x15
> [ 35.104658] [<ffffffff8027a454>] read_cache_page_async+0x118/0x143
> [ 35.104661] [<ffffffff802cc4ef>] ? blkdev_readpage+0x0/0x15
> [ 35.104663] [<ffffffff8027a48d>] read_cache_page+0xe/0x46
> [ 35.104668] [<ffffffff802f03a0>] read_dev_sector+0x2e/0x93
> [ 35.104671] [<ffffffff802f411f>] read_lba+0x5b/0xb3
> [ 35.104674] [<ffffffff80258f25>] ? trace_hardirqs_on+0xd/0xf
> [ 35.104677] [<ffffffff802f43cb>] efi_partition+0x9f/0x5f8
> [ 35.104679] [<ffffffff80258f25>] ? trace_hardirqs_on+0xd/0xf
> [ 35.104682] [<ffffffff80258eed>] ? trace_hardirqs_on_caller+0xf9/0x124
> [ 35.104686] [<ffffffff802f0bb2>] rescan_partitions+0x159/0x2e1
> [ 35.104693] [<ffffffffa01a047a>] ? sd_open+0xcd/0x18d [sd_mod]
> [ 35.104695] [<ffffffff802cbf4b>] __blkdev_get+0x1ff/0x2cf
> [ 35.104699] [<ffffffff80332697>] ? kobject_put+0x47/0x4b
> [ 35.104701] [<ffffffff802cc026>] blkdev_get+0xb/0xd
> [ 35.104704] [<ffffffff802f04e5>] register_disk+0xe0/0x145
> [ 35.104707] [<ffffffff80329280>] add_disk+0xc0/0x124
> [ 35.104711] [<ffffffffa01a1fa8>] sd_probe+0x2c6/0x39e [sd_mod]
> [ 35.104715] [<ffffffff802f6c1e>] ? sysfs_create_link+0xe/0x10
> [ 35.104719] [<ffffffff803ad9f2>] driver_probe_device+0xc0/0x16e
> [ 35.104721] [<ffffffff803adb02>] __driver_attach+0x62/0x8c
> [ 35.104724] [<ffffffff803adaa0>] ? __driver_attach+0x0/0x8c
> [ 35.104726] [<ffffffff803ad269>] bus_for_each_dev+0x52/0x8c
> [ 35.104729] [<ffffffff803ad83a>] driver_attach+0x1c/0x1e
> [ 35.104731] [<ffffffff803acb2a>] bus_add_driver+0xba/0x207
> [ 35.104734] [<ffffffff803adcf6>] driver_register+0xab/0x12b
> [ 35.104749] [<ffffffffa002dcbc>] scsi_register_driver+0x11/0x13
> [scsi_mod]
> [ 35.104752] [<ffffffffa01ac0a4>] init_sd+0xa4/0xff [sd_mod]
> [ 35.104756] [<ffffffffa01ac000>] ? init_sd+0x0/0xff [sd_mod]
> [ 35.104760] [<ffffffff80209058>] _stext+0x58/0x138
> [ 35.104763] [<ffffffff80256daf>] ? trace_hardirqs_off+0xd/0xf
> [ 35.104766] [<ffffffff8045acb9>] ? _spin_unlock_irqrestore+0x38/0x47
> [ 35.104769] [<ffffffff80233a6c>] ? try_to_wake_up+0x186/0x198
> [ 35.104772] [<ffffffff80258f25>] ? trace_hardirqs_on+0xd/0xf
> [ 35.104775] [<ffffffff80258eed>] ? trace_hardirqs_on_caller+0xf9/0x124
> [ 35.104780] [<ffffffff802642a7>] sys_init_module+0xab/0x1bc
> [ 35.104783] [<ffffffff8020be9b>] system_call_fastpath+0x16/0x1b
> [ 35.104785] ---[ end trace 08ddd733955d992c ]---
> [
>
> 2.) Patch
>
> From 698916fcee612e84ecce89f27ea66dd5f21bc351 Mon Sep 17 00:00:00 2001
> From: Mike Anderson <[email protected]>
> Date: Thu, 30 Oct 2008 02:16:20 -0700
> Subject: [PATCH 1/1] blk: move blk_delete_timer call in end_that_request_last
>
> Move the calling blk_delete_timer to later in end_that_request_last to
> address an issue where blkdev_dequeue_request may have add a timer for the
> request.
>
> Signed-off-by: Mike Anderson <[email protected]>
> ---
> block/blk-core.c | 4 ++--
> 1 files changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/block/blk-core.c b/block/blk-core.c
> index c3df30c..10e8a64 100644
> --- a/block/blk-core.c
> +++ b/block/blk-core.c
> @@ -1770,8 +1770,6 @@ static void end_that_request_last(struct request *req, int error)
> {
> struct gendisk *disk = req->rq_disk;
>
> - blk_delete_timer(req);
> -
> if (blk_rq_tagged(req))
> blk_queue_end_tag(req->q, req);
>
> @@ -1781,6 +1779,8 @@ static void end_that_request_last(struct request *req, int error)
> if (unlikely(laptop_mode) && blk_fs_request(req))
> laptop_io_completion();
>
> + blk_delete_timer(req);
> +
> /*
> * Account IO completion. bar_rq isn't accounted as a normal
> * IO on queueing nor completion. Accounting the containing
> --
> 1.5.6.5

Good catch, I queued this up for 2.6.28 (and added Tejuns ack).


--
Jens Axboe