Bug 1894177

Summary: [XFS] Kernel: Metadata corruption detected at xfs_inode_buf_verify+0x148/0x158 [xfs], xfs_inode block 0x25c680 xfs_inode_buf_verify
Product: [Fedora] Fedora Reporter: Dennis Gilmore <dgilmore>
Component: kernelAssignee: Gao Xiang <hsiangkao>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 33CC: acaringi, adscvr, airlied, bskeggs, dchinner, dmach, esandeen, hdegoede, hsiangkao, itamar, jarodwilson, jeremy, jglisse, jonathan, josef, kernel-maint, lgoncalv, linville, masami256, mchehab, mjg59, pbrobinson, pwhalen, steved
Target Milestone: ---   
Target Release: ---   
Hardware: armv7hl   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-12-01 17:04:06 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 245418    

Description Dennis Gilmore 2020-11-03 17:18:46 UTC 
1. Please describe the problem:
Post upgrade from fedora 32 to fedora 33 I frequently am seeing issues with xfs metadata corruption, 

2. What is the Version-Release number of the kernel:
5.8.x and 5.9.2

3. Did it work previously in Fedora? If so, what kernel version did the issue
   *first* appear?  Old kernels are available for download at
   https://koji.fedoraproject.org/koji/packageinfo?packageID=8 :

it worked in fedora 32, and I can reproduce by running previously working kernels. talking to sandeen the imacted inode is in /var/cache/dnf and running dnf  seems to reliably trigger the issue. I suspect there is two bugs here, one in xfs not handling something and the other in dnf beiong bad. 

4. Can you reproduce this issue? If so, please provide the steps to reproduce
   the issue below:
dnf update triggers it 

5. Does this problem occur with the latest Rawhide kernel? To install the
   Rawhide kernel, run ``sudo dnf install fedora-repos-rawhide`` followed by
   ``sudo dnf update --enablerepo=rawhide kernel``:


6. Are you running any modules that not shipped with directly Fedora's kernel?:


7. Please attach the kernel logs. You can get the complete kernel log
   for a boot with ``journalctl --no-hostname -k > dmesg.txt``. If the
   issue occurred on a previous boot, use the journalctl ``-b`` flag.

[  431.082754] XFS: Assertion failed: new_size <= XFS_IFORK_SIZE(ip, whichfork), file: fs/xfs/libxfs/xfs_inode_fork.c, line: 482
[  431.095345] ------------[ cut here ]------------
[  431.101585] WARNING: CPU: 3 PID: 3804 at fs/xfs/xfs_message.c:97 xfs_idata_realloc+0xb8/0x170 [xfs]
[  431.111068] Modules linked in: rfkill vfat fat dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua snd_soc_hdmi_codec rc_cec dw_hdmi_i2s_audio dw_hdmi_cec sun4i_codec sun8i_codec_analog sun8i_adda_pr_regmap snd_soc_core cp210x snd_comp
ress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore sun8i_drm_hdmi sunxi_wdt dw_hdmi sunxi_cir sun8i_thermal sunxi_cedrus(C) sun8i_di videobuf2_dma_contig videobuf2_memops v4l2_mem2mem videobuf2_v4l2 videobuf2_common videodev
 sun8i_mixer nvmem_sunxi_sid mc leds_gpio cpufreq_dt auth_rpcgss sunrpc ip_tables xfs sy8106a_regulator mmc_block governor_simpleondemand dwmac_sun8i stmmac_platform stmmac i2c_mv64xxx mdio_xpcs lima phylink gpu_sched mdio_mux sunxi phy_
generic sun4i_drm des_generic sun4i_frontend libdes musb_hdrc sun4i_tcon sun8i_tcon_top ohci_platform drm_kms_helper ohci_hcd udc_core syscopyarea ehci_platform sun6i_dma phy_sun4i_usb sysfillrect sun8i_ce sunxi_mmc sysimgblt fb_sys_fops
 cec display_connector drm gpio_keys
