Bug 217138 - [xfstests] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &rec) == NULL, file: fs/xfs/libxfs/xfs_inode_fork.c, line: 557
Summary: [xfstests] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &re...
Status: NEW
Alias: None
Product: File System
Classification: Unclassified
Component: XFS (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: FileSystem/XFS Default Virtual Assignee
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-03-05 06:21 UTC by Zorro Lang
Modified: 2023-03-19 11:11 UTC (History)
0 users

See Also:
Kernel Version: v6.3-rc0
Subsystem:
Regression: No
Bisected commit-id:


Attachments
console.log (2.26 MB, text/plain)
2023-03-05 06:21 UTC, Zorro Lang
Details

Description Zorro Lang 2023-03-05 06:21:02 UTC
Created attachment 303854 [details]
console.log

Recently I start to hit a kernel assertion bug by running xfstests on xfs with pmem (persistent memory)devices. No matter the mount option is dax=always/inode/never, all can trigger this bug.

[ 8266.774823] run fstests generic/270 at 2023-03-03 15:56:00 
[ 8269.422750] memfd_create() without MFD_EXEC nor MFD_NOEXEC_SEAL, pid=2216706 'systemd' 
[ 8270.586114] XFS (pmem0): DAX enabled. Warning: EXPERIMENTAL, use at your own risk 
[ 8270.595040] XFS (pmem0): Mounting V5 Filesystem 2d15fd14-f03b-40c6-9443-d3af15fe64c2 
[ 8270.616055] XFS (pmem0): Ending clean mount 
[ 8270.621619] XFS (pmem0): Quotacheck needed: Please wait. 
[ 8270.635448] XFS (pmem0): Quotacheck: Done. 
[ 8273.499839] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &rec) == NULL, file: fs/xfs/libxfs/xfs_inode_fork.c, line: 557 
[ 8273.512622] ------------[ cut here ]------------ 
[ 8273.517282] WARNING: CPU: 24 PID: 2216892 at fs/xfs/xfs_message.c:104 assfail+0x54/0x70 [xfs] 
[ 8273.526050] Modules linked in: ext4 mbcache jbd2 loop intel_rapl_msr intel_rapl_common intel_uncore_frequency intel_uncore_frequency_common rfkill i10nm_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp ipmi_ssif kvm_intel mgag200 i2c_algo_bit mlx5_ib drm_shmem_helper dell_smbios drm_kms_helper ib_uverbs kvm iTCO_wdt iTCO_vendor_support sunrpc dcdbas irqbypass rapl intel_cstate acpi_ipmi ipmi_si intel_uncore ib_core dax_pmem nd_pmem dell_wmi_descriptor wmi_bmof mei_me syscopyarea pcspkr ipmi_devintf dax_hmem isst_if_mbox_pci i2c_i801 isst_if_mmio sysfillrect mei sysimgblt isst_if_common i2c_smbus intel_vsec ipmi_msghandler acpi_power_meter drm fuse xfs libcrc32c sd_mod t10_pi sg mlx5_core crct10dif_pclmul crc32_pclmul crc32c_intel mlxfw ahci libahci tls ghash_clmulni_intel psample megaraid_sas libata tg3 pci_hyperv_intf wmi dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_debug] 
[ 8273.605731] CPU: 24 PID: 2216892 Comm: 2216549.fsstres Kdump: loaded Not tainted 6.2.0+ #1 
[ 8273.614012] Hardware name: Dell Inc. PowerEdge R750/0PJ80M, BIOS 1.5.4 12/17/2021 
[ 8273.621518] RIP: 0010:assfail+0x54/0x70 [xfs] 
[ 8273.626087] Code: c1 48 ba 00 00 00 00 00 fc ff df 48 89 c1 83 e0 07 48 c1 e9 03 0f b6 14 11 38 c2 7f 04 84 d2 75 10 80 3d ae 16 2f 00 00 75 15 <0f> 0b c3 cc cc cc cc 48 c7 c7 f0 14 95 c1 e8 59 dc e6 d5 eb e2 0f 
[ 8273.644857] RSP: 0018:ffa0000026497278 EFLAGS: 00010246 
[ 8273.650109] RAX: 0000000000000000 RBX: ff110006fbfa5040 RCX: 1ffffffff832a29e 
[ 8273.657278] RDX: 0000000000000004 RSI: ffa0000026496fe0 RDI: ffffffffc17ad880 
[ 8273.664435] RBP: ffa00000264972f0 R08: 00000000ffffffea R09: ffa0000026496f87 
[ 8273.671601] R10: fff3fc0004c92df0 R11: 0000000000000001 R12: ffa00000264972d0 
[ 8273.678761] R13: ff11000687e3b288 R14: 00000000000000f0 R15: ff110006fbfa5000 
[ 8273.685919] FS:  00007f40e02b5740(0000) GS:ff11000ced800000(0000) knlGS:0000000000000000 
[ 8273.694031] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033 
[ 8273.699803] CR2: 0000000001ebb178 CR3: 00000006cb6d2004 CR4: 0000000000771ee0 
[ 8273.706963] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 
[ 8273.714120] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 
[ 8273.721281] PKRU: 55555554 
[ 8273.724018] Call Trace: 
[ 8273.726498]  <TASK> 
[ 8273.728630]  xfs_iextents_copy+0x412/0x610 [xfs] 
[ 8273.733462]  ? __pfx_xfs_iextents_copy+0x10/0x10 [xfs] 
[ 8273.738818]  ? xfs_inode_to_log_dinode+0x8d7/0x1370 [xfs] 
[ 8273.744445]  ? do_raw_spin_unlock+0x55/0x1f0 
[ 8273.748755]  xfs_inode_item_format_data_fork+0x9c9/0x10f0 [xfs] 
[ 8273.754905]  xfs_inode_item_format+0x6b3/0xb40 [xfs] 
[ 8273.760088]  ? trace_contention_end+0x177/0x1f0 
[ 8273.764656]  ? __pfx_xfs_inode_item_format+0x10/0x10 [xfs] 
[ 8273.770375]  xlog_cil_insert_format_items+0x2b2/0x5f0 [xfs] 
[ 8273.776173]  xlog_cil_insert_items+0xe2/0x1060 [xfs] 
[ 8273.781370]  ? __lock_acquired+0x209/0x830 
[ 8273.785507]  ? __pfx___lock_acquired+0x10/0x10 
[ 8273.789980]  ? __pfx___down_read_trylock+0x10/0x10 
[ 8273.794805]  ? __pfx_xlog_cil_insert_items+0x10/0x10 [xfs] 
[ 8273.800502]  ? xlog_cil_commit+0x59/0x690 [xfs] 
[ 8273.805252]  xlog_cil_commit+0xa3/0x690 [xfs] 
[ 8273.809856]  __xfs_trans_commit+0x8c3/0xec0 [xfs] 
[ 8273.814781]  ? __pfx___xfs_trans_commit+0x10/0x10 [xfs] 
[ 8273.820223]  ? __pfx_xfs_trans_alloc_inode+0x10/0x10 [xfs] 
[ 8273.825957]  xfs_iomap_write_direct+0x362/0x630 [xfs] 
[ 8273.831233]  ? __pfx_xfs_iomap_write_direct+0x10/0x10 [xfs] 
[ 8273.837050]  ? xfs_direct_write_iomap_begin+0x8ad/0xd80 [xfs] 
[ 8273.842998]  ? rcu_read_lock_sched_held+0x43/0x80 
[ 8273.847737]  xfs_direct_write_iomap_begin+0x8d6/0xd80 [xfs] 
[ 8273.853536]  ? slab_free_freelist_hook+0x11d/0x1d0 
[ 8273.858355]  ? __pfx_xfs_direct_write_iomap_begin+0x10/0x10 [xfs] 
[ 8273.864648]  ? __xfs_trans_commit+0x8cd/0xec0 [xfs] 
[ 8273.869752]  ? kmem_cache_free+0xf9/0x3c0 
[ 8273.873837]  ? __pfx_xfs_direct_write_iomap_begin+0x10/0x10 [xfs] 
[ 8273.880133]  iomap_iter+0x341/0xe40 
[ 8273.883667]  dax_iomap_rw+0x216/0x3a0 
[ 8273.887366]  ? __pfx_dax_iomap_rw+0x10/0x10 
[ 8273.891625]  ? xfs_file_write_checks+0x4b6/0x960 [xfs] 
[ 8273.896991]  xfs_file_dax_write+0x278/0x9d0 [xfs] 
[ 8273.901903]  ? __pfx_xfs_file_dax_write+0x10/0x10 [xfs] 
[ 8273.907336]  ? xfs_file_write_iter+0x236/0x6a0 [xfs] 
[ 8273.912513]  vfs_write+0x807/0xc70 
[ 8273.915966]  ? __pfx_vfs_write+0x10/0x10 
[ 8273.919934]  ? __fget_files+0x1d0/0x3f0 
[ 8273.923848]  ksys_write+0xf9/0x1d0 
[ 8273.927281]  ? __pfx_ksys_write+0x10/0x10 
[ 8273.931316]  ? ktime_get_coarse_real_ts64+0x130/0x170 
[ 8273.936421]  do_syscall_64+0x59/0x90 
[ 8273.940033]  ? do_syscall_64+0x69/0x90 
[ 8273.943813]  ? lockdep_hardirqs_on+0x79/0x100 
[ 8273.948199]  ? do_syscall_64+0x69/0x90 
[ 8273.951979]  ? lockdep_hardirqs_on+0x79/0x100 
[ 8273.956364]  ? do_syscall_64+0x69/0x90 
[ 8273.960142]  ? lockdep_hardirqs_on+0x79/0x100 
[ 8273.964529]  ? do_syscall_64+0x69/0x90 
[ 8273.968305]  ? lockdep_hardirqs_on+0x79/0x100 
[ 8273.972693]  entry_SYSCALL_64_after_hwframe+0x72/0xdc 
[ 8273.977768] RIP: 0033:0x7f40e013eb97 
[ 8273.981374] Code: 0b 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b7 0f 1f 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 51 c3 48 83 ec 28 48 89 54 24 18 48 89 74 24 
[ 8274.000150] RSP: 002b:00007ffec966ee78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 
[ 8274.007747] RAX: ffffffffffffffda RBX: 0000000000014f69 RCX: 00007f40e013eb97 
[ 8274.014903] RDX: 0000000000014f69 RSI: 0000000001e5be00 RDI: 0000000000000004 
[ 8274.022054] RBP: 0000000000000004 R08: 0000000000000003 R09: 0000000000000079 
[ 8274.029205] R10: 0000000000000102 R11: 0000000000000246 R12: 0000000000000169 
[ 8274.036364] R13: 00000000003ec889 R14: 0000000001e5be00 R15: 0000000000000000 
[ 8274.043554]  </TASK> 
[ 8274.045769] irq event stamp: 104511 
[ 8274.049286] hardirqs last  enabled at (104521): [<ffffffff96dfac3b>] __up_console_sem+0x6b/0x80 
[ 8274.058006] hardirqs last disabled at (104530): [<ffffffff96dfac20>] __up_console_sem+0x50/0x80 
[ 8274.066729] softirqs last  enabled at (104544): [<ffffffff990ea156>] __do_softirq+0x616/0x9c7 
[ 8274.075277] softirqs last disabled at (104539): [<ffffffff96c48f76>] __irq_exit_rcu+0x136/0x2a0 
[ 8274.083994] ---[ end trace 0000000000000000 ]--- 
[ 8274.110301] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &rec) == NULL, file: fs/xfs/libxfs/xfs_inode_fork.c, line: 557 
[ 8274.122725] ------------[ cut here ]------------ 
[ 8274.127367] WARNING: CPU: 24 PID: 2216824 at fs/xfs/xfs_message.c:104 assfail+0x54/0x70 [xfs] 
...
...

