[REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[John Garry]

Hi guys,

JFYI, While doing some testing on v5.9-rc1, I stumbled across this:

[  218.792457] 
==================================================================
[  218.799686] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8
[  218.805248] Read of size 8 at addr ffff002a084d8a00 by task fio/1554
[  218.811589]
[  218.813074] CPU: 37 PID: 1554 Comm: fio Not tainted 
5.9.0-rc1-31278-g9689aa7be1cb-dirty #755
[  218.821499] Hardware name: Huawei D06 /D06, BIOS Hisilicon D06 UEFI 
RC0 - V1.16.01 03/15/2019
[  218.830012] Call trace:
[  218.832453]  dump_backtrace+0x0/0x2d0
[  218.836106]  show_stack+0x18/0x28
[  218.839412]  dump_stack+0xf4/0x168
[  218.842806]  print_address_description.constprop.12+0x6c/0x4ec
[  218.848628]  kasan_report+0x130/0x200
[  218.852279]  __asan_load8+0x9c/0xd8
[  218.855757]  bt_iter+0x80/0xf8
[  218.858801]  blk_mq_queue_tag_busy_iter+0x2dc/0x528
[  218.863670]  blk_mq_in_flight+0x80/0xb8
[  218.867496]  part_stat_show+0xd8/0x238
[  218.871237]  dev_attr_show+0x44/0x90
[  218.874804]  sysfs_kf_seq_show+0x128/0x1c0
[  218.878890]  kernfs_seq_show+0xa0/0xb8
[  218.882630]  seq_read+0x1c0/0x7d0
[  218.885935]  kernfs_fop_read+0x70/0x330
[  218.889762]  vfs_read+0xe4/0x250
[  218.892980]  ksys_read+0xc8/0x178
[  218.896285]  __arm64_sys_read+0x44/0x58
[  218.900112]  el0_svc_common.constprop.2+0xc4/0x1e8
[  218.904893]  do_el0_svc+0x90/0xa0
[  218.908198]  el0_sync_handler+0x150/0x1b8
[  218.912196]  el0_sync+0x158/0x180
[  218.915498]
[  218.916979] Allocated by task 1553:
[  218.920459]  kasan_save_stack+0x28/0x58
[  218.924284]  __kasan_kmalloc.isra.6+0xcc/0xf0
[  218.928630]  kasan_slab_alloc+0x18/0x28
[  218.932457]  slab_post_alloc_hook+0x64/0x2b8
[  218.936717]  kmem_cache_alloc+0x160/0x260
[  218.940719]  getname_flags+0x68/0x240
[  218.944371]  user_path_at_empty+0x30/0x68
[  218.948370]  vfs_statx+0xf8/0x200
[  218.951674]  __do_sys_newfstatat+0x84/0xd8
[  218.955760]  __arm64_sys_newfstatat+0x54/0x68
[  218.960107]  el0_svc_common.constprop.2+0xc4/0x1e8
[  218.964888]  do_el0_svc+0x90/0xa0
[  218.968192]  el0_sync_handler+0x150/0x1b8
[  218.972191]  el0_sync+0x158/0x180
[  218.975493]
[  218.976974] Freed by task 1553:
[  218.980104]  kasan_save_stack+0x28/0x58
[  218.983928]  kasan_set_track+0x28/0x40
[  218.987667]  kasan_set_free_info+0x24/0x48
[  218.991752]  __kasan_slab_free+0x104/0x188
[  218.995838]  kasan_slab_free+0x14/0x20
[  218.999577]  slab_free_freelist_hook+0x8c/0x190
[  219.004097]  kmem_cache_free+0x98/0x3e0
[  219.007923]  putname+0x8c/0xa8
[  219.010968]  filename_lookup.part.70+0x130/0x1e8
[  219.015575]  user_path_at_empty+0x50/0x68
[  219.019573]  vfs_statx+0xf8/0x200
[  219.022878]  __do_sys_newfstatat+0x84/0xd8
[  219.026963]  __arm64_sys_newfstatat+0x54/0x68
[  219.031310]  el0_svc_common.constprop.2+0xc4/0x1e8
[  219.036091]  do_el0_svc+0x90/0xa0
[  219.039396]  el0_sync_handler+0x150/0x1b8
[  219.043394]  el0_sync+0x158/0x180
[  219.046696]
[  219.048178] The buggy address belongs to the object at ffff002a084d8000
[  219.048178]  which belongs to the cache names_cache of size 4096
[  219.060771] The buggy address is located 2560 bytes inside of
[  219.060771]  4096-byte region [ffff002a084d8000, ffff002a084d9000)
[  219.072668] The buggy address belongs to the page:
[  219.077456] page:0000000099a7b02f refcount:1 mapcount:0 
mapping:0000000000000000 index:0x0 pfn:0x2a084d8
[  219.086924] head:0000000099a7b02f order:3 compound_mapcount:0 
compound_pincount:0
[  219.094396] flags: 0x2ffff00000010200(slab|head)
[  219.099006] raw: 2ffff00000010200 dead000000000100 dead000000000122 
ffff002a53180f00
[  219.106739] raw: 0000000000000000 0000000000070007 00000001ffffffff 
0000000000000000
[  219.114469] page dumped because: kasan: bad access detected
[  219.120028]
[  219.121507] Memory state around the buggy address:
[  219.126287]  ffff002a084d8900: fb fb fb fb fb fb fb fb fb fb fb fb fb 
fb fb fb
[  219.133499]  ffff002a084d8980: fb fb fb fb fb fb fb fb fb fb fb fb fb 
fb fb fb
[  219.140709] >ffff002a084d8a00: fb fb fb fb fb fb fb fb fb fb fb fb fb 
fb fb fb
[  219.147918]  ^
[  219.151135]  ffff002a084d8a80: fb fb fb fb fb fb fb fb fb fb fb fb fb 
fb fb fb
[  219.158347]  ffff002a084d8b00: fb fb fb fb fb fb fb fb fb fb fb fb fb 
fb fb fb
[  219.165555] 
==================================================================

Here's my steps to recreate (some may be redundant):

root@ubuntu:/sys/class/block/sda/queue# more scheduler
[mq-deadline] kyber bfq none
fio /home/john/sda.fio   # just run fio on sda
echo 400 > nr_requests
fio /home/john/sda.fio
echo 30 > nr_requests
fio /home/john/sda.fio
echo none > scheduler
fio /home/john/sda.fio [issue triggered here]

I assume that this is a block issue, I'll have a look when I can.

Cheers,
john

Some config options (in addition to KASAN):
john@htsatcamb-server:~/kernel-dev4$ more .config | grep BLK
CONFIG_BLK_CGROUP=y
CONFIG_BLK_DEV_INITRD=y
CONFIG_CRYPTO_AES_ARM64_CE_BLK=y
CONFIG_CRYPTO_AES_ARM64_NEON_BLK=m
CONFIG_BLK_RQ_ALLOC_TIME=y
CONFIG_BLK_SCSI_REQUEST=y
CONFIG_BLK_CGROUP_RWSTAT=y
CONFIG_BLK_DEV_BSG=y
CONFIG_BLK_DEV_BSGLIB=y
CONFIG_BLK_DEV_INTEGRITY=y
CONFIG_BLK_DEV_INTEGRITY_T10=y
CONFIG_BLK_DEV_ZONED=y
CONFIG_BLK_DEV_THROTTLING=y
# CONFIG_BLK_DEV_THROTTLING_LOW is not set
CONFIG_BLK_CMDLINE_PARSER=y
CONFIG_BLK_WBT=y
CONFIG_BLK_CGROUP_IOLATENCY=y
CONFIG_BLK_CGROUP_IOCOST=y
CONFIG_BLK_WBT_MQ=y
CONFIG_BLK_DEBUG_FS=y
CONFIG_BLK_DEBUG_FS_ZONED=y
CONFIG_BLK_SED_OPAL=y
# CONFIG_BLK_INLINE_ENCRYPTION is not set
CONFIG_BLK_MQ_PCI=y
CONFIG_BLK_MQ_VIRTIO=y
CONFIG_BLK_PM=y
CONFIG_MTD_BLKDEVS=y
CONFIG_BLK_DEV=y
CONFIG_BLK_DEV_NULL_BLK=m
CONFIG_BLK_DEV_PCIESSD_MTIP32XX=y
CONFIG_BLK_DEV_UMEM=y
CONFIG_BLK_DEV_LOOP=y
CONFIG_BLK_DEV_LOOP_MIN_COUNT=8
CONFIG_BLK_DEV_CRYPTOLOOP=y
CONFIG_BLK_DEV_DRBD=y
CONFIG_BLK_DEV_NBD=y
# CONFIG_BLK_DEV_SKD is not set
# CONFIG_BLK_DEV_SX8 is not set
# CONFIG_BLK_DEV_RAM is not set
CONFIG_XEN_BLKDEV_FRONTEND=y
# CONFIG_XEN_BLKDEV_BACKEND is not set
CONFIG_VIRTIO_BLK=y
CONFIG_BLK_DEV_RBD=y
# CONFIG_BLK_DEV_RSXX is not set
# CONFIG_BLK_DEV_NVME is not set
CONFIG_BLK_DEV_SD=y
# CONFIG_BLK_DEV_SR is not set
# CONFIG_BLK_DEV_3W_XXXX_RAID is not set
CONFIG_BLK_DEV_MD=y
CONFIG_BLK_DEV_DM_BUILTIN=y
CONFIG_BLK_DEV_DM=y
# NOTE: USB_STORAGE depends on SCSI but BLK_DEV_SD may
# CONFIG_SQUASHFS_4K_DEVBLK_SIZE is not set
# CONFIG_PSTORE_BLK is not set

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[John Garry]

On 18/08/2020 13:03, John Garry wrote:
> Hi guys,
> 
> JFYI, While doing some testing on v5.9-rc1, I stumbled across this:

I bisected to here (hopefully without mistake):

commit 37f4a24c2469a10a4c16c641671bd766e276cf9f
Author: Ming Lei <ming.lei@redhat.com>
Date:Tue Jun 30 22:03:57 2020 +0800

  blk-mq: centralise related handling into blk_mq_get_driver_tag

  Move .nr_active update and request assignment into 
blk_mq_get_driver_tag(),
  all are good to do during getting driver tag.

  Meantime blk-flush related code is simplified and flush request needn't
  to update the request table manually any more.

  Signed-off-by: Ming Lei <ming.lei@redhat.com>
  Cc: Christoph Hellwig <hch@infradead.org>
  Signed-off-by: Jens Axboe <axboe@kernel.dk>


I'll verify that tomorrow. I see that there is a fix for that patch 
included in v5.9-rc1. Bisect log below:

git bisect start
# bad: [9123e3a74ec7b934a4a099e98af6a61c2f80bbf5] Linux 5.9-rc1
git bisect bad 9123e3a74ec7b934a4a099e98af6a61c2f80bbf5
# good: [bcf876870b95592b52519ed4aafcf9d95999bc9c] Linux 5.8
git bisect good bcf876870b95592b52519ed4aafcf9d95999bc9c
# good: [bcf876870b95592b52519ed4aafcf9d95999bc9c] Linux 5.8
git bisect good bcf876870b95592b52519ed4aafcf9d95999bc9c
# bad: [8186749621ed6b8fc42644c399e8c755a2b6f630] Merge tag 
'drm-next-2020-08-06' of git://anongit.freedesktop.org/drm/drm
git bisect bad 8186749621ed6b8fc42644c399e8c755a2b6f630
# bad: [2324d50d051ec0f14a548e78554fb02513d6dcef] Merge tag 'docs-5.9' 
of git://git.lwn.net/linux
git bisect bad 2324d50d051ec0f14a548e78554fb02513d6dcef
# bad: [92c59e126b21fd212195358a0d296e787e444087] Merge tag 
'arm-defconfig-5.9' of 
git://git.kernel.org/pub/scm/linux/kernel/git/soc/soc
git bisect bad 92c59e126b21fd212195358a0d296e787e444087
# bad: [cdc8fcb49905c0b67e355e027cb462ee168ffaa3] Merge tag 
'for-5.9/io_uring-20200802' of git://git.kernel.dk/linux-block
git bisect bad cdc8fcb49905c0b67e355e027cb462ee168ffaa3
# good: [ab5c60b79ab6cc50b39bbb21b2f9fb55af900b84] Merge branch 'linus' 
of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
git bisect good ab5c60b79ab6cc50b39bbb21b2f9fb55af900b84
# bad: [d958e343bdc3de2643ce25225bed082dc222858d] block: blk-timeout: 
delete duplicated word
git bisect bad d958e343bdc3de2643ce25225bed082dc222858d
# bad: [53042f3cc411adc79811ba3cfbca5d7a42a7b806] ps3vram: stop using 
->queuedata
git bisect bad 53042f3cc411adc79811ba3cfbca5d7a42a7b806
# good: [621c1f42945e76015c3a585e7a9fe6e71665eba0] block: move struct 
block_device to blk_types.h
git bisect good 621c1f42945e76015c3a585e7a9fe6e71665eba0
# good: [36a3df5a4574d5ddf59804fcd0c4e9654c514d9a] blk-mq: put driver 
tag when this request is completed
git bisect good 36a3df5a4574d5ddf59804fcd0c4e9654c514d9a
# good: [570e9b73b0af2e5381ca5343759779b8c1ed20e3] blk-mq: move 
blk_mq_get_driver_tag into blk-mq.c
git bisect good 570e9b73b0af2e5381ca5343759779b8c1ed20e3
# bad: [b5fc1e8bedf8ad2c6381e0df6331ad5686aca425] blk-mq: remove 
pointless call of list_entry_rq() in hctx_show_busy_rq()
git bisect bad b5fc1e8bedf8ad2c6381e0df6331ad5686aca425
# bad: [37f4a24c2469a10a4c16c641671bd766e276cf9f] blk-mq: centralise 
related handling into blk_mq_get_driver_tag
git bisect bad 37f4a24c2469a10a4c16c641671bd766e276cf9f
# good: [723bf178f158abd1ce6069cb049581b3cb003aab] blk-mq: move 
blk_mq_put_driver_tag() into blk-mq.c
git bisect good 723bf178f158abd1ce6069cb049581b3cb003aab
# first bad commit: [37f4a24c2469a10a4c16c641671bd766e276cf9f] blk-mq: 
centralise related handling into blk_mq_get_driver_tag

BTW, only need to change scheduler and not change nr_requests to trigger 
this.

Thanks,
John

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[Ming Lei]

On Tue, Aug 18, 2020 at 07:19:57PM +0100, John Garry wrote:
> On 18/08/2020 13:03, John Garry wrote:
> > Hi guys,
> > 
> > JFYI, While doing some testing on v5.9-rc1, I stumbled across this:
> 
> I bisected to here (hopefully without mistake):

This one is a long-term problem, see the following discussion:

https://lore.kernel.org/linux-block/1553492318-1810-1-git-send-email-jianchao.w.wang@oracle.com/


Thanks,
Ming

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[John Garry]

On 19/08/2020 01:00, Ming Lei wrote:
> On Tue, Aug 18, 2020 at 07:19:57PM +0100, John Garry wrote:
>> On 18/08/2020 13:03, John Garry wrote:
>>> Hi guys,
>>>
>>> JFYI, While doing some testing on v5.9-rc1, I stumbled across this:
>>
>> I bisected to here (hopefully without mistake):
> 
> This one is a long-term problem, see the following discussion:
> 
> https://lore.kernel.org/linux-block/1553492318-1810-1-git-send-email-jianchao.w.wang@oracle.com/
> 
> 

ah, right. I vaguely remember this. Well, if we didn't have a reliable 
reproducer before, we do now.

Thanks,
John

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[Ming Lei]

On Wed, Aug 19, 2020 at 08:43:46AM +0100, John Garry wrote:
> On 19/08/2020 01:00, Ming Lei wrote:
> > On Tue, Aug 18, 2020 at 07:19:57PM +0100, John Garry wrote:
> > > On 18/08/2020 13:03, John Garry wrote:
> > > > Hi guys,
> > > > 
> > > > JFYI, While doing some testing on v5.9-rc1, I stumbled across this:
> > > 
> > > I bisected to here (hopefully without mistake):
> > 
> > This one is a long-term problem, see the following discussion:
> > 
> > https://lore.kernel.org/linux-block/1553492318-1810-1-git-send-email-jianchao.w.wang@oracle.com/
> > 
> > 
> 
> ah, right. I vaguely remember this. Well, if we didn't have a reliable
> reproducer before, we do now.

OK, that is great, please try the following patch:

diff --git a/block/blk-mq-tag.c b/block/blk-mq-tag.c
index 32d82e23b095..f18632c524e9 100644
--- a/block/blk-mq-tag.c
+++ b/block/blk-mq-tag.c
@@ -185,19 +185,19 @@ static bool bt_iter(struct sbitmap *bitmap, unsigned int bitnr, void *data)
 {
 	struct bt_iter_data *iter_data = data;
 	struct blk_mq_hw_ctx *hctx = iter_data->hctx;
-	struct blk_mq_tags *tags = hctx->tags;
+	struct blk_mq_tags *tags = hctx->sched_tags ?: hctx->tags;
 	bool reserved = iter_data->reserved;
 	struct request *rq;
 
 	if (!reserved)
 		bitnr += tags->nr_reserved_tags;
-	rq = tags->rqs[bitnr];
+	rq = tags->static_rqs[bitnr];
 
 	/*
 	 * We can hit rq == NULL here, because the tagging functions
 	 * test and set the bit before assigning ->rqs[].
 	 */
-	if (rq && rq->q == hctx->queue)
+	if (rq && rq->tag >= 0 && rq->q == hctx->queue)
 		return iter_data->fn(hctx, rq, iter_data->data, reserved);
 	return true;
 }
@@ -406,7 +406,7 @@ void blk_mq_queue_tag_busy_iter(struct request_queue *q, busy_iter_fn *fn,
 		return;
 
 	queue_for_each_hw_ctx(q, hctx, i) {
-		struct blk_mq_tags *tags = hctx->tags;
+		struct blk_mq_tags *tags = hctx->sched_tags ?: hctx->tags;
 
 		/*
 		 * If no software queues are currently mapped to this

-- 
Ming

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[John Garry]

On 19/08/2020 09:58, Ming Lei wrote:
>> ah, right. I vaguely remember this. Well, if we didn't have a reliable
>> reproducer before, we do now.
> OK, that is great, please try the following patch:
> 
> diff --git a/block/blk-mq-tag.c b/block/blk-mq-tag.c
> index 32d82e23b095..f18632c524e9 100644
> --- a/block/blk-mq-tag.c
> +++ b/block/blk-mq-tag.c
> @@ -185,19 +185,19 @@ static bool bt_iter(struct sbitmap *bitmap, unsigned int bitnr, void *data)
>   {
>   	struct bt_iter_data *iter_data = data;
>   	struct blk_mq_hw_ctx *hctx = iter_data->hctx;
> -	struct blk_mq_tags *tags = hctx->tags;
> +	struct blk_mq_tags *tags = hctx->sched_tags ?: hctx->tags;
>   	bool reserved = iter_data->reserved;
>   	struct request *rq;
>   
>   	if (!reserved)
>   		bitnr += tags->nr_reserved_tags;
> -	rq = tags->rqs[bitnr];
> +	rq = tags->static_rqs[bitnr];
>   
>   	/*
>   	 * We can hit rq == NULL here, because the tagging functions
>   	 * test and set the bit before assigning ->rqs[].
>   	 */
> -	if (rq && rq->q == hctx->queue)
> +	if (rq && rq->tag >= 0 && rq->q == hctx->queue)
>   		return iter_data->fn(hctx, rq, iter_data->data, reserved);
>   	return true;
>   }
> @@ -406,7 +406,7 @@ void blk_mq_queue_tag_busy_iter(struct request_queue *q, busy_iter_fn *fn,
>   		return;
>   
>   	queue_for_each_hw_ctx(q, hctx, i) {
> -		struct blk_mq_tags *tags = hctx->tags;
> +		struct blk_mq_tags *tags = hctx->sched_tags ?: hctx->tags;
>   
>   		/*
>   		 * If no software queues are currently mapped to this

I gave it a quick try and it looks to silence KASAN. I'll try to test 
more over the next day or so.

BTW, I doubt KASAN is even right to complain about this. I'll check that 
thread you pointed me at to learn more about what was discussed on that.

Thanks,
John

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[Ming Lei]

On Wed, Aug 19, 2020 at 11:14:34AM +0100, John Garry wrote:
> On 19/08/2020 09:58, Ming Lei wrote:
> > > ah, right. I vaguely remember this. Well, if we didn't have a reliable
> > > reproducer before, we do now.
> > OK, that is great, please try the following patch:
> > 
> > diff --git a/block/blk-mq-tag.c b/block/blk-mq-tag.c
> > index 32d82e23b095..f18632c524e9 100644
> > --- a/block/blk-mq-tag.c
> > +++ b/block/blk-mq-tag.c
> > @@ -185,19 +185,19 @@ static bool bt_iter(struct sbitmap *bitmap, unsigned int bitnr, void *data)
> >   {
> >   	struct bt_iter_data *iter_data = data;
> >   	struct blk_mq_hw_ctx *hctx = iter_data->hctx;
> > -	struct blk_mq_tags *tags = hctx->tags;
> > +	struct blk_mq_tags *tags = hctx->sched_tags ?: hctx->tags;
> >   	bool reserved = iter_data->reserved;
> >   	struct request *rq;
> >   	if (!reserved)
> >   		bitnr += tags->nr_reserved_tags;
> > -	rq = tags->rqs[bitnr];
> > +	rq = tags->static_rqs[bitnr];
> >   	/*
> >   	 * We can hit rq == NULL here, because the tagging functions
> >   	 * test and set the bit before assigning ->rqs[].
> >   	 */
> > -	if (rq && rq->q == hctx->queue)
> > +	if (rq && rq->tag >= 0 && rq->q == hctx->queue)
> >   		return iter_data->fn(hctx, rq, iter_data->data, reserved);
> >   	return true;
> >   }
> > @@ -406,7 +406,7 @@ void blk_mq_queue_tag_busy_iter(struct request_queue *q, busy_iter_fn *fn,
> >   		return;
> >   	queue_for_each_hw_ctx(q, hctx, i) {
> > -		struct blk_mq_tags *tags = hctx->tags;
> > +		struct blk_mq_tags *tags = hctx->sched_tags ?: hctx->tags;
> >   		/*
> >   		 * If no software queues are currently mapped to this
> 
> I gave it a quick try and it looks to silence KASAN. I'll try to test more
> over the next day or so.
> 
> BTW, I doubt KASAN is even right to complain about this. I'll check that
> thread you pointed me at to learn more about what was discussed on that.

I guess that elevator switch may have to be involved in your reproducer, stale
request which are freed before switching to new elevator can stay in tags->rqs[],
then these stale requests are retrieved when reading iostat before old request slots in
tags->rqs[] are reset.

The patch should fix this issue.

Thanks,
Ming

Re: [REPORT] BUG: KASAN: use-after-free in bt_iter+0x80/0xf8

[John Garry]

On 19/08/2020 15:21, Ming Lei wrote:
> I guess that elevator switch may have to be involved in your reproducer, stale
> request which are freed before switching to new elevator can stay in tags->rqs[],
> then these stale requests are retrieved when reading iostat before old request slots in
> tags->rqs[] are reset.

Yeah, just switching -> "none" seems to do it. If I hack the elevator 
code to default to "none", then no issue.

Thanks