216114 – page dumped because: VM_BUG_ON_FOLIO(!folio_contains(folio, index)) and kernel BUG at mm/truncate.c:669!

Bug 216114 - page dumped because: VM_BUG_ON_FOLIO(!folio_contains(folio, index)) and kernel BUG at mm/truncate.c:669!

Summary: page dumped because: VM_BUG_ON_FOLIO(!folio_contains(folio, index)) and kerne...

Status:	RESOLVED CODE_FIX

Alias:	None

Product:	Memory Management
Classification:	Unclassified
Component:	Other (show other bugs)
Hardware:	All Linux

Importance:	P1 normal
Assignee:	Andrew Morton

URL:
Keywords:

Depends on:
Blocks:

Reported:	2022-06-11 10:50 UTC by Zorro Lang
Modified:	2024-02-15 17:30 UTC (History)
CC List:	2 users (show)

See Also:
Kernel Version:	5.19-rc1
Subsystem:
Regression:	No
Bisected commit-id:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Description Zorro Lang 2022-06-11 10:50:53 UTC

xfstests on x86_64 with 64k directory size (mkfs.xfs -n size=65536) XFS[1] hit panic[2]. The kernel HEAD which I used is 

commit 874c8ca1e60b2c564a48f7e7acc40d328d5c8733
Author: David Howells <dhowells@redhat.com>
Date:   Thu Jun 9 21:46:04 2022 +0100

    netfs: Fix gcc-12 warning by embedding vfs inode in netfs_i_context


[1]
meta-data=/dev/sda4              isize=512    agcount=16, agsize=245696 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=1    bigtime=1 inobtcount=1
data     =                       bsize=4096   blocks=3931136, imaxpct=25
         =                       sunit=64     swidth=192 blks
naming   =version 2              bsize=65536  ascii-ci=0, ftype=1
log      =internal log           bsize=4096   blocks=16384, version=2
         =                       sectsz=512   sunit=64 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0

