Re: Crash with PREEMPT_RT on aarch64 machine

[Pierre Gondois <pierre.gondois@arm.com>]

On 11/9/22 10:55, Mark Rutland wrote:
> On Tue, Nov 08, 2022 at 06:45:29PM +0100, Jan Kara wrote:
>> On Tue 08-11-22 10:53:40, Mark Rutland wrote:
>>> On Mon, Nov 07, 2022 at 11:49:01AM -0500, Waiman Long wrote:
>>>> On 11/7/22 10:10, Sebastian Andrzej Siewior wrote:
>>>>> + locking, arm64
>>>>>
>>>>> On 2022-11-07 14:56:36 [+0100], Jan Kara wrote:
>>>>>>> spinlock_t and raw_spinlock_t differ slightly in terms of locking.
>>>>>>> rt_spin_lock() has the fast path via try_cmpxchg_acquire(). If you
>>>>>>> enable CONFIG_DEBUG_RT_MUTEXES then you would force the slow path which
>>>>>>> always acquires the rt_mutex_base::wait_lock (which is a raw_spinlock_t)
>>>>>>> while the actual lock is modified via cmpxchg.
>>>>>> So I've tried enabling CONFIG_DEBUG_RT_MUTEXES and indeed the corruption
>>>>>> stops happening as well. So do you suspect some bug in the CPU itself?
>>>>> If it is only enabling CONFIG_DEBUG_RT_MUTEXES (and not whole lockdep)
>>>>> then it looks very suspicious.
>>>>> CONFIG_DEBUG_RT_MUTEXES enables a few additional checks but the main
>>>>> part is that rt_mutex_cmpxchg_acquire() + rt_mutex_cmpxchg_release()
>>>>> always fail (and so the slowpath under a raw_spinlock_t is done).
>>>>>
>>>>> So if it is really the fast path (rt_mutex_cmpxchg_acquire()) then it
>>>>> somehow smells like the CPU is misbehaving.
>>>>>
>>>>> Could someone from the locking/arm64 department check if the locking in
>>>>> RT-mutex (rtlock_lock()) is correct?
>>>>>
>>>>> rtmutex locking uses try_cmpxchg_acquire(, ptr, ptr) for the fastpath
>>>>> (and try_cmpxchg_release(, ptr, ptr) for unlock).
>>>>> Now looking at it again, I don't see much difference compared to what
>>>>> queued_spin_trylock() does except the latter always operates on 32bit
>>>>> value instead a pointer.
>>>>
>>>> Both the fast path of queued spinlock and rt_spin_lock are using
>>>> try_cmpxchg_acquire(), the only difference I saw is the size of the data to
>>>> be cmpxchg'ed. qspinlock uses 32-bit integer whereas rt_spin_lock uses
>>>> 64-bit pointer. So I believe it is more on how the arm64 does cmpxchg. I
>>>> believe there are two different ways of doing it depending on whether LSE
>>>> atomics is available in the platform. So exactly what arm64 system is being
>>>> used here and what hardware capability does it have?
>>>
>>>  From the /proc/cpuinfo output earlier, this is a Neoverse N1 system, with the
>>> LSE atomics. Assuming the kernel was built with support for atomics in-kernel
>>> (which is selected by default), it'll be using the LSE version.
>>
>> So I was able to reproduce the corruption both with LSE atomics enabled &
>> disabled in the kernel. It seems the problem takes considerably longer to
>> reproduce with LSE atomics enabled but it still does happen.
>>
>> BTW, I've tried to reproduced the problem on another aarch64 machine with
>> CPU from a different vendor:
>>
>> processor       : 0
>> BogoMIPS        : 200.00
>> Features        : fp asimd evtstrm aes pmull sha1 sha2 crc32 atomics fphp asimdhp cpuid asimdrdm jscvt fcma dcpop asimddp asimdfhm
>> CPU implementer : 0x48
>> CPU architecture: 8
>> CPU variant     : 0x1
>> CPU part        : 0xd01
>> CPU revision    : 0
>>
>> And there the problem does not reproduce. So might it be a genuine bug in
>> the CPU implementation?
> 
> Perhaps, though I suspect it's more likely that we have an ordering bug in the
> kernel code, and it shows up on CPUs with legitimate but more relaxed ordering.
> We've had a couple of those show up on Apple M1, so it might be worth trying on
> one of those.
> 
> How easy is this to reproduce? What's necessary?
> 
> Thanks,
> Mark.

It is possible to reproduce it on an Ampere Altra, which has the following cpuinfo:
   processor       : 0
   BogoMIPS        : 50.00
   Features        : fp asimd evtstrm aes pmull sha1 sha2 crc32 atomics fphp asimdhp cpuid asimdrdm lrcpc dcpop asimddp ssbs
   CPU implementer : 0x41
   CPU architecture: 8
   CPU variant     : 0x3
   CPU part        : 0xd0c
   CPU revision    : 1

Command used:
   dbench 80 -t 300 --clients-per-process=8

With the diff [2] applied, I get [1]. So sb_clear_inode_writeback()
seems to be called on a CPU with a null i_count. Maybe:
- CPUx deletes the inode via iput().
- CPUy calls sb_clear_inode_writeback() to update inode->i_wb_list
   at the same time.

