xfs: list corruption in xfs_setup_inode()

xfs: list corruption in xfs_setup_inode()

[Cong Wang]

Hello,

We triggered a list corruption (double add) warning below on our 4.9
kernel (the 4.9 kernel we use is based on -stable release, with only a
few unrelated networking backports):


WARNING: CPU: 5 PID: 628 at lib/list_debug.c:36 __list_add+0xac/0xb0
list_add double add: new=ffff8d9d691e0aa0, prev=ffff8d9d7a716608,
next=ffff8d9d691e0aa0.
Modules linked in: raid0 tcp_diag inet_diag intel_rapl
x86_pkg_temp_thermal coretemp iTCO_wdt iTCO_vendor_support
crct10dif_pclmul crc32_pclmul ghash_clmulni_intel mpt3sas raid_class
scsi_transport_sas i2c_i801 i2c_smbus i2c_core ie31200_edac lpc_ich
shpchp edac_core video ipmi_si ipmi_devintf ipmi_msghandler
acpi_cpufreq sch_fq_codel xfs libcrc32c crc32c_intel e1000e ptp
pps_core
CPU: 5 PID: 628 Comm: systemd-tmpfile Tainted: G        W
4.9.34.el7.x86_64 #1
Hardware name: TYAN S5512/S5512, BIOS V8.B13 03/20/2014
 ffffb0d48a0abb30 ffffffff8e389f47 ffffb0d48a0abb80 0000000000000000
 ffffb0d48a0abb70 ffffffff8e08989b 0000002400000000 ffff8d9d691e0aa0
 ffff8d9d7a716608 ffff8d9d691e0aa0 0000000000004000 ffff8d9d7de6d800
Call Trace:
 [<ffffffff8e389f47>] dump_stack+0x4d/0x66
 [<ffffffff8e08989b>] __warn+0xcb/0xf0
 [<ffffffff8e08991f>] warn_slowpath_fmt+0x5f/0x80
 [<ffffffff8e3a979c>] __list_add+0xac/0xb0
 [<ffffffff8e2355bb>] inode_sb_list_add+0x3b/0x50
 [<ffffffffc040157c>] xfs_setup_inode+0x2c/0x170 [xfs]
 [<ffffffffc0402097>] xfs_ialloc+0x317/0x5c0 [xfs]
 [<ffffffffc0404347>] xfs_dir_ialloc+0x77/0x220 [xfs]
 [<ffffffff8e74cf32>] ? down_write+0x12/0x40
 [<ffffffffc0404972>] xfs_create+0x482/0x760 [xfs]
 [<ffffffffc04019ae>] xfs_generic_create+0x21e/0x2c0 [xfs]
 [<ffffffffc0401a84>] xfs_vn_mknod+0x14/0x20 [xfs]
 [<ffffffffc0401aa6>] xfs_vn_mkdir+0x16/0x20 [xfs]
 [<ffffffff8e226698>] vfs_mkdir+0xe8/0x140
 [<ffffffff8e22aa4a>] SyS_mkdir+0x7a/0xf0
 [<ffffffff8e74f8e0>] entry_SYSCALL_64_fastpath+0x13/0x94

_Without_ looking deeper, it seems this warning could be shut up by:

--- a/fs/xfs/xfs_icache.c
+++ b/fs/xfs/xfs_icache.c
@@ -1138,6 +1138,8 @@ xfs_reclaim_inode(
        xfs_iunlock(ip, XFS_ILOCK_EXCL);

        XFS_STATS_INC(ip->i_mount, xs_ig_reclaims);
+
+       inode_sb_list_del(VFS_I(ip));

with properly exporting inode_sb_list_del(). Does this make any sense?
I don't want to pretend I understand XFS code at all.

BTW, there is a same bug report here, on 3.10 CentOS 7 kernel:
https://bugs.centos.org/print_bug_page.php?bug_id=10254

Please let me know if I can provide any other information.

Thanks!

Re: xfs: list corruption in xfs_setup_inode()

[Dave Chinner]

On Mon, Oct 30, 2017 at 02:55:43PM -0700, Cong Wang wrote:
> Hello,
> 
> We triggered a list corruption (double add) warning below on our 4.9
> kernel (the 4.9 kernel we use is based on -stable release, with only a
> few unrelated networking backports):
> 
> 
> WARNING: CPU: 5 PID: 628 at lib/list_debug.c:36 __list_add+0xac/0xb0
> list_add double add: new=ffff8d9d691e0aa0, prev=ffff8d9d7a716608,
> next=ffff8d9d691e0aa0.
> Modules linked in: raid0 tcp_diag inet_diag intel_rapl
> x86_pkg_temp_thermal coretemp iTCO_wdt iTCO_vendor_support
> crct10dif_pclmul crc32_pclmul ghash_clmulni_intel mpt3sas raid_class
> scsi_transport_sas i2c_i801 i2c_smbus i2c_core ie31200_edac lpc_ich
> shpchp edac_core video ipmi_si ipmi_devintf ipmi_msghandler
> acpi_cpufreq sch_fq_codel xfs libcrc32c crc32c_intel e1000e ptp
> pps_core
> CPU: 5 PID: 628 Comm: systemd-tmpfile Tainted: G        W

Kernel was already tainted before this warning was triggered. What
was the previous warning(s) that the kernel threw?

> 4.9.34.el7.x86_64 #1
> Hardware name: TYAN S5512/S5512, BIOS V8.B13 03/20/2014
>  ffffb0d48a0abb30 ffffffff8e389f47 ffffb0d48a0abb80 0000000000000000
>  ffffb0d48a0abb70 ffffffff8e08989b 0000002400000000 ffff8d9d691e0aa0
>  ffff8d9d7a716608 ffff8d9d691e0aa0 0000000000004000 ffff8d9d7de6d800
> Call Trace:
>  [<ffffffff8e389f47>] dump_stack+0x4d/0x66
>  [<ffffffff8e08989b>] __warn+0xcb/0xf0
>  [<ffffffff8e08991f>] warn_slowpath_fmt+0x5f/0x80
>  [<ffffffff8e3a979c>] __list_add+0xac/0xb0
>  [<ffffffff8e2355bb>] inode_sb_list_add+0x3b/0x50
>  [<ffffffffc040157c>] xfs_setup_inode+0x2c/0x170 [xfs]
>  [<ffffffffc0402097>] xfs_ialloc+0x317/0x5c0 [xfs]
>  [<ffffffffc0404347>] xfs_dir_ialloc+0x77/0x220 [xfs]

Inode allocation, so should be a new inode straight from the slab
cache. THat implies memory corruption of some kind. Please turn on
slab poisoning and try to reproduce.

>  [<ffffffff8e74cf32>] ? down_write+0x12/0x40
>  [<ffffffffc0404972>] xfs_create+0x482/0x760 [xfs]
>  [<ffffffffc04019ae>] xfs_generic_create+0x21e/0x2c0 [xfs]
>  [<ffffffffc0401a84>] xfs_vn_mknod+0x14/0x20 [xfs]
>  [<ffffffffc0401aa6>] xfs_vn_mkdir+0x16/0x20 [xfs]
>  [<ffffffff8e226698>] vfs_mkdir+0xe8/0x140
>  [<ffffffff8e22aa4a>] SyS_mkdir+0x7a/0xf0
>  [<ffffffff8e74f8e0>] entry_SYSCALL_64_fastpath+0x13/0x94
> 
> _Without_ looking deeper, it seems this warning could be shut up by:
> 
> --- a/fs/xfs/xfs_icache.c
> +++ b/fs/xfs/xfs_icache.c
> @@ -1138,6 +1138,8 @@ xfs_reclaim_inode(
>         xfs_iunlock(ip, XFS_ILOCK_EXCL);
> 
>         XFS_STATS_INC(ip->i_mount, xs_ig_reclaims);
> +
> +       inode_sb_list_del(VFS_I(ip));
> 
> with properly exporting inode_sb_list_del(). Does this make any sense?

No, because by this stage the inode has already been removed from
the superblock indoe list. Doing this sort of thing here would just
paper over whatever the underlying problem might be.

> Please let me know if I can provide any other information.

How do you reproduce the problem?

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: xfs: list corruption in xfs_setup_inode()

[Cong Wang]

On Mon, Oct 30, 2017 at 5:33 PM, Dave Chinner <david@fromorbit.com> wrote:
> On Mon, Oct 30, 2017 at 02:55:43PM -0700, Cong Wang wrote:
>> Hello,
>>
>> We triggered a list corruption (double add) warning below on our 4.9
>> kernel (the 4.9 kernel we use is based on -stable release, with only a
>> few unrelated networking backports):
>>
>>
>> WARNING: CPU: 5 PID: 628 at lib/list_debug.c:36 __list_add+0xac/0xb0
>> list_add double add: new=ffff8d9d691e0aa0, prev=ffff8d9d7a716608,
>> next=ffff8d9d691e0aa0.
>> Modules linked in: raid0 tcp_diag inet_diag intel_rapl
>> x86_pkg_temp_thermal coretemp iTCO_wdt iTCO_vendor_support
>> crct10dif_pclmul crc32_pclmul ghash_clmulni_intel mpt3sas raid_class
>> scsi_transport_sas i2c_i801 i2c_smbus i2c_core ie31200_edac lpc_ich
>> shpchp edac_core video ipmi_si ipmi_devintf ipmi_msghandler
>> acpi_cpufreq sch_fq_codel xfs libcrc32c crc32c_intel e1000e ptp
>> pps_core
>> CPU: 5 PID: 628 Comm: systemd-tmpfile Tainted: G        W
>
> Kernel was already tainted before this warning was triggered. What
> was the previous warning(s) that the kernel threw?

Ah, there was a same warning right before the above one:


:[   19.953754] EXT4-fs (md0): mounted filesystem with writeback data
mode. Opts: errors=remount-ro,data=writeback
:[   19.979051] ------------[ cut here ]------------
:[   19.979216] WARNING: CPU: 3 PID: 628 at lib/list_debug.c:36
__list_add+0xac/0xb0
:[   19.979470] list_add double add: new=ffff8d9d691d72a0,
prev=ffff8d9d7a716608, next=ffff8d9d691d72a0.
:[   19.979780] Modules linked in: raid0 tcp_diag inet_diag intel_rapl
x86_pkg_temp_thermal coretemp iTCO_wdt iTCO_vendor_support
crct10dif_pclmul crc32_pclmul ghash_clmulni_intel mpt3sas raid_class
scsi_transport_sas i2c_i801 i2c_smbus i2c_core ie31200_edac lpc_ich
shpchp edac_core video ipmi_si ipmi_devintf ipmi_msghandler
acpi_cpufreq sch_fq_codel xfs libcrc32c crc32c_intel e1000e ptp
pps_core
:[   19.981201] CPU: 3 PID: 628 Comm: systemd-tmpfile Not tainted
4.9.34.el7.x86_64 #1
:[   19.981491] Hardware name: TYAN S5512/S5512, BIOS V8.B13 03/20/2014
:[   19.981706]  ffffb0d48a0abb30 ffffffff8e389f47 ffffb0d48a0abb80
0000000000000000
:[   19.982000]  ffffb0d48a0abb70 ffffffff8e08989b 0000002400000000
ffff8d9d691d72a0
:[   19.982278]  ffff8d9d7a716608 ffff8d9d691d72a0 0000000000004000
ffff8d9d7de6d800
:[   19.982555] Call Trace:
:[   19.982645]  [<ffffffff8e389f47>] dump_stack+0x4d/0x66
:[   19.982823]  [<ffffffff8e08989b>] __warn+0xcb/0xf0
:[   19.983007]  [<ffffffff8e08991f>] warn_slowpath_fmt+0x5f/0x80
:[   19.983205]  [<ffffffff8e3a979c>] __list_add+0xac/0xb0
:[   19.983383]  [<ffffffff8e2355bb>] inode_sb_list_add+0x3b/0x50
:[   19.983610]  [<ffffffffc040157c>] xfs_setup_inode+0x2c/0x170 [xfs]
:[   19.983837]  [<ffffffffc0402097>] xfs_ialloc+0x317/0x5c0 [xfs]
:[   19.984072]  [<ffffffffc0404347>] xfs_dir_ialloc+0x77/0x220 [xfs]
:[   19.984283]  [<ffffffff8e74cf32>] ? down_write+0x12/0x40
:[   19.984481]  [<ffffffffc0404972>] xfs_create+0x482/0x760 [xfs]
:[   19.984697]  [<ffffffffc04019ae>] xfs_generic_create+0x21e/0x2c0 [xfs]
:[   19.984955]  [<ffffffffc0401a84>] xfs_vn_mknod+0x14/0x20 [xfs]
:[   19.985171]  [<ffffffffc0401aa6>] xfs_vn_mkdir+0x16/0x20 [xfs]
:[   19.985373]  [<ffffffff8e226698>] vfs_mkdir+0xe8/0x140
:[   19.985551]  [<ffffffff8e22aa4a>] SyS_mkdir+0x7a/0xf0
:[   19.985726]  [<ffffffff8e74f8e0>] entry_SYSCALL_64_fastpath+0x13/0x94
:[   19.985987] ---[ end trace b461c28386dac363 ]---
:[   19.987613] ------------[ cut here ]------------



>
>> 4.9.34.el7.x86_64 #1
>> Hardware name: TYAN S5512/S5512, BIOS V8.B13 03/20/2014
>>  ffffb0d48a0abb30 ffffffff8e389f47 ffffb0d48a0abb80 0000000000000000
>>  ffffb0d48a0abb70 ffffffff8e08989b 0000002400000000 ffff8d9d691e0aa0
>>  ffff8d9d7a716608 ffff8d9d691e0aa0 0000000000004000 ffff8d9d7de6d800
>> Call Trace:
>>  [<ffffffff8e389f47>] dump_stack+0x4d/0x66
>>  [<ffffffff8e08989b>] __warn+0xcb/0xf0
>>  [<ffffffff8e08991f>] warn_slowpath_fmt+0x5f/0x80
>>  [<ffffffff8e3a979c>] __list_add+0xac/0xb0
>>  [<ffffffff8e2355bb>] inode_sb_list_add+0x3b/0x50
>>  [<ffffffffc040157c>] xfs_setup_inode+0x2c/0x170 [xfs]
>>  [<ffffffffc0402097>] xfs_ialloc+0x317/0x5c0 [xfs]
>>  [<ffffffffc0404347>] xfs_dir_ialloc+0x77/0x220 [xfs]
>
> Inode allocation, so should be a new inode straight from the slab
> cache. THat implies memory corruption of some kind. Please turn on
> slab poisoning and try to reproduce.

Are you sure? xfs_iget() seems searching in a cache before allocating
a new one:

        ip = radix_tree_lookup(&pag->pag_ici_root, agino);

        if (ip) {
                error = xfs_iget_cache_hit(pag, ip, ino, flags, lock_flags);
                if (error)
                        goto out_error_or_again;
        } else {
                rcu_read_unlock();
                if (flags & XFS_IGET_INCORE) {
                        error = -ENOENT;
                        goto out_error_or_again;
                }
                XFS_STATS_INC(mp, xs_ig_missed);

                error = xfs_iget_cache_miss(mp, pag, tp, ino, &ip,
                                                        flags, lock_flags);
                if (error)
                        goto out_error_or_again;
        }


>
>>  [<ffffffff8e74cf32>] ? down_write+0x12/0x40
>>  [<ffffffffc0404972>] xfs_create+0x482/0x760 [xfs]
>>  [<ffffffffc04019ae>] xfs_generic_create+0x21e/0x2c0 [xfs]
>>  [<ffffffffc0401a84>] xfs_vn_mknod+0x14/0x20 [xfs]
>>  [<ffffffffc0401aa6>] xfs_vn_mkdir+0x16/0x20 [xfs]
>>  [<ffffffff8e226698>] vfs_mkdir+0xe8/0x140
>>  [<ffffffff8e22aa4a>] SyS_mkdir+0x7a/0xf0
>>  [<ffffffff8e74f8e0>] entry_SYSCALL_64_fastpath+0x13/0x94
>>
>> _Without_ looking deeper, it seems this warning could be shut up by:
>>
>> --- a/fs/xfs/xfs_icache.c
>> +++ b/fs/xfs/xfs_icache.c
>> @@ -1138,6 +1138,8 @@ xfs_reclaim_inode(
>>         xfs_iunlock(ip, XFS_ILOCK_EXCL);
>>
>>         XFS_STATS_INC(ip->i_mount, xs_ig_reclaims);
>> +
>> +       inode_sb_list_del(VFS_I(ip));
>>
>> with properly exporting inode_sb_list_del(). Does this make any sense?
>
> No, because by this stage the inode has already been removed from
> the superblock indoe list. Doing this sort of thing here would just
> paper over whatever the underlying problem might be.


For me, it looks like the inode in the cache pag->pag_ici_root
is not removed from sb list before removing from cache. Existing
RCU readers could still read and add it to sb list again before the
RCU callback executes. This could also explain why it is not
easy to trigger (only two people including me reported it so far).


>
>> Please let me know if I can provide any other information.
>
> How do you reproduce the problem?


The warning is reported via ABRT email, we don't know what was
happening at the time of crash.


Thanks!

Re: xfs: list corruption in xfs_setup_inode()

[Dave Chinner]

On Tue, Oct 31, 2017 at 06:51:08PM -0700, Cong Wang wrote:
> On Mon, Oct 30, 2017 at 5:33 PM, Dave Chinner <david@fromorbit.com> wrote:
> > On Mon, Oct 30, 2017 at 02:55:43PM -0700, Cong Wang wrote:
> >> Hello,
> >>
> >> We triggered a list corruption (double add) warning below on our 4.9
> >> kernel (the 4.9 kernel we use is based on -stable release, with only a
> >> few unrelated networking backports):
...
> >> 4.9.34.el7.x86_64 #1
> >> Hardware name: TYAN S5512/S5512, BIOS V8.B13 03/20/2014
> >>  ffffb0d48a0abb30 ffffffff8e389f47 ffffb0d48a0abb80 0000000000000000
> >>  ffffb0d48a0abb70 ffffffff8e08989b 0000002400000000 ffff8d9d691e0aa0
> >>  ffff8d9d7a716608 ffff8d9d691e0aa0 0000000000004000 ffff8d9d7de6d800
> >> Call Trace:
> >>  [<ffffffff8e389f47>] dump_stack+0x4d/0x66
> >>  [<ffffffff8e08989b>] __warn+0xcb/0xf0
> >>  [<ffffffff8e08991f>] warn_slowpath_fmt+0x5f/0x80
> >>  [<ffffffff8e3a979c>] __list_add+0xac/0xb0
> >>  [<ffffffff8e2355bb>] inode_sb_list_add+0x3b/0x50
> >>  [<ffffffffc040157c>] xfs_setup_inode+0x2c/0x170 [xfs]
> >>  [<ffffffffc0402097>] xfs_ialloc+0x317/0x5c0 [xfs]
> >>  [<ffffffffc0404347>] xfs_dir_ialloc+0x77/0x220 [xfs]
> >
> > Inode allocation, so should be a new inode straight from the slab
> > cache. THat implies memory corruption of some kind. Please turn on
> > slab poisoning and try to reproduce.
> 
> Are you sure? xfs_iget() seems searching in a cache before allocating
> a new one:

/me sighs

You started with "I don't know the XFS code very well", so I omitted
the complexity of describing about 10 different corner cases where
we /could/ find the unlinked inode still in the cache via the
lookup. But they aren't common cases - the common case in the real
world is allocation of cache cold inodes. IOWs: "so should be a new
inode straight from the slab cache".

So, yes, we could find the old unlinked inode still cached in the
XFS inode cache, but I don't have the time to explain how RCU lookup
code works to everyone who reports a bug.

All you need to understand is that all of this happens below the VFS
and so inodes being reclaimed or newly allocated the in-cache inode
should never, ever be on the VFS sb inode list.

> >>  [<ffffffff8e74cf32>] ? down_write+0x12/0x40
> >>  [<ffffffffc0404972>] xfs_create+0x482/0x760 [xfs]
> >>  [<ffffffffc04019ae>] xfs_generic_create+0x21e/0x2c0 [xfs]
> >>  [<ffffffffc0401a84>] xfs_vn_mknod+0x14/0x20 [xfs]
> >>  [<ffffffffc0401aa6>] xfs_vn_mkdir+0x16/0x20 [xfs]
> >>  [<ffffffff8e226698>] vfs_mkdir+0xe8/0x140
> >>  [<ffffffff8e22aa4a>] SyS_mkdir+0x7a/0xf0
> >>  [<ffffffff8e74f8e0>] entry_SYSCALL_64_fastpath+0x13/0x94
> >>
> >> _Without_ looking deeper, it seems this warning could be shut up by:
> >>
> >> --- a/fs/xfs/xfs_icache.c
> >> +++ b/fs/xfs/xfs_icache.c
> >> @@ -1138,6 +1138,8 @@ xfs_reclaim_inode(
> >>         xfs_iunlock(ip, XFS_ILOCK_EXCL);
> >>
> >>         XFS_STATS_INC(ip->i_mount, xs_ig_reclaims);
> >> +
> >> +       inode_sb_list_del(VFS_I(ip));
> >>
> >> with properly exporting inode_sb_list_del(). Does this make any sense?
> >
> > No, because by this stage the inode has already been removed from
> > the superblock indoe list. Doing this sort of thing here would just
> > paper over whatever the underlying problem might be.
> 
> 
> For me, it looks like the inode in the cache pag->pag_ici_root
> is not removed from sb list before removing from cache.

Sure, we have list corruption. Where we detect that corruption
implies nothing about the cause of the list corruption. The two
events are not connected in any way. Clearing that VFS list here
does nothing to fix the problem causing the list corruption to
occur.

> >> Please let me know if I can provide any other information.
> >
> > How do you reproduce the problem?
> 
> The warning is reported via ABRT email, we don't know what was
> happening at the time of crash.

Which makes it even harder to track down. Perhaps you should
configure the box to crashdump on such a failure and then we
can do some post-failure forensic analysis...

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: xfs: list corruption in xfs_setup_inode()

[Cong Wang]

On Tue, Oct 31, 2017 at 8:05 PM, Dave Chinner <david@fromorbit.com> wrote:
> On Tue, Oct 31, 2017 at 06:51:08PM -0700, Cong Wang wrote:
>> On Mon, Oct 30, 2017 at 5:33 PM, Dave Chinner <david@fromorbit.com> wrote:
>> > On Mon, Oct 30, 2017 at 02:55:43PM -0700, Cong Wang wrote:
>> >> Hello,
>> >>
>> >> We triggered a list corruption (double add) warning below on our 4.9
>> >> kernel (the 4.9 kernel we use is based on -stable release, with only a
>> >> few unrelated networking backports):
> ...
>> >> 4.9.34.el7.x86_64 #1
>> >> Hardware name: TYAN S5512/S5512, BIOS V8.B13 03/20/2014
>> >>  ffffb0d48a0abb30 ffffffff8e389f47 ffffb0d48a0abb80 0000000000000000
>> >>  ffffb0d48a0abb70 ffffffff8e08989b 0000002400000000 ffff8d9d691e0aa0
>> >>  ffff8d9d7a716608 ffff8d9d691e0aa0 0000000000004000 ffff8d9d7de6d800
>> >> Call Trace:
>> >>  [<ffffffff8e389f47>] dump_stack+0x4d/0x66
>> >>  [<ffffffff8e08989b>] __warn+0xcb/0xf0
>> >>  [<ffffffff8e08991f>] warn_slowpath_fmt+0x5f/0x80
>> >>  [<ffffffff8e3a979c>] __list_add+0xac/0xb0
>> >>  [<ffffffff8e2355bb>] inode_sb_list_add+0x3b/0x50
>> >>  [<ffffffffc040157c>] xfs_setup_inode+0x2c/0x170 [xfs]
>> >>  [<ffffffffc0402097>] xfs_ialloc+0x317/0x5c0 [xfs]
>> >>  [<ffffffffc0404347>] xfs_dir_ialloc+0x77/0x220 [xfs]
>> >
>> > Inode allocation, so should be a new inode straight from the slab
>> > cache. THat implies memory corruption of some kind. Please turn on
>> > slab poisoning and try to reproduce.
>>
>> Are you sure? xfs_iget() seems searching in a cache before allocating
>> a new one:
>
> /me sighs
>
> You started with "I don't know the XFS code very well", so I omitted
> the complexity of describing about 10 different corner cases where
> we /could/ find the unlinked inode still in the cache via the
> lookup. But they aren't common cases - the common case in the real
> world is allocation of cache cold inodes. IOWs: "so should be a new
> inode straight from the slab cache".
>
> So, yes, we could find the old unlinked inode still cached in the
> XFS inode cache, but I don't have the time to explain how RCU lookup
> code works to everyone who reports a bug.

Oh, sorry about it. I understand it now.


>
> All you need to understand is that all of this happens below the VFS
> and so inodes being reclaimed or newly allocated the in-cache inode
> should never, ever be on the VFS sb inode list.
>

OK.


>> >>  [<ffffffff8e74cf32>] ? down_write+0x12/0x40
>> >>  [<ffffffffc0404972>] xfs_create+0x482/0x760 [xfs]
>> >>  [<ffffffffc04019ae>] xfs_generic_create+0x21e/0x2c0 [xfs]
>> >>  [<ffffffffc0401a84>] xfs_vn_mknod+0x14/0x20 [xfs]
>> >>  [<ffffffffc0401aa6>] xfs_vn_mkdir+0x16/0x20 [xfs]
>> >>  [<ffffffff8e226698>] vfs_mkdir+0xe8/0x140
>> >>  [<ffffffff8e22aa4a>] SyS_mkdir+0x7a/0xf0
>> >>  [<ffffffff8e74f8e0>] entry_SYSCALL_64_fastpath+0x13/0x94
>> >>
>> >> _Without_ looking deeper, it seems this warning could be shut up by:
>> >>
>> >> --- a/fs/xfs/xfs_icache.c
>> >> +++ b/fs/xfs/xfs_icache.c
>> >> @@ -1138,6 +1138,8 @@ xfs_reclaim_inode(
>> >>         xfs_iunlock(ip, XFS_ILOCK_EXCL);
>> >>
>> >>         XFS_STATS_INC(ip->i_mount, xs_ig_reclaims);
>> >> +
>> >> +       inode_sb_list_del(VFS_I(ip));
>> >>
>> >> with properly exporting inode_sb_list_del(). Does this make any sense?
>> >
>> > No, because by this stage the inode has already been removed from
>> > the superblock indoe list. Doing this sort of thing here would just
>> > paper over whatever the underlying problem might be.
>>
>>
>> For me, it looks like the inode in the cache pag->pag_ici_root
>> is not removed from sb list before removing from cache.
>
> Sure, we have list corruption. Where we detect that corruption
> implies nothing about the cause of the list corruption. The two
> events are not connected in any way. Clearing that VFS list here
> does nothing to fix the problem causing the list corruption to
> occur.

OK.

>
>> >> Please let me know if I can provide any other information.
>> >
>> > How do you reproduce the problem?
>>
>> The warning is reported via ABRT email, we don't know what was
>> happening at the time of crash.
>
> Which makes it even harder to track down. Perhaps you should
> configure the box to crashdump on such a failure and then we
> can do some post-failure forensic analysis...

Yeah.

We are trying to make kdump working, but even if kdump works
we still can't turn on panic_on_warn since this is production machine.


Thanks!

Re: xfs: list corruption in xfs_setup_inode()

[Dave Chinner]

On Tue, Oct 31, 2017 at 09:43:03PM -0700, Cong Wang wrote:
> On Tue, Oct 31, 2017 at 8:05 PM, Dave Chinner <david@fromorbit.com> wrote:
> > On Tue, Oct 31, 2017 at 06:51:08PM -0700, Cong Wang wrote:
> >> >> Please let me know if I can provide any other information.
> >> >
> >> > How do you reproduce the problem?
> >>
> >> The warning is reported via ABRT email, we don't know what was
> >> happening at the time of crash.
> >
> > Which makes it even harder to track down. Perhaps you should
> > configure the box to crashdump on such a failure and then we
> > can do some post-failure forensic analysis...
> 
> Yeah.
> 
> We are trying to make kdump working, but even if kdump works
> we still can't turn on panic_on_warn since this is production
> machine.

Hmmm. Ok, maybe you could leave a trace of the xfs_iget* trace
points running and check the log tail for unusual events around the
time of the next crash. e.g. xfs_iget_reclaim_fail events. That
might point us to a potential interaction we can look at more
closely. I'd also suggest slab poisoning as well, as that will
catch other lifecycle problems that could be causing list
corruptions such as use-after-free.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: xfs: list corruption in xfs_setup_inode()

[Christoph Hellwig]

On Wed, Nov 01, 2017 at 04:07:01PM +1100, Dave Chinner wrote:
> > We are trying to make kdump working, but even if kdump works
> > we still can't turn on panic_on_warn since this is production
> > machine.
> 
> Hmmm. Ok, maybe you could leave a trace of the xfs_iget* trace
> points running and check the log tail for unusual events around the
> time of the next crash. e.g. xfs_iget_reclaim_fail events. That
> might point us to a potential interaction we can look at more
> closely. I'd also suggest slab poisoning as well, as that will
> catch other lifecycle problems that could be causing list
> corruptions such as use-after-free.

KASAN has also been really useful for these kinds of issues.

Re: xfs: list corruption in xfs_setup_inode()

[Dave Chinner]

On Wed, Nov 01, 2017 at 04:07:01PM +1100, Dave Chinner wrote:
> On Tue, Oct 31, 2017 at 09:43:03PM -0700, Cong Wang wrote:
> > On Tue, Oct 31, 2017 at 8:05 PM, Dave Chinner <david@fromorbit.com> wrote:
> > > On Tue, Oct 31, 2017 at 06:51:08PM -0700, Cong Wang wrote:
> > >> >> Please let me know if I can provide any other information.
> > >> >
> > >> > How do you reproduce the problem?
> > >>
> > >> The warning is reported via ABRT email, we don't know what was
> > >> happening at the time of crash.
> > >
> > > Which makes it even harder to track down. Perhaps you should
> > > configure the box to crashdump on such a failure and then we
> > > can do some post-failure forensic analysis...
> > 
> > Yeah.
> > 
> > We are trying to make kdump working, but even if kdump works
> > we still can't turn on panic_on_warn since this is production
> > machine.
> 
> Hmmm. Ok, maybe you could leave a trace of the xfs_iget* trace
> points running and check the log tail for unusual events around the
> time of the next crash. e.g. xfs_iget_reclaim_fail events. That
> might point us to a potential interaction we can look at more
> closely. I'd also suggest slab poisoning as well, as that will
> catch other lifecycle problems that could be causing list
> corruptions such as use-after-free.

FWIW, I note that you are reporting another memory
corruption/use-after-free related crash in the pipe_inode_info
structure on these same machines.  I'd suggest that you start with
the premise that this list corruption has the same root cause...

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: xfs: list corruption in xfs_setup_inode()

[Cong Wang]

On Wed, Nov 1, 2017 at 2:32 PM, Dave Chinner <david@fromorbit.com> wrote:
> On Wed, Nov 01, 2017 at 04:07:01PM +1100, Dave Chinner wrote:
>> On Tue, Oct 31, 2017 at 09:43:03PM -0700, Cong Wang wrote:
>> > On Tue, Oct 31, 2017 at 8:05 PM, Dave Chinner <david@fromorbit.com> wrote:
>> > > On Tue, Oct 31, 2017 at 06:51:08PM -0700, Cong Wang wrote:
>> > >> >> Please let me know if I can provide any other information.
>> > >> >
>> > >> > How do you reproduce the problem?
>> > >>
>> > >> The warning is reported via ABRT email, we don't know what was
>> > >> happening at the time of crash.
>> > >
>> > > Which makes it even harder to track down. Perhaps you should
>> > > configure the box to crashdump on such a failure and then we
>> > > can do some post-failure forensic analysis...
>> >
>> > Yeah.
>> >
>> > We are trying to make kdump working, but even if kdump works
>> > we still can't turn on panic_on_warn since this is production
>> > machine.
>>
>> Hmmm. Ok, maybe you could leave a trace of the xfs_iget* trace
>> points running and check the log tail for unusual events around the
>> time of the next crash. e.g. xfs_iget_reclaim_fail events. That
>> might point us to a potential interaction we can look at more
>> closely. I'd also suggest slab poisoning as well, as that will
>> catch other lifecycle problems that could be causing list
>> corruptions such as use-after-free.

Not sure if I can use trace, because this stack trace was triggered
by systemd-tmpfile during boot (before login).

>
> FWIW, I note that you are reporting another memory
> corruption/use-after-free related crash in the pipe_inode_info
> structure on these same machines.  I'd suggest that you start with
> the premise that this list corruption has the same root cause...

That's impossible. First of all, the machine triggered xfs warning
is different from the machines triggered free_pipe_info() crashes.
Secondly, this one is on 4.9 kernel while the other one is on 4.1.

Thanks.

Re: xfs: list corruption in xfs_setup_inode()

[Cong Wang]

On Mon, Oct 30, 2017 at 2:55 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
> Hello,
>
> We triggered a list corruption (double add) warning below on our 4.9
> kernel (the 4.9 kernel we use is based on -stable release, with only a
> few unrelated networking backports):

We still keep getting this warning on 4.9 kernel. Looking into this again,
it seems xfs_setup_inode() could be called twice if an XFS inode is gotten
from disk? Once in xfs_iget() => xfs_setup_existing_inode(), and once
in xfs_ialloc().

Does the following patch (compile-only) make any sense? Again, I don't
want to pretend to understand XFS...


diff --git a/fs/xfs/xfs_inode.c b/fs/xfs/xfs_inode.c
index 604ee384a00a..6761b1f8fa2f 100644
--- a/fs/xfs/xfs_inode.c
+++ b/fs/xfs/xfs_inode.c
@@ -775,6 +775,7 @@ xfs_ialloc(
        int             error;
        struct timespec tv;
        struct inode    *inode;
+       bool            had_imode;

        /*
         * Call the space management code to pick
@@ -801,6 +802,7 @@ xfs_ialloc(
                return error;
        ASSERT(ip != NULL);
        inode = VFS_I(ip);
+       had_imode = !!inode->i_mode;

        /*
         * We always convert v1 inodes to v2 now - we only support filesystems
@@ -946,7 +948,8 @@ xfs_ialloc(
        xfs_trans_log_inode(tp, ip, flags);

        /* now that we have an i_mode we can setup the inode structure */
-       xfs_setup_inode(ip);
+       if (!had_imode)
+               xfs_setup_inode(ip);

        *ipp = ip;
        return 0;

Re: xfs: list corruption in xfs_setup_inode()

[Dave Chinner]

On Mon, Mar 19, 2018 at 02:37:22PM -0700, Cong Wang wrote:
> On Mon, Oct 30, 2017 at 2:55 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
> > Hello,
> >
> > We triggered a list corruption (double add) warning below on our 4.9
> > kernel (the 4.9 kernel we use is based on -stable release, with only a
> > few unrelated networking backports):
> 
> We still keep getting this warning on 4.9 kernel. Looking into this again,
> it seems xfs_setup_inode() could be called twice if an XFS inode is gotten
> from disk? Once in xfs_iget() => xfs_setup_existing_inode(), and once
> in xfs_ialloc().

AFAICT, the only way this can happen is that if the inode ->i_mode
has been corrupted in some way. i.e. there is either on-disk or
in-memory corruption occurring.

> Does the following patch (compile-only) make any sense? Again, I don't
> want to pretend to understand XFS...

No, it doesn't make sense because a newly allocated inode should
always have a zero i_mode.

Have you turned on memory poisoning to try to identify where the
corruption is coming from?

And given that it might actually be on-disk corruption that is
causing this, have you run xfs_repair on these filesystems to
determine if they are free from on-disk corruption?

Indeed, that makes me wonder format are you running on these
filesystems, because on the more recent v5 format we don't read
newly allocated inodes from disk. Can you provide the info listed
here:

http://xfs.org/index.php/XFS_FAQ#Q:_What_information_should_I_include_when_reporting_a_problem.3F

as that will tell us what code paths are executing on inode
allocation.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: xfs: list corruption in xfs_setup_inode()

[Cong Wang]

On Mon, Mar 19, 2018 at 4:39 PM, Dave Chinner <david@fromorbit.com> wrote:
> On Mon, Mar 19, 2018 at 02:37:22PM -0700, Cong Wang wrote:
>> On Mon, Oct 30, 2017 at 2:55 PM, Cong Wang <xiyou.wangcong@gmail.com> wrote:
>> > Hello,
>> >
>> > We triggered a list corruption (double add) warning below on our 4.9
>> > kernel (the 4.9 kernel we use is based on -stable release, with only a
>> > few unrelated networking backports):
>>
>> We still keep getting this warning on 4.9 kernel. Looking into this again,
>> it seems xfs_setup_inode() could be called twice if an XFS inode is gotten
>> from disk? Once in xfs_iget() => xfs_setup_existing_inode(), and once
>> in xfs_ialloc().
>
> AFAICT, the only way this can happen is that if the inode ->i_mode
> has been corrupted in some way. i.e. there is either on-disk or
> in-memory corruption occurring.
>
>> Does the following patch (compile-only) make any sense? Again, I don't
>> want to pretend to understand XFS...
>
> No, it doesn't make sense because a newly allocated inode should
> always have a zero i_mode.

Got it.

>
> Have you turned on memory poisoning to try to identify where the
> corruption is coming from?
>

I don't consider it as a memory corruption until you point it out.
Will try to add slub_debug.


> And given that it might actually be on-disk corruption that is
> causing this, have you run xfs_repair on these filesystems to
> determine if they are free from on-disk corruption?

Not yet, I can try when it happens again.


>
> Indeed, that makes me wonder format are you running on these
> filesystems, because on the more recent v5 format we don't read

Seems I can't check the format on a mounted fs?

$ xfs_db -x /dev/sda1
xfs_db: /dev/sda1 contains a mounted filesystem

fatal error -- couldn't initialize XFS library


> newly allocated inodes from disk. Can you provide the info listed
> here:
>
> http://xfs.org/index.php/XFS_FAQ#Q:_What_information_should_I_include_when_reporting_a_problem.3F
>
> as that will tell us what code paths are executing on inode
> allocation.
>

The machine is already rebooted after that warning, so I don't know if
it is too late to collect xfs information, but here it is:

$ xfs_repair -V
xfs_repair version 4.5.0

$ xfs_info /
meta-data=/dev/sda1              isize=256    agcount=4, agsize=1310720 blks
         =                       sectsz=512   attr=2, projid32bit=0
         =                       crc=0        finobt=0 spinodes=0
data     =                       bsize=4096   blocks=5242880, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0 ftype=0
log      =internal               bsize=4096   blocks=2560, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0