[  431.198961] CPU: 3 PID: 3804 Comm: yum Tainted: G         C        5.8.18-300.fc33.armv7hl+debug #1
[  431.208230] Hardware name: Allwinner sun8i Family
[  431.213092] [<c0311098>] (unwind_backtrace) from [<c030b250>] (show_stack+0x18/0x1c)
[  431.221035] [<c030b250>] (show_stack) from [<c085321c>] (dump_stack+0xd4/0x108)
[  431.228559] [<c085321c>] (dump_stack) from [<c034d6a0>] (__warn+0xf0/0x108)
[  431.235721] [<c034d6a0>] (__warn) from [<c034da78>] (warn_slowpath_fmt+0x70/0x84)
[  431.244741] [<c034da78>] (warn_slowpath_fmt) from [<bf2e34f0>] (xfs_idata_realloc+0xb8/0x170 [xfs])
[  431.256757] [<bf2e34f0>] (xfs_idata_realloc [xfs]) from [<bf2ac4b8>] (xfs_attr_shortform_add+0xa8/0x26c [xfs])
[  431.269528] [<bf2ac4b8>] (xfs_attr_shortform_add [xfs]) from [<bf2aa160>] (xfs_attr_shortform_addname+0x1a4/0x1c0 [xfs])
[  431.283195] [<bf2aa160>] (xfs_attr_shortform_addname [xfs]) from [<bf2aa19c>] (xfs_attr_try_sf_addname+0x20/0x88 [xfs])
[  431.296697] [<bf2aa19c>] (xfs_attr_try_sf_addname [xfs]) from [<bf2aa728>] (xfs_attr_set_args+0x50/0xe4 [xfs])
[  431.309393] [<bf2aa728>] (xfs_attr_set_args [xfs]) from [<bf2aa9f0>] (xfs_attr_set+0x1a0/0x2cc [xfs])
[  431.321318] [<bf2aa9f0>] (xfs_attr_set [xfs]) from [<bf32d618>] (xfs_xattr_set+0x6c/0x98 [xfs])
[  431.331573] [<bf32d618>] (xfs_xattr_set [xfs]) from [<c0574958>] (__vfs_setxattr+0x74/0x80)
[  431.340181] [<c0574958>] (__vfs_setxattr) from [<c057556c>] (__vfs_setxattr_noperm+0x68/0xf8)
[  431.348932] [<c057556c>] (__vfs_setxattr_noperm) from [<c05756ec>] (vfs_setxattr+0x58/0xa0)
[  431.357500] [<c05756ec>] (vfs_setxattr) from [<c05758e8>] (setxattr+0x1b4/0x1cc)
[  431.365142] [<c05758e8>] (setxattr) from [<c0575b5c>] (sys_fsetxattr+0x60/0x88)
[  431.372641] [<c0575b5c>] (sys_fsetxattr) from [<c03000c0>] (ret_fast_syscall+0x0/0x28)
[  431.380758] Exception stack(0xdebdffa8 to 0xdebdfff0)
[  431.385961] ffa0:                   00000000 01c387b8 0000000c 01c387b8 01c2eeb0 00000041
[  431.394334] ffc0: 00000000 01c387b8 00000001 000000e4 be8ebf84 be8ebf80 00000000 01c387b8
[  431.402712] ffe0: b5c72978 be8ebd50 b5c44334 b6c078e0
[  431.408203] irq event stamp: 451069
[  431.411933] hardirqs last  enabled at (451087): [<c03bc98c>] console_unlock+0x51c/0x574
[  431.420196] hardirqs last disabled at (451104): [<c03bc4dc>] console_unlock+0x6c/0x574
[  431.428391] softirqs last  enabled at (451120): [<c0301438>] __do_softirq+0x190/0x47c
[  431.436479] softirqs last disabled at (451131): [<c03544a8>] __irq_exit_rcu+0xd0/0x184
[  431.444647] ---[ end trace aaffc01de98c9763 ]---
[  436.038688] abrt-action-sav (3952) used greatest stack depth: 3776 bytes left
[  471.625032] XFS: Assertion failed: ifp->if_bytes <= XFS_IFORK_SIZE(ip, whichfork), file: fs/xfs/libxfs/xfs_inode_fork.c, line: 611
[  471.637634] ------------[ cut here ]------------
[  471.643901] WARNING: CPU: 1 PID: 390 at fs/xfs/xfs_message.c:97 xfs_iflush_fork+0x140/0x440 [xfs]
[  471.625032] XFS: Assertion failed: ifp->if_bytes <= XFS_IFORK_SIZE(ip, whichfork), file: fs/xfs/libxfs/xfs_inode_fork.c, line: 611
[  471.637634] ------------[ cut here ]------------
[  471.643901] WARNING: CPU: 1 PID: 390 at fs/xfs/xfs_message.c:97 xfs_iflush_fork+0x140/0x440 [xfs]
[  471.653246] Modules linked in: rfkill vfat fat dm_multipath scsi_dh_rdac scsi_dh_emc scsi_dh_alua snd_soc_hdmi_codec rc_cec dw_hdmi_i2s_audio dw_hdmi_cec sun4i_codec sun8i_codec_analog sun8i_adda_pr_regmap snd_soc_core cp210x snd_comp
ress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore sun8i_drm_hdmi sunxi_wdt dw_hdmi sunxi_cir sun8i_thermal sunxi_cedrus(C) sun8i_di videobuf2_dma_contig videobuf2_memops v4l2_mem2mem videobuf2_v4l2 videobuf2_common videodev
 sun8i_mixer nvmem_sunxi_sid mc leds_gpio cpufreq_dt auth_rpcgss sunrpc ip_tables xfs sy8106a_regulator mmc_block governor_simpleondemand dwmac_sun8i stmmac_platform stmmac i2c_mv64xxx mdio_xpcs lima phylink gpu_sched mdio_mux sunxi phy_