[1]
[  165.003036] ------------[ cut here ]------------
[  165.003042] kernel BUG at fs/fs-writeback.c:1294!
[  165.003047] Internal error: Oops - BUG: 0 [#1] PREEMPT_RT SMP
[  165.003052] Modules linked in: [...]
[  165.003131] CPU: 87 PID: 9 Comm: kworker/u320:0 Not tainted 6.0.5-rt14-[...] #92
[  165.003137] Hardware name: WIWYNN Mt.Jade Server System B81.03001.0005/Mt.Jade Motherboard, BIOS 1.08.20220218 (SCP: 1.08.20220218) 2022/02/18
[  165.003138] Workqueue: ext4-rsv-conversion ext4_end_io_rsv_work
[  165.003148] pstate: 60400009 (nZCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  165.003151] pc : sb_clear_inode_writeback (fs/fs-writeback.c:1294 (discriminator 1))
[  165.003159] lr : sb_clear_inode_writeback (./include/linux/atomic/atomic-instrumented.h:28 fs/fs-writeback.c:1292)
[...]
[  165.003219] Call trace:
[  165.003222] sb_clear_inode_writeback (fs/fs-writeback.c:1294 (discriminator 1))
[  165.003226] __folio_end_writeback (./include/linux/spinlock_rt.h:123 mm/page-writeback.c:2942)
[  165.003231] folio_end_writeback (mm/filemap.c:1620)
[  165.003234] end_page_writeback (mm/folio-compat.c:27)
[  165.003237] ext4_finish_bio (fs/ext4/page-io.c:145)
[  165.003240] ext4_release_io_end (fs/ext4/page-io.c:161 (discriminator 3))
[  165.003243] ext4_end_io_rsv_work (./include/linux/list.h:292 fs/ext4/page-io.c:254 fs/ext4/page-io.c:273)
[  165.003246] process_one_work (kernel/workqueue.c:2294)
[  165.003250] worker_thread (./include/linux/list.h:292 kernel/workqueue.c:2437)
[  165.003252] kthread (kernel/kthread.c:376)
[  165.003255] ret_from_fork (arch/arm64/kernel/entry.S:861)
[ 165.003260] Code: 54fff8a0 942cf1d4 17ffffc3 d4210000 (d4210000)
[...]
[  165.245010] ------------[ cut here ]------------


[2]
diff --git a/fs/fs-writeback.c b/fs/fs-writeback.c
index 443f83382b9b..0edb03eb43a4 100644
--- a/fs/fs-writeback.c
+++ b/fs/fs-writeback.c
@@ -1252,13 +1252,27 @@ void sb_mark_inode_writeback(struct inode *inode)
  {
         struct super_block *sb = inode->i_sb;
         unsigned long flags;
+       int local_count;
  
         if (list_empty(&inode->i_wb_list)) {
                 spin_lock_irqsave(&sb->s_inode_wblist_lock, flags);
+
+               local_count = atomic_read(&inode->count) + 1;
+               BUG_ON(local_count != atomic_inc_return(&inode->count));
+               BUG_ON(!atomic_read(&inode->i_count));
+
                 if (list_empty(&inode->i_wb_list)) {
+
+                       BUG_ON(!atomic_read(&inode->i_count));
+
                         list_add_tail(&inode->i_wb_list, &sb->s_inodes_wb);
                         trace_sb_mark_inode_writeback(inode);
                 }
+
+               local_count = atomic_read(&inode->count) + 1;
+               BUG_ON(local_count != atomic_inc_return(&inode->count));
+               BUG_ON(!atomic_read(&inode->i_count));
+
                 spin_unlock_irqrestore(&sb->s_inode_wblist_lock, flags);
         }
  }
@@ -1270,13 +1284,27 @@ void sb_clear_inode_writeback(struct inode *inode)
  {
         struct super_block *sb = inode->i_sb;
         unsigned long flags;
+       int local_count;
  
         if (!list_empty(&inode->i_wb_list)) {
                 spin_lock_irqsave(&sb->s_inode_wblist_lock, flags);
+
+               local_count = atomic_read(&inode->count) - 1;
+               BUG_ON(local_count != atomic_dec_return(&inode->count));
+               BUG_ON(!atomic_read(&inode->i_count));
+
                 if (!list_empty(&inode->i_wb_list)) {
+
+                       BUG_ON(!atomic_read(&inode->i_count));
+
                         list_del_init(&inode->i_wb_list);
                         trace_sb_clear_inode_writeback(inode);
                 }
+
+               local_count = atomic_read(&inode->count) - 1;
+               BUG_ON(local_count != atomic_dec_return(&inode->count));
+               BUG_ON(!atomic_read(&inode->i_count));
+
                 spin_unlock_irqrestore(&sb->s_inode_wblist_lock, flags);
         }
  }
diff --git a/include/linux/fs.h b/include/linux/fs.h
index 56a4b4b02477..67027d4973a1 100644
--- a/include/linux/fs.h
+++ b/include/linux/fs.h
@@ -658,6 +658,7 @@ struct inode {
         struct list_head        i_lru;          /* inode LRU list */
         struct list_head        i_sb_list;
         struct list_head        i_wb_list;      /* backing dev writeback list */
+       atomic_t                count;
         union {
                 struct hlist_head       i_dentry;
                 struct rcu_head         i_rcu;