[2]
# ./scripts/decode_stacktrace.sh vmlinux < crash.log                                                                                                                
[ 8525.364621] run fstests generic/132 at 2022-06-10 17:58:32                                                                                                                                  
[ 8529.173644] XFS (sda4): Mounting V5 Filesystem                       
[ 8529.338529] XFS (sda4): Ending clean mount                                                  
[ 8531.015050] restraintd[1356]: *** Current Time: Fri Jun 10 17:58:44 2022  Localwatchdog at: Sun Jun 12 15:40:44 2022
[ 8560.723674] XFS (sda5): Unmounting Filesystem
[ 8560.984233] XFS (sda4): EXPERIMENTAL online scrub feature in use. Use at your own risk!
[ 8561.787448] XFS (sda4): Unmounting Filesystem
[ 8562.925361] XFS (sda4): Mounting V5 Filesystem
[ 8563.101997] XFS (sda4): Ending clean mount
[ 8563.163581] XFS (sda4): Unmounting Filesystem 
[ 8563.890637] XFS (sda5): Mounting V5 Filesystem
[ 8564.087515] XFS (sda5): Ending clean mount
[ 8567.049332] XFS (sda4): Mounting V5 Filesystem
[ 8567.176278] XFS (sda4): Ending clean mount
[ 8567.213659] XFS (sda4): Unmounting Filesystem         
[ 8567.476953] XFS (sda5): EXPERIMENTAL online scrub feature in use. Use at your own risk!
[ 8573.888318] XFS (sda5): Unmounting Filesystem
[ 8575.293213] XFS (sda5): Mounting V5 Filesystem
[ 8575.545576] XFS (sda5): Ending clean mount
[ 8575.883979] run fstests generic/133 at 2022-06-10 17:59:23
[ 8590.600151] page:0000000027772b07 refcount:2 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x2a7a00
[ 8590.601327] flags: 0x57ffffc0050000(head|reclaim|node=1|zone=2|lastcpupid=0x1fffff)
[ 8590.601341] raw: 0057ffffc0050000 0000000000000000 dead000000000122 0000000000000000
[ 8590.601345] raw: 0000000000007300 0000000000000000 00000001ffffffff 0000000000000000
[ 8590.601348] page dumped because: VM_BUG_ON_FOLIO(!folio_contains(folio, index))
[ 8590.601416] ------------[ cut here ]------------                             
[ 8590.601417] kernel BUG at mm/truncate.c:669!                                 
[ 8590.601431] invalid opcode: 0000 [#1] PREEMPT SMP KASAN NOPTI                
[ 8590.606841] Hardware name: HP ProLiant DL385p Gen8, BIOS A28 02/06/2014                 
[ 8590.607178] RIP: 0010:invalidate_inode_pages2_range (mm/truncate.c:669 (discriminator 1)) 
[ 8590.607924] Code: c0 03 38 d0 7c 08 84 d2 0f 85 aa 06 00 00 41 8b 47 5c 49 39 c6 0f 82 80 fe ff ff 48 c7 c6 a0 3b 55 99 4c 89 ff e8 7e 9f 07 00 <0f> 0b e8 37 ec fd ff 4c 89 ff e8 9f c3 03 
00 84 c0 0f 85 2d 02 00   
All code              
========
   0:   c0 03 38                rolb   $0x38,(%rbx)        
   3:   d0 7c 08 84             sarb   -0x7c(%rax,%rcx,1)     
   7:   d2 0f                   rorb   %cl,(%rdi)
   9:   85 aa 06 00 00 41       test   %ebp,0x41000006(%rdx)                                 
   f:   8b 47 5c                mov    0x5c(%rdi),%eax     
  12:   49 39 c6                cmp    %rax,%r14                 
  15:   0f 82 80 fe ff ff       jb     0xfffffffffffffe9b           
  1b:   48 c7 c6 a0 3b 55 99    mov    $0xffffffff99553ba0,%rsi                                                                                                                                
  22:   4c 89 ff                mov    %r15,%rdi
  25:   e8 7e 9f 07 00          callq  0x79fa8
  2a:*  0f 0b                   ud2             <-- trapping instruction
  2c:   e8 37 ec fd ff          callq  0xfffffffffffdec68
  31:   4c 89 ff                mov    %r15,%rdi
  34:   e8 9f c3 03 00          callq  0x3c3d8
  39:   84 c0                   test   %al,%al
  3b:   0f                      .byte 0xf
  3c:   85                      .byte 0x85
  3d:   2d                      .byte 0x2d
  3e:   02 00                   add    (%rax),%al

Code starting with the faulting instruction
===========================================
   0:   0f 0b                   ud2    
   2:   e8 37 ec fd ff          callq  0xfffffffffffdec3e
   7:   4c 89 ff                mov    %r15,%rdi
   a:   e8 9f c3 03 00          callq  0x3c3ae
   f:   84 c0                   test   %al,%al
  11:   0f                      .byte 0xf
  12:   85                      .byte 0x85
  13:   2d                      .byte 0x2d
  14:   02 00                   add    (%rax),%al
[ 8590.609335] RSP: 0018:ffffc9000bd976d0 EFLAGS: 00010286
[ 8590.609697] RAX: 0000000000000043 RBX: dffffc0000000000 RCX: 0000000000000000
[ 8590.610771] RDX: 0000000000000001 RSI: 0000000000000004 RDI: fffff520017b2eca
[ 8590.611576] RBP: 0000000000000000 R08: 0000000000000043 R09: ffff8888367efd0b
[ 8590.612349] R10: ffffed1106cfdfa1 R11: 0000000000000001 R12: ffff88825a578418
[ 8590.613117] R13: 0000000000007340 R14: 000000000000733f R15: ffffea000a9e8000
[ 8590.613902] FS:  00007f93f6f56740(0000) GS:ffff888836600000(0000) knlGS:0000000000000000
[ 8590.614346] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 8590.615008] CR2: 00007f0576919150 CR3: 0000000649990000 CR4: 00000000000406e0
[ 8590.615761] Call Trace:
[ 8590.615914]  <TASK>
[ 8590.616425] ? mapping_evict_folio.part.0 (mm/truncate.c:630)                                                                                                                        [86/196]
[ 8590.616718] ? pagevec_lookup_range_tag (mm/swap.c:1122) 
[ 8590.617492] ? __filemap_fdatawait_range (mm/filemap.c:518) 
[ 8590.618140] ? xas_reload (mm/filemap.c:503)  
[ 8590.618357] ? filemap_fdatawrite_wbc (./include/linux/backing-dev.h:138 mm/filemap.c:383) 
[ 8590.619013] ? filemap_range_has_page (mm/filemap.c:498) 
[ 8590.619866] ? delete_from_page_cache_batch (mm/filemap.c:413) 
[ 8590.620201] ? rcu_read_lock_sched_held (kernel/rcu/update.c:125) 
[ 8590.620864] ? filemap_check_errors (./arch/x86/include/asm/bitops.h:207 ./include/asm-generic/bitops/instrumented-non-atomic.h:135 mm/filemap.c:351) 
[ 8590.621542] __iomap_dio_rw (fs/iomap/direct-io.c:582) 
[ 8590.621768] ? iomap_dio_bio_iter (fs/iomap/direct-io.c:487) 
[ 8590.622436] ? trace_xfs_setattr (fs/xfs/xfs_iops.c:1020) xfs
[ 8590.623386] ? iu[ 8590.708322] iomap_dio_rw (fs/iomap/direct-io.c:689) 
[ 8590.724063] xfs_file_dio_write_aligned (fs/xfs/xfs_file.c:536) xfs
[ 8590.724539] ? xfs_file_dio_write_unaligned (fs/xfs/xfs_file.c:515) xfs
[ 8590.725586] xfs_file_write_iter (fs/xfs/xfs_file.c:792) xfs
[ 8590.726382] new_sync_write (fs/read_write.c:505 (discriminator 1)) 
[ 8590.726593] ? new_sync_read (fs/read_write.c:494) 
[ 8590.726801] ? lock_acquire (kernel/locking/lockdep.c:466 kernel/locking/lockdep.c:5667 kernel/locking/lockdep.c:5630) 
[ 8590.727040] ? rcu_read_unlock (./include/linux/rcupdate.h:724 (discriminator 5)) 
[ 8590.727267] vfs_write (fs/read_write.c:591)  
[ 8590.727815] __x64_sys_pwrite64 (fs/read_write.c:706 fs/read_write.c:716 fs/read_write.c:713 fs/read_write.c:713) 
[ 8590.728051] ? vfs_write (fs/read_write.c:713) 
[ 8590.728263] ? ktime_get_coarse_real_ts64 (./include/linux/seqlock.h:104 kernel/time/timekeeping.c:2258) 
[ 8590.728546] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 8590.728756] ? do_syscall_64 (arch/x86/entry/common.c:87) 
[ 8590.728983] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4383) 
[ 8590.729600] ? do_syscall_64 (arch/x86/entry/common.c:87) 
[ 8590.729833] ? do_syscall_64+0x69/[ 8591.130203] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4383) 
[ 8591.130866] ? do_syscall_64 (arch/x86/entry/common.c:87) 
[ 8591.131115] ? do_syscall_64 (arch/x86/entry/common.c:87) 
[ 8591.131331] ? do_syscall_64 (arch/x86/entry/common.c:87) 
[ 8591.131576] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4383) 
[ 8591.132207] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:115) 
[ 8591.132501] RIP: 0033:0x7f93f6d3cddf
[ 8591.132737] Code: 08 89 3c 24 48 89 4c 24 18 e8 6d fe f5 ff 4c 8b 54 24 18 48 8b 54 24 10 41 89 c0 48 8b 74 24 08 8b 3c 24 b8 12 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 31 44 89 c7 48 89 04 
24 e8 bd fe f5 ff 48 8b
All code
========
   0:   08 89 3c 24 48 89       or     %cl,-0x76b7dbc4(%rcx)
   6:   4c 24 18                rex.WR and $0x18,%al
   9:   e8 6d fe f5 ff          callq  0xfffffffffff5fe7b
   e:   4c 8b 54 24 18          mov    0x18(%rsp),%r10
  13:   48 8b 54 24 10          mov    0x10(%rsp),%rdx
  18:   41 89 c0                mov    %eax,%r8d
  1b:   48 8b 74 24 08          mov    0x8(%rsp),%rsi
  20:   8b 3c 24                mov    (%rsp),%edi
  23:   b8 12 00 00 00          mov    $0x12,%eax
  28:   0f 05                   syscall 
  2a:*  48 3d 00 f0 ff ff       cmp    $0xfffffffffffff000,%rax         <-- trapping instruction
  30:   77 31                   ja     0x63
  32:   44 89 c7                mov    %r8d,%edi
  35:   48 89 04 24             mov    %rax,(%rsp)
  39:   e8 bd fe f5 ff          callq  0xfffffffffff5fefb
  3e:   48                      rex.W
  3f:   8b                      .byte 0x8b