I hit this bug many times by different xfstests cases. e.g. generic/270, generic/476 and generic/650. And the g/650 trigger another assertion and kernel panic at last. More details refer to attachment console.log.

The HEAD commit I tested is:

commit 2eb29d59ddf02e39774abfb60b2030b0b7e27c1f
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date:   Thu Mar 2 15:08:54 2023 -0800

    Merge tag 'drm-next-2023-03-03-1' of git://anongit.freedesktop.org/drm/drm
Comment 1 Zorro Lang 2023-03-14 15:22:36 UTC
[  854.173089] run fstests generic/270 at 2023-03-12 13:58:29 
[  856.833887] memfd_create() without MFD_EXEC nor MFD_NOEXEC_SEAL, pid=110193 'systemd' 
[  849.010141] restraintd[2857]: *** Current Time: Sun Mar 12 13:58:32 2023  Localwatchdog at: Tue Mar 14 13:47:32 2023 
[  857.976080] XFS (pmem0): DAX enabled. Warning: EXPERIMENTAL, use at your own risk 
[  857.985038] XFS (pmem0): Mounting V5 Filesystem e50966df-cb79-4d0c-9600-17be31022868 
[  858.005751] XFS (pmem0): Ending clean mount 
[  858.012146] XFS (pmem0): Quotacheck needed: Please wait. 
[  858.025572] XFS (pmem0): Quotacheck: Done. 
[  865.178004] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &rec) == NULL, file: fs/xfs/libxfs/xfs_inode_fork.c, line: 559 
[  865.190634] ------------[ cut here ]------------ 
[  865.195296] WARNING: CPU: 39 PID: 110331 at fs/xfs/xfs_message.c:104 assfail+0x54/0x70 [xfs] 
[  865.204026] Modules linked in: loop rfkill intel_rapl_msr intel_rapl_common intel_uncore_frequency intel_uncore_frequency_common ipmi_ssif i10nm_edac nfit x86_pkg_temp_thermal intel_powerclamp coretemp mlx5_ib mgag200 i2c_algo_bit drm_shmem_helper ib_uverbs dell_smbios drm_kms_helper kvm_intel iTCO_wdt iTCO_vendor_support sunrpc dcdbas kvm irqbypass rapl intel_cstate acpi_ipmi ib_core intel_uncore ipmi_si dax_pmem nd_pmem syscopyarea wmi_bmof dell_wmi_descriptor pcspkr dax_hmem isst_if_mbox_pci mei_me i2c_i801 ipmi_devintf sysfillrect isst_if_mmio mei sysimgblt isst_if_common i2c_smbus intel_vsec ipmi_msghandler acpi_power_meter drm fuse xfs libcrc32c sd_mod t10_pi sg mlx5_core crct10dif_pclmul crc32_pclmul crc32c_intel mlxfw ahci libahci tls ghash_clmulni_intel psample megaraid_sas tg3 libata pci_hyperv_intf wmi dm_mirror dm_region_hash dm_log dm_mod 
[  865.279707] CPU: 39 PID: 110331 Comm: 110035.fsstress Kdump: loaded Not tainted 6.3.0-rc1+ #1 
[  865.288254] Hardware name: Dell Inc. PowerEdge R750/0PJ80M, BIOS 1.5.4 12/17/2021 
[  865.295761] RIP: 0010:assfail+0x54/0x70 [xfs] 
[  865.300361] Code: c1 48 ba 00 00 00 00 00 fc ff df 48 89 c1 83 e0 07 48 c1 e9 03 0f b6 14 11 38 c2 7f 04 84 d2 75 10 80 3d fe 16 2f 00 00 75 15 <0f> 0b c3 cc cc cc cc 48 c7 c7 10 46 9c c1 e8 89 ac ff d4 eb e2 0f 
[  865.319133] RSP: 0018:ffa0000038f6efc8 EFLAGS: 00010246 
[  865.324384] RAX: 0000000000000000 RBX: ffa0000038f6f050 RCX: 1ffffffff83388c2 
[  865.331544] RDX: 0000000000000004 RSI: ffa0000038f6ed30 RDI: ffffffffc1820a00 
[  865.338700] RBP: ff11000723a9c040 R08: 00000000ffffffea R09: ffa0000038f6ecd7 
[  865.345867] R10: fff3fc00071edd9a R11: 0000000000000001 R12: ff11000723a9c000 
[  865.353018] R13: ffa0000038f6f030 R14: ff1100108dee11c8 R15: 0000000000000000 
[  865.360178] FS:  00007fdd43d29740(0000) GS:ff11002035c00000(0000) knlGS:0000000000000000 
[  865.368288] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033 
[  865.374062] CR2: 0000000000d50538 CR3: 00000006b3594003 CR4: 0000000000771ee0 
[  865.381223] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 
[  865.388380] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 
[  865.395538] PKRU: 55555554 
[  865.398285] Call Trace: 
[  865.400767]  <TASK> 
[  865.402899]  xfs_iextents_copy+0x4ec/0x6e0 [xfs] 
[  865.407746]  ? xfs_bmap_validate_extent+0x1e3/0x2a0 [xfs] 
[  865.413370]  ? __pfx_xfs_iextents_copy+0x10/0x10 [xfs] 
[  865.418747]  ? xfs_inode_to_log_dinode+0x8d7/0x1370 [xfs] 
[  865.424389]  ? do_raw_spin_unlock+0x55/0x1f0 
[  865.428698]  xfs_inode_item_format_data_fork+0x9c9/0x10f0 [xfs] 
[  865.434864]  xfs_inode_item_format+0x6b3/0xb40 [xfs] 
[  865.440079]  ? trace_contention_end+0x177/0x1f0 
[  865.444645]  ? __pfx_xfs_inode_item_format+0x10/0x10 [xfs] 
[  865.450386]  xlog_cil_insert_format_items+0x2b2/0x5f0 [xfs] 
[  865.456206]  xlog_cil_insert_items+0xe2/0x1060 [xfs] 
[  865.461429]  ? __lock_acquired+0x209/0x830 
[  865.465566]  ? __pfx___lock_acquired+0x10/0x10 
[  865.470037]  ? __pfx___down_read_trylock+0x10/0x10 
[  865.474864]  ? __pfx_xlog_cil_insert_items+0x10/0x10 [xfs] 
[  865.480600]  ? xlog_cil_commit+0x59/0x690 [xfs] 
[  865.485373]  xlog_cil_commit+0xa3/0x690 [xfs] 
[  865.489981]  __xfs_trans_commit+0x8c3/0xec0 [xfs] 
[  865.494936]  ? __pfx___xfs_trans_commit+0x10/0x10 [xfs] 
[  865.500395]  ? __pfx_xfs_trans_alloc_inode+0x10/0x10 [xfs] 
[  865.506131]  xfs_iomap_write_direct+0x362/0x630 [xfs] 
[  865.511439]  ? __pfx_xfs_iomap_write_direct+0x10/0x10 [xfs] 
[  865.517253]  ? xfs_direct_write_iomap_begin+0x8ad/0xd80 [xfs] 
[  865.523249]  ? rcu_read_lock_sched_held+0x43/0x80 
[  865.527996]  xfs_direct_write_iomap_begin+0x8d6/0xd80 [xfs] 
[  865.533812]  ? slab_free_freelist_hook+0x11d/0x1d0 
[  865.538639]  ? __pfx_xfs_direct_write_iomap_begin+0x10/0x10 [xfs] 
[  865.544960]  ? __xfs_trans_commit+0x8cd/0xec0 [xfs] 
[  865.550074]  ? kmem_cache_free+0xf9/0x3c0 
[  865.554161]  ? __pfx_xfs_direct_write_iomap_begin+0x10/0x10 [xfs] 
[  865.560496]  iomap_iter+0x341/0xe40 
[  865.564037]  dax_iomap_rw+0x216/0x3a0 
[  865.567735]  ? __pfx_dax_iomap_rw+0x10/0x10 
[  865.571998]  ? xfs_file_write_checks+0x4b6/0x960 [xfs] 
[  865.577388]  xfs_file_dax_write+0x278/0x9d0 [xfs] 
[  865.582323]  ? __pfx_xfs_file_dax_write+0x10/0x10 [xfs] 
[  865.587770]  ? __mutex_lock+0x741/0x1490 
[  865.591732]  ? xfs_file_write_iter+0x236/0x6a0 [xfs] 
[  865.596932]  do_iter_readv_writev+0x199/0x300 
[  865.601327]  ? __pfx_do_iter_readv_writev+0x10/0x10 
[  865.606248]  ? selinux_file_permission+0x356/0x440 
[  865.611096]  do_iter_write+0x11f/0x3b0 
[  865.614883]  iter_file_splice_write+0x5a5/0xaf0 
[  865.619471]  ? __pfx_iter_file_splice_write+0x10/0x10 
[  865.624548]  ? lock_acquire+0x1d8/0x660 
[  865.628425]  ? __pfx_lock_acquire+0x10/0x10 
[  865.632677]  do_splice+0x3d9/0xcc0 
[  865.636117]  ? __pfx_do_splice+0x10/0x10 
[  865.640077]  ? __might_fault+0xbc/0x160 
[  865.643958]  __do_splice+0x102/0x1d0 
[  865.647574]  ? __pfx___do_splice+0x10/0x10 
[  865.651721]  __x64_sys_splice+0x151/0x210 
[  865.655778]  do_syscall_64+0x59/0x90 
[  865.659399]  ? do_syscall_64+0x69/0x90 
[  865.663175]  ? lockdep_hardirqs_on+0x79/0x100 
[  865.667565]  ? do_syscall_64+0x69/0x90 
[  865.671346]  ? do_syscall_64+0x69/0x90 
[  865.675133]  ? do_syscall_64+0x69/0x90 
[  865.678914]  ? do_syscall_64+0x69/0x90 
[  865.682692]  ? lockdep_hardirqs_on+0x79/0x100 
[  865.687081]  entry_SYSCALL_64_after_hwframe+0x72/0xdc 
[  865.692166] RIP: 0033:0x7fdd43b4ec8a 
[  865.695772] Code: d8 64 89 02 48 c7 c0 ff ff ff ff eb b9 0f 1f 00 f3 0f 1e fa 49 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 15 b8 13 01 00 00 0f 05 <48> 3d 00 f0 ff ff 77 7e c3 0f 1f 44 00 00 41 54 48 83 ec 30 44 89 
[  865.714543] RSP: 002b:00007fff2a17aa78 EFLAGS: 00000246 ORIG_RAX: 0000000000000113 
[  865.722144] RAX: ffffffffffffffda RBX: 0000000000010000 RCX: 00007fdd43b4ec8a 
[  865.729303] RDX: 0000000000000005 RSI: 0000000000000000 RDI: 0000000000000006 
[  865.736461] RBP: 0000000000000005 R08: 0000000000010000 R09: 0000000000000000 
[  865.743624] R10: 00007fff2a17aac0 R11: 0000000000000246 R12: 0000000000010000 
[  865.750788] R13: 0000000000000004 R14: 000000000001e468 R15: 0000000000000000 
[  865.757977]  </TASK> 
[  865.760199] irq event stamp: 305803 
[  865.763717] hardirqs last  enabled at (305813): [<ffffffff95ffacab>] __up_console_sem+0x6b/0x80 
[  865.772436] hardirqs last disabled at (305822): [<ffffffff95ffac90>] __up_console_sem+0x50/0x80 
[  865.781154] softirqs last  enabled at (305770): [<ffffffff982eb156>] __do_softirq+0x616/0x9c7 
[  865.789699] softirqs last disabled at (305765): [<ffffffff95e48ff6>] __irq_exit_rcu+0x136/0x2a0 
[  865.798421] ---[ end trace 0000000000000000 ]--- 

