Re: v4.20-rc6: Sporadic use-after-free in bt_iter()

[Jens Axboe <axboe@kernel.dk>]

On 12/19/18 5:16 PM, Bart Van Assche wrote:
> On Wed, 2018-12-19 at 16:27 -0700, Jens Axboe wrote:
>> On 12/19/18 4:24 PM, Bart Van Assche wrote:
>>> Hello,
>>>
>>> If I run the srp blktests in a loop then I see the below call stack appearing
>>> sporadically. I have not yet had the time to analyze this but I'm reporting
>>> this here in case someone else would already have had a look at this.
>>>
>>> Bart.
>>>
>>> ==================================================================
>>> BUG: KASAN: use-after-free in bt_iter+0x86/0xf0
>>> Read of size 8 at addr ffff88803b335240 by task fio/21412
>>>
>>> CPU: 0 PID: 21412 Comm: fio Tainted: G        W         4.20.0-rc6-dbg+ #3
>>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
>>> Call Trace:
>>>  dump_stack+0x86/0xca
>>>  print_address_description+0x71/0x239
>>>  kasan_report.cold.5+0x242/0x301
>>>  __asan_load8+0x54/0x90
>>>  bt_iter+0x86/0xf0
>>>  blk_mq_queue_tag_busy_iter+0x373/0x5e0
>>>  blk_mq_in_flight+0x96/0xb0
>>>  part_in_flight+0x40/0x140
>>>  part_round_stats+0x18e/0x370
>>>  blk_account_io_start+0x3d7/0x670
>>>  blk_mq_bio_to_request+0x19c/0x3a0
>>>  blk_mq_make_request+0x7a9/0xcb0
>>>  generic_make_request+0x41d/0x960
>>>  submit_bio+0x9b/0x250
>>>  do_blockdev_direct_IO+0x435c/0x4c70
>>>  __blockdev_direct_IO+0x79/0x88
>>>  ext4_direct_IO+0x46c/0xc00
>>>  generic_file_direct_write+0x119/0x210
>>>  __generic_file_write_iter+0x11c/0x280
>>>  ext4_file_write_iter+0x1b8/0x6f0
>>>  aio_write+0x204/0x310
>>>  io_submit_one+0x9d3/0xe80
>>>  __x64_sys_io_submit+0x115/0x340
>>>  do_syscall_64+0x71/0x210
>>>  entry_SYSCALL_64_after_hwframe+0x49/0xbe
>>> RIP: 0033:0x7f02cf043219
>>
>> I've seen this one before as well, it's not a new thing. As far as I can
>> tell, it's a false positive. There should be no possibility for a
>> use-after-free iterating the static tags/requests.
> 
> Are you sure this is a false positive?

No I'm not, but the few times I have seen it, I haven't been able to
make much sense of it. It goes back quite a bit.

I have not yet encountered any false
> positive KASAN complaints. According to the following gdb output this complaint
> refers to reading rq->q:
> 
> (gdb) list *(bt_iter+0x86)
> 0xffffffff816b9346 is in bt_iter (block/blk-mq-tag.c:237).
> 232
> 233             /*
> 234              * We can hit rq == NULL here, because the tagging functions
> 235              * test and set the bit before assigning ->rqs[].
> 236              */
> 237             if (rq && rq->q == hctx->queue)
> 238                     iter_data->fn(hctx, rq, iter_data->data, reserved);
> 239             return true;
> 240     }
> 241
> 
> From the disassembly output:
> 
> 232
> 233             /*
> 234              * We can hit rq == NULL here, because the tagging functions
> 235              * test and set the bit before assigning ->rqs[].
> 236              */
> 237             if (rq && rq->q == hctx->queue)
>    0xffffffff816b9339 <+121>:   test   %r12,%r12
>    0xffffffff816b933c <+124>:   je     0xffffffff816b935f <bt_iter+159>
>    0xffffffff816b933e <+126>:   mov    %r12,%rdi
>    0xffffffff816b9341 <+129>:   callq  0xffffffff813bd3e0 <__asan_load8>
>    0xffffffff816b9346 <+134>:   lea    0x138(%r13),%rdi
>    0xffffffff816b934d <+141>:   mov    (%r12),%r14
>    0xffffffff816b9351 <+145>:   callq  0xffffffff813bd3e0 <__asan_load8>
>    0xffffffff816b9356 <+150>:   cmp    0x138(%r13),%r14
>    0xffffffff816b935d <+157>:   je     0xffffffff816b936f <bt_iter+175>
> 
> BTW, rq may but does not have to refer to tags->static_rqs[...]. It may also
> refer to hctx->fq.flush_rq.

But even those are persistent for the lifetime of the queue... But since
kasan complains it belongs to a specific page, I'm guessing it's one
of the regular requests since those are out of a chopped up page. Which
means it makes even less sense.

Is this happening while devices are being actively torn down? And
are you using shared tags? That's the only way I could see this
triggering.

-- 
Jens Axboe