Code starting with the faulting instruction
===========================================
   0:   48 3d 00 f0 ff ff       cmp    $0xfffffffffffff000,%rax
   6:   77 31                   ja     0x39
   8:   44 89 c7                mov    %r8d,%edi
   b:   48 89 04 24             mov    %rax,(%rsp)
   f:   e8 bd fe f5 ff          callq  0xfffffffffff5fed1
  14:   48                      rex.W
  15:   8b                      .byte 0x8b
[ 8591.134056] RSP: 002b:00007ffd8aac5a20 EFLAGS: 00000293 ORIG_RAX: 0000000000000012
[ 8591.134828] RAX: ffffffffffffffda RBX: 0000000007340000 RCX: 00007f93f6d3cddf
[ 8591.135648] RDX: 0000000000010000 RSI: 0000000000b63000 RDI: 0000000000000003
[ 8591.136425] RBP: 00000000ffffffff R08: 0000000000000000 R09: 0000000000000079
[ 8591.137179] R10: 0000000007340000 R11: 0000000000000293 R12: 0000000007340000
[ 8591.138020] R13: 0000000000000000 R14: 0000000000000734 R15: 0000000018cc0000
[ 8591.138804]  </TASK>
[ 8591.138985] Modules limi sysimgblt fb_sys_fops hpilo ipmi_si ipmi_devintf ipmi_msghandler sunrpc acpi_power_meter drm fuse xfs libcrc32c sd_mod t10_pi crc64_rocksoft_generic crc64_rocksoft
 crc64 sr_mod cdrom sg crct10dif_pclmul crc32_pclmul crc32c_intel ahci ata_generic libahci ghash_clmulni_intel serio_raw libata hpsa tg3 scsi_transport_sas hpwdt [last unloaded: scsi_debug]