# Get the debug information which asked by Darrick:

[  865.803066] XFS (pmem0): bmbt_rec: startoff=11594, startblock=11594, blockcount=0, state=0x0....validation returned addr 0x00000000d67d9cc8 
[  865.803066]
Comment 2 Zorro Lang 2023-03-19 11:11:24 UTC
Still can reproduce this issue on linux v6.3-rc2+. Besides pmem device, I hit this issue on 64k pagesize aarch64 [1] machine too.


[1]
FSTYP         -- xfs (debug)
PLATFORM      -- Linux/aarch64 ampere-mtsnow-altramax-49 6.3.0-rc2+ #1 SMP PREEMPT_DYNAMIC Sat Mar 18 04:48:48 EDT 2023
MKFS_OPTIONS  -- -f -b size=65536 -m crc=1,finobt=1,reflink=1,rmapbt=0,bigtime=1,inobtcount=1 /dev/nvme0n1p4
MOUNT_OPTIONS -- -o context=system_u:object_r:root_t:s0 /dev/nvme0n1p4 /mnt/xfstests/scratch

generic/650       _check_xfs_filesystem: filesystem on /dev/nvme0n1p5 has dirty log
(see /var/lib/xfstests/results//generic/650.full for details)
./common/xfs: line 715: 514331 Segmentation fault      (core dumped) $XFS_REPAIR_PROG -n $extra_options $extra_log_options $extra_rt_options $device > $tmp.repair 2>&1
_check_xfs_filesystem: filesystem on /dev/nvme0n1p5 is inconsistent (r)
(see /var/lib/xfstests/results//generic/650.full for details)
_check_dmesg: something found in dmesg (see /var/lib/xfstests/results//generic/650.dmesg)
- output mismatch (see /var/lib/xfstests/results//generic/650.out.bad)
    --- tests/generic/650.out	2023-03-18 05:05:09.431268800 -0400
    +++ /var/lib/xfstests/results//generic/650.out.bad	2023-03-18 09:26:13.099142159 -0400
    @@ -1,2 +1,259 @@
     QA output created by 650
     Silence is golden.
    +fsstress: check_cwd stat64() returned -1 with errno: 5 (Input/output error)
    +fsstress: check_cwd stat64() returned -1 with errno: 5 (Input/output error)
    +fsstress: check_cwd stat64() returned -1 with errno: 5 (Input/output error)
    +fsstress: check_cwd failure
    +fsstress: check_cwd failure
    ...
    (Run 'diff -u /var/lib/xfstests/tests/generic/650.out /var/lib/xfstests/results//generic/650.out.bad'  to see the entire diff)
Ran: generic/650
Failures: generic/650
Failed 1 of 1 tests



[16046.257289] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &rec) == NULL, file: fs/xfs/libxfs/xfs_inode_fork.c, line: 557 
[16046.269683] ------------[ cut here ]------------ 
[16046.274289] WARNING: CPU: 109 PID: 514058 at fs/xfs/xfs_message.c:104 assfail+0x6c/0x90 [xfs] 
[16046.282946] Modules linked in: overlay dm_zero dm_log_writes dm_thin_pool dm_persistent_data dm_bio_prison sg dm_snapshot dm_bufio ext4 mbcache jbd2 loop dm_flakey dm_mod tls rfkill sunrpc vfat fat ast acpi_ipmi drm_shmem_helper ipmi_ssif drm_kms_helper arm_spe_pmu syscopyarea sysfillrect sysimgblt ipmi_devintf ipmi_msghandler arm_dmc620_pmu arm_cmn cppc_cpufreq arm_dsu_pmu drm fuse xfs libcrc32c crct10dif_ce nvme ghash_ce nvme_core sha2_ce sha256_arm64 sha1_ce sbsa_gwdt nvme_common igb i2c_designware_platform i2c_algo_bit i2c_designware_core xgene_hwmon [last unloaded: scsi_debug] 
[16046.334506] CPU: 109 PID: 514058 Comm: kworker/u256:10 Kdump: loaded Tainted: G        W I        6.3.0-rc2+ #1 
[16046.344582] Hardware name: GIGABYTE R152-P31-00/MP32-AR1-00, BIOS F31n (SCP: 2.10.20220810) 09/30/2022 
[16046.353876] Workqueue: writeback wb_workfn (flush-259:0) 
[16046.359181] pstate: 80400009 (Nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--) 
[16046.366131] pc : assfail+0x6c/0x90 [xfs] 
[16046.370182] lr : assfail+0x38/0x90 [xfs] 
[16046.374233] sp : ffff80005206e550 
[16046.377535] x29: ffff80005206e550 x28: ffffad52485aae74 x27: 0000000000000000 
[16046.384663] x26: ffff080524799ac0 x25: 0000000000000050 x24: ffff08070f1101d8 
[16046.391790] x23: ffff80005206e630 x22: ffffad527672f9e0 x21: ffff080524799b00 
[16046.398917] x20: dfff800000000000 x19: ffff80005206e650 x18: ffff80005206e4e8 
[16046.406043] x17: 26202c6b726f6668 x16: ffffad52735e1340 x15: 28746e657478655f 
[16046.413170] x14: 65746164696c6176 x13: 0000000000000001 x12: ffff70000a40dc2b 
[16046.420297] x11: 1ffff0000a40dc2a x10: ffff70000a40dc2a x9 : ffffad52729aab58 
[16046.427423] x8 : 0000000041b58ab3 x7 : 00000000f1f1f1f1 x6 : 00000000ffffffc0 
[16046.434550] x5 : 0000000000000021 x4 : 00000000ffffffca x3 : 1ffff5aa490ee736 
[16046.441677] x2 : 0000000000000000 x1 : 0000000000000004 x0 : 0000000000000000 
[16046.448803] Call trace: 
[16046.451238]  assfail+0x6c/0x90 [xfs] 
[16046.454942]  xfs_iextents_copy+0x480/0x670 [xfs] 
[16046.459688]  xfs_inode_item_format_data_fork+0x544/0x9b0 [xfs] 
[16046.465649]  xfs_inode_item_format+0x614/0x970 [xfs] 
[16046.470741]  xlog_cil_insert_format_items.constprop.0+0x1f8/0x478 [xfs] 
[16046.477483]  xlog_cil_insert_items+0xd4/0xee0 [xfs] 
[16046.482488]  xlog_cil_commit+0xa4/0x600 [xfs] 
[16046.486973]  __xfs_trans_commit+0x7e8/0xe18 [xfs] 
[16046.491804]  xfs_trans_commit+0x18/0x28 [xfs] 
[16046.496288]  xfs_bmapi_convert_delalloc+0x848/0xa68 [xfs] 
[16046.501815]  xfs_map_blocks+0x4a0/0xfb0 [xfs] 
[16046.506300]  iomap_writepage_map+0x258/0xb20 
[16046.510560]  iomap_do_writepage+0x308/0x698 
[16046.514733]  write_cache_pages+0x35c/0xac0 
[16046.518819]  iomap_writepages+0x4c/0xc0 
[16046.522644]  xfs_vm_writepages+0x124/0x198 [xfs] 
[16046.527389]  do_writepages+0x148/0x4e0 
[16046.531127]  __writeback_single_inode+0x140/0xc50 
[16046.535821]  writeback_sb_inodes+0x3c8/0xbe8 
[16046.540079]  wb_writeback+0x2bc/0xc08 
[16046.543731]  wb_do_writeback+0x220/0x928 
[16046.547643]  wb_workfn+0x13c/0x630 
[16046.551034]  process_one_work+0x798/0x1660 
[16046.555120]  worker_thread+0x3cc/0xc38 
[16046.558859]  kthread+0x238/0x2a0 
[16046.562077]  ret_from_fork+0x10/0x20 
[16046.565642] irq event stamp: 0 
[16046.568685] hardirqs last  enabled at (0): [<0000000000000000>] 0x0 
[16046.574941] hardirqs last disabled at (0): [<ffffad5272816968>] copy_process+0x1118/0x3fe8 
[16046.583193] softirqs last  enabled at (0): [<ffffad527281699c>] copy_process+0x114c/0x3fe8 
[16046.591445] softirqs last disabled at (0): [<0000000000000000>] 0x0 
[16046.597700] ---[ end trace 0000000000000000 ]--- 
[16046.603400] XFS: Assertion failed: xfs_bmap_validate_extent(ip, whichfork, &rec) == NULL, file: fs/xfs/libxfs/xfs_inode_fork.c, line: 557 
[16046.615925] ------------[ cut here ]------------ 


Thanks,
Zorro

Note You need to log in before you can comment on or make changes to this bug.