generic sun4i_drm des_generic sun4i_frontend libdes musb_hdrc sun4i_tcon sun8i_tcon_top ohci_platform drm_kms_helper ohci_hcd udc_core syscopyarea ehci_platform sun6i_dma phy_sun4i_usb sysfillrect sun8i_ce sunxi_mmc sysimgblt fb_sys_fops
 cec display_connector drm gpio_keys
[  471.740899] CPU: 1 PID: 390 Comm: xfsaild/mmcblk2 Tainted: G        WC        5.8.18-300.fc33.armv7hl+debug #1
[  471.751132] Hardware name: Allwinner sun8i Family
[  471.755976] [<c0311098>] (unwind_backtrace) from [<c030b250>] (show_stack+0x18/0x1c)
[  471.763888] [<c030b250>] (show_stack) from [<c085321c>] (dump_stack+0xd4/0x108)
[  471.771361] [<c085321c>] (dump_stack) from [<c034d6a0>] (__warn+0xf0/0x108)
[  471.778469] [<c034d6a0>] (__warn) from [<c034da78>] (warn_slowpath_fmt+0x70/0x84)
[  471.787418] [<c034da78>] (warn_slowpath_fmt) from [<bf2e39fc>] (xfs_iflush_fork+0x140/0x440 [xfs])
[  471.799028] [<bf2e39fc>] (xfs_iflush_fork [xfs]) from [<bf31a548>] (xfs_iflush_int+0x374/0x3e8 [xfs])
[  471.810644] [<bf31a548>] (xfs_iflush_int [xfs]) from [<bf31e790>] (xfs_iflush+0x1c4/0x218 [xfs])
[  471.821797] [<bf31e790>] (xfs_iflush [xfs]) from [<bf33c2a8>] (xfs_inode_item_push+0x108/0x17c [xfs])
[  471.833415] [<bf33c2a8>] (xfs_inode_item_push [xfs]) from [<bf34457c>] (xfsaild+0x47c/0x998 [xfs])
[  471.843821] [<bf34457c>] (xfsaild [xfs]) from [<c037033c>] (kthread+0x140/0x150)
[  471.851405] [<c037033c>] (kthread) from [<c0300178>] (ret_from_fork+0x14/0x3c)
[  471.858778] Exception stack(0xc97d9fb0 to 0xc97d9ff8)
[  471.863944] 9fa0:                                     00000000 00000000 00000000 00000000
[  471.872288] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  471.880632] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[  471.887765] irq event stamp: 129055
[  471.891469] hardirqs last  enabled at (129073): [<c03bc98c>] console_unlock+0x51c/0x574
[  471.899762] hardirqs last disabled at (129090): [<c03bc4dc>] console_unlock+0x6c/0x574
[  471.908029] softirqs last  enabled at (129106): [<c0301438>] __do_softirq+0x190/0x47c
[  471.916278] softirqs last disabled at (129117): [<c03544a8>] __irq_exit_rcu+0xd0/0x184
[  471.924553] ---[ end trace aaffc01de98c9764 ]---
[  471.937959] XFS (mmcblk2p4): Metadata corruption detected at xfs_inode_buf_verify+0x148/0x158 [xfs], xfs_inode block 0x25c680 xfs_inode_buf_verify
[  471.951542] XFS (mmcblk2p4): Unmount and run xfs_repair
[  471.957047] XFS (mmcblk2p4): First 128 bytes of corrupted metadata buffer:
[  471.964373] 00000000: 76 61 72 5f 63 61 63 68 65 5f 74 3a 73 30 00 1a  var_cache_t:s0..
[  471.972698] 00000010: 41 00 5a 69 66 2e 4d 64 43 68 65 63 6b 73 75 6d  A.Zif.MdChecksum
[  471.981030] 00000020: 5b 31 36 30 34 33 32 36 32 37 36 5d 35 36 36 35  [1604326276]5665
[  471.989341] 00000030: 65 38 65 61 34 65 64 35 66 64 66 61 63 34 31 38  e8ea4ed5fdfac418
[  471.997663] 00000040: 66 61 63 35 66 65 61 62 31 62 62 66 61 31 39 61  fac5feab1bbfa19a
[  472.005991] 00000050: 63 33 37 65 33 32 37 65 32 36 62 30 32 35 64 34  c37e327e26b025d4
[  472.014421] 00000060: 33 31 64 62 38 64 33 36 62 37 62 62 00 1a 41 00  31db8d36b7bb..A.
[  472.022775] 00000070: 5a 69 66 2e 4d 64 43 68 65 63 6b 73 75 6d 5b 31  Zif.MdChecksum[1
[  472.031119] CPU: 3 PID: 390 Comm: xfsaild/mmcblk2 Tainted: G        WC        5.8.18-300.fc33.armv7hl+debug #1
[  472.041314] Hardware name: Allwinner sun8i Family
[  472.046153] [<c0311098>] (unwind_backtrace) from [<c030b250>] (show_stack+0x18/0x1c)
[  472.054063] [<c030b250>] (show_stack) from [<c085321c>] (dump_stack+0xd4/0x108)
[  472.062803] [<c085321c>] (dump_stack) from [<bf2e4254>] (xfs_inode_buf_verify+0x148/0x158 [xfs])
[  472.073938] [<bf2e4254>] (xfs_inode_buf_verify [xfs]) from [<bf301278>] (_xfs_buf_ioapply+0x3c/0x31c [xfs])
[  472.086310] [<bf301278>] (_xfs_buf_ioapply [xfs]) from [<bf3017c8>] (__xfs_buf_submit+0x1e0/0x260 [xfs])
[  472.098264] [<bf3017c8>] (__xfs_buf_submit [xfs]) from [<bf301e78>] (xfs_buf_delwri_submit_buffers+0x130/0x214 [xfs])
[  472.111269] [<bf301e78>] (xfs_buf_delwri_submit_buffers [xfs]) from [<bf344444>] (xfsaild+0x344/0x998 [xfs])
[  472.122537] [<bf344444>] (xfsaild [xfs]) from [<c037033c>] (kthread+0x140/0x150)
[  472.130118] [<c037033c>] (kthread) from [<c0300178>] (ret_from_fork+0x14/0x3c)
[  472.137486] Exception stack(0xc97d9fb0 to 0xc97d9ff8)
[  472.142645] 9fa0:                                     00000000 00000000 00000000 00000000
[  472.150980] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  472.159311] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[  472.179143] XFS (mmcblk2p4): xfs_do_force_sh
                                               [  475.971179] Core dump to |/usr/lib/systemd/systemd-coredump pipe failed
[  476.043254] yum (3804) used greatest stack depth: 3504 bytes left
Comment 1 Eric Sandeen 2020-11-03 23:04:42 UTC 
Ok, so yum is setting an extended attribute, and when it needs to change the "fork size" where the attr goes, we hit an assertion about the size being too small:

new_size <= XFS_IFORK_SIZE(ip, whichfork)

and corruption ensues, which makes sense.  So this is a good hint, I'll go look a bit more at what's changed here recently.
Comment 3 Dennis Gilmore 2020-12-01 16:41:09 UTC 
this was fixed in 5.9.11 with https://www.spinics.net/lists/linux-xfs/msg46873.html
Comment 4 Eric Sandeen 2020-12-01 17:04:06 UTC 
Which has been built for f33, so I'll close this CURRENTRELEASE

https://kojipkgs.fedoraproject.org//packages/kernel/5.9.11/200.fc33/