[ 8591.641707] ---[ end trace 0000000000000000 ]---
[ 8591.644539] amd_iommu_report_page_fault: 501 callbacks suppressed
[ 8591.644554] hpilo 0000:02:00.2: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x000d address=0xbde0e000 flags=0x0000]
[ 8591.650728] hpilo 0000:02:00.2: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x000d address=0xbde0e000 flags=0x0000]
[ 8591.655235] hpilo 0000:02:00.2: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x000d address=0xbde0e000 flags=0x0000]
[ 8591.661240] hpilo 0000:02:00.2: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x000d address=0xbde0e000 flags=0x0000]
[ 8591.666237] hpilo 0000:02:00.2: AMD-Vi: Event logged [IO_PAGE_FAULT domain=0x000d address=0xbde0e000 flags=0x0000]
[ 8591.670741] hpilo 0000:02:00.2: AMD-ViIP: 0010:invalidate_inode_pages2_range (mm/truncate.c:669 (discriminator 1)) 
[ 8591.676251] Code: c0 03 38 d0 7c 08 84 d2 0f 85 aa 06 00 00 41 8b 47 5c 49 39 c6 0f 82 80 fe ff ff 48 c7 c6 a0 3b 55 99 4c 89 ff e8 7e 9f 07 00 <0f> 0b e8 37 ec fd ff 4c 89 ff e8 9f c3 03 
00 84 c0 0f 85 2d 02 00
All code
========
   0:   c0 03 38                rolb   $0x38,(%rbx)
   3:   d0 7c 08 84             sarb   -0x7c(%rax,%rcx,1)
   7:   d2 0f                   rorb   %cl,(%rdi)
   9:   85 aa 06 00 00 41       test   %ebp,0x41000006(%rdx)
   f:   8b 47 5c                mov    0x5c(%rdi),%eax
  12:   49 39 c6                cmp    %rax,%r14
  15:   0f 82 80 fe ff ff       jb     0xfffffffffffffe9b
  1b:   48 c7 c6 a0 3b 55 99    mov    $0xffffffff99553ba0,%rsi
  22:   4c 89 ff                mov    %r15,%rdi
  25:   e8 7e 9f 07 00          callq  0x79fa8
  2a:*  0f 0b                   ud2             <-- trapping instruction
  2c:   e8 37 ec fd ff          callq  0xfffffffffffdec68
  31:   4c 89 ff                mov    %r15,%rdi
  34:   e8 9f c3 03 00          callq  0x3c3d8
  39:   84 c0                   test   %al,%al
  3b:   0f                      .byte 0xf
  3c:   85                      .byte 0x85
  3d:   2d                      .byte 0x2d
  3e:   02 00                   add    (%rax),%al

