Re: [GIT PULL] Queue free fix (was Re: [PATCH] block: Free queueresources at blk_release_queue())

From: Hannes Reinecke
Date: Fri Nov 04 2011 - 09:37:36 EST


On 11/04/2011 02:30 PM, Mike Snitzer wrote:
On Fri, Nov 04 2011 at 5:19am -0400,
Heiko Carstens<heiko.carstens@xxxxxxxxxx> wrote:

On Thu, Nov 03, 2011 at 02:25:48PM -0400, Mike Snitzer wrote:
On Mon, Oct 31 2011 at 9:00am -0400,
Heiko Carstens<heiko.carstens@xxxxxxxxxx> wrote:

On Mon, Oct 31, 2011 at 08:46:06PM +0900, Jun'ichi Nomura wrote:
Hm, dm_softirq_done is generic completion code of original
request in dm-multipath.
So oops here might be another manifestation of use-after-free.

Do you always hit the oops at the same address?

I think we saw this bug the first time. But before that the scsi
logging level was higher. Gonzalo is trying to recreate it with
the same (old) scsi logging level.
Afterwards we will try with barrier=0.

Both on v3.0.7 btw.

Could you find corresponding source code line for
the crashed address, dm_softirq_done+0x72/0x140,
and which pointer was invalid?

It crashes in the inlined function dm_done() when trying to
dereference tio (aka clone->end_io_data):

static void dm_done(struct request *clone, int error, bool mapped)
{
int r = error;
struct dm_rq_target_io *tio = clone->end_io_data;
dm_request_endio_fn rq_end_io = tio->ti->type->rq_end_io;

Hi,

Which underlying storage driver is being used by this multipath device?

It's the s390 only zfcp device driver.

FWIW, yet another use-after-free crash, this time however in multipath_end_io:

[96875.870593] Unable to handle kernel pointer dereference at virtual kernel address 6b6b6b6b6b6b6000
[96875.870602] Oops: 0038 [#1]
[96875.870674] PREEMPT SMP DEBUG_PAGEALLOC
[96875.870683] Modules linked in: dm_round_robin sunrpc ipv6 qeth_l2 binfmt_misc dm_multipath scsi_dh dm_mod qeth ccwgroup [la\
st unloaded: scsi_wait_scan]
[96875.870722] CPU: 2 Tainted: G W 3.0.7-50.x.20111024-s390xdefault #1
[96875.870728] Process udevd (pid: 36697, task: 0000000072c8a3a8, ksp: 0000000057c43868)
[96875.870732] Krnl PSW : 0704200180000000 000003e001347138 (multipath_end_io+0x50/0x140 [dm_multipath])
[96875.870746] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:0 CC:2 PM:0 EA:3
[96875.870751] Krnl GPRS: 0000000000000000 000003e000000000 6b6b6b6b6b6b6b6b 00000000717ab940
[96875.870755] 0000000000000000 00000000717abab0 0000000000000002 0700000000000008
[96875.870759] 0000000000000002 0000000000000000 0000000058dd37a8 000000006f845478
[96875.870764] 000003e0012e1000 000000005613d1f0 000000007a737bf0 000000007a737ba0
[96875.870768] Krnl Code: 000003e00134712a: b90200dd ltgr %r13,%r13
[96875.870793] 000003e00134712e: a7840017 brc 8,3e00134715c
[96875.870800] 000003e001347132: e320d0100004 lg %r2,16(%r13)
[96875.870809]>000003e001347138: e31020180004 lg %r1,24(%r2)
[96875.870818] 000003e00134713e: e31010580004 lg %r1,88(%r1)
[96875.870827] 000003e001347144: b9020011 ltgr %r1,%r1
[96875.870835] 000003e001347148: a784000a brc 8,3e00134715c
[96875.870841] 000003e00134714c: 41202018 la %r2,24(%r2)
[96875.870889] Call Trace:
[96875.870892] ([<0700000000000008>] 0x700000000000008)
[96875.870897] [<000003e0012e3662>] dm_softirq_done+0x9a/0x140 [dm_mod]
[96875.870915] [<000000000040d29c>] blk_done_softirq+0xd4/0xf0
[96875.870925] [<00000000001587c2>] __do_softirq+0xda/0x398
[96875.870932] [<000000000010f47e>] do_softirq+0xe2/0xe8
[96875.870940] [<0000000000158e2c>] irq_exit+0xc8/0xcc
[96875.870945] [<00000000004ceb48>] do_IRQ+0x910/0x1bfc
[96875.870953] [<000000000061a164>] io_return+0x0/0x16
[96875.870961] [<000000000019c84e>] lock_acquire+0xd2/0x204
[96875.870969] ([<000000000019c836>] lock_acquire+0xba/0x204)
[96875.870974] [<0000000000615f8e>] mutex_lock_killable_nested+0x92/0x520
[96875.870983] [<0000000000292796>] vfs_readdir+0x8a/0xe4
[96875.870992] [<00000000002928e0>] SyS_getdents+0x60/0xe8
[96875.870999] [<0000000000619af2>] sysc_noemu+0x16/0x1c
[96875.871024] [<000003fffd1ec83e>] 0x3fffd1ec83e
[96875.871028] INFO: lockdep is turned off.
[96875.871031] Last Breaking-Event-Address:
[96875.871037] [<000003e0012e3660>] dm_softirq_done+0x98/0x140 [dm_mod]

static int multipath_end_io(struct dm_target *ti, struct request *clone,
int error, union map_info *map_context)
{
struct multipath *m = ti->private;
struct dm_mpath_io *mpio = map_context->ptr;
struct pgpath *pgpath = mpio->pgpath;
struct path_selector *ps;
int r;

r = do_end_io(m, clone, error, mpio);
if (pgpath) {
ps =&pgpath->pg->ps;<--- crashes here
if (ps->type->end_io)
ps->type->end_io(ps,&pgpath->path, mpio->nr_bytes);
}
mempool_free(mpio, m->mpio_pool);

return r;
}

It crashes when trying to derefence pgpath, which was freed. Since we have
SLUB debugging turned on the freed object tells us that it was allocated
via a call to multipath_ctr() and freed via a call to free_priority_group().

FWIW, this reproduction was done with barriers off.

Btw, since I cc'ed you rather late I'm not sure if you are aware of the
test scenario: it's I/O stress with multipathing were paths come and go
all the time. It usually takes quite a few hours before the crashes are
observed.

OK, thanks for the backstory.

That is the same type of testing we've been doing with some partners
for RHEL6.2 with the qla2xxx driver. They have seen the same crash that
you originally reported here: https://lkml.org/lkml/2011/10/31/64

The really interesting observation that was made is that the qla2xxx
driver was made lockless in RHEL6.2. We've found that reverting the
qla2xxx lockless changes eliminates the problems seen with it and I/O
stress testing with multipath path failures.

The zfcp driver was also made lockless upstream, via this commit:
e55f875 [SCSI] zfcp: Issue FCP command without holding SCSI host_lock

It would be great if you could try reverting e55f875 and see how your
testing goes.

If doing so resolves the crashes for you then the post mortem on why
these lockless SCSI driver changes are causing such odd multipath
completion failures is going to be "fun" ;)

And before anyone asks:

We will _not_ be reverting the lockless changes.

Cheers,

Hannes
--
Dr. Hannes Reinecke zSeries & Storage
hare@xxxxxxx +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/