Linux-BTRFS Archive on lore.kernel.org
 help / color / Atom feed
* KASAN splat during mount on 5.4.5, no reproducer
@ 2019-12-28 20:03 Zygo Blaxell
  2019-12-29  1:32 ` Qu Wenruo
  2020-01-20 19:46 ` David Sterba
  0 siblings, 2 replies; 8+ messages in thread
From: Zygo Blaxell @ 2019-12-28 20:03 UTC (permalink / raw)
  To: linux-btrfs

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

Mounting the filesystem on a fresh boot...

	[   39.771351][ T4188] BTRFS info (device dm-3): enabling ssd optimizations
	[   39.772749][ T4188] BTRFS info (device dm-3): turning on flush-on-commit
	[   39.773929][ T4188] BTRFS info (device dm-3): turning on discard
	[   39.774888][ T4188] BTRFS info (device dm-3): use zstd compression, level 3
	[   39.776554][ T4188] BTRFS info (device dm-3): using free space tree
	[   39.777738][ T4188] BTRFS info (device dm-3): has skinny extents
	[  156.831607][ T4188] ==================================================================
	[  156.833652][ T4188] BUG: KASAN: use-after-free in __list_del_entry_valid+0x52/0x81
	[  156.835662][ T4188] Read of size 8 at addr ffff8881f34e0a50 by task mount/4188
	[  156.837026][ T4188] 
	[  156.837435][ T4188] CPU: 2 PID: 4188 Comm: mount Not tainted 5.4.5-0eecf81ee46e+ #1
	[  156.838868][ T4188] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
	[  156.840490][ T4188] Call Trace:
	[  156.841195][ T4188]  dump_stack+0xc1/0x11a
	[  156.841937][ T4188]  ? __list_del_entry_valid+0x52/0x81
	[  156.842952][ T4188]  print_address_description.constprop.7+0x20/0x200
	[  156.844695][ T4188]  ? __list_del_entry_valid+0x52/0x81
	[  156.845616][ T4188]  ? __list_del_entry_valid+0x52/0x81
	[  156.847673][ T4188]  __kasan_report.cold.10+0x1b/0x39
	[  156.848624][ T4188]  ? __list_del_entry_valid+0x52/0x81
	[  156.849711][ T4188]  kasan_report+0x12/0x20
	[  156.850973][ T4188]  __asan_load8+0x54/0x90
	[  156.852261][ T4188]  __list_del_entry_valid+0x52/0x81
	[  156.853120][ T4188]  clean_dirty_subvols+0x7f/0x200
	[  156.854527][ T4188]  btrfs_recover_relocation+0x73c/0x770
	[  156.855462][ T4188]  ? btrfs_relocate_block_group+0x4f0/0x4f0
	[  156.856446][ T4188]  ? __del_qgroup_relation+0x440/0x440
	[  156.857529][ T4188]  open_ctree+0x2f4e/0x33f8
	[  156.858849][ T4188]  ? close_ctree+0x4e0/0x4e0
	[  156.860678][ T4188]  ? super_setup_bdi_name+0x11e/0x180
	[  156.861770][ T4188]  ? vfs_get_tree+0x150/0x150
	[  156.862653][ T4188]  ? snprintf+0x91/0xc0
	[  156.863479][ T4188]  btrfs_mount_root+0x809/0x990
	[  156.864884][ T4188]  ? btrfs_decode_error+0x40/0x40
	[  156.866954][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[  156.869360][ T4188]  ? check_flags.part.42+0x86/0x220
	[  156.870419][ T4188]  ? __kasan_check_read+0x11/0x20
	[  156.871464][ T4188]  ? vfs_parse_fs_string+0xca/0x110
	[  156.872507][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[  156.873617][ T4188]  ? rcu_read_lock_bh_held+0xb0/0xb0
	[  156.874731][ T4188]  ? __lookup_constant+0x54/0x90
	[  156.875735][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
	[  156.877000][ T4188]  ? kfree+0x1dd/0x210
	[  156.877829][ T4188]  ? btrfs_decode_error+0x40/0x40
	[  156.878878][ T4188]  legacy_get_tree+0x89/0xd0
	[  156.880010][ T4188]  vfs_get_tree+0x52/0x150
	[  156.880926][ T4188]  fc_mount+0x14/0x60
	[  156.881742][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
	[  156.882941][ T4188]  vfs_kern_mount+0x13/0x20
	[  156.883896][ T4188]  btrfs_mount+0x21a/0xbbe
	[  156.884783][ T4188]  ? check_chain_key+0x1e6/0x2e0
	[  156.885768][ T4188]  ? sched_clock_cpu+0x1b/0x120
	[  156.886769][ T4188]  ? btrfs_remount+0x7f0/0x7f0
	[  156.887807][ T4188]  ? check_flags.part.42+0x86/0x220
	[  156.888864][ T4188]  ? __kasan_check_read+0x11/0x20
	[  156.889927][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[  156.891051][ T4188]  ? check_flags.part.42+0x86/0x220
	[  156.892100][ T4188]  ? __kasan_check_read+0x11/0x20
	[  156.893140][ T4188]  ? vfs_parse_fs_string+0xca/0x110
	[  156.894831][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[  156.896399][ T4188]  ? rcu_read_lock_bh_held+0xb0/0xb0
	[  156.898575][ T4188]  ? __lookup_constant+0x54/0x90
	[  156.899992][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
	[  156.901807][ T4188]  ? cap_capable+0xd2/0x110
	[  156.902983][ T4188]  ? btrfs_remount+0x7f0/0x7f0
	[  156.904129][ T4188]  legacy_get_tree+0x89/0xd0
	[  156.905021][ T4188]  ? btrfs_remount+0x7f0/0x7f0
	[  156.905957][ T4188]  ? legacy_get_tree+0x89/0xd0
	[  156.907026][ T4188]  vfs_get_tree+0x52/0x150
	[  156.907902][ T4188]  do_mount+0xe8c/0x10c0
	[  156.908732][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[  156.909826][ T4188]  ? copy_mount_string+0x20/0x20
	[  156.911504][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
	[  156.913203][ T4188]  ? kmem_cache_alloc_trace+0x5af/0x740
	[  156.914287][ T4188]  ? __kasan_check_write+0x14/0x20
	[  156.915258][ T4188]  ? __kasan_check_read+0x11/0x20
	[  156.916204][ T4188]  ? copy_mount_options+0x120/0x1e0
	[  156.917199][ T4188]  ksys_mount+0xb6/0xd0
	[  156.918362][ T4188]  __x64_sys_mount+0x67/0x80
	[  156.919684][ T4188]  do_syscall_64+0x77/0x2a0
	[  156.920701][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
	[  156.922481][ T4188] RIP: 0033:0x7fe51245ffea
	[  156.923456][ T4188] Code: 48 8b 0d a9 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48
	[  156.929628][ T4188] RSP: 002b:00007ffc323252e8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
	[  156.931386][ T4188] RAX: ffffffffffffffda RBX: 0000559d045b4b40 RCX: 00007fe51245ffea
	[  156.933199][ T4188] RDX: 0000559d045bc5e0 RSI: 0000559d045b4d90 RDI: 0000559d045b4ed0
	[  156.936309][ T4188] RBP: 00007fe5127ad1c4 R08: 0000559d045b4e20 R09: 0000559d045bca20
	[  156.937882][ T4188] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
	[  156.939349][ T4188] R13: 0000000000000400 R14: 0000559d045b4ed0 R15: 0000559d045bc5e0
	[  156.940986][ T4188] 
	[  156.941570][ T4188] Allocated by task 4188:
	[  156.942628][ T4188]  save_stack+0x21/0x90
	[  156.943485][ T4188]  __kasan_kmalloc.constprop.14+0xc1/0xd0
	[  156.944806][ T4188]  kasan_kmalloc+0x9/0x10
	[  156.945843][ T4188]  kmem_cache_alloc_trace+0x134/0x740
	[  156.947091][ T4188]  btrfs_read_tree_root+0x6d/0x1b0
	[  156.948080][ T4188]  btrfs_read_fs_root+0xf/0x60
	[  156.949010][ T4188]  btrfs_recover_relocation+0x205/0x770
	[  156.950080][ T4188]  open_ctree+0x2f4e/0x33f8
	[  156.951163][ T4188]  btrfs_mount_root+0x809/0x990
	[  156.952377][ T4188]  legacy_get_tree+0x89/0xd0
	[  156.953789][ T4188]  vfs_get_tree+0x52/0x150
	[  156.954727][ T4188]  fc_mount+0x14/0x60
	[  156.955785][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
	[  156.957275][ T4188]  vfs_kern_mount+0x13/0x20
	[  156.958498][ T4188]  btrfs_mount+0x21a/0xbbe
	[  156.959413][ T4188]  legacy_get_tree+0x89/0xd0
	[  156.960326][ T4188]  vfs_get_tree+0x52/0x150
	[  156.961804][ T4188]  do_mount+0xe8c/0x10c0
	[  156.963439][ T4188]  ksys_mount+0xb6/0xd0
	[  156.964745][ T4188]  __x64_sys_mount+0x67/0x80
	[  156.965817][ T4188]  do_syscall_64+0x77/0x2a0
	[  156.966888][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
	[  156.968160][ T4188] 
	[  156.968792][ T4188] Freed by task 4188:
	[  156.970260][ T4188]  save_stack+0x21/0x90
	[  156.971212][ T4188]  __kasan_slab_free+0x118/0x170
	[  156.972610][ T4188]  kasan_slab_free+0xe/0x10
	[  156.973582][ T4188]  kfree+0xd1/0x210
	[  156.974391][ T4188]  btrfs_drop_snapshot+0xd68/0xfa0
	[  156.975424][ T4188]  clean_dirty_subvols+0x1bb/0x200
	[  156.976482][ T4188]  btrfs_recover_relocation+0x73c/0x770
	[  156.977665][ T4188]  open_ctree+0x2f4e/0x33f8
	[  156.978578][ T4188]  btrfs_mount_root+0x809/0x990
	[  156.979620][ T4188]  legacy_get_tree+0x89/0xd0
	[  156.980543][ T4188]  vfs_get_tree+0x52/0x150
	[  156.981433][ T4188]  fc_mount+0x14/0x60
	[  156.982365][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
	[  156.983622][ T4188]  vfs_kern_mount+0x13/0x20
	[  156.984719][ T4188]  btrfs_mount+0x21a/0xbbe
	[  156.985642][ T4188]  legacy_get_tree+0x89/0xd0
	[  156.986614][ T4188]  vfs_get_tree+0x52/0x150
	[  156.987565][ T4188]  do_mount+0xe8c/0x10c0
	[  156.988531][ T4188]  ksys_mount+0xb6/0xd0
	[  156.989418][ T4188]  __x64_sys_mount+0x67/0x80
	[  156.991955][ T4188]  do_syscall_64+0x77/0x2a0
	[  156.993077][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
	[  156.995441][ T4188] 
	[  156.996116][ T4188] The buggy address belongs to the object at ffff8881f34e0000
	[  156.996116][ T4188]  which belongs to the cache kmalloc-4k of size 4096
	[  156.999361][ T4188] The buggy address is located 2640 bytes inside of
	[  156.999361][ T4188]  4096-byte region [ffff8881f34e0000, ffff8881f34e1000)
	[  157.002852][ T4188] The buggy address belongs to the page:
	[  157.004697][ T4188] page:ffffea0007cd3800 refcount:1 mapcount:0 mapping:ffff888107c028c0 index:0xffff8881f32d0ac0 compound_mapcount: 0
	[  157.007312][ T4188] raw: 017ffe0000010200 ffffea0007d7f188 ffffea00077c3488 ffff888107c028c0
	[  157.009094][ T4188] raw: ffff8881f32d0ac0 ffff8881f34e0000 0000000100000001 0000000000000000
	[  157.010976][ T4188] page dumped because: kasan: bad access detected
	[  157.012332][ T4188] 
	[  157.012846][ T4188] Memory state around the buggy address:
	[  157.015055][ T4188]  ffff8881f34e0900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[  157.019204][ T4188]  ffff8881f34e0980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[  157.022892][ T4188] >ffff8881f34e0a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[  157.025313][ T4188]                                                  ^
	[  157.026785][ T4188]  ffff8881f34e0a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[  157.029435][ T4188]  ffff8881f34e0b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[  157.031585][ T4188] ==================================================================
	[  157.033308][ T4188] Disabling lock debugging due to kernel taint
	[  165.881365][ T4188] list_del corruption. prev->next should be ffff8881ce3b4a50, but was 0000000000000000
	[  165.883152][ T4188] ------------[ cut here ]------------
	[  165.884214][ T4188] kernel BUG at lib/list_debug.c:53!

[...etc...it dumps the same stacks again in the BUG]

The deepest level of fs/btrfs code is the list_del_init in
clean_dirty_subvols.

After a reboot the next mount (and all subsequent mounts so far)
was successful.  I don't have a reproducer.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 195 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5, no reproducer
  2019-12-28 20:03 KASAN splat during mount on 5.4.5, no reproducer Zygo Blaxell
@ 2019-12-29  1:32 ` Qu Wenruo
  2019-12-29  5:14   ` Zygo Blaxell
  2020-01-20 19:46 ` David Sterba
  1 sibling, 1 reply; 8+ messages in thread
From: Qu Wenruo @ 2019-12-29  1:32 UTC (permalink / raw)
  To: Zygo Blaxell, linux-btrfs

[-- Attachment #1.1: Type: text/plain, Size: 11258 bytes --]



On 2019/12/29 上午4:03, Zygo Blaxell wrote:
> Mounting the filesystem on a fresh boot...
> 
> 	[   39.771351][ T4188] BTRFS info (device dm-3): enabling ssd optimizations
> 	[   39.772749][ T4188] BTRFS info (device dm-3): turning on flush-on-commit
> 	[   39.773929][ T4188] BTRFS info (device dm-3): turning on discard
> 	[   39.774888][ T4188] BTRFS info (device dm-3): use zstd compression, level 3
> 	[   39.776554][ T4188] BTRFS info (device dm-3): using free space tree
> 	[   39.777738][ T4188] BTRFS info (device dm-3): has skinny extents
> 	[  156.831607][ T4188] ==================================================================
> 	[  156.833652][ T4188] BUG: KASAN: use-after-free in __list_del_entry_valid+0x52/0x81
> 	[  156.835662][ T4188] Read of size 8 at addr ffff8881f34e0a50 by task mount/4188
> 	[  156.837026][ T4188] 
> 	[  156.837435][ T4188] CPU: 2 PID: 4188 Comm: mount Not tainted 5.4.5-0eecf81ee46e+ #1
> 	[  156.838868][ T4188] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> 	[  156.840490][ T4188] Call Trace:
> 	[  156.841195][ T4188]  dump_stack+0xc1/0x11a
> 	[  156.841937][ T4188]  ? __list_del_entry_valid+0x52/0x81
> 	[  156.842952][ T4188]  print_address_description.constprop.7+0x20/0x200
> 	[  156.844695][ T4188]  ? __list_del_entry_valid+0x52/0x81
> 	[  156.845616][ T4188]  ? __list_del_entry_valid+0x52/0x81
> 	[  156.847673][ T4188]  __kasan_report.cold.10+0x1b/0x39
> 	[  156.848624][ T4188]  ? __list_del_entry_valid+0x52/0x81
> 	[  156.849711][ T4188]  kasan_report+0x12/0x20
> 	[  156.850973][ T4188]  __asan_load8+0x54/0x90
> 	[  156.852261][ T4188]  __list_del_entry_valid+0x52/0x81
> 	[  156.853120][ T4188]  clean_dirty_subvols+0x7f/0x200

It's from list_del_init(), which means we're accessing a subvolume tree.

> 	[  156.854527][ T4188]  btrfs_recover_relocation+0x73c/0x770
> 	[  156.855462][ T4188]  ? btrfs_relocate_block_group+0x4f0/0x4f0
> 	[  156.856446][ T4188]  ? __del_qgroup_relation+0x440/0x440
> 	[  156.857529][ T4188]  open_ctree+0x2f4e/0x33f8
> 	[  156.858849][ T4188]  ? close_ctree+0x4e0/0x4e0
> 	[  156.860678][ T4188]  ? super_setup_bdi_name+0x11e/0x180
> 	[  156.861770][ T4188]  ? vfs_get_tree+0x150/0x150
> 	[  156.862653][ T4188]  ? snprintf+0x91/0xc0
> 	[  156.863479][ T4188]  btrfs_mount_root+0x809/0x990
> 	[  156.864884][ T4188]  ? btrfs_decode_error+0x40/0x40
> 	[  156.866954][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[  156.869360][ T4188]  ? check_flags.part.42+0x86/0x220
> 	[  156.870419][ T4188]  ? __kasan_check_read+0x11/0x20
> 	[  156.871464][ T4188]  ? vfs_parse_fs_string+0xca/0x110
> 	[  156.872507][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[  156.873617][ T4188]  ? rcu_read_lock_bh_held+0xb0/0xb0
> 	[  156.874731][ T4188]  ? __lookup_constant+0x54/0x90
> 	[  156.875735][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> 	[  156.877000][ T4188]  ? kfree+0x1dd/0x210
> 	[  156.877829][ T4188]  ? btrfs_decode_error+0x40/0x40
> 	[  156.878878][ T4188]  legacy_get_tree+0x89/0xd0
> 	[  156.880010][ T4188]  vfs_get_tree+0x52/0x150
> 	[  156.880926][ T4188]  fc_mount+0x14/0x60
> 	[  156.881742][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
> 	[  156.882941][ T4188]  vfs_kern_mount+0x13/0x20
> 	[  156.883896][ T4188]  btrfs_mount+0x21a/0xbbe
> 	[  156.884783][ T4188]  ? check_chain_key+0x1e6/0x2e0
> 	[  156.885768][ T4188]  ? sched_clock_cpu+0x1b/0x120
> 	[  156.886769][ T4188]  ? btrfs_remount+0x7f0/0x7f0
> 	[  156.887807][ T4188]  ? check_flags.part.42+0x86/0x220
> 	[  156.888864][ T4188]  ? __kasan_check_read+0x11/0x20
> 	[  156.889927][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[  156.891051][ T4188]  ? check_flags.part.42+0x86/0x220
> 	[  156.892100][ T4188]  ? __kasan_check_read+0x11/0x20
> 	[  156.893140][ T4188]  ? vfs_parse_fs_string+0xca/0x110
> 	[  156.894831][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[  156.896399][ T4188]  ? rcu_read_lock_bh_held+0xb0/0xb0
> 	[  156.898575][ T4188]  ? __lookup_constant+0x54/0x90
> 	[  156.899992][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> 	[  156.901807][ T4188]  ? cap_capable+0xd2/0x110
> 	[  156.902983][ T4188]  ? btrfs_remount+0x7f0/0x7f0
> 	[  156.904129][ T4188]  legacy_get_tree+0x89/0xd0
> 	[  156.905021][ T4188]  ? btrfs_remount+0x7f0/0x7f0
> 	[  156.905957][ T4188]  ? legacy_get_tree+0x89/0xd0
> 	[  156.907026][ T4188]  vfs_get_tree+0x52/0x150
> 	[  156.907902][ T4188]  do_mount+0xe8c/0x10c0
> 	[  156.908732][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[  156.909826][ T4188]  ? copy_mount_string+0x20/0x20
> 	[  156.911504][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> 	[  156.913203][ T4188]  ? kmem_cache_alloc_trace+0x5af/0x740
> 	[  156.914287][ T4188]  ? __kasan_check_write+0x14/0x20
> 	[  156.915258][ T4188]  ? __kasan_check_read+0x11/0x20
> 	[  156.916204][ T4188]  ? copy_mount_options+0x120/0x1e0
> 	[  156.917199][ T4188]  ksys_mount+0xb6/0xd0
> 	[  156.918362][ T4188]  __x64_sys_mount+0x67/0x80
> 	[  156.919684][ T4188]  do_syscall_64+0x77/0x2a0
> 	[  156.920701][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 	[  156.922481][ T4188] RIP: 0033:0x7fe51245ffea
> 	[  156.923456][ T4188] Code: 48 8b 0d a9 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48
> 	[  156.929628][ T4188] RSP: 002b:00007ffc323252e8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
> 	[  156.931386][ T4188] RAX: ffffffffffffffda RBX: 0000559d045b4b40 RCX: 00007fe51245ffea
> 	[  156.933199][ T4188] RDX: 0000559d045bc5e0 RSI: 0000559d045b4d90 RDI: 0000559d045b4ed0
> 	[  156.936309][ T4188] RBP: 00007fe5127ad1c4 R08: 0000559d045b4e20 R09: 0000559d045bca20
> 	[  156.937882][ T4188] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
> 	[  156.939349][ T4188] R13: 0000000000000400 R14: 0000559d045b4ed0 R15: 0000559d045bc5e0
> 	[  156.940986][ T4188] 
> 	[  156.941570][ T4188] Allocated by task 4188:
> 	[  156.942628][ T4188]  save_stack+0x21/0x90
> 	[  156.943485][ T4188]  __kasan_kmalloc.constprop.14+0xc1/0xd0
> 	[  156.944806][ T4188]  kasan_kmalloc+0x9/0x10
> 	[  156.945843][ T4188]  kmem_cache_alloc_trace+0x134/0x740
> 	[  156.947091][ T4188]  btrfs_read_tree_root+0x6d/0x1b0
> 	[  156.948080][ T4188]  btrfs_read_fs_root+0xf/0x60
> 	[  156.949010][ T4188]  btrfs_recover_relocation+0x205/0x770

Here the root is allocated from btrfs_read_fs_root(), which means it
should be a reloc tree other than subvolume tree.

It looks like something is wrong in the relocation recovery path.

> 	[  156.950080][ T4188]  open_ctree+0x2f4e/0x33f8
> 	[  156.951163][ T4188]  btrfs_mount_root+0x809/0x990
> 	[  156.952377][ T4188]  legacy_get_tree+0x89/0xd0
> 	[  156.953789][ T4188]  vfs_get_tree+0x52/0x150
> 	[  156.954727][ T4188]  fc_mount+0x14/0x60
> 	[  156.955785][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
> 	[  156.957275][ T4188]  vfs_kern_mount+0x13/0x20
> 	[  156.958498][ T4188]  btrfs_mount+0x21a/0xbbe
> 	[  156.959413][ T4188]  legacy_get_tree+0x89/0xd0
> 	[  156.960326][ T4188]  vfs_get_tree+0x52/0x150
> 	[  156.961804][ T4188]  do_mount+0xe8c/0x10c0
> 	[  156.963439][ T4188]  ksys_mount+0xb6/0xd0
> 	[  156.964745][ T4188]  __x64_sys_mount+0x67/0x80
> 	[  156.965817][ T4188]  do_syscall_64+0x77/0x2a0
> 	[  156.966888][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 	[  156.968160][ T4188] 
> 	[  156.968792][ T4188] Freed by task 4188:
> 	[  156.970260][ T4188]  save_stack+0x21/0x90
> 	[  156.971212][ T4188]  __kasan_slab_free+0x118/0x170
> 	[  156.972610][ T4188]  kasan_slab_free+0xe/0x10
> 	[  156.973582][ T4188]  kfree+0xd1/0x210
> 	[  156.974391][ T4188]  btrfs_drop_snapshot+0xd68/0xfa0
> 	[  156.975424][ T4188]  clean_dirty_subvols+0x1bb/0x200

This also means the root we're freeing up is from another
btrfs_drop_snapshot() call inside clean_dirty_subvols().

Means the root is freed as a reloc tree.

Something doesn't look sane here.

Would you like to provide the correct line of these mentioned functions?

Thanks,
Qu

> 	[  156.976482][ T4188]  btrfs_recover_relocation+0x73c/0x770
> 	[  156.977665][ T4188]  open_ctree+0x2f4e/0x33f8
> 	[  156.978578][ T4188]  btrfs_mount_root+0x809/0x990
> 	[  156.979620][ T4188]  legacy_get_tree+0x89/0xd0
> 	[  156.980543][ T4188]  vfs_get_tree+0x52/0x150
> 	[  156.981433][ T4188]  fc_mount+0x14/0x60
> 	[  156.982365][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
> 	[  156.983622][ T4188]  vfs_kern_mount+0x13/0x20
> 	[  156.984719][ T4188]  btrfs_mount+0x21a/0xbbe
> 	[  156.985642][ T4188]  legacy_get_tree+0x89/0xd0
> 	[  156.986614][ T4188]  vfs_get_tree+0x52/0x150
> 	[  156.987565][ T4188]  do_mount+0xe8c/0x10c0
> 	[  156.988531][ T4188]  ksys_mount+0xb6/0xd0
> 	[  156.989418][ T4188]  __x64_sys_mount+0x67/0x80
> 	[  156.991955][ T4188]  do_syscall_64+0x77/0x2a0
> 	[  156.993077][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 	[  156.995441][ T4188] 
> 	[  156.996116][ T4188] The buggy address belongs to the object at ffff8881f34e0000
> 	[  156.996116][ T4188]  which belongs to the cache kmalloc-4k of size 4096
> 	[  156.999361][ T4188] The buggy address is located 2640 bytes inside of
> 	[  156.999361][ T4188]  4096-byte region [ffff8881f34e0000, ffff8881f34e1000)
> 	[  157.002852][ T4188] The buggy address belongs to the page:
> 	[  157.004697][ T4188] page:ffffea0007cd3800 refcount:1 mapcount:0 mapping:ffff888107c028c0 index:0xffff8881f32d0ac0 compound_mapcount: 0
> 	[  157.007312][ T4188] raw: 017ffe0000010200 ffffea0007d7f188 ffffea00077c3488 ffff888107c028c0
> 	[  157.009094][ T4188] raw: ffff8881f32d0ac0 ffff8881f34e0000 0000000100000001 0000000000000000
> 	[  157.010976][ T4188] page dumped because: kasan: bad access detected
> 	[  157.012332][ T4188] 
> 	[  157.012846][ T4188] Memory state around the buggy address:
> 	[  157.015055][ T4188]  ffff8881f34e0900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[  157.019204][ T4188]  ffff8881f34e0980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[  157.022892][ T4188] >ffff8881f34e0a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[  157.025313][ T4188]                                                  ^
> 	[  157.026785][ T4188]  ffff8881f34e0a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[  157.029435][ T4188]  ffff8881f34e0b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[  157.031585][ T4188] ==================================================================
> 	[  157.033308][ T4188] Disabling lock debugging due to kernel taint
> 	[  165.881365][ T4188] list_del corruption. prev->next should be ffff8881ce3b4a50, but was 0000000000000000
> 	[  165.883152][ T4188] ------------[ cut here ]------------
> 	[  165.884214][ T4188] kernel BUG at lib/list_debug.c:53!
> 
> [...etc...it dumps the same stacks again in the BUG]
> 
> The deepest level of fs/btrfs code is the list_del_init in
> clean_dirty_subvols.
> 
> After a reboot the next mount (and all subsequent mounts so far)
> was successful.  I don't have a reproducer.
> 


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5, no reproducer
  2019-12-29  1:32 ` Qu Wenruo
@ 2019-12-29  5:14   ` Zygo Blaxell
  0 siblings, 0 replies; 8+ messages in thread
From: Zygo Blaxell @ 2019-12-29  5:14 UTC (permalink / raw)
  To: Qu Wenruo; +Cc: linux-btrfs

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

On Sun, Dec 29, 2019 at 09:32:41AM +0800, Qu Wenruo wrote:
> 
> 
> On 2019/12/29 上午4:03, Zygo Blaxell wrote:
> > Mounting the filesystem on a fresh boot...
> > 
> > 	[   39.771351][ T4188] BTRFS info (device dm-3): enabling ssd optimizations
> > 	[   39.772749][ T4188] BTRFS info (device dm-3): turning on flush-on-commit
> > 	[   39.773929][ T4188] BTRFS info (device dm-3): turning on discard
> > 	[   39.774888][ T4188] BTRFS info (device dm-3): use zstd compression, level 3
> > 	[   39.776554][ T4188] BTRFS info (device dm-3): using free space tree
> > 	[   39.777738][ T4188] BTRFS info (device dm-3): has skinny extents
> > 	[  156.831607][ T4188] ==================================================================
> > 	[  156.833652][ T4188] BUG: KASAN: use-after-free in __list_del_entry_valid+0x52/0x81
> > 	[  156.835662][ T4188] Read of size 8 at addr ffff8881f34e0a50 by task mount/4188
> > 	[  156.837026][ T4188] 
> > 	[  156.837435][ T4188] CPU: 2 PID: 4188 Comm: mount Not tainted 5.4.5-0eecf81ee46e+ #1
> > 	[  156.838868][ T4188] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> > 	[  156.840490][ T4188] Call Trace:
> > 	[  156.841195][ T4188]  dump_stack+0xc1/0x11a
> > 	[  156.841937][ T4188]  ? __list_del_entry_valid+0x52/0x81
> > 	[  156.842952][ T4188]  print_address_description.constprop.7+0x20/0x200
> > 	[  156.844695][ T4188]  ? __list_del_entry_valid+0x52/0x81
> > 	[  156.845616][ T4188]  ? __list_del_entry_valid+0x52/0x81
> > 	[  156.847673][ T4188]  __kasan_report.cold.10+0x1b/0x39
> > 	[  156.848624][ T4188]  ? __list_del_entry_valid+0x52/0x81
> > 	[  156.849711][ T4188]  kasan_report+0x12/0x20
> > 	[  156.850973][ T4188]  __asan_load8+0x54/0x90
> > 	[  156.852261][ T4188]  __list_del_entry_valid+0x52/0x81
> > 	[  156.853120][ T4188]  clean_dirty_subvols+0x7f/0x200
> 
> It's from list_del_init(), which means we're accessing a subvolume tree.
>
> > 	[  156.854527][ T4188]  btrfs_recover_relocation+0x73c/0x770
> > 	[  156.855462][ T4188]  ? btrfs_relocate_block_group+0x4f0/0x4f0
> > 	[  156.856446][ T4188]  ? __del_qgroup_relation+0x440/0x440
> > 	[  156.857529][ T4188]  open_ctree+0x2f4e/0x33f8
> > 	[  156.858849][ T4188]  ? close_ctree+0x4e0/0x4e0
> > 	[  156.860678][ T4188]  ? super_setup_bdi_name+0x11e/0x180
> > 	[  156.861770][ T4188]  ? vfs_get_tree+0x150/0x150
> > 	[  156.862653][ T4188]  ? snprintf+0x91/0xc0
> > 	[  156.863479][ T4188]  btrfs_mount_root+0x809/0x990
> > 	[  156.864884][ T4188]  ? btrfs_decode_error+0x40/0x40
> > 	[  156.866954][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[  156.869360][ T4188]  ? check_flags.part.42+0x86/0x220
> > 	[  156.870419][ T4188]  ? __kasan_check_read+0x11/0x20
> > 	[  156.871464][ T4188]  ? vfs_parse_fs_string+0xca/0x110
> > 	[  156.872507][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[  156.873617][ T4188]  ? rcu_read_lock_bh_held+0xb0/0xb0
> > 	[  156.874731][ T4188]  ? __lookup_constant+0x54/0x90
> > 	[  156.875735][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> > 	[  156.877000][ T4188]  ? kfree+0x1dd/0x210
> > 	[  156.877829][ T4188]  ? btrfs_decode_error+0x40/0x40
> > 	[  156.878878][ T4188]  legacy_get_tree+0x89/0xd0
> > 	[  156.880010][ T4188]  vfs_get_tree+0x52/0x150
> > 	[  156.880926][ T4188]  fc_mount+0x14/0x60
> > 	[  156.881742][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
> > 	[  156.882941][ T4188]  vfs_kern_mount+0x13/0x20
> > 	[  156.883896][ T4188]  btrfs_mount+0x21a/0xbbe
> > 	[  156.884783][ T4188]  ? check_chain_key+0x1e6/0x2e0
> > 	[  156.885768][ T4188]  ? sched_clock_cpu+0x1b/0x120
> > 	[  156.886769][ T4188]  ? btrfs_remount+0x7f0/0x7f0
> > 	[  156.887807][ T4188]  ? check_flags.part.42+0x86/0x220
> > 	[  156.888864][ T4188]  ? __kasan_check_read+0x11/0x20
> > 	[  156.889927][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[  156.891051][ T4188]  ? check_flags.part.42+0x86/0x220
> > 	[  156.892100][ T4188]  ? __kasan_check_read+0x11/0x20
> > 	[  156.893140][ T4188]  ? vfs_parse_fs_string+0xca/0x110
> > 	[  156.894831][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[  156.896399][ T4188]  ? rcu_read_lock_bh_held+0xb0/0xb0
> > 	[  156.898575][ T4188]  ? __lookup_constant+0x54/0x90
> > 	[  156.899992][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> > 	[  156.901807][ T4188]  ? cap_capable+0xd2/0x110
> > 	[  156.902983][ T4188]  ? btrfs_remount+0x7f0/0x7f0
> > 	[  156.904129][ T4188]  legacy_get_tree+0x89/0xd0
> > 	[  156.905021][ T4188]  ? btrfs_remount+0x7f0/0x7f0
> > 	[  156.905957][ T4188]  ? legacy_get_tree+0x89/0xd0
> > 	[  156.907026][ T4188]  vfs_get_tree+0x52/0x150
> > 	[  156.907902][ T4188]  do_mount+0xe8c/0x10c0
> > 	[  156.908732][ T4188]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[  156.909826][ T4188]  ? copy_mount_string+0x20/0x20
> > 	[  156.911504][ T4188]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> > 	[  156.913203][ T4188]  ? kmem_cache_alloc_trace+0x5af/0x740
> > 	[  156.914287][ T4188]  ? __kasan_check_write+0x14/0x20
> > 	[  156.915258][ T4188]  ? __kasan_check_read+0x11/0x20
> > 	[  156.916204][ T4188]  ? copy_mount_options+0x120/0x1e0
> > 	[  156.917199][ T4188]  ksys_mount+0xb6/0xd0
> > 	[  156.918362][ T4188]  __x64_sys_mount+0x67/0x80
> > 	[  156.919684][ T4188]  do_syscall_64+0x77/0x2a0
> > 	[  156.920701][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > 	[  156.922481][ T4188] RIP: 0033:0x7fe51245ffea
> > 	[  156.923456][ T4188] Code: 48 8b 0d a9 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48
> > 	[  156.929628][ T4188] RSP: 002b:00007ffc323252e8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
> > 	[  156.931386][ T4188] RAX: ffffffffffffffda RBX: 0000559d045b4b40 RCX: 00007fe51245ffea
> > 	[  156.933199][ T4188] RDX: 0000559d045bc5e0 RSI: 0000559d045b4d90 RDI: 0000559d045b4ed0
> > 	[  156.936309][ T4188] RBP: 00007fe5127ad1c4 R08: 0000559d045b4e20 R09: 0000559d045bca20
> > 	[  156.937882][ T4188] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
> > 	[  156.939349][ T4188] R13: 0000000000000400 R14: 0000559d045b4ed0 R15: 0000559d045bc5e0
> > 	[  156.940986][ T4188] 
> > 	[  156.941570][ T4188] Allocated by task 4188:
> > 	[  156.942628][ T4188]  save_stack+0x21/0x90
> > 	[  156.943485][ T4188]  __kasan_kmalloc.constprop.14+0xc1/0xd0
> > 	[  156.944806][ T4188]  kasan_kmalloc+0x9/0x10
> > 	[  156.945843][ T4188]  kmem_cache_alloc_trace+0x134/0x740
> > 	[  156.947091][ T4188]  btrfs_read_tree_root+0x6d/0x1b0
> > 	[  156.948080][ T4188]  btrfs_read_fs_root+0xf/0x60
> > 	[  156.949010][ T4188]  btrfs_recover_relocation+0x205/0x770
>
> Here the root is allocated from btrfs_read_fs_root(), which means it
> should be a reloc tree other than subvolume tree.
> 
> It looks like something is wrong in the relocation recovery path.
> 
> > 	[  156.950080][ T4188]  open_ctree+0x2f4e/0x33f8
> > 	[  156.951163][ T4188]  btrfs_mount_root+0x809/0x990
> > 	[  156.952377][ T4188]  legacy_get_tree+0x89/0xd0
> > 	[  156.953789][ T4188]  vfs_get_tree+0x52/0x150
> > 	[  156.954727][ T4188]  fc_mount+0x14/0x60
> > 	[  156.955785][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
> > 	[  156.957275][ T4188]  vfs_kern_mount+0x13/0x20
> > 	[  156.958498][ T4188]  btrfs_mount+0x21a/0xbbe
> > 	[  156.959413][ T4188]  legacy_get_tree+0x89/0xd0
> > 	[  156.960326][ T4188]  vfs_get_tree+0x52/0x150
> > 	[  156.961804][ T4188]  do_mount+0xe8c/0x10c0
> > 	[  156.963439][ T4188]  ksys_mount+0xb6/0xd0
> > 	[  156.964745][ T4188]  __x64_sys_mount+0x67/0x80
> > 	[  156.965817][ T4188]  do_syscall_64+0x77/0x2a0
> > 	[  156.966888][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > 	[  156.968160][ T4188] 
> > 	[  156.968792][ T4188] Freed by task 4188:
> > 	[  156.970260][ T4188]  save_stack+0x21/0x90
> > 	[  156.971212][ T4188]  __kasan_slab_free+0x118/0x170
> > 	[  156.972610][ T4188]  kasan_slab_free+0xe/0x10
> > 	[  156.973582][ T4188]  kfree+0xd1/0x210
> > 	[  156.974391][ T4188]  btrfs_drop_snapshot+0xd68/0xfa0
> > 	[  156.975424][ T4188]  clean_dirty_subvols+0x1bb/0x200
>
> This also means the root we're freeing up is from another
> btrfs_drop_snapshot() call inside clean_dirty_subvols().
> 
> Means the root is freed as a reloc tree.
> 
> Something doesn't look sane here.

Sanity is unusual when we hit the BUG_ONs.  ;)

> Would you like to provide the correct line of these mentioned functions?

	(gdb) list *(clean_dirty_subvols+0x7f)
	0xffffffff818a754f is in clean_dirty_subvols (./include/linux/list.h:190).
	185      * list_del_init - deletes entry from list and reinitialize it.
	186      * @entry: the element to delete from the list.
	187      */
	188     static inline void list_del_init(struct list_head *entry)
	189     {
	190             __list_del_entry(entry);
	191             INIT_LIST_HEAD(entry);
	192     }
	193
	194     /**
	(gdb) list *(btrfs_recover_relocation+0x205)
	0xffffffff818afc75 is in btrfs_recover_relocation (fs/btrfs/relocation.c:4530).
	4525
	4526                    if (key.objectid != BTRFS_TREE_RELOC_OBJECTID ||
	4527                        key.type != BTRFS_ROOT_ITEM_KEY)
	4528                            break;
	4529
	4530                    reloc_root = btrfs_read_fs_root(root, &key);
	4531                    if (IS_ERR(reloc_root)) {
	4532                            err = PTR_ERR(reloc_root);
	4533                            goto out;
	4534                    }
	(gdb) list *(clean_dirty_subvols+0x1bb)
	0xffffffff818a768b is in clean_dirty_subvols (fs/btrfs/relocation.c:2215).
	2210                            clear_bit(BTRFS_ROOT_DEAD_RELOC_TREE, &root->state);
	2211                            btrfs_put_fs_root(root);
	2212                    } else {
	2213                            /* Orphan reloc tree, just clean it up */
	2214                            ret2 = btrfs_drop_snapshot(root, NULL, 0, 1);
	2215                            if (ret2 < 0 && !ret)
	2216                                    ret = ret2;
	2217                    }
	2218            }
	2219            return ret;

> Thanks,
> Qu
> 
> > 	[  156.976482][ T4188]  btrfs_recover_relocation+0x73c/0x770
> > 	[  156.977665][ T4188]  open_ctree+0x2f4e/0x33f8
> > 	[  156.978578][ T4188]  btrfs_mount_root+0x809/0x990
> > 	[  156.979620][ T4188]  legacy_get_tree+0x89/0xd0
> > 	[  156.980543][ T4188]  vfs_get_tree+0x52/0x150
> > 	[  156.981433][ T4188]  fc_mount+0x14/0x60
> > 	[  156.982365][ T4188]  vfs_kern_mount.part.35+0x61/0xa0
> > 	[  156.983622][ T4188]  vfs_kern_mount+0x13/0x20
> > 	[  156.984719][ T4188]  btrfs_mount+0x21a/0xbbe
> > 	[  156.985642][ T4188]  legacy_get_tree+0x89/0xd0
> > 	[  156.986614][ T4188]  vfs_get_tree+0x52/0x150
> > 	[  156.987565][ T4188]  do_mount+0xe8c/0x10c0
> > 	[  156.988531][ T4188]  ksys_mount+0xb6/0xd0
> > 	[  156.989418][ T4188]  __x64_sys_mount+0x67/0x80
> > 	[  156.991955][ T4188]  do_syscall_64+0x77/0x2a0
> > 	[  156.993077][ T4188]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > 	[  156.995441][ T4188] 
> > 	[  156.996116][ T4188] The buggy address belongs to the object at ffff8881f34e0000
> > 	[  156.996116][ T4188]  which belongs to the cache kmalloc-4k of size 4096
> > 	[  156.999361][ T4188] The buggy address is located 2640 bytes inside of
> > 	[  156.999361][ T4188]  4096-byte region [ffff8881f34e0000, ffff8881f34e1000)
> > 	[  157.002852][ T4188] The buggy address belongs to the page:
> > 	[  157.004697][ T4188] page:ffffea0007cd3800 refcount:1 mapcount:0 mapping:ffff888107c028c0 index:0xffff8881f32d0ac0 compound_mapcount: 0
> > 	[  157.007312][ T4188] raw: 017ffe0000010200 ffffea0007d7f188 ffffea00077c3488 ffff888107c028c0
> > 	[  157.009094][ T4188] raw: ffff8881f32d0ac0 ffff8881f34e0000 0000000100000001 0000000000000000
> > 	[  157.010976][ T4188] page dumped because: kasan: bad access detected
> > 	[  157.012332][ T4188] 
> > 	[  157.012846][ T4188] Memory state around the buggy address:
> > 	[  157.015055][ T4188]  ffff8881f34e0900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[  157.019204][ T4188]  ffff8881f34e0980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[  157.022892][ T4188] >ffff8881f34e0a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[  157.025313][ T4188]                                                  ^
> > 	[  157.026785][ T4188]  ffff8881f34e0a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[  157.029435][ T4188]  ffff8881f34e0b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[  157.031585][ T4188] ==================================================================
> > 	[  157.033308][ T4188] Disabling lock debugging due to kernel taint
> > 	[  165.881365][ T4188] list_del corruption. prev->next should be ffff8881ce3b4a50, but was 0000000000000000
> > 	[  165.883152][ T4188] ------------[ cut here ]------------
> > 	[  165.884214][ T4188] kernel BUG at lib/list_debug.c:53!
> > 
> > [...etc...it dumps the same stacks again in the BUG]
> > 
> > The deepest level of fs/btrfs code is the list_del_init in
> > clean_dirty_subvols.
> > 
> > After a reboot the next mount (and all subsequent mounts so far)
> > was successful.  I don't have a reproducer.
> > 
> 




[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 195 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5, no reproducer
  2019-12-28 20:03 KASAN splat during mount on 5.4.5, no reproducer Zygo Blaxell
  2019-12-29  1:32 ` Qu Wenruo
@ 2020-01-20 19:46 ` David Sterba
  2020-02-03 18:44   ` Zygo Blaxell
  1 sibling, 1 reply; 8+ messages in thread
From: David Sterba @ 2020-01-20 19:46 UTC (permalink / raw)
  To: Zygo Blaxell; +Cc: linux-btrfs

On Sat, Dec 28, 2019 at 03:03:26PM -0500, Zygo Blaxell wrote:
> 
> [...etc...it dumps the same stacks again in the BUG]
> 
> The deepest level of fs/btrfs code is the list_del_init in
> clean_dirty_subvols.
> 
> After a reboot the next mount (and all subsequent mounts so far)
> was successful.  I don't have a reproducer.

For the record, this and other KASAN reports regarding reloc root, is
going to be fixed in 5.4.14, "btrfs: relocation: fix reloc_root lifespan
and access" (6282675e6708ec78). Thanks for the reports and debugging
help.

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5, no reproducer
  2020-01-20 19:46 ` David Sterba
@ 2020-02-03 18:44   ` Zygo Blaxell
  2020-02-13  5:20     ` KASAN splat during mount on 5.4.5...and 5.5.3 Zygo Blaxell
  0 siblings, 1 reply; 8+ messages in thread
From: Zygo Blaxell @ 2020-02-03 18:44 UTC (permalink / raw)
  To: dsterba, linux-btrfs

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

On Mon, Jan 20, 2020 at 08:46:50PM +0100, David Sterba wrote:
> On Sat, Dec 28, 2019 at 03:03:26PM -0500, Zygo Blaxell wrote:
> > 
> > [...etc...it dumps the same stacks again in the BUG]
> > 
> > The deepest level of fs/btrfs code is the list_del_init in
> > clean_dirty_subvols.
> > 
> > After a reboot the next mount (and all subsequent mounts so far)
> > was successful.  I don't have a reproducer.
> 
> For the record, this and other KASAN reports regarding reloc root, is
> going to be fixed in 5.4.14, "btrfs: relocation: fix reloc_root lifespan
> and access" (6282675e6708ec78). Thanks for the reports and debugging
> help.

Confirmed:  I have not seen this bug since applying the first versions of
the patch to my test kernels in 5.4.8.  I've been testing continuously
since then, replacing the early version with the final upstream version
in 5.4.14, and now running 5.4.16.  After applying "Btrfs: fix race
between adding and putting tree mod seq elements and nodes" I have seen
no crashing bugs _at all_ (no deadlock, BUG_ON or KASAN).

Thank you for all the fixes!  Much appreciated!

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 195 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5...and 5.5.3
  2020-02-03 18:44   ` Zygo Blaxell
@ 2020-02-13  5:20     ` Zygo Blaxell
  2020-02-13  5:57       ` Qu Wenruo
  0 siblings, 1 reply; 8+ messages in thread
From: Zygo Blaxell @ 2020-02-13  5:20 UTC (permalink / raw)
  To: dsterba, linux-btrfs; +Cc: Qu Wenruo

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

On Mon, Feb 03, 2020 at 01:44:25PM -0500, Zygo Blaxell wrote:
> On Mon, Jan 20, 2020 at 08:46:50PM +0100, David Sterba wrote:
> > On Sat, Dec 28, 2019 at 03:03:26PM -0500, Zygo Blaxell wrote:
> > > 
> > > [...etc...it dumps the same stacks again in the BUG]
> > > 
> > > The deepest level of fs/btrfs code is the list_del_init in
> > > clean_dirty_subvols.
> > > 
> > > After a reboot the next mount (and all subsequent mounts so far)
> > > was successful.  I don't have a reproducer.
> > 
> > For the record, this and other KASAN reports regarding reloc root, is
> > going to be fixed in 5.4.14, "btrfs: relocation: fix reloc_root lifespan
> > and access" (6282675e6708ec78). Thanks for the reports and debugging
> > help.
> 
> Confirmed:  I have not seen this bug since applying the first versions of
> the patch to my test kernels in 5.4.8.  

D'oh...maybe not?  Here's 5.5.3:

	[   40.692923][ T4088] BTRFS info (device dm-3): enabling ssd optimizations
	[   40.694158][ T4088] BTRFS info (device dm-3): turning on flush-on-commit
	[   40.695344][ T4088] BTRFS info (device dm-3): turning on discard
	[   40.696375][ T4088] BTRFS info (device dm-3): use zstd compression, level 3
	[   40.697563][ T4088] BTRFS info (device dm-3): using free space tree
	[   40.698639][ T4088] BTRFS info (device dm-3): has skinny extents
	[   53.675342][ T4088] ==================================================================
	[   53.676988][ T4088] BUG: KASAN: use-after-free in __list_del_entry_valid+0x52/0x81
	[   53.678199][ T4088] Read of size 8 at addr ffff8881d1f74a50 by task mount/4088
	[   53.679267][ T4088] 
	[   53.679620][ T4088] CPU: 1 PID: 4088 Comm: mount Not tainted 5.5.3-69e958fb39c2+ #6
	[   53.680736][ T4088] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
	[   53.682089][ T4088] Call Trace:
	[   53.682587][ T4088]  dump_stack+0xc1/0x11a
	[   53.683372][ T4088]  ? __list_del_entry_valid+0x52/0x81
	[   53.684170][ T4088]  print_address_description.constprop.7+0x20/0x200
	[   53.685163][ T4088]  ? __list_del_entry_valid+0x52/0x81
	[   53.685943][ T4088]  ? __list_del_entry_valid+0x52/0x81
	[   53.686727][ T4088]  __kasan_report.cold.10+0x1b/0x39
	[   53.687490][ T4088]  ? __list_del_entry_valid+0x52/0x81
	[   53.688272][ T4088]  kasan_report+0x12/0x20
	[   53.688906][ T4088]  __asan_load8+0x54/0x90
	[   53.689534][ T4088]  __list_del_entry_valid+0x52/0x81
	[   53.690287][ T4088]  clean_dirty_subvols+0x7f/0x230
	[   53.691034][ T4088]  btrfs_recover_relocation+0x738/0x7c0
	[   53.691856][ T4088]  ? btrfs_relocate_block_group+0x4e0/0x4e0
	[   53.692717][ T4088]  ? __del_qgroup_relation+0x440/0x440
	[   53.693513][ T4088]  ? migrate_swap_stop+0x3e0/0x3e0
	[   53.694249][ T4088]  ? _raw_read_unlock+0x22/0x30
	[   53.694982][ T4088]  open_ctree+0x2db1/0x34b0
	[   53.695691][ T4088]  ? close_ctree+0x4a4/0x4a4
	[   53.696380][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
	[   53.697177][ T4088]  ? btrfs_decode_error+0x40/0x40
	[   53.697935][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[   53.698735][ T4088]  ? check_flags.part.42+0x86/0x220
	[   53.699491][ T4088]  ? __kasan_check_read+0x11/0x20
	[   53.700218][ T4088]  ? vfs_parse_fs_string+0xca/0x110
	[   53.700972][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[   53.701772][ T4088]  ? rcu_read_lock_bh_held+0xb0/0xb0
	[   53.702532][ T4088]  ? __lookup_constant+0x54/0x90
	[   53.703244][ T4088]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
	[   53.704160][ T4088]  ? kfree+0x1dd/0x210
	[   53.704760][ T4088]  ? btrfs_decode_error+0x40/0x40
	[   53.705486][ T4088]  legacy_get_tree+0x89/0xd0
	[   53.706152][ T4088]  vfs_get_tree+0x52/0x150
	[   53.706814][ T4088]  fc_mount+0x14/0x60
	[   53.707391][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
	[   53.708149][ T4088]  vfs_kern_mount+0x13/0x20
	[   53.708797][ T4088]  btrfs_mount+0x21a/0xbbe
	[   53.709430][ T4088]  ? check_chain_key+0x1e6/0x2e0
	[   53.710142][ T4088]  ? sched_clock_cpu+0x1b/0x120
	[   53.710856][ T4088]  ? btrfs_remount+0x7f0/0x7f0
	[   53.711544][ T4088]  ? check_flags.part.42+0x86/0x220
	[   53.712291][ T4088]  ? __kasan_check_read+0x11/0x20
	[   53.713025][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[   53.713825][ T4088]  ? check_flags.part.42+0x86/0x220
	[   53.714575][ T4088]  ? __kasan_check_read+0x11/0x20
	[   53.715304][ T4088]  ? vfs_parse_fs_string+0xca/0x110
	[   53.716056][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[   53.716855][ T4088]  ? rcu_read_lock_bh_held+0xb0/0xb0
	[   53.717612][ T4088]  ? __lookup_constant+0x54/0x90
	[   53.718329][ T4088]  ? cap_capable+0xd2/0x110
	[   53.718994][ T4088]  ? btrfs_remount+0x7f0/0x7f0
	[   53.719680][ T4088]  legacy_get_tree+0x89/0xd0
	[   53.720334][ T4088]  ? legacy_get_tree+0x89/0xd0
	[   53.721029][ T4088]  vfs_get_tree+0x52/0x150
	[   53.721675][ T4088]  do_mount+0xe7d/0x10b0
	[   53.722280][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
	[   53.723110][ T4088]  ? copy_mount_string+0x20/0x20
	[   53.723820][ T4088]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
	[   53.724732][ T4088]  ? kmem_cache_alloc_trace+0x5af/0x740
	[   53.725533][ T4088]  ? __kasan_check_write+0x14/0x20
	[   53.726277][ T4088]  ? __kasan_check_read+0x11/0x20
	[   53.727000][ T4088]  ? copy_mount_options+0x120/0x1e0
	[   53.727762][ T4088]  __x64_sys_mount+0x100/0x120
	[   53.728463][ T4088]  do_syscall_64+0x77/0x2c0
	[   53.729118][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
	[   53.729962][ T4088] RIP: 0033:0x7fc1d6a4ffea
	[   53.730598][ T4088] Code: 48 8b 0d a9 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48
	[   53.733376][ T4088] RSP: 002b:00007ffcf166ba18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
	[   53.734579][ T4088] RAX: ffffffffffffffda RBX: 0000558f7d225b40 RCX: 00007fc1d6a4ffea
	[   53.735714][ T4088] RDX: 0000558f7d22d5e0 RSI: 0000558f7d225d90 RDI: 0000558f7d225ed0
	[   53.736848][ T4088] RBP: 00007fc1d6d9d1c4 R08: 0000558f7d225e20 R09: 0000558f7d22da20
	[   53.737984][ T4088] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
	[   53.739120][ T4088] R13: 0000000000000400 R14: 0000558f7d225ed0 R15: 0000558f7d22d5e0
	[   53.740636][ T4088] Allocated by task 4088:
	[   53.741254][ T4088]  save_stack+0x21/0x90
	[   53.741850][ T4088]  __kasan_kmalloc.constprop.16+0xc1/0xd0
	[   53.742668][ T4088]  kasan_kmalloc+0x9/0x10
	[   53.743286][ T4088]  kmem_cache_alloc_trace+0x134/0x740
	[   53.744056][ T4088]  btrfs_read_tree_root+0x6d/0x1b0
	[   53.744788][ T4088]  btrfs_read_fs_root+0xf/0x60
	[   53.745473][ T4088]  btrfs_recover_relocation+0x205/0x7c0
	[   53.746261][ T4088]  open_ctree+0x2db1/0x34b0
	[   53.746905][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
	[   53.747673][ T4088]  legacy_get_tree+0x89/0xd0
	[   53.748326][ T4088]  vfs_get_tree+0x52/0x150
	[   53.748966][ T4088]  fc_mount+0x14/0x60
	[   53.749542][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
	[   53.750287][ T4088]  vfs_kern_mount+0x13/0x20
	[   53.750938][ T4088]  btrfs_mount+0x21a/0xbbe
	[   53.751571][ T4088]  legacy_get_tree+0x89/0xd0
	[   53.752224][ T4088]  vfs_get_tree+0x52/0x150
	[   53.752858][ T4088]  do_mount+0xe7d/0x10b0
	[   53.753467][ T4088]  __x64_sys_mount+0x100/0x120
	[   53.754152][ T4088]  do_syscall_64+0x77/0x2c0
	[   53.754801][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
	[   53.755647][ T4088] 
	[   53.755985][ T4088] Freed by task 4088:
	[   53.756563][ T4088]  save_stack+0x21/0x90
	[   53.757159][ T4088]  __kasan_slab_free+0x118/0x170
	[   53.757872][ T4088]  kasan_slab_free+0xe/0x10
	[   53.758516][ T4088]  kfree+0xd1/0x210
	[   53.759063][ T4088]  btrfs_drop_snapshot+0xde0/0x1010
	[   53.759809][ T4088]  clean_dirty_subvols+0x1d2/0x230
	[   53.760541][ T4088]  btrfs_recover_relocation+0x738/0x7c0
	[   53.761339][ T4088]  open_ctree+0x2db1/0x34b0
	[   53.761996][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
	[   53.762762][ T4088]  legacy_get_tree+0x89/0xd0
	[   53.763416][ T4088]  vfs_get_tree+0x52/0x150
	[   53.764055][ T4088]  fc_mount+0x14/0x60
	[   53.764632][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
	[   53.765377][ T4088]  vfs_kern_mount+0x13/0x20
	[   53.766024][ T4088]  btrfs_mount+0x21a/0xbbe
	[   53.766660][ T4088]  legacy_get_tree+0x89/0xd0
	[   53.767313][ T4088]  vfs_get_tree+0x52/0x150
	[   53.767952][ T4088]  do_mount+0xe7d/0x10b0
	[   53.768565][ T4088]  __x64_sys_mount+0x100/0x120
	[   53.769240][ T4088]  do_syscall_64+0x77/0x2c0
	[   53.769888][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
	[   53.770728][ T4088] 
	[   53.771066][ T4088] The buggy address belongs to the object at ffff8881d1f74000
	[   53.771066][ T4088]  which belongs to the cache kmalloc-4k of size 4096
	[   53.773068][ T4088] The buggy address is located 2640 bytes inside of
	[   53.773068][ T4088]  4096-byte region [ffff8881d1f74000, ffff8881d1f75000)
	[   53.774978][ T4088] The buggy address belongs to the page:
	[   53.775786][ T4088] page:ffffea000747dd00 refcount:1 mapcount:0 mapping:ffff888107c02c40 index:0xffff8881e4d680c0 compound_mapcount: 0
	[   53.777519][ T4088] raw: 017ffe0000010200 ffffea0007903c08 ffffea00078dbe88 ffff888107c02c40
	[   53.778740][ T4088] raw: ffff8881e4d680c0 ffff8881d1f74000 0000000100000001 0000000000000000
	[   53.780019][ T4088] page dumped because: kasan: bad access detected
	[   53.780950][ T4088] 
	[   53.781293][ T4088] Memory state around the buggy address:
	[   53.782138][ T4088]  ffff8881d1f74900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[   53.783350][ T4088]  ffff8881d1f74980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[   53.784568][ T4088] >ffff8881d1f74a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[   53.785780][ T4088]                                                  ^
	[   53.786785][ T4088]  ffff8881d1f74a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[   53.787994][ T4088]  ffff8881d1f74b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
	[   53.789203][ T4088] ==================================================================
	[   53.790409][ T4088] Disabling lock debugging due to kernel taint
	[   53.886422][ T4088] BTRFS info (device dm-3): balance: resume skipped
	[   53.888140][ T4088] BTRFS info (device dm-3): checking UUID tree
	[   73.938826][ T4293] BTRFS debug (device dm-3): cleaner removing 9497

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 195 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5...and 5.5.3
  2020-02-13  5:20     ` KASAN splat during mount on 5.4.5...and 5.5.3 Zygo Blaxell
@ 2020-02-13  5:57       ` Qu Wenruo
  2020-02-13 18:36         ` Zygo Blaxell
  0 siblings, 1 reply; 8+ messages in thread
From: Qu Wenruo @ 2020-02-13  5:57 UTC (permalink / raw)
  To: Zygo Blaxell, dsterba, linux-btrfs

[-- Attachment #1.1: Type: text/plain, Size: 11326 bytes --]



On 2020/2/13 下午1:20, Zygo Blaxell wrote:
> On Mon, Feb 03, 2020 at 01:44:25PM -0500, Zygo Blaxell wrote:
>> On Mon, Jan 20, 2020 at 08:46:50PM +0100, David Sterba wrote:
>>> On Sat, Dec 28, 2019 at 03:03:26PM -0500, Zygo Blaxell wrote:
>>>>
>>>> [...etc...it dumps the same stacks again in the BUG]
>>>>
>>>> The deepest level of fs/btrfs code is the list_del_init in
>>>> clean_dirty_subvols.
>>>>
>>>> After a reboot the next mount (and all subsequent mounts so far)
>>>> was successful.  I don't have a reproducer.
>>>
>>> For the record, this and other KASAN reports regarding reloc root, is
>>> going to be fixed in 5.4.14, "btrfs: relocation: fix reloc_root lifespan
>>> and access" (6282675e6708ec78). Thanks for the reports and debugging
>>> help.
>>
>> Confirmed:  I have not seen this bug since applying the first versions of
>> the patch to my test kernels in 5.4.8.  
> 
> D'oh...maybe not?  Here's 5.5.3:
> 
> 	[   40.692923][ T4088] BTRFS info (device dm-3): enabling ssd optimizations
> 	[   40.694158][ T4088] BTRFS info (device dm-3): turning on flush-on-commit
> 	[   40.695344][ T4088] BTRFS info (device dm-3): turning on discard
> 	[   40.696375][ T4088] BTRFS info (device dm-3): use zstd compression, level 3
> 	[   40.697563][ T4088] BTRFS info (device dm-3): using free space tree
> 	[   40.698639][ T4088] BTRFS info (device dm-3): has skinny extents
> 	[   53.675342][ T4088] ==================================================================
> 	[   53.676988][ T4088] BUG: KASAN: use-after-free in __list_del_entry_valid+0x52/0x81
> 	[   53.678199][ T4088] Read of size 8 at addr ffff8881d1f74a50 by task mount/4088
> 	[   53.679267][ T4088] 
> 	[   53.679620][ T4088] CPU: 1 PID: 4088 Comm: mount Not tainted 5.5.3-69e958fb39c2+ #6
> 	[   53.680736][ T4088] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> 	[   53.682089][ T4088] Call Trace:
> 	[   53.682587][ T4088]  dump_stack+0xc1/0x11a
> 	[   53.683372][ T4088]  ? __list_del_entry_valid+0x52/0x81
> 	[   53.684170][ T4088]  print_address_description.constprop.7+0x20/0x200
> 	[   53.685163][ T4088]  ? __list_del_entry_valid+0x52/0x81
> 	[   53.685943][ T4088]  ? __list_del_entry_valid+0x52/0x81
> 	[   53.686727][ T4088]  __kasan_report.cold.10+0x1b/0x39
> 	[   53.687490][ T4088]  ? __list_del_entry_valid+0x52/0x81
> 	[   53.688272][ T4088]  kasan_report+0x12/0x20
> 	[   53.688906][ T4088]  __asan_load8+0x54/0x90
> 	[   53.689534][ T4088]  __list_del_entry_valid+0x52/0x81
> 	[   53.690287][ T4088]  clean_dirty_subvols+0x7f/0x230
> 	[   53.691034][ T4088]  btrfs_recover_relocation+0x738/0x7c0

That's from the mount time recovery path.

I guess it's the list_del_init() in clean_dirty_subvols(), which means
its root->reloc_dirty_list is not properly initialized?

That doesn't even make sense.
As that root is grabbed from list_for_each_entry_safe(), using
reloc_dirty_list.

This doesn't look correct, do you have similar reports with similar
backtrace?

Thanks,
Qu


> 	[   53.691856][ T4088]  ? btrfs_relocate_block_group+0x4e0/0x4e0
> 	[   53.692717][ T4088]  ? __del_qgroup_relation+0x440/0x440
> 	[   53.693513][ T4088]  ? migrate_swap_stop+0x3e0/0x3e0
> 	[   53.694249][ T4088]  ? _raw_read_unlock+0x22/0x30
> 	[   53.694982][ T4088]  open_ctree+0x2db1/0x34b0
> 	[   53.695691][ T4088]  ? close_ctree+0x4a4/0x4a4
> 	[   53.696380][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
> 	[   53.697177][ T4088]  ? btrfs_decode_error+0x40/0x40
> 	[   53.697935][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[   53.698735][ T4088]  ? check_flags.part.42+0x86/0x220
> 	[   53.699491][ T4088]  ? __kasan_check_read+0x11/0x20
> 	[   53.700218][ T4088]  ? vfs_parse_fs_string+0xca/0x110
> 	[   53.700972][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[   53.701772][ T4088]  ? rcu_read_lock_bh_held+0xb0/0xb0
> 	[   53.702532][ T4088]  ? __lookup_constant+0x54/0x90
> 	[   53.703244][ T4088]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> 	[   53.704160][ T4088]  ? kfree+0x1dd/0x210
> 	[   53.704760][ T4088]  ? btrfs_decode_error+0x40/0x40
> 	[   53.705486][ T4088]  legacy_get_tree+0x89/0xd0
> 	[   53.706152][ T4088]  vfs_get_tree+0x52/0x150
> 	[   53.706814][ T4088]  fc_mount+0x14/0x60
> 	[   53.707391][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
> 	[   53.708149][ T4088]  vfs_kern_mount+0x13/0x20
> 	[   53.708797][ T4088]  btrfs_mount+0x21a/0xbbe
> 	[   53.709430][ T4088]  ? check_chain_key+0x1e6/0x2e0
> 	[   53.710142][ T4088]  ? sched_clock_cpu+0x1b/0x120
> 	[   53.710856][ T4088]  ? btrfs_remount+0x7f0/0x7f0
> 	[   53.711544][ T4088]  ? check_flags.part.42+0x86/0x220
> 	[   53.712291][ T4088]  ? __kasan_check_read+0x11/0x20
> 	[   53.713025][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[   53.713825][ T4088]  ? check_flags.part.42+0x86/0x220
> 	[   53.714575][ T4088]  ? __kasan_check_read+0x11/0x20
> 	[   53.715304][ T4088]  ? vfs_parse_fs_string+0xca/0x110
> 	[   53.716056][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[   53.716855][ T4088]  ? rcu_read_lock_bh_held+0xb0/0xb0
> 	[   53.717612][ T4088]  ? __lookup_constant+0x54/0x90
> 	[   53.718329][ T4088]  ? cap_capable+0xd2/0x110
> 	[   53.718994][ T4088]  ? btrfs_remount+0x7f0/0x7f0
> 	[   53.719680][ T4088]  legacy_get_tree+0x89/0xd0
> 	[   53.720334][ T4088]  ? legacy_get_tree+0x89/0xd0
> 	[   53.721029][ T4088]  vfs_get_tree+0x52/0x150
> 	[   53.721675][ T4088]  do_mount+0xe7d/0x10b0
> 	[   53.722280][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> 	[   53.723110][ T4088]  ? copy_mount_string+0x20/0x20
> 	[   53.723820][ T4088]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> 	[   53.724732][ T4088]  ? kmem_cache_alloc_trace+0x5af/0x740
> 	[   53.725533][ T4088]  ? __kasan_check_write+0x14/0x20
> 	[   53.726277][ T4088]  ? __kasan_check_read+0x11/0x20
> 	[   53.727000][ T4088]  ? copy_mount_options+0x120/0x1e0
> 	[   53.727762][ T4088]  __x64_sys_mount+0x100/0x120
> 	[   53.728463][ T4088]  do_syscall_64+0x77/0x2c0
> 	[   53.729118][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 	[   53.729962][ T4088] RIP: 0033:0x7fc1d6a4ffea
> 	[   53.730598][ T4088] Code: 48 8b 0d a9 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48
> 	[   53.733376][ T4088] RSP: 002b:00007ffcf166ba18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
> 	[   53.734579][ T4088] RAX: ffffffffffffffda RBX: 0000558f7d225b40 RCX: 00007fc1d6a4ffea
> 	[   53.735714][ T4088] RDX: 0000558f7d22d5e0 RSI: 0000558f7d225d90 RDI: 0000558f7d225ed0
> 	[   53.736848][ T4088] RBP: 00007fc1d6d9d1c4 R08: 0000558f7d225e20 R09: 0000558f7d22da20
> 	[   53.737984][ T4088] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
> 	[   53.739120][ T4088] R13: 0000000000000400 R14: 0000558f7d225ed0 R15: 0000558f7d22d5e0
> 	[   53.740636][ T4088] Allocated by task 4088:
> 	[   53.741254][ T4088]  save_stack+0x21/0x90
> 	[   53.741850][ T4088]  __kasan_kmalloc.constprop.16+0xc1/0xd0
> 	[   53.742668][ T4088]  kasan_kmalloc+0x9/0x10
> 	[   53.743286][ T4088]  kmem_cache_alloc_trace+0x134/0x740
> 	[   53.744056][ T4088]  btrfs_read_tree_root+0x6d/0x1b0
> 	[   53.744788][ T4088]  btrfs_read_fs_root+0xf/0x60
> 	[   53.745473][ T4088]  btrfs_recover_relocation+0x205/0x7c0
> 	[   53.746261][ T4088]  open_ctree+0x2db1/0x34b0
> 	[   53.746905][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
> 	[   53.747673][ T4088]  legacy_get_tree+0x89/0xd0
> 	[   53.748326][ T4088]  vfs_get_tree+0x52/0x150
> 	[   53.748966][ T4088]  fc_mount+0x14/0x60
> 	[   53.749542][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
> 	[   53.750287][ T4088]  vfs_kern_mount+0x13/0x20
> 	[   53.750938][ T4088]  btrfs_mount+0x21a/0xbbe
> 	[   53.751571][ T4088]  legacy_get_tree+0x89/0xd0
> 	[   53.752224][ T4088]  vfs_get_tree+0x52/0x150
> 	[   53.752858][ T4088]  do_mount+0xe7d/0x10b0
> 	[   53.753467][ T4088]  __x64_sys_mount+0x100/0x120
> 	[   53.754152][ T4088]  do_syscall_64+0x77/0x2c0
> 	[   53.754801][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 	[   53.755647][ T4088] 
> 	[   53.755985][ T4088] Freed by task 4088:
> 	[   53.756563][ T4088]  save_stack+0x21/0x90
> 	[   53.757159][ T4088]  __kasan_slab_free+0x118/0x170
> 	[   53.757872][ T4088]  kasan_slab_free+0xe/0x10
> 	[   53.758516][ T4088]  kfree+0xd1/0x210
> 	[   53.759063][ T4088]  btrfs_drop_snapshot+0xde0/0x1010
> 	[   53.759809][ T4088]  clean_dirty_subvols+0x1d2/0x230
> 	[   53.760541][ T4088]  btrfs_recover_relocation+0x738/0x7c0
> 	[   53.761339][ T4088]  open_ctree+0x2db1/0x34b0
> 	[   53.761996][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
> 	[   53.762762][ T4088]  legacy_get_tree+0x89/0xd0
> 	[   53.763416][ T4088]  vfs_get_tree+0x52/0x150
> 	[   53.764055][ T4088]  fc_mount+0x14/0x60
> 	[   53.764632][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
> 	[   53.765377][ T4088]  vfs_kern_mount+0x13/0x20
> 	[   53.766024][ T4088]  btrfs_mount+0x21a/0xbbe
> 	[   53.766660][ T4088]  legacy_get_tree+0x89/0xd0
> 	[   53.767313][ T4088]  vfs_get_tree+0x52/0x150
> 	[   53.767952][ T4088]  do_mount+0xe7d/0x10b0
> 	[   53.768565][ T4088]  __x64_sys_mount+0x100/0x120
> 	[   53.769240][ T4088]  do_syscall_64+0x77/0x2c0
> 	[   53.769888][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 	[   53.770728][ T4088] 
> 	[   53.771066][ T4088] The buggy address belongs to the object at ffff8881d1f74000
> 	[   53.771066][ T4088]  which belongs to the cache kmalloc-4k of size 4096
> 	[   53.773068][ T4088] The buggy address is located 2640 bytes inside of
> 	[   53.773068][ T4088]  4096-byte region [ffff8881d1f74000, ffff8881d1f75000)
> 	[   53.774978][ T4088] The buggy address belongs to the page:
> 	[   53.775786][ T4088] page:ffffea000747dd00 refcount:1 mapcount:0 mapping:ffff888107c02c40 index:0xffff8881e4d680c0 compound_mapcount: 0
> 	[   53.777519][ T4088] raw: 017ffe0000010200 ffffea0007903c08 ffffea00078dbe88 ffff888107c02c40
> 	[   53.778740][ T4088] raw: ffff8881e4d680c0 ffff8881d1f74000 0000000100000001 0000000000000000
> 	[   53.780019][ T4088] page dumped because: kasan: bad access detected
> 	[   53.780950][ T4088] 
> 	[   53.781293][ T4088] Memory state around the buggy address:
> 	[   53.782138][ T4088]  ffff8881d1f74900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[   53.783350][ T4088]  ffff8881d1f74980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[   53.784568][ T4088] >ffff8881d1f74a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[   53.785780][ T4088]                                                  ^
> 	[   53.786785][ T4088]  ffff8881d1f74a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[   53.787994][ T4088]  ffff8881d1f74b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> 	[   53.789203][ T4088] ==================================================================
> 	[   53.790409][ T4088] Disabling lock debugging due to kernel taint
> 	[   53.886422][ T4088] BTRFS info (device dm-3): balance: resume skipped
> 	[   53.888140][ T4088] BTRFS info (device dm-3): checking UUID tree
> 	[   73.938826][ T4293] BTRFS debug (device dm-3): cleaner removing 9497
> 


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: KASAN splat during mount on 5.4.5...and 5.5.3
  2020-02-13  5:57       ` Qu Wenruo
@ 2020-02-13 18:36         ` Zygo Blaxell
  0 siblings, 0 replies; 8+ messages in thread
From: Zygo Blaxell @ 2020-02-13 18:36 UTC (permalink / raw)
  To: Qu Wenruo; +Cc: dsterba, linux-btrfs

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

On Thu, Feb 13, 2020 at 01:57:32PM +0800, Qu Wenruo wrote:
> 
> 
> On 2020/2/13 下午1:20, Zygo Blaxell wrote:
> > On Mon, Feb 03, 2020 at 01:44:25PM -0500, Zygo Blaxell wrote:
> >> On Mon, Jan 20, 2020 at 08:46:50PM +0100, David Sterba wrote:
> >>> On Sat, Dec 28, 2019 at 03:03:26PM -0500, Zygo Blaxell wrote:
> >>>>
> >>>> [...etc...it dumps the same stacks again in the BUG]
> >>>>
> >>>> The deepest level of fs/btrfs code is the list_del_init in
> >>>> clean_dirty_subvols.
> >>>>
> >>>> After a reboot the next mount (and all subsequent mounts so far)
> >>>> was successful.  I don't have a reproducer.
> >>>
> >>> For the record, this and other KASAN reports regarding reloc root, is
> >>> going to be fixed in 5.4.14, "btrfs: relocation: fix reloc_root lifespan
> >>> and access" (6282675e6708ec78). Thanks for the reports and debugging
> >>> help.
> >>
> >> Confirmed:  I have not seen this bug since applying the first versions of
> >> the patch to my test kernels in 5.4.8.  
> > 
> > D'oh...maybe not?  Here's 5.5.3:
> > 
> > 	[   40.692923][ T4088] BTRFS info (device dm-3): enabling ssd optimizations
> > 	[   40.694158][ T4088] BTRFS info (device dm-3): turning on flush-on-commit
> > 	[   40.695344][ T4088] BTRFS info (device dm-3): turning on discard
> > 	[   40.696375][ T4088] BTRFS info (device dm-3): use zstd compression, level 3
> > 	[   40.697563][ T4088] BTRFS info (device dm-3): using free space tree
> > 	[   40.698639][ T4088] BTRFS info (device dm-3): has skinny extents
> > 	[   53.675342][ T4088] ==================================================================
> > 	[   53.676988][ T4088] BUG: KASAN: use-after-free in __list_del_entry_valid+0x52/0x81
> > 	[   53.678199][ T4088] Read of size 8 at addr ffff8881d1f74a50 by task mount/4088
> > 	[   53.679267][ T4088] 
> > 	[   53.679620][ T4088] CPU: 1 PID: 4088 Comm: mount Not tainted 5.5.3-69e958fb39c2+ #6
> > 	[   53.680736][ T4088] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> > 	[   53.682089][ T4088] Call Trace:
> > 	[   53.682587][ T4088]  dump_stack+0xc1/0x11a
> > 	[   53.683372][ T4088]  ? __list_del_entry_valid+0x52/0x81
> > 	[   53.684170][ T4088]  print_address_description.constprop.7+0x20/0x200
> > 	[   53.685163][ T4088]  ? __list_del_entry_valid+0x52/0x81
> > 	[   53.685943][ T4088]  ? __list_del_entry_valid+0x52/0x81
> > 	[   53.686727][ T4088]  __kasan_report.cold.10+0x1b/0x39
> > 	[   53.687490][ T4088]  ? __list_del_entry_valid+0x52/0x81
> > 	[   53.688272][ T4088]  kasan_report+0x12/0x20
> > 	[   53.688906][ T4088]  __asan_load8+0x54/0x90
> > 	[   53.689534][ T4088]  __list_del_entry_valid+0x52/0x81
> > 	[   53.690287][ T4088]  clean_dirty_subvols+0x7f/0x230
> > 	[   53.691034][ T4088]  btrfs_recover_relocation+0x738/0x7c0
> 
> That's from the mount time recovery path.
> 
> I guess it's the list_del_init() in clean_dirty_subvols(), which means
> its root->reloc_dirty_list is not properly initialized?
> 
> That doesn't even make sense.
> As that root is grabbed from list_for_each_entry_safe(), using
> reloc_dirty_list.
> 
> This doesn't look correct, do you have similar reports with similar
> backtrace?

Only these two so far.  The previous one was on 5.4.5.  I've done about
50 mounts in between on various kernels without incident.

All of these are mounts after a crash while under heavy write load,
either due to a natural kernel bug or forced by resetting the VM.
I don't bother testing clean umounts or crashes while idle--those are
not typical operating conditions in the production environment.  ;)

My guess is that you could reproduce this by setting up a VM to run
continuous write stress workloads, then force-reboot the VM over and
over until this reproduces.  Shouldn't take more than 100 cycles to hit
the stack trace.



> Thanks,
> Qu
> 
> 
> > 	[   53.691856][ T4088]  ? btrfs_relocate_block_group+0x4e0/0x4e0
> > 	[   53.692717][ T4088]  ? __del_qgroup_relation+0x440/0x440
> > 	[   53.693513][ T4088]  ? migrate_swap_stop+0x3e0/0x3e0
> > 	[   53.694249][ T4088]  ? _raw_read_unlock+0x22/0x30
> > 	[   53.694982][ T4088]  open_ctree+0x2db1/0x34b0
> > 	[   53.695691][ T4088]  ? close_ctree+0x4a4/0x4a4
> > 	[   53.696380][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
> > 	[   53.697177][ T4088]  ? btrfs_decode_error+0x40/0x40
> > 	[   53.697935][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[   53.698735][ T4088]  ? check_flags.part.42+0x86/0x220
> > 	[   53.699491][ T4088]  ? __kasan_check_read+0x11/0x20
> > 	[   53.700218][ T4088]  ? vfs_parse_fs_string+0xca/0x110
> > 	[   53.700972][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[   53.701772][ T4088]  ? rcu_read_lock_bh_held+0xb0/0xb0
> > 	[   53.702532][ T4088]  ? __lookup_constant+0x54/0x90
> > 	[   53.703244][ T4088]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> > 	[   53.704160][ T4088]  ? kfree+0x1dd/0x210
> > 	[   53.704760][ T4088]  ? btrfs_decode_error+0x40/0x40
> > 	[   53.705486][ T4088]  legacy_get_tree+0x89/0xd0
> > 	[   53.706152][ T4088]  vfs_get_tree+0x52/0x150
> > 	[   53.706814][ T4088]  fc_mount+0x14/0x60
> > 	[   53.707391][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
> > 	[   53.708149][ T4088]  vfs_kern_mount+0x13/0x20
> > 	[   53.708797][ T4088]  btrfs_mount+0x21a/0xbbe
> > 	[   53.709430][ T4088]  ? check_chain_key+0x1e6/0x2e0
> > 	[   53.710142][ T4088]  ? sched_clock_cpu+0x1b/0x120
> > 	[   53.710856][ T4088]  ? btrfs_remount+0x7f0/0x7f0
> > 	[   53.711544][ T4088]  ? check_flags.part.42+0x86/0x220
> > 	[   53.712291][ T4088]  ? __kasan_check_read+0x11/0x20
> > 	[   53.713025][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[   53.713825][ T4088]  ? check_flags.part.42+0x86/0x220
> > 	[   53.714575][ T4088]  ? __kasan_check_read+0x11/0x20
> > 	[   53.715304][ T4088]  ? vfs_parse_fs_string+0xca/0x110
> > 	[   53.716056][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[   53.716855][ T4088]  ? rcu_read_lock_bh_held+0xb0/0xb0
> > 	[   53.717612][ T4088]  ? __lookup_constant+0x54/0x90
> > 	[   53.718329][ T4088]  ? cap_capable+0xd2/0x110
> > 	[   53.718994][ T4088]  ? btrfs_remount+0x7f0/0x7f0
> > 	[   53.719680][ T4088]  legacy_get_tree+0x89/0xd0
> > 	[   53.720334][ T4088]  ? legacy_get_tree+0x89/0xd0
> > 	[   53.721029][ T4088]  vfs_get_tree+0x52/0x150
> > 	[   53.721675][ T4088]  do_mount+0xe7d/0x10b0
> > 	[   53.722280][ T4088]  ? rcu_read_lock_sched_held+0xa1/0xd0
> > 	[   53.723110][ T4088]  ? copy_mount_string+0x20/0x20
> > 	[   53.723820][ T4088]  ? debug_lockdep_rcu_enabled.part.18+0x1a/0x30
> > 	[   53.724732][ T4088]  ? kmem_cache_alloc_trace+0x5af/0x740
> > 	[   53.725533][ T4088]  ? __kasan_check_write+0x14/0x20
> > 	[   53.726277][ T4088]  ? __kasan_check_read+0x11/0x20
> > 	[   53.727000][ T4088]  ? copy_mount_options+0x120/0x1e0
> > 	[   53.727762][ T4088]  __x64_sys_mount+0x100/0x120
> > 	[   53.728463][ T4088]  do_syscall_64+0x77/0x2c0
> > 	[   53.729118][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > 	[   53.729962][ T4088] RIP: 0033:0x7fc1d6a4ffea
> > 	[   53.730598][ T4088] Code: 48 8b 0d a9 0e 0c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 76 0e 0c 00 f7 d8 64 89 01 48
> > 	[   53.733376][ T4088] RSP: 002b:00007ffcf166ba18 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
> > 	[   53.734579][ T4088] RAX: ffffffffffffffda RBX: 0000558f7d225b40 RCX: 00007fc1d6a4ffea
> > 	[   53.735714][ T4088] RDX: 0000558f7d22d5e0 RSI: 0000558f7d225d90 RDI: 0000558f7d225ed0
> > 	[   53.736848][ T4088] RBP: 00007fc1d6d9d1c4 R08: 0000558f7d225e20 R09: 0000558f7d22da20
> > 	[   53.737984][ T4088] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000000
> > 	[   53.739120][ T4088] R13: 0000000000000400 R14: 0000558f7d225ed0 R15: 0000558f7d22d5e0
> > 	[   53.740636][ T4088] Allocated by task 4088:
> > 	[   53.741254][ T4088]  save_stack+0x21/0x90
> > 	[   53.741850][ T4088]  __kasan_kmalloc.constprop.16+0xc1/0xd0
> > 	[   53.742668][ T4088]  kasan_kmalloc+0x9/0x10
> > 	[   53.743286][ T4088]  kmem_cache_alloc_trace+0x134/0x740
> > 	[   53.744056][ T4088]  btrfs_read_tree_root+0x6d/0x1b0
> > 	[   53.744788][ T4088]  btrfs_read_fs_root+0xf/0x60
> > 	[   53.745473][ T4088]  btrfs_recover_relocation+0x205/0x7c0
> > 	[   53.746261][ T4088]  open_ctree+0x2db1/0x34b0
> > 	[   53.746905][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
> > 	[   53.747673][ T4088]  legacy_get_tree+0x89/0xd0
> > 	[   53.748326][ T4088]  vfs_get_tree+0x52/0x150
> > 	[   53.748966][ T4088]  fc_mount+0x14/0x60
> > 	[   53.749542][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
> > 	[   53.750287][ T4088]  vfs_kern_mount+0x13/0x20
> > 	[   53.750938][ T4088]  btrfs_mount+0x21a/0xbbe
> > 	[   53.751571][ T4088]  legacy_get_tree+0x89/0xd0
> > 	[   53.752224][ T4088]  vfs_get_tree+0x52/0x150
> > 	[   53.752858][ T4088]  do_mount+0xe7d/0x10b0
> > 	[   53.753467][ T4088]  __x64_sys_mount+0x100/0x120
> > 	[   53.754152][ T4088]  do_syscall_64+0x77/0x2c0
> > 	[   53.754801][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > 	[   53.755647][ T4088] 
> > 	[   53.755985][ T4088] Freed by task 4088:
> > 	[   53.756563][ T4088]  save_stack+0x21/0x90
> > 	[   53.757159][ T4088]  __kasan_slab_free+0x118/0x170
> > 	[   53.757872][ T4088]  kasan_slab_free+0xe/0x10
> > 	[   53.758516][ T4088]  kfree+0xd1/0x210
> > 	[   53.759063][ T4088]  btrfs_drop_snapshot+0xde0/0x1010
> > 	[   53.759809][ T4088]  clean_dirty_subvols+0x1d2/0x230
> > 	[   53.760541][ T4088]  btrfs_recover_relocation+0x738/0x7c0
> > 	[   53.761339][ T4088]  open_ctree+0x2db1/0x34b0
> > 	[   53.761996][ T4088]  btrfs_mount_root.cold.69+0xe/0x10e
> > 	[   53.762762][ T4088]  legacy_get_tree+0x89/0xd0
> > 	[   53.763416][ T4088]  vfs_get_tree+0x52/0x150
> > 	[   53.764055][ T4088]  fc_mount+0x14/0x60
> > 	[   53.764632][ T4088]  vfs_kern_mount.part.36+0x61/0xa0
> > 	[   53.765377][ T4088]  vfs_kern_mount+0x13/0x20
> > 	[   53.766024][ T4088]  btrfs_mount+0x21a/0xbbe
> > 	[   53.766660][ T4088]  legacy_get_tree+0x89/0xd0
> > 	[   53.767313][ T4088]  vfs_get_tree+0x52/0x150
> > 	[   53.767952][ T4088]  do_mount+0xe7d/0x10b0
> > 	[   53.768565][ T4088]  __x64_sys_mount+0x100/0x120
> > 	[   53.769240][ T4088]  do_syscall_64+0x77/0x2c0
> > 	[   53.769888][ T4088]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > 	[   53.770728][ T4088] 
> > 	[   53.771066][ T4088] The buggy address belongs to the object at ffff8881d1f74000
> > 	[   53.771066][ T4088]  which belongs to the cache kmalloc-4k of size 4096
> > 	[   53.773068][ T4088] The buggy address is located 2640 bytes inside of
> > 	[   53.773068][ T4088]  4096-byte region [ffff8881d1f74000, ffff8881d1f75000)
> > 	[   53.774978][ T4088] The buggy address belongs to the page:
> > 	[   53.775786][ T4088] page:ffffea000747dd00 refcount:1 mapcount:0 mapping:ffff888107c02c40 index:0xffff8881e4d680c0 compound_mapcount: 0
> > 	[   53.777519][ T4088] raw: 017ffe0000010200 ffffea0007903c08 ffffea00078dbe88 ffff888107c02c40
> > 	[   53.778740][ T4088] raw: ffff8881e4d680c0 ffff8881d1f74000 0000000100000001 0000000000000000
> > 	[   53.780019][ T4088] page dumped because: kasan: bad access detected
> > 	[   53.780950][ T4088] 
> > 	[   53.781293][ T4088] Memory state around the buggy address:
> > 	[   53.782138][ T4088]  ffff8881d1f74900: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[   53.783350][ T4088]  ffff8881d1f74980: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[   53.784568][ T4088] >ffff8881d1f74a00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[   53.785780][ T4088]                                                  ^
> > 	[   53.786785][ T4088]  ffff8881d1f74a80: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[   53.787994][ T4088]  ffff8881d1f74b00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > 	[   53.789203][ T4088] ==================================================================
> > 	[   53.790409][ T4088] Disabling lock debugging due to kernel taint
> > 	[   53.886422][ T4088] BTRFS info (device dm-3): balance: resume skipped
> > 	[   53.888140][ T4088] BTRFS info (device dm-3): checking UUID tree
> > 	[   73.938826][ T4293] BTRFS debug (device dm-3): cleaner removing 9497
> > 
> 




[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 195 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, back to index

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-12-28 20:03 KASAN splat during mount on 5.4.5, no reproducer Zygo Blaxell
2019-12-29  1:32 ` Qu Wenruo
2019-12-29  5:14   ` Zygo Blaxell
2020-01-20 19:46 ` David Sterba
2020-02-03 18:44   ` Zygo Blaxell
2020-02-13  5:20     ` KASAN splat during mount on 5.4.5...and 5.5.3 Zygo Blaxell
2020-02-13  5:57       ` Qu Wenruo
2020-02-13 18:36         ` Zygo Blaxell

Linux-BTRFS Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/linux-btrfs/0 linux-btrfs/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 linux-btrfs linux-btrfs/ https://lore.kernel.org/linux-btrfs \
		linux-btrfs@vger.kernel.org
	public-inbox-index linux-btrfs

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-btrfs


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git