Code starting with the faulting instruction
===========================================
   0:   0f 0b                   ud2    
   2:   e8 37 ec fd ff          callq  0xfffffffffffdec3e
   7:   4c 89 ff                mov    %r15,%rdi
   a:   e8 9f c3 03 00          callq  0x3c3ae
   f:   84 c0                   test   %al,%al
  11:   0f                      .byte 0xf
  12:   85                      .byte 0x85
  13:   2d                      .byte 0x2d
  14:   02 00                   add    (%rax),%al
[ 8591.676261] RSP: 0018:ffffc9000bd976d0 EFLAGS: 00010286
[ 8591.676273] RAX: 0000000000000043 RBX: dffffc0000000000 RCX: 0000000000000000
[ 8591.676279] RDX: 0000000000000001 RSI: 0000000000000004 RDI: fffff520017b2eca
[ 8591.676287] RBP: 0000000000000000 R08: 0000000000000043 R09: ffff8888367efd0b
[ 8591.676293] R10: ffffed1106cfdfa1 R11: 0000000000000001 R12: ffff88825a578418
[ 8591.676327] R13: 0000000000007340 R14: 000000000000733f R15: ffffea000a9e8000
[ 8591.676336] FS:  00007f93f6f56740(0000) GS:ffff888836600000(0000) knlGS:0000000000000000
[ 8591.676344] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 8591.676350] CR2: 00007f0576919150 CR3: 0000000649990000 CR4: 00000000000406e0
[ 8591.013708] restraintd[1356]: *** Current Time: Fri Jun 10 17:59:44 2022  Localwatchdog at: Sun Jun 12 15:40:44 2022
[-- MARK -- Fri Jun 10 22:00:00 2022]

Comment 1 Luis Chamberlain 2023-12-05 04:05:29 UTC

I managed to reproduced this a few times on v6.6-rc5 with other tests on kdevops on the following config as defined by XFS's configurations for XFS with the following failure rates annotated

  * xfs_reflink_4k: F:1/278 - one out of 278 times
  - generic/451: https://gist.github.com/mcgrof/8cecdd032927fb5509bd0ee61eaee42a
  * xfs_nocrc_4k: F:1/1604 - one ou tof 1604 times
  - generic/451: https://gist.github.com/mcgrof/2c40a14979ceeb7321d2234a525c32a6

To be clear F:1/1604 means you can run the test in a loop and on test number about 1604 you may run into the bug.

[0] https://github.com/linux-kdevops/
[1] https://github.com/linux-kdevops/kdevops/blob/master/playbooks/roles/fstests/templates/xfs/xfs.config

The reflink crash noted below. This is triggered when we mix buffered-io with async DIO, which although we don't recommend we should not crash the system.

Nov 05 23:20:54 r451-xfs-reflink-4k unknown: run fstests generic/451 at 2023-11-05 23:20:54
Nov 05 23:21:25 r451-xfs-reflink-4k kernel: XFS (loop16): EXPERIMENTAL online scrub feature in use. Use at your own risk!
Nov 05 23:21:25 r451-xfs-reflink-4k kernel: XFS (loop16): Unmounting Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 05 23:21:25 r451-xfs-reflink-4k kernel: XFS (loop16): Mounting V5 Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 05 23:21:25 r451-xfs-reflink-4k kernel: XFS (loop16): Ending clean mount
Nov 05 23:21:26 r451-xfs-reflink-4k kernel: kmemleak: 14 new suspected memory leaks (see /sys/kernel/debug/kmemleak)
Nov 05 23:21:26 r451-xfs-reflink-4k kernel: XFS (loop16): Unmounting Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 05 23:21:27 r451-xfs-reflink-4k kernel: XFS (loop16): Mounting V5 Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 05 23:21:27 r451-xfs-reflink-4k kernel: XFS (loop16): Ending clean mount
Nov 05 23:21:28 r451-xfs-reflink-4k kernel: XFS (loop5): Mounting V5 Filesystem c1814fb4-5f79-4274-96fa-7bf6fabe0ee8
Nov 05 23:21:28 r451-xfs-reflink-4k kernel: XFS (loop5): Ending clean mount
Nov 05 23:21:28 r451-xfs-reflink-4k kernel: XFS (loop5): Unmounting Filesystem c1814fb4-5f79-4274-96fa-7bf6fabe0ee8
Nov 05 23:21:28 r451-xfs-reflink-4k kernel: XFS (loop16): EXPERIMENTAL online scrub feature in use. Use at your own risk!
Nov 05 23:21:28 r451-xfs-reflink-4k kernel: XFS (loop16): Unmounting Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 05 23:21:29 r451-xfs-reflink-4k kernel: XFS (loop16): Mounting V5 Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 05 23:21:29 r451-xfs-reflink-4k kernel: XFS (loop16): Ending clean mount
Nov 05 23:21:29 r451-xfs-reflink-4k unknown: run fstests generic/451 at 2023-11-05 23:21:29

