* lockdep + kasan bug?
@ 2023-11-20 23:36 Kent Overstreet
2023-11-21 10:36 ` Peter Zijlstra
0 siblings, 1 reply; 6+ messages in thread
From: Kent Overstreet @ 2023-11-20 23:36 UTC (permalink / raw
To: Peter Zijlstra, Ingo Molnar, Will Deacon, Waiman Long, Boqun Feng
Cc: linux-kernel
I've been seeing a lot of reports like the following in a lot of my
lockdep + kasan tests.
Some lockdep patches are in my tree: they don't touch this code path
(except I do have to increase MAX_LOCK_DEPTH from 48 to 63, perhaps that
has unintended side effects?)
https://evilpiepirate.org/git/bcachefs.git/log/?id=2f42f415f7573001b4f4887b785d8a8747b3757f
bcachefs does take a _large_ number of locks for lockdep to track, also
possibly relevant
Have not dug into the lockdep hash table of outstanding locks code yet
but happy to test patches...
04752 ========= TEST tiering_variable_buckets_replicas
04752
04752 WATCHDOG 3600
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): mounting version 1.3: rebalance_work opts=metadata_replicas=2,data_replicas=2,foreground_target=ssd,background_target=hdd,promote_target=ssd,fsck
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): initializing new filesystem
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): going read-write
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): marking superblocks
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): initializing freespace
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): done initializing freespace
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): reading snapshots table
04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): reading snapshots done
04753 WATCHDOG 3600
04753 randrw: (g=0): rw=randrw, bs=(R) 4096B-1024KiB, (W) 4096B-1024KiB, (T) 4096B-1024KiB, ioengine=libaio, iodepth=64
04753 fio-3.33
04753 Starting 1 process
04753 randrw: Laying out IO file (1 file / 3500MiB)
05117 Jobs: 1 (f=1)
05117 BUG: KASAN: global-out-of-bounds in add_chain_block+0x44/0x288
05117 Read of size 4 at addr ffffffc081b7a8bc by task fio/120528
05117
05117 CPU: 11 PID: 120528 Comm: fio Tainted: G L 6.6.0-ktest-gc18b7260ddd3 #8209
05117 Hardware name: linux,dummy-virt (DT)
05117 Call trace:
05117 dump_backtrace+0xa8/0xe8
05117 show_stack+0x1c/0x30
05117 dump_stack_lvl+0x5c/0xa0
05117 print_report+0x1e4/0x5a0
05117 kasan_report+0x80/0xc0
05117 __asan_load4+0x90/0xb0
05117 add_chain_block+0x44/0x288
05117 __lock_acquire+0x1104/0x24f8
05117 lock_acquire+0x1e0/0x470
05117 _raw_spin_lock_nested+0x54/0x78
05117 raw_spin_rq_lock_nested+0x30/0x50
05117 try_to_wake_up+0x3b4/0x1050
05117 wake_up_process+0x1c/0x30
05117 kick_pool+0x104/0x1b0
05117 __queue_work+0x350/0xa58
05117 queue_work_on+0x98/0xd0
05117 __bch2_btree_node_write+0xec0/0x10a0
05117 bch2_btree_node_write+0x88/0x138
05117 btree_split+0x744/0x14a0
05117 bch2_btree_split_leaf+0x94/0x258
05117 bch2_trans_commit_error.isra.0+0x234/0x7d0
05117 __bch2_trans_commit+0x1128/0x3010
05117 bch2_extent_update+0x410/0x570
05117 bch2_write_index_default+0x404/0x598
05117 __bch2_write_index+0xb0/0x3b0
05117 __bch2_write+0x6f0/0x928
05117 bch2_write+0x368/0x8e0
05117 bch2_direct_write+0xaa8/0x12c0
05117 bch2_write_iter+0x2e4/0x1050
05117 aio_write.constprop.0+0x19c/0x420
05117 io_submit_one.constprop.0+0xf30/0x17a0
05117 __arm64_sys_io_submit+0x244/0x388
05117 invoke_syscall.constprop.0+0x64/0x138
05117 do_el0_svc+0x7c/0x120
05117 el0_svc+0x34/0x80
05117 el0t_64_sync_handler+0xb8/0xc0
05117 el0t_64_sync+0x14c/0x150
05117
05117 The buggy address belongs to the variable:
05117 nr_large_chain_blocks+0x3c/0x40
05117
05117 The buggy address belongs to the virtual mapping at
05117 [ffffffc081710000, ffffffc088861000) created by:
05117 paging_init+0x260/0x820
05117
05117 The buggy address belongs to the physical page:
05117 page:00000000ce625900 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x41d7a
05117 flags: 0x4000(reserved|zone=0)
05117 page_type: 0xffffffff()
05117 raw: 0000000000004000 fffffffe00075e88 fffffffe00075e88 0000000000000000
05117 raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
05117 page dumped because: kasan: bad access detected
05117
05117 Memory state around the buggy address:
05117 ffffffc081b7a780: 00 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9 f9 f9 f9 f9
05117 ffffffc081b7a800: 00 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
05117 >ffffffc081b7a880: 04 f9 f9 f9 f9 f9 f9 f9 00 00 00 00 00 00 00 00
05117 ^
05117 ffffffc081b7a900: f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9
05117 ffffffc081b7a980: f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9
05117 ==================================================================
05117 Kernel panic - not syncing: kasan.fault=panic set ...
05117 CPU: 11 PID: 120528 Comm: fio Tainted: G L 6.6.0-ktest-gc18b7260ddd3 #8209
05117 Hardware name: linux,dummy-virt (DT)
05117 Call trace:
05117 dump_backtrace+0xa8/0xe8
05117 show_stack+0x1c/0x30
05117 dump_stack_lvl+0x5c/0xa0
05117 dump_stack+0x18/0x20
05117 panic+0x3ac/0x408
05117 kasan_report_invalid_free+0x0/0x90
05117 kasan_report+0x90/0xc0
05117 __asan_load4+0x90/0xb0
05117 add_chain_block+0x44/0x288
05117 __lock_acquire+0x1104/0x24f8
05117 lock_acquire+0x1e0/0x470
05117 _raw_spin_lock_nested+0x54/0x78
05117 raw_spin_rq_lock_nested+0x30/0x50
05117 try_to_wake_up+0x3b4/0x1050
05117 wake_up_process+0x1c/0x30
05117 kick_pool+0x104/0x1b0
05117 __queue_work+0x350/0xa58
05117 queue_work_on+0x98/0xd0
05117 __bch2_btree_node_write+0xec0/0x10a0
05117 bch2_btree_node_write+0x88/0x138
05117 btree_split+0x744/0x14a0
05117 bch2_btree_split_leaf+0x94/0x258
05117 bch2_trans_commit_error.isra.0+0x234/0x7d0
05117 __bch2_trans_commit+0x1128/0x3010
05117 bch2_extent_update+0x410/0x570
05117 bch2_write_index_default+0x404/0x598
05117 __bch2_write_index+0xb0/0x3b0
05117 __bch2_write+0x6f0/0x928
05117 bch2_write+0x368/0x8e0
05117 bch2_direct_write+0xaa8/0x12c0
05117 bch2_write_iter+0x2e4/0x1050
05117 aio_write.constprop.0+0x19c/0x420
05117 io_submit_one.constprop.0+0xf30/0x17a0
05117 __arm64_sys_io_submit+0x244/0x388
05117 invoke_syscall.constprop.0+0x64/0x138
05117 do_el0_svc+0x7c/0x120
05117 el0_svc+0x34/0x80
05117 el0t_64_sync_handler+0xb8/0xc0
05117 el0t_64_sync+0x14c/0x150
05117 SMP: stopping secondary CPUs
05117 Kernel Offset: disabled
05117 CPU features: 0x0,00000000,70000001,1040500b
05117 Memory Limit: none
05117 ---[ end Kernel panic - not syncing: kasan.fault=panic set ... ]---
05122 ========= FAILED TIMEOUT tiering_variable_buckets_replicas in 3600s
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: lockdep + kasan bug?
2023-11-20 23:36 lockdep + kasan bug? Kent Overstreet
@ 2023-11-21 10:36 ` Peter Zijlstra
2023-11-21 11:14 ` Mark Rutland
0 siblings, 1 reply; 6+ messages in thread
From: Peter Zijlstra @ 2023-11-21 10:36 UTC (permalink / raw
To: Kent Overstreet
Cc: Ingo Molnar, Will Deacon, Waiman Long, Boqun Feng, linux-kernel
On Mon, Nov 20, 2023 at 06:36:59PM -0500, Kent Overstreet wrote:
> I've been seeing a lot of reports like the following in a lot of my
> lockdep + kasan tests.
I'm not aware of any such issues, then again, I rarely run with KASAN
enabled myself, I mostly leave that to the robots, who are far more
patient than me with slow kernels.
> Some lockdep patches are in my tree: they don't touch this code path
> (except I do have to increase MAX_LOCK_DEPTH from 48 to 63, perhaps that
> has unintended side effects?)
>
> https://evilpiepirate.org/git/bcachefs.git/log/?id=2f42f415f7573001b4f4887b785d8a8747b3757f
yeah, don't see anything weird there. I mean, sad about the no-recursion
thing, esp. after you did those custom order bits.
> bcachefs does take a _large_ number of locks for lockdep to track, also
> possibly relevant
>
> Have not dug into the lockdep hash table of outstanding locks code yet
> but happy to test patches...
>
> 04752 ========= TEST tiering_variable_buckets_replicas
> 04752
> 04752 WATCHDOG 3600
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): mounting version 1.3: rebalance_work opts=metadata_replicas=2,data_replicas=2,foreground_target=ssd,background_target=hdd,promote_target=ssd,fsck
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): initializing new filesystem
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): going read-write
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): marking superblocks
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): initializing freespace
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): done initializing freespace
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): reading snapshots table
> 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): reading snapshots done
> 04753 WATCHDOG 3600
> 04753 randrw: (g=0): rw=randrw, bs=(R) 4096B-1024KiB, (W) 4096B-1024KiB, (T) 4096B-1024KiB, ioengine=libaio, iodepth=64
> 04753 fio-3.33
> 04753 Starting 1 process
> 04753 randrw: Laying out IO file (1 file / 3500MiB)
> 05117 Jobs: 1 (f=1)
> 05117 BUG: KASAN: global-out-of-bounds in add_chain_block+0x44/0x288
> 05117 Read of size 4 at addr ffffffc081b7a8bc by task fio/120528
> 05117
> 05117 CPU: 11 PID: 120528 Comm: fio Tainted: G L 6.6.0-ktest-gc18b7260ddd3 #8209
> 05117 Hardware name: linux,dummy-virt (DT)
> 05117 Call trace:
> 05117 dump_backtrace+0xa8/0xe8
> 05117 show_stack+0x1c/0x30
> 05117 dump_stack_lvl+0x5c/0xa0
> 05117 print_report+0x1e4/0x5a0
> 05117 kasan_report+0x80/0xc0
> 05117 __asan_load4+0x90/0xb0
> 05117 add_chain_block+0x44/0x288
> 05117 __lock_acquire+0x1104/0x24f8
> 05117 lock_acquire+0x1e0/0x470
> 05117 _raw_spin_lock_nested+0x54/0x78
> 05117 raw_spin_rq_lock_nested+0x30/0x50
> 05117 try_to_wake_up+0x3b4/0x1050
> 05117 wake_up_process+0x1c/0x30
> 05117 kick_pool+0x104/0x1b0
> 05117 __queue_work+0x350/0xa58
> 05117 queue_work_on+0x98/0xd0
> 05117 __bch2_btree_node_write+0xec0/0x10a0
> 05117 bch2_btree_node_write+0x88/0x138
> 05117 btree_split+0x744/0x14a0
> 05117 bch2_btree_split_leaf+0x94/0x258
> 05117 bch2_trans_commit_error.isra.0+0x234/0x7d0
> 05117 __bch2_trans_commit+0x1128/0x3010
> 05117 bch2_extent_update+0x410/0x570
> 05117 bch2_write_index_default+0x404/0x598
> 05117 __bch2_write_index+0xb0/0x3b0
> 05117 __bch2_write+0x6f0/0x928
> 05117 bch2_write+0x368/0x8e0
> 05117 bch2_direct_write+0xaa8/0x12c0
> 05117 bch2_write_iter+0x2e4/0x1050
> 05117 aio_write.constprop.0+0x19c/0x420
> 05117 io_submit_one.constprop.0+0xf30/0x17a0
> 05117 __arm64_sys_io_submit+0x244/0x388
> 05117 invoke_syscall.constprop.0+0x64/0x138
> 05117 do_el0_svc+0x7c/0x120
> 05117 el0_svc+0x34/0x80
> 05117 el0t_64_sync_handler+0xb8/0xc0
> 05117 el0t_64_sync+0x14c/0x150
> 05117
> 05117 The buggy address belongs to the variable:
> 05117 nr_large_chain_blocks+0x3c/0x40
This is weird, nr_lage_chain_blocks is a single variable, if the
compiler keeps layout according to the source file, this would be
chaing_block_bucket[14] or something weird like that.
Perhaps figure out what it things the @size argument to
add_chain_block() would be?
> 05117
> 05117 The buggy address belongs to the virtual mapping at
> 05117 [ffffffc081710000, ffffffc088861000) created by:
> 05117 paging_init+0x260/0x820
> 05117
> 05117 The buggy address belongs to the physical page:
> 05117 page:00000000ce625900 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x41d7a
> 05117 flags: 0x4000(reserved|zone=0)
> 05117 page_type: 0xffffffff()
> 05117 raw: 0000000000004000 fffffffe00075e88 fffffffe00075e88 0000000000000000
> 05117 raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
> 05117 page dumped because: kasan: bad access detected
> 05117
> 05117 Memory state around the buggy address:
> 05117 ffffffc081b7a780: 00 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9 f9 f9 f9 f9
> 05117 ffffffc081b7a800: 00 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
> 05117 >ffffffc081b7a880: 04 f9 f9 f9 f9 f9 f9 f9 00 00 00 00 00 00 00 00
> 05117 ^
> 05117 ffffffc081b7a900: f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9
> 05117 ffffffc081b7a980: f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9
> 05117 ==================================================================
> 05117 Kernel panic - not syncing: kasan.fault=panic set ...
> 05117 CPU: 11 PID: 120528 Comm: fio Tainted: G L 6.6.0-ktest-gc18b7260ddd3 #8209
> 05117 Hardware name: linux,dummy-virt (DT)
> 05117 Call trace:
> 05117 dump_backtrace+0xa8/0xe8
> 05117 show_stack+0x1c/0x30
> 05117 dump_stack_lvl+0x5c/0xa0
> 05117 dump_stack+0x18/0x20
> 05117 panic+0x3ac/0x408
> 05117 kasan_report_invalid_free+0x0/0x90
> 05117 kasan_report+0x90/0xc0
> 05117 __asan_load4+0x90/0xb0
> 05117 add_chain_block+0x44/0x288
> 05117 __lock_acquire+0x1104/0x24f8
> 05117 lock_acquire+0x1e0/0x470
> 05117 _raw_spin_lock_nested+0x54/0x78
> 05117 raw_spin_rq_lock_nested+0x30/0x50
> 05117 try_to_wake_up+0x3b4/0x1050
> 05117 wake_up_process+0x1c/0x30
> 05117 kick_pool+0x104/0x1b0
> 05117 __queue_work+0x350/0xa58
> 05117 queue_work_on+0x98/0xd0
> 05117 __bch2_btree_node_write+0xec0/0x10a0
> 05117 bch2_btree_node_write+0x88/0x138
> 05117 btree_split+0x744/0x14a0
> 05117 bch2_btree_split_leaf+0x94/0x258
> 05117 bch2_trans_commit_error.isra.0+0x234/0x7d0
> 05117 __bch2_trans_commit+0x1128/0x3010
> 05117 bch2_extent_update+0x410/0x570
> 05117 bch2_write_index_default+0x404/0x598
> 05117 __bch2_write_index+0xb0/0x3b0
> 05117 __bch2_write+0x6f0/0x928
> 05117 bch2_write+0x368/0x8e0
> 05117 bch2_direct_write+0xaa8/0x12c0
> 05117 bch2_write_iter+0x2e4/0x1050
> 05117 aio_write.constprop.0+0x19c/0x420
> 05117 io_submit_one.constprop.0+0xf30/0x17a0
> 05117 __arm64_sys_io_submit+0x244/0x388
> 05117 invoke_syscall.constprop.0+0x64/0x138
> 05117 do_el0_svc+0x7c/0x120
> 05117 el0_svc+0x34/0x80
> 05117 el0t_64_sync_handler+0xb8/0xc0
> 05117 el0t_64_sync+0x14c/0x150
> 05117 SMP: stopping secondary CPUs
> 05117 Kernel Offset: disabled
> 05117 CPU features: 0x0,00000000,70000001,1040500b
> 05117 Memory Limit: none
> 05117 ---[ end Kernel panic - not syncing: kasan.fault=panic set ... ]---
> 05122 ========= FAILED TIMEOUT tiering_variable_buckets_replicas in 3600s
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: lockdep + kasan bug?
2023-11-21 10:36 ` Peter Zijlstra
@ 2023-11-21 11:14 ` Mark Rutland
2023-11-21 11:41 ` Peter Zijlstra
0 siblings, 1 reply; 6+ messages in thread
From: Mark Rutland @ 2023-11-21 11:14 UTC (permalink / raw
To: Peter Zijlstra
Cc: Kent Overstreet, Ingo Molnar, Will Deacon, Waiman Long,
Boqun Feng, linux-kernel
On Tue, Nov 21, 2023 at 11:36:14AM +0100, Peter Zijlstra wrote:
> On Mon, Nov 20, 2023 at 06:36:59PM -0500, Kent Overstreet wrote:
> > I've been seeing a lot of reports like the following in a lot of my
> > lockdep + kasan tests.
>
> I'm not aware of any such issues, then again, I rarely run with KASAN
> enabled myself, I mostly leave that to the robots, who are far more
> patient than me with slow kernels.
>
> > Some lockdep patches are in my tree: they don't touch this code path
> > (except I do have to increase MAX_LOCK_DEPTH from 48 to 63, perhaps that
> > has unintended side effects?)
> >
> > https://evilpiepirate.org/git/bcachefs.git/log/?id=2f42f415f7573001b4f4887b785d8a8747b3757f
>
> yeah, don't see anything weird there. I mean, sad about the no-recursion
> thing, esp. after you did those custom order bits.
>
> > bcachefs does take a _large_ number of locks for lockdep to track, also
> > possibly relevant
> >
> > Have not dug into the lockdep hash table of outstanding locks code yet
> > but happy to test patches...
> >
> > 04752 ========= TEST tiering_variable_buckets_replicas
> > 04752
> > 04752 WATCHDOG 3600
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): mounting version 1.3: rebalance_work opts=metadata_replicas=2,data_replicas=2,foreground_target=ssd,background_target=hdd,promote_target=ssd,fsck
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): initializing new filesystem
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): going read-write
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): marking superblocks
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): initializing freespace
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): done initializing freespace
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): reading snapshots table
> > 04753 bcachefs (ea667958-8bbd-451b-9043-9132a2fd2fa4): reading snapshots done
> > 04753 WATCHDOG 3600
> > 04753 randrw: (g=0): rw=randrw, bs=(R) 4096B-1024KiB, (W) 4096B-1024KiB, (T) 4096B-1024KiB, ioengine=libaio, iodepth=64
> > 04753 fio-3.33
> > 04753 Starting 1 process
> > 04753 randrw: Laying out IO file (1 file / 3500MiB)
> > 05117 Jobs: 1 (f=1)
> > 05117 BUG: KASAN: global-out-of-bounds in add_chain_block+0x44/0x288
> > 05117 Read of size 4 at addr ffffffc081b7a8bc by task fio/120528
> > 05117
> > 05117 CPU: 11 PID: 120528 Comm: fio Tainted: G L 6.6.0-ktest-gc18b7260ddd3 #8209
> > 05117 Hardware name: linux,dummy-virt (DT)
> > 05117 Call trace:
> > 05117 dump_backtrace+0xa8/0xe8
> > 05117 show_stack+0x1c/0x30
> > 05117 dump_stack_lvl+0x5c/0xa0
> > 05117 print_report+0x1e4/0x5a0
> > 05117 kasan_report+0x80/0xc0
> > 05117 __asan_load4+0x90/0xb0
> > 05117 add_chain_block+0x44/0x288
> > 05117 __lock_acquire+0x1104/0x24f8
> > 05117 lock_acquire+0x1e0/0x470
> > 05117 _raw_spin_lock_nested+0x54/0x78
> > 05117 raw_spin_rq_lock_nested+0x30/0x50
> > 05117 try_to_wake_up+0x3b4/0x1050
> > 05117 wake_up_process+0x1c/0x30
> > 05117 kick_pool+0x104/0x1b0
> > 05117 __queue_work+0x350/0xa58
> > 05117 queue_work_on+0x98/0xd0
> > 05117 __bch2_btree_node_write+0xec0/0x10a0
> > 05117 bch2_btree_node_write+0x88/0x138
> > 05117 btree_split+0x744/0x14a0
> > 05117 bch2_btree_split_leaf+0x94/0x258
> > 05117 bch2_trans_commit_error.isra.0+0x234/0x7d0
> > 05117 __bch2_trans_commit+0x1128/0x3010
> > 05117 bch2_extent_update+0x410/0x570
> > 05117 bch2_write_index_default+0x404/0x598
> > 05117 __bch2_write_index+0xb0/0x3b0
> > 05117 __bch2_write+0x6f0/0x928
> > 05117 bch2_write+0x368/0x8e0
> > 05117 bch2_direct_write+0xaa8/0x12c0
> > 05117 bch2_write_iter+0x2e4/0x1050
> > 05117 aio_write.constprop.0+0x19c/0x420
> > 05117 io_submit_one.constprop.0+0xf30/0x17a0
> > 05117 __arm64_sys_io_submit+0x244/0x388
> > 05117 invoke_syscall.constprop.0+0x64/0x138
> > 05117 do_el0_svc+0x7c/0x120
> > 05117 el0_svc+0x34/0x80
> > 05117 el0t_64_sync_handler+0xb8/0xc0
> > 05117 el0t_64_sync+0x14c/0x150
> > 05117
> > 05117 The buggy address belongs to the variable:
> > 05117 nr_large_chain_blocks+0x3c/0x40
>
> This is weird, nr_lage_chain_blocks is a single variable, if the
> compiler keeps layout according to the source file, this would be
> chaing_block_bucket[14] or something weird like that.
I think the size here is bogus; IIUC that's determined form the start of the
next symbol, which happens to be 64 bytes away from the start of
nr_lage_chain_blocks.
From the memory state dump, there's padding/redzone between two global objects,
and I think we're accessing a negative offset from the next object. More on
that below.
> Perhaps figure out what it things the @size argument to
> add_chain_block() would be?
>
> > 05117
> > 05117 The buggy address belongs to the virtual mapping at
> > 05117 [ffffffc081710000, ffffffc088861000) created by:
> > 05117 paging_init+0x260/0x820
> > 05117
> > 05117 The buggy address belongs to the physical page:
> > 05117 page:00000000ce625900 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x41d7a
> > 05117 flags: 0x4000(reserved|zone=0)
> > 05117 page_type: 0xffffffff()
> > 05117 raw: 0000000000004000 fffffffe00075e88 fffffffe00075e88 0000000000000000
> > 05117 raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
> > 05117 page dumped because: kasan: bad access detected
> > 05117
> > 05117 Memory state around the buggy address:
> > 05117 ffffffc081b7a780: 00 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9 f9 f9 f9 f9
> > 05117 ffffffc081b7a800: 00 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
> > 05117 >ffffffc081b7a880: 04 f9 f9 f9 f9 f9 f9 f9 00 00 00 00 00 00 00 00
> > 05117 ^
In this dump:
* '00' means all 8 bytes of an 8-byte region areaccessible
* '04' means the first 4 bytes on an 8-byte region are accessible
* 'f9' means KASAN_GLOBAL_REDZONE / padding between objects
So at 0xffffffc081b7a880 we have a 4-byte object, 60 bytes of padding, then a
64-byte object.
I think the 4-byte object at 0xffffffc081b7a880 is nr_large_chain_blocks, and
the later 64-byte object is chain_block_buckets[].
I suspect the dodgy access is to chain_block_buckets[-1], which hits the last 4
bytes of the redzone and gets (incorrectly/misleadingly) attributed to
nr_large_chain_blocks.
Mark.
> > 05117 ffffffc081b7a900: f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9
> > 05117 ffffffc081b7a980: f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9
> > 05117 ==================================================================
> > 05117 Kernel panic - not syncing: kasan.fault=panic set ...
> > 05117 CPU: 11 PID: 120528 Comm: fio Tainted: G L 6.6.0-ktest-gc18b7260ddd3 #8209
> > 05117 Hardware name: linux,dummy-virt (DT)
> > 05117 Call trace:
> > 05117 dump_backtrace+0xa8/0xe8
> > 05117 show_stack+0x1c/0x30
> > 05117 dump_stack_lvl+0x5c/0xa0
> > 05117 dump_stack+0x18/0x20
> > 05117 panic+0x3ac/0x408
> > 05117 kasan_report_invalid_free+0x0/0x90
> > 05117 kasan_report+0x90/0xc0
> > 05117 __asan_load4+0x90/0xb0
> > 05117 add_chain_block+0x44/0x288
> > 05117 __lock_acquire+0x1104/0x24f8
> > 05117 lock_acquire+0x1e0/0x470
> > 05117 _raw_spin_lock_nested+0x54/0x78
> > 05117 raw_spin_rq_lock_nested+0x30/0x50
> > 05117 try_to_wake_up+0x3b4/0x1050
> > 05117 wake_up_process+0x1c/0x30
> > 05117 kick_pool+0x104/0x1b0
> > 05117 __queue_work+0x350/0xa58
> > 05117 queue_work_on+0x98/0xd0
> > 05117 __bch2_btree_node_write+0xec0/0x10a0
> > 05117 bch2_btree_node_write+0x88/0x138
> > 05117 btree_split+0x744/0x14a0
> > 05117 bch2_btree_split_leaf+0x94/0x258
> > 05117 bch2_trans_commit_error.isra.0+0x234/0x7d0
> > 05117 __bch2_trans_commit+0x1128/0x3010
> > 05117 bch2_extent_update+0x410/0x570
> > 05117 bch2_write_index_default+0x404/0x598
> > 05117 __bch2_write_index+0xb0/0x3b0
> > 05117 __bch2_write+0x6f0/0x928
> > 05117 bch2_write+0x368/0x8e0
> > 05117 bch2_direct_write+0xaa8/0x12c0
> > 05117 bch2_write_iter+0x2e4/0x1050
> > 05117 aio_write.constprop.0+0x19c/0x420
> > 05117 io_submit_one.constprop.0+0xf30/0x17a0
> > 05117 __arm64_sys_io_submit+0x244/0x388
> > 05117 invoke_syscall.constprop.0+0x64/0x138
> > 05117 do_el0_svc+0x7c/0x120
> > 05117 el0_svc+0x34/0x80
> > 05117 el0t_64_sync_handler+0xb8/0xc0
> > 05117 el0t_64_sync+0x14c/0x150
> > 05117 SMP: stopping secondary CPUs
> > 05117 Kernel Offset: disabled
> > 05117 CPU features: 0x0,00000000,70000001,1040500b
> > 05117 Memory Limit: none
> > 05117 ---[ end Kernel panic - not syncing: kasan.fault=panic set ... ]---
> > 05122 ========= FAILED TIMEOUT tiering_variable_buckets_replicas in 3600s
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: lockdep + kasan bug?
2023-11-21 11:14 ` Mark Rutland
@ 2023-11-21 11:41 ` Peter Zijlstra
2023-11-22 23:57 ` Kent Overstreet
2023-11-24 10:16 ` [tip: locking/urgent] lockdep: Fix block chain corruption tip-bot2 for Peter Zijlstra
0 siblings, 2 replies; 6+ messages in thread
From: Peter Zijlstra @ 2023-11-21 11:41 UTC (permalink / raw
To: Mark Rutland
Cc: Kent Overstreet, Ingo Molnar, Will Deacon, Waiman Long,
Boqun Feng, linux-kernel
On Tue, Nov 21, 2023 at 11:14:37AM +0000, Mark Rutland wrote:
> > > 05117 The buggy address belongs to the variable:
> > > 05117 nr_large_chain_blocks+0x3c/0x40
> >
> > This is weird, nr_lage_chain_blocks is a single variable, if the
> > compiler keeps layout according to the source file, this would be
> > chaing_block_bucket[14] or something weird like that.
>
> I think the size here is bogus; IIUC that's determined form the start of the
> next symbol, which happens to be 64 bytes away from the start of
> nr_lage_chain_blocks.
>
> From the memory state dump, there's padding/redzone between two global objects,
> and I think we're accessing a negative offset from the next object. More on
> that below.
>
> > Perhaps figure out what it things the @size argument to
> > add_chain_block() would be?
> >
> > > 05117
> > > 05117 The buggy address belongs to the virtual mapping at
> > > 05117 [ffffffc081710000, ffffffc088861000) created by:
> > > 05117 paging_init+0x260/0x820
> > > 05117
> > > 05117 The buggy address belongs to the physical page:
> > > 05117 page:00000000ce625900 refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x41d7a
> > > 05117 flags: 0x4000(reserved|zone=0)
> > > 05117 page_type: 0xffffffff()
> > > 05117 raw: 0000000000004000 fffffffe00075e88 fffffffe00075e88 0000000000000000
> > > 05117 raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
> > > 05117 page dumped because: kasan: bad access detected
> > > 05117
> > > 05117 Memory state around the buggy address:
> > > 05117 ffffffc081b7a780: 00 f9 f9 f9 f9 f9 f9 f9 00 f9 f9 f9 f9 f9 f9 f9
> > > 05117 ffffffc081b7a800: 00 f9 f9 f9 f9 f9 f9 f9 04 f9 f9 f9 f9 f9 f9 f9
> > > 05117 >ffffffc081b7a880: 04 f9 f9 f9 f9 f9 f9 f9 00 00 00 00 00 00 00 00
> > > 05117 ^
>
> In this dump:
>
> * '00' means all 8 bytes of an 8-byte region areaccessible
> * '04' means the first 4 bytes on an 8-byte region are accessible
> * 'f9' means KASAN_GLOBAL_REDZONE / padding between objects
>
> So at 0xffffffc081b7a880 we have a 4-byte object, 60 bytes of padding, then a
> 64-byte object.
>
> I think the 4-byte object at 0xffffffc081b7a880 is nr_large_chain_blocks, and
> the later 64-byte object is chain_block_buckets[].
Oh! That's very helpful, thanks!
> I suspect the dodgy access is to chain_block_buckets[-1], which hits the last 4
> bytes of the redzone and gets (incorrectly/misleadingly) attributed to
> nr_large_chain_blocks.
That would mean @size == 0, at which point size_to_bucket() returns -1
and the above happens.
alloc_chain_hlocks() has 'size - req', for the first with the
precondition 'size >= rq', which allows the 0.
The second is an iteration with the condition size > req, which does not
allow the 0 case.
So the first, thing, IIRC, this is trying to split a block,
del_chain_block() takes what we need, and add_chain_block() puts back
the remainder, except in the above case the remainder is 0 sized and
things go sideways or so.
Does the below help?
---
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index e85b5ad3e206..151bd3de5936 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -3497,7 +3497,8 @@ static int alloc_chain_hlocks(int req)
size = chain_block_size(curr);
if (likely(size >= req)) {
del_chain_block(0, size, chain_block_next(curr));
- add_chain_block(curr + req, size - req);
+ if (size > req)
+ add_chain_block(curr + req, size - req);
return curr;
}
}
^ permalink raw reply related [flat|nested] 6+ messages in thread
* Re: lockdep + kasan bug?
2023-11-21 11:41 ` Peter Zijlstra
@ 2023-11-22 23:57 ` Kent Overstreet
2023-11-24 10:16 ` [tip: locking/urgent] lockdep: Fix block chain corruption tip-bot2 for Peter Zijlstra
1 sibling, 0 replies; 6+ messages in thread
From: Kent Overstreet @ 2023-11-22 23:57 UTC (permalink / raw
To: Peter Zijlstra
Cc: Mark Rutland, Ingo Molnar, Will Deacon, Waiman Long, Boqun Feng,
linux-kernel
On Tue, Nov 21, 2023 at 12:41:26PM +0100, Peter Zijlstra wrote:
> > I suspect the dodgy access is to chain_block_buckets[-1], which hits the last 4
> > bytes of the redzone and gets (incorrectly/misleadingly) attributed to
> > nr_large_chain_blocks.
>
> That would mean @size == 0, at which point size_to_bucket() returns -1
> and the above happens.
>
> alloc_chain_hlocks() has 'size - req', for the first with the
> precondition 'size >= rq', which allows the 0.
>
> The second is an iteration with the condition size > req, which does not
> allow the 0 case.
>
> So the first, thing, IIRC, this is trying to split a block,
> del_chain_block() takes what we need, and add_chain_block() puts back
> the remainder, except in the above case the remainder is 0 sized and
> things go sideways or so.
>
> Does the below help?
>
> ---
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index e85b5ad3e206..151bd3de5936 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -3497,7 +3497,8 @@ static int alloc_chain_hlocks(int req)
> size = chain_block_size(curr);
> if (likely(size >= req)) {
> del_chain_block(0, size, chain_block_next(curr));
> - add_chain_block(curr + req, size - req);
> + if (size > req)
> + add_chain_block(curr + req, size - req);
> return curr;
> }
> }
>
Yep, no kasan splats with that patch
^ permalink raw reply [flat|nested] 6+ messages in thread
* [tip: locking/urgent] lockdep: Fix block chain corruption
2023-11-21 11:41 ` Peter Zijlstra
2023-11-22 23:57 ` Kent Overstreet
@ 2023-11-24 10:16 ` tip-bot2 for Peter Zijlstra
1 sibling, 0 replies; 6+ messages in thread
From: tip-bot2 for Peter Zijlstra @ 2023-11-24 10:16 UTC (permalink / raw
To: linux-tip-commits
Cc: Kent Overstreet, Peter Zijlstra (Intel), x86, linux-kernel
The following commit has been merged into the locking/urgent branch of tip:
Commit-ID: bca4104b00fec60be330cd32818dd5c70db3d469
Gitweb: https://git.kernel.org/tip/bca4104b00fec60be330cd32818dd5c70db3d469
Author: Peter Zijlstra <peterz@infradead.org>
AuthorDate: Tue, 21 Nov 2023 12:41:26 +01:00
Committer: Peter Zijlstra <peterz@infradead.org>
CommitterDate: Fri, 24 Nov 2023 11:04:54 +01:00
lockdep: Fix block chain corruption
Kent reported an occasional KASAN splat in lockdep. Mark then noted:
> I suspect the dodgy access is to chain_block_buckets[-1], which hits the last 4
> bytes of the redzone and gets (incorrectly/misleadingly) attributed to
> nr_large_chain_blocks.
That would mean @size == 0, at which point size_to_bucket() returns -1
and the above happens.
alloc_chain_hlocks() has 'size - req', for the first with the
precondition 'size >= rq', which allows the 0.
This code is trying to split a block, del_chain_block() takes what we
need, and add_chain_block() puts back the remainder, except in the
above case the remainder is 0 sized and things go sideways.
Fixes: 810507fe6fd5 ("locking/lockdep: Reuse freed chain_hlocks entries")
Reported-by: Kent Overstreet <kent.overstreet@linux.dev>
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Tested-by: Kent Overstreet <kent.overstreet@linux.dev>
Link: https://lkml.kernel.org/r/20231121114126.GH8262@noisy.programming.kicks-ass.net
---
kernel/locking/lockdep.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index e85b5ad..151bd3d 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -3497,7 +3497,8 @@ static int alloc_chain_hlocks(int req)
size = chain_block_size(curr);
if (likely(size >= req)) {
del_chain_block(0, size, chain_block_next(curr));
- add_chain_block(curr + req, size - req);
+ if (size > req)
+ add_chain_block(curr + req, size - req);
return curr;
}
}
^ permalink raw reply related [flat|nested] 6+ messages in thread
end of thread, other threads:[~2023-11-24 10:16 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-11-20 23:36 lockdep + kasan bug? Kent Overstreet
2023-11-21 10:36 ` Peter Zijlstra
2023-11-21 11:14 ` Mark Rutland
2023-11-21 11:41 ` Peter Zijlstra
2023-11-22 23:57 ` Kent Overstreet
2023-11-24 10:16 ` [tip: locking/urgent] lockdep: Fix block chain corruption tip-bot2 for Peter Zijlstra
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.