... over 17 hours later or after loop number #1604 of the test

Nov 06 16:06:07 r451-xfs-reflink-4k unknown: run fstests generic/451 at 2023-11-06 16:06:07
Nov 06 16:06:38 r451-xfs-reflink-4k kernel: XFS (loop16): EXPERIMENTAL online scrub feature in use. Use at your own risk!
Nov 06 16:06:38 r451-xfs-reflink-4k kernel: XFS (loop16): Unmounting Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 06 16:06:38 r451-xfs-reflink-4k kernel: XFS (loop16): Mounting V5 Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 06 16:06:38 r451-xfs-reflink-4k kernel: XFS (loop16): Ending clean mount
Nov 06 16:06:41 r451-xfs-reflink-4k kernel: kmemleak: 9 new suspected memory leaks (see /sys/kernel/debug/kmemleak)
Nov 06 16:06:42 r451-xfs-reflink-4k kernel: XFS (loop16): Unmounting Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 06 16:06:42 r451-xfs-reflink-4k kernel: XFS (loop16): Mounting V5 Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 06 16:06:42 r451-xfs-reflink-4k kernel: XFS (loop16): Ending clean mount
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop5): Mounting V5 Filesystem 6a017bf9-aa36-474a-af1b-670d8bae14cf
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop5): Ending clean mount
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop5): Unmounting Filesystem 6a017bf9-aa36-474a-af1b-670d8bae14cf
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop16): EXPERIMENTAL online scrub feature in use. Use at your own risk!
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop16): Unmounting Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop16): Mounting V5 Filesystem 2ed74cf8-8238-4817-bc04-d9b3f4f79275
Nov 06 16:06:47 r451-xfs-reflink-4k kernel: XFS (loop16): Ending clean mount
Nov 06 16:06:47 r451-xfs-reflink-4k unknown: run fstests generic/451 at 2023-11-06 16:06:47
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: page:00000000bda16be1 refcount:8 mapcount:0 mapping:00000000258b6ed6 index:0x5c pfn:0x19728
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: head:00000000bda16be1 order:2 entire_mapcount:0 nr_pages_mapped:0 pincount:0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: memcg:ffff987b9ecec000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: aops:xfs_address_space_operations [xfs] ino:83 dentry name:"tst-aio-dio-cycle-write.451"
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: flags: 0xffffce0000826d(locked|referenced|uptodate|lru|workingset|private|head|node=0|zone=1|lastcpupid=0x1ffff)
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: page_type: 0xffffffff()
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: raw: 00ffffce0000826d ffffdce9c08b6048 ffff987b9eced120 ffff987b83ef0ab8
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: raw: 000000000000005c ffff987b94c07620 00000007ffffffff ffff987b9ecec000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: page dumped because: VM_BUG_ON_FOLIO(!folio_contains(folio, indices[i]))
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: ------------[ cut here ]------------
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: kernel BUG at mm/truncate.c:662!
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: invalid opcode: 0000 [#1] PREEMPT SMP NOPTI
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: CPU: 2 PID: 2235189 Comm: kworker/2:0 Not tainted 6.6.0-rc5 #1
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: Workqueue: dio/loop16 iomap_dio_complete_work
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RIP: 0010:invalidate_inode_pages2_range+0x258/0x4b0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: Code: e8 ad f9 ff ff 48 8b 00 f6 c4 01 0f 84 ab fe ff ff 4c 3b 6b 20 0f 84 e3 fe ff ff 48 c7 c6 20 b8 43 92 48 89 df e8 c8 74 03 00 <0f> 0b 8b 43>
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RSP: 0018:ffffb5cd81fa7cd0 EFLAGS: 00010246
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RAX: 0000000000000048 RBX: ffffdce9c065ca00 RCX: 0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RDX: 0000000000000000 RSI: 0000000000000027 RDI: 00000000ffffffff
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RBP: 0000000000000000 R08: 0000000000000000 R09: ffffb5cd81fa7b80
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: R10: 0000000000000003 R11: ffffffff926b5520 R12: ffff987b83ef0ab8
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: R13: ffffffffffffffa4 R14: 0000000000000000 R15: 0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: FS:  0000000000000000(0000) GS:ffff987bfbc80000(0000) knlGS:0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: CR2: 00007ffcdc8e98f0 CR3: 000000005c438003 CR4: 0000000000770ee0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: PKRU: 55555554
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: Call Trace:
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  <TASK>
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? die+0x32/0x80
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? do_trap+0xd6/0x100
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? invalidate_inode_pages2_range+0x258/0x4b0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? do_error_trap+0x6a/0x90
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? invalidate_inode_pages2_range+0x258/0x4b0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? exc_invalid_op+0x4c/0x60
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? invalidate_inode_pages2_range+0x258/0x4b0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? asm_exc_invalid_op+0x16/0x20
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? invalidate_inode_pages2_range+0x258/0x4b0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? update_load_avg+0x7e/0x780
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? update_load_avg+0x7e/0x780
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? dequeue_entity+0x133/0x4a0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? _raw_spin_unlock+0x15/0x30
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  kiocb_invalidate_post_direct_write+0x39/0x50
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  iomap_dio_complete+0x12a/0x1a0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? __pfx_aio_complete_rw+0x10/0x10
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  iomap_dio_complete_work+0x17/0x30
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  process_one_work+0x171/0x340
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  worker_thread+0x277/0x3a0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? __pfx_worker_thread+0x10/0x10
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  kthread+0xf0/0x120
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? __pfx_kthread+0x10/0x10
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ret_from_fork+0x2d/0x50
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ? __pfx_kthread+0x10/0x10
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  ret_from_fork_asm+0x1b/0x30
Nov 06 16:07:16 r451-xfs-reflink-4k kernel:  </TASK>
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: Modules linked in: xfs sunrpc nvme_fabrics nvme_core t10_pi crc64_rocksoft_generic crc64_rocksoft crc64 kvm_intel kvm irqbypass crct10dif_pclmul >
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: ---[ end trace 0000000000000000 ]---
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RIP: 0010:invalidate_inode_pages2_range+0x258/0x4b0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: Code: e8 ad f9 ff ff 48 8b 00 f6 c4 01 0f 84 ab fe ff ff 4c 3b 6b 20 0f 84 e3 fe ff ff 48 c7 c6 20 b8 43 92 48 89 df e8 c8 74 03 00 <0f> 0b 8b 43>
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RSP: 0018:ffffb5cd81fa7cd0 EFLAGS: 00010246
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RAX: 0000000000000048 RBX: ffffdce9c065ca00 RCX: 0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RDX: 0000000000000000 RSI: 0000000000000027 RDI: 00000000ffffffff
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: RBP: 0000000000000000 R08: 0000000000000000 R09: ffffb5cd81fa7b80
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: R10: 0000000000000003 R11: ffffffff926b5520 R12: ffff987b83ef0ab8
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: R13: ffffffffffffffa4 R14: 0000000000000000 R15: 0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: FS:  0000000000000000(0000) GS:ffff987bfbc80000(0000) knlGS:0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: CR2: 00007fa1980081d8 CR3: 000000010c812006 CR4: 0000000000770ee0
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Nov 06 16:07:16 r451-xfs-reflink-4k kernel: PKRU: 55555554

Comment 2 Luis Chamberlain 2024-02-15 17:30:03 UTC

I've confirmed this issue is now fixed, the commit which
Matthew Wilcox suggested would likely fix this [0], commit
fc346d0a70a1 ("mm: migrate high-order folios in swap cache correctly")
is merged since v6.7-rc8. I've ran generic/451 in a loop 400 times
without failure.
    
[0] https://lkml.kernel.org/r/ZXQAgFl8WGr2pK7R@casper.infradead.org

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