Greeting,
FYI, we noticed the following commit (built with gcc-11):
commit: 47a6df7cd3174b91c6c862eae0b8d4e13591df52 ("xfs: shut down filesystem if we xfs_trans_cancel with deferred work items")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: xfstests
version: xfstests-x86_64-c1144bf-1_20220704
with following parameters:
disk: 4HDD
fs: xfs
test: xfs-group-07
ucode: 0x21
test-description: xfstests is a regression test suite for xfs and other files ystems.
test-url: git://git.kernel.org/pub/scm/fs/xfs/xfstests-dev.git
on test machine: 4 threads 1 sockets Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz with 8G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>
[ 94.271323][ T9089] XFS (sda5): Mounting V5 Filesystem
[ 94.369992][ T9089] XFS (sda5): Ending clean mount
[ 94.376046][ T9089] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 112.154792][ T311] xfs/076 IPMI BMC is not supported on this machine, skip bmc-watchdog setup!
[ 112.154805][ T311]
[ 161.426026][T29384] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 951
[ 161.437713][T29384] ------------[ cut here ]------------
[ 161.443155][T29384] kernel BUG at fs/xfs/xfs_message.c:110!
[ 161.448854][T29384] invalid opcode: 0000 [#1] SMP KASAN PTI
[ 161.454536][T29384] CPU: 1 PID: 29384 Comm: touch Not tainted 5.16.0-rc5-00001-g47a6df7cd317 #1
[ 161.463337][T29384] Hardware name: Hewlett-Packard HP Pro 3340 MT/17A1, BIOS 8.07 01/24/2013
[161.471891][T29384] RIP: 0010:assfail (kbuild/src/consumer/fs/xfs/./xfs_trace.h:2125 (discriminator 6)) xfs
[ 161.477179][T29384] Code: c1 e2 2a 83 e0 07 48 c1 e9 03 8a 14 11 38 c2 7f 10 84 d2 74 0c 48 c7 c7 cc 1a 03 c2 e8 d7 c9 a1 bf 80 3d 1c 1f 1a 00 00 74 02 <0f> 0b 0f 0b c3 48 8d 45 10 48 8d 54 24 28 4c 89 f6 48 c7 c7 80 63
All code
========
0: c1 e2 2a shl $0x2a,%edx
3: 83 e0 07 and $0x7,%eax
6: 48 c1 e9 03 shr $0x3,%rcx
a: 8a 14 11 mov (%rcx,%rdx,1),%dl
d: 38 c2 cmp %al,%dl
f: 7f 10 jg 0x21
11: 84 d2 test %dl,%dl
13: 74 0c je 0x21
15: 48 c7 c7 cc 1a 03 c2 mov $0xffffffffc2031acc,%rdi
1c: e8 d7 c9 a1 bf callq 0xffffffffbfa1c9f8
21: 80 3d 1c 1f 1a 00 00 cmpb $0x0,0x1a1f1c(%rip) # 0x1a1f44
28: 74 02 je 0x2c
2a:* 0f 0b ud2 <-- trapping instruction
2c: 0f 0b ud2
2e: c3 retq
2f: 48 8d 45 10 lea 0x10(%rbp),%rax
33: 48 8d 54 24 28 lea 0x28(%rsp),%rdx
38: 4c 89 f6 mov %r14,%rsi
3b: 48 rex.W
3c: c7 .byte 0xc7
3d: c7 .byte 0xc7
3e: 80 .byte 0x80
3f: 63 .byte 0x63
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 0f 0b ud2
4: c3 retq
5: 48 8d 45 10 lea 0x10(%rbp),%rax
9: 48 8d 54 24 28 lea 0x28(%rsp),%rdx
e: 4c 89 f6 mov %r14,%rsi
11: 48 rex.W
12: c7 .byte 0xc7
13: c7 .byte 0xc7
14: 80 .byte 0x80
15: 63 .byte 0x63
[ 161.496921][T29384] RSP: 0018:ffffc9000e52f640 EFLAGS: 00010202
[ 161.502959][T29384] RAX: 0000000000000004 RBX: ffff8882083ee448 RCX: 1ffffffff8406359
[ 161.510906][T29384] RDX: dffffc0000000000 RSI: dffffc0000000000 RDI: fffff52001ca5eba
[ 161.518852][T29384] RBP: ffff8882083ee378 R08: ffffc9000e52f4d0 R09: ffff8881a5cb3a07
[ 161.526791][T29384] R10: ffffed1034b96740 R11: 0000000000000001 R12: ffff88820c2ee000
[ 161.534739][T29384] R13: ffff88820c2ee468 R14: ffff8882083ee394 R15: 0000000000000005
[ 161.542662][T29384] FS: 00007fa30092b5c0(0000) GS:ffff8881a5c80000(0000) knlGS:0000000000000000
[ 161.551525][T29384] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 161.558075][T29384] CR2: 00007fa300849e60 CR3: 0000000212c78006 CR4: 00000000001706e0
[ 161.566059][T29384] Call Trace:
[ 161.569247][T29384] <TASK>
[161.572091][T29384] xfs_trans_cancel (kbuild/src/consumer/fs/xfs/xfs_trans.c:951 (discriminator 2)) xfs
[161.577535][T29384] xfs_create (kbuild/src/consumer/fs/xfs/xfs_inode.c:1104) xfs
[161.582457][T29384] ? xfs_irele (kbuild/src/consumer/fs/xfs/xfs_inode.c:966) xfs
[161.587475][T29384] ? get_cached_acl_rcu (kbuild/src/consumer/fs/posix_acl.c:40)
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
--
0-DAY CI Kernel Test Service
https://01.org/lkp
On Tue, Jul 12, 2022 at 03:20:08PM +0800, kernel test robot wrote:
>
>
> Greeting,
>
> FYI, we noticed the following commit (built with gcc-11):
>
> commit: 47a6df7cd3174b91c6c862eae0b8d4e13591df52 ("xfs: shut down filesystem if we xfs_trans_cancel with deferred work items")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> in testcase: xfstests
> version: xfstests-x86_64-c1144bf-1_20220704
> with following parameters:
>
> disk: 4HDD
> fs: xfs
> test: xfs-group-07
> ucode: 0x21
>
> test-description: xfstests is a regression test suite for xfs and other files ystems.
> test-url: git://git.kernel.org/pub/scm/fs/xfs/xfstests-dev.git
>
>
> on test machine: 4 threads 1 sockets Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz with 8G memory
>
> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>
>
>
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <[email protected]>
>
>
> [ 94.271323][ T9089] XFS (sda5): Mounting V5 Filesystem
> [ 94.369992][ T9089] XFS (sda5): Ending clean mount
> [ 94.376046][ T9089] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
> [ 112.154792][ T311] xfs/076 IPMI BMC is not supported on this machine, skip bmc-watchdog setup!
> [ 112.154805][ T311]
> [ 161.426026][T29384] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 951
> [ 161.437713][T29384] ------------[ cut here ]------------
> [ 161.443155][T29384] kernel BUG at fs/xfs/xfs_message.c:110!
> [ 161.448854][T29384] invalid opcode: 0000 [#1] SMP KASAN PTI
> [ 161.454536][T29384] CPU: 1 PID: 29384 Comm: touch Not tainted 5.16.0-rc5-00001-g47a6df7cd317 #1
5.16-rc5? Seems like a really old kernel to be testing....
Does this reproduce on a current 5.19-rc6 kernel?
-Dave.
--
Dave Chinner
[email protected]
hi Dave,
On Wed, Jul 13, 2022 at 07:47:45AM +1000, Dave Chinner wrote:
> >
> > If you fix the issue, kindly add following tag
> > Reported-by: kernel test robot <[email protected]>
> >
> >
> > [ 94.271323][ T9089] XFS (sda5): Mounting V5 Filesystem
> > [ 94.369992][ T9089] XFS (sda5): Ending clean mount
> > [ 94.376046][ T9089] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
> > [ 112.154792][ T311] xfs/076 IPMI BMC is not supported on this machine, skip bmc-watchdog setup!
> > [ 112.154805][ T311]
> > [ 161.426026][T29384] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 951
> > [ 161.437713][T29384] ------------[ cut here ]------------
> > [ 161.443155][T29384] kernel BUG at fs/xfs/xfs_message.c:110!
> > [ 161.448854][T29384] invalid opcode: 0000 [#1] SMP KASAN PTI
> > [ 161.454536][T29384] CPU: 1 PID: 29384 Comm: touch Not tainted 5.16.0-rc5-00001-g47a6df7cd317 #1
>
> 5.16-rc5? Seems like a really old kernel to be testing....
>
> Does this reproduce on a current 5.19-rc6 kernel?
yes, it's still reproducible. however, it's actually random on both 47a6df7cd3
and 5.19-rc6, as below.
it's clean on 40 runs of v5.16-rc5,
on 47a6df7cd3, it's reproduced 9 times out of 40 runs,
on v5.19-rc6, it's reprodced 7 times out of 20 runs.
v5.16-rc5 47a6df7cd3174b91c6c862eae0b v5.19-rc6
---------------- --------------------------- ---------------------------
fail:runs %reproduction fail:runs %reproduction fail:runs
| | | | |
:40 22% 9:40 18% 7:20 dmesg.Assertion_failed
:40 22% 9:40 18% 7:20 dmesg.Kernel_panic-not_syncing:Fatal_exception
:40 22% 9:40 18% 7:20 dmesg.RIP:assfail[xfs]
:40 22% 9:40 18% 7:20 dmesg.boot_failures
:40 22% 9:40 18% 7:20 dmesg.invalid_opcode:#[##]
:40 22% 9:40 18% 7:20 dmesg.kernel_BUG_at_fs/xfs/xfs_message.c
attached the config to build v5.19-rc6 and one dmesg FYI.
[ 162.318194][T29029] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 993
[ 162.330026][T29029] ------------[ cut here ]------------
[ 162.335361][T29029] kernel BUG at fs/xfs/xfs_message.c:102!
[ 162.340998][T29029] invalid opcode: 0000 [#1] SMP KASAN PTI
[ 162.346594][T29029] CPU: 3 PID: 29029 Comm: touch Tainted: G S 5.19.0-rc6 #1
[ 162.354954][T29029] Hardware name: Hewlett-Packard HP Pro 3340 MT/17A1, BIOS 8.07 01/24/2013
[ 162.363394][T29029] RIP: 0010:assfail+0x5e/0x63 [xfs]
[ 162.368612][T29029] Code: c1 e2 2a 83 e0 07 48 c1 e9 03 8a 14 11 38 c2 7f 10 84 d2 74 0c 48 c7 c7 d0 7e ec c1 e8 e1 84 bd bf 80 3d aa 9f 1a 00 00 74
02 <0f> 0b 0f 0b c3 48 8d 45 10 48 8d 54 24 28 4c 89 f6 48 c7 c7 e0 58
[ 162.388062][T29029] RSP: 0018:ffffc9000ecdf640 EFLAGS: 00010202
[ 162.393996][T29029] RAX: 0000000000000000 RBX: ffff888133d8b73c RCX: 1ffffffff83d8fda
[ 162.401831][T29029] RDX: dffffc0000000004 RSI: ffffc9000ecdf3a8 RDI: fffff52001d9beb9
[ 162.409665][T29029] RBP: ffff888133d8b720 R08: 00000000ffffffea R09: ffff8881a57b3847
[ 162.417498][T29029] R10: ffffed1034af6708 R11: 0000000000000001 R12: ffff888212cde000
[ 162.425494][T29029] R13: ffff88810a44e800 R14: ffff888212cde468 R15: ffff888133d8b7f0
[ 162.433333][T29029] FS: 00007f1528d6e5c0(0000) GS:ffff8881a5780000(0000) knlGS:0000000000000000
[ 162.442121][T29029] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 162.448569][T29029] CR2: 00007f1528c8ce60 CR3: 0000000211db8001 CR4: 00000000001706e0
[ 162.456403][T29029] Call Trace:
[ 162.459557][T29029] <TASK>
[ 162.462366][T29029] xfs_trans_cancel+0x458/0x580 [xfs]
[ 162.467723][T29029] xfs_create+0x9e8/0xe80 [xfs]
[ 162.472567][T29029] ? xfs_irele+0x100/0x100 [xfs]
[ 162.477491][T29029] ? posix_acl_fix_xattr_userns+0x280/0x280
[ 162.483251][T29029] ? xfs_dir_canenter+0x40/0x40 [xfs]
[ 162.488600][T29029] xfs_generic_create+0x22e/0x640 [xfs]
[ 162.494131][T29029] ? xfs_setup_iops+0x3c0/0x3c0 [xfs]
[ 162.499485][T29029] ? d_splice_alias+0xfa/0x500
[ 162.504122][T29029] ? xfs_vn_link+0x1c0/0x1c0 [xfs]
[ 162.509216][T29029] ? xfs_vn_lookup+0x143/0x180 [xfs]
[ 162.514488][T29029] ? from_kgid+0x84/0xc0
[ 162.518602][T29029] ? inode_permission+0x91/0x500
[ 162.523413][T29029] ? xfs_vn_link+0x1c0/0x1c0 [xfs]
[ 162.528536][T29029] lookup_open+0xd7b/0x1740
[ 162.533521][T29029] ? do_open+0xf80/0xf80
[ 162.537636][T29029] ? down_write_killable+0x140/0x140
[ 162.542794][T29029] open_last_lookups+0x4d8/0x1000
[ 162.547689][T29029] ? lookup_open+0x1740/0x1740
[ 162.552925][T29029] ? path_init+0xd7e/0x1740
[ 162.557300][T29029] ? lookup_one_len_unlocked+0x140/0x140
[ 162.562796][T29029] ? __mutex_init+0xb5/0x140
[ 162.567586][T29029] ? __alloc_file+0x197/0x2c0
[ 162.572128][T29029] ? __kasan_slab_alloc+0x66/0x80
[ 162.577025][T29029] path_openat+0x179/0x680
[ 162.581305][T29029] ? open_last_lookups+0x1000/0x1000
[ 162.586455][T29029] do_filp_open+0x1aa/0x400
[ 162.590823][T29029] ? may_open_dev+0x100/0x100
[ 162.595364][T29029] ? _raw_spin_lock+0x81/0x100
[ 162.599991][T29029] ? _raw_write_lock_irq+0x100/0x100
[ 162.605140][T29029] ? __check_object_size+0x4f/0x140
[ 162.610809][T29029] ? alloc_fd+0x39e/0x500
[ 162.615012][T29029] do_sys_openat2+0x122/0x400
[ 162.619560][T29029] ? build_open_flags+0x480/0x480
[ 162.624448][T29029] __x64_sys_openat+0x11f/0x200
[ 162.629163][T29029] ? __ia32_compat_sys_open+0x1c0/0x1c0
[ 162.634571][T29029] do_syscall_64+0x3b/0xc0
[ 162.638852][T29029] entry_SYSCALL_64_after_hwframe+0x46/0xb0
[ 162.644608][T29029] RIP: 0033:0x7f1528c96be7
[ 162.648891][T29029] Code: 25 00 00 41 00 3d 00 00 41 00 74 47 64 8b 04 25 18 00 00 00 85 c0 75 6b 44 89 e2 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f
05 <48> 3d 00 f0 ff ff 0f 87 95 00 00 00 48 8b 4c 24 28 64 48 2b 0c 25
[ 162.668348][T29029] RSP: 002b:00007ffd8f4c09e0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
[ 162.676623][T29029] RAX: ffffffffffffffda RBX: 00007ffd8f4c0c98 RCX: 00007f1528c96be7
[ 162.684457][T29029] RDX: 0000000000000941 RSI: 00007ffd8f4c28f2 RDI: 00000000ffffff9c
[ 162.692292][T29029] RBP: 00007ffd8f4c28f2 R08: 0000000000000000 R09: 0000000000000000
[ 162.700128][T29029] R10: 00000000000001b6 R11: 0000000000000246 R12: 0000000000000941
[ 162.707963][T29029] R13: 00007ffd8f4c28f2 R14: 0000000000000000 R15: 0000000000000000
[ 162.715798][T29029] </TASK>
[ 162.718689][T29029] Modules linked in: loop xfs dm_mod netconsole btrfs blake2b_generic xor raid6_pq zstd_compress libcrc32c sd_mod t10_pi intel_rapl
_msr crc64_rocksoft_generic intel_rapl_common crc64_rocksoft crc64 x86_pkg_temp_thermal intel_powerclamp sg coretemp ipmi_devintf ipmi_msghandler kvm_in
tel i915 kvm irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel intel_gtt wmi_bmof drm_buddy rapl drm_display_helper ahci mei_me i
ntel_cstate libahci ttm intel_uncore drm_kms_helper libata syscopyarea mei sysfillrect sysimgblt fb_sys_fops wmi video drm fuse ip_tables
[ 162.770434][T29029] ---[ end trace 0000000000000000 ]---
[ 162.775784][T29029] RIP: 0010:assfail+0x5e/0x63 [xfs]
[ 162.781017][T29029] Code: c1 e2 2a 83 e0 07 48 c1 e9 03 8a 14 11 38 c2 7f 10 84 d2 74 0c 48 c7 c7 d0 7e ec c1 e8 e1 84 bd bf 80 3d aa 9f 1a 00 00 74
02 <0f> 0b 0f 0b c3 48 8d 45 10 48 8d 54 24 28 4c 89 f6 48 c7 c7 e0 58
[ 162.800498][T29029] RSP: 0018:ffffc9000ecdf640 EFLAGS: 00010202
[ 162.806460][T29029] RAX: 0000000000000000 RBX: ffff888133d8b73c RCX: 1ffffffff83d8fda
[ 162.814323][T29029] RDX: dffffc0000000004 RSI: ffffc9000ecdf3a8 RDI: fffff52001d9beb9
[ 162.822184][T29029] RBP: ffff888133d8b720 R08: 00000000ffffffea R09: ffff8881a57b3847
[ 162.830044][T29029] R10: ffffed1034af6708 R11: 0000000000000001 R12: ffff888212cde000
[ 162.837903][T29029] R13: ffff88810a44e800 R14: ffff888212cde468 R15: ffff888133d8b7f0
[ 162.845771][T29029] FS: 00007f1528d6e5c0(0000) GS:ffff8881a5780000(0000) knlGS:0000000000000000
[ 162.854588][T29029] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 162.861060][T29029] CR2: 00007f1528c8ce60 CR3: 0000000211db8001 CR4: 00000000001706e0
[ 162.868921][T29029] Kernel panic - not syncing: Fatal exception
[ 162.875038][T29029] Kernel Offset: disabled
>
> -Dave.
> --
> Dave Chinner
> [email protected]
On Wed, Jul 13, 2022 at 02:25:25PM +0800, Oliver Sang wrote:
> hi Dave,
>
> On Wed, Jul 13, 2022 at 07:47:45AM +1000, Dave Chinner wrote:
> > >
> > > If you fix the issue, kindly add following tag
> > > Reported-by: kernel test robot <[email protected]>
> > >
> > >
> > > [ 94.271323][ T9089] XFS (sda5): Mounting V5 Filesystem
> > > [ 94.369992][ T9089] XFS (sda5): Ending clean mount
> > > [ 94.376046][ T9089] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
> > > [ 112.154792][ T311] xfs/076 IPMI BMC is not supported on this machine, skip bmc-watchdog setup!
> > > [ 112.154805][ T311]
> > > [ 161.426026][T29384] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 951
> > > [ 161.437713][T29384] ------------[ cut here ]------------
> > > [ 161.443155][T29384] kernel BUG at fs/xfs/xfs_message.c:110!
> > > [ 161.448854][T29384] invalid opcode: 0000 [#1] SMP KASAN PTI
> > > [ 161.454536][T29384] CPU: 1 PID: 29384 Comm: touch Not tainted 5.16.0-rc5-00001-g47a6df7cd317 #1
> >
> > 5.16-rc5? Seems like a really old kernel to be testing....
> >
> > Does this reproduce on a current 5.19-rc6 kernel?
>
> yes, it's still reproducible. however, it's actually random on both 47a6df7cd3
> and 5.19-rc6, as below.
> it's clean on 40 runs of v5.16-rc5,
> on 47a6df7cd3, it's reproduced 9 times out of 40 runs,
Of course, 47a6df7cd3 introduced the ASSERT that is firing. You'll
never see the failure on kernels before this, even if the issue is
occurring. It also points out this isn't a new issue, it's been
around since before we added detection of it.
> on v5.19-rc6, it's reprodced 7 times out of 20 runs.
Hmmm. I've just run 50 iterations here on my 5.19-rc6 based VMs
and I haven't seen a single failure. So it's not failing regularly
here which means it is influenced by environmental factors.
How big are the disks you are testing with?
Cheers,
Dave.
--
Dave Chinner
[email protected]
Hi, Dave,
On Thu, Jul 14, 2022 at 11:24:21AM +1000, Dave Chinner wrote:
> On Wed, Jul 13, 2022 at 02:25:25PM +0800, Oliver Sang wrote:
> > hi Dave,
> >
> > On Wed, Jul 13, 2022 at 07:47:45AM +1000, Dave Chinner wrote:
> > > >
> > > > If you fix the issue, kindly add following tag
> > > > Reported-by: kernel test robot <[email protected]>
> > > >
> > > >
> > > > [ 94.271323][ T9089] XFS (sda5): Mounting V5 Filesystem
> > > > [ 94.369992][ T9089] XFS (sda5): Ending clean mount
> > > > [ 94.376046][ T9089] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
> > > > [ 112.154792][ T311] xfs/076 IPMI BMC is not supported on this machine, skip bmc-watchdog setup!
> > > > [ 112.154805][ T311]
> > > > [ 161.426026][T29384] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 951
> > > > [ 161.437713][T29384] ------------[ cut here ]------------
> > > > [ 161.443155][T29384] kernel BUG at fs/xfs/xfs_message.c:110!
> > > > [ 161.448854][T29384] invalid opcode: 0000 [#1] SMP KASAN PTI
> > > > [ 161.454536][T29384] CPU: 1 PID: 29384 Comm: touch Not tainted 5.16.0-rc5-00001-g47a6df7cd317 #1
> > >
> > > 5.16-rc5? Seems like a really old kernel to be testing....
> > >
> > > Does this reproduce on a current 5.19-rc6 kernel?
> >
> > yes, it's still reproducible. however, it's actually random on both 47a6df7cd3
> > and 5.19-rc6, as below.
> > it's clean on 40 runs of v5.16-rc5,
> > on 47a6df7cd3, it's reproduced 9 times out of 40 runs,
>
> Of course, 47a6df7cd3 introduced the ASSERT that is firing. You'll
> never see the failure on kernels before this, even if the issue is
> occurring. It also points out this isn't a new issue, it's been
> around since before we added detection of it.
understood. for such kind of ASSERT (or WARNING, etc.) we normally reported
on the commit we could bisected out (like this 47a6df7cd3 :) ) just for
information since it could help people in the area to notice there is maybe
something wrong around.
it's kind of hard for us to backport the commit to old commits then each step
of bisection to figure out when the issue really starts to happen, (but hope
we can do this one day :) )
>
> > on v5.19-rc6, it's reprodced 7 times out of 20 runs.
>
> Hmmm. I've just run 50 iterations here on my 5.19-rc6 based VMs
> and I haven't seen a single failure. So it's not failing regularly
> here which means it is influenced by environmental factors.
>
> How big are the disks you are testing with?
for this xfstests/4HDD-xfs-xfs-group-07 test, we used 4 HDD, each with the size
of 300G.
but I noticed the ASSERT always happen after xfs/076, which seems only use two
of them (below sda2, sda5)
[ 92.590707][ T1440] run fstests xfs/076 at 2022-07-13 01:44:34
[ 93.231849][ T8987] XFS (sda2): Mounting V5 Filesystem
[ 93.267497][ T8987] XFS (sda2): Ending clean mount
[ 93.274183][ T8987] xfs filesystem being mounted at /fs/sda2 supports timestamps until 2038 (0x7fffffff)
[ 95.221223][ T9080] XFS (sda5): Mounting V5 Filesystem
[ 95.384072][ T9080] XFS (sda5): Ending clean mount
[ 95.409130][ T9080] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 95.425082][ T9089] XFS (sda5): Unmounting Filesystem
[ 95.752530][ T9111] XFS (sda5): Mounting V5 Filesystem
[ 95.827062][ T9111] XFS (sda5): Ending clean mount
[ 95.833635][ T9111] xfs filesystem being mounted at /fs/scratch supports timestamps until 2038 (0x7fffffff)
[ 113.521272][ T306] xfs/076 IPMI BMC is not supported on this machine, skip bmc-watchdog setup!
[ 113.521286][ T306]
[ 162.318194][T29029] XFS: Assertion failed: xfs_is_shutdown(mp) || list_empty(&tp->t_dfops), file: fs/xfs/xfs_trans.c, line: 993
[ 162.330026][T29029] ------------[ cut here ]------------
...
root@lkp-ivb-d04 ~# lsblk
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
sda 8:0 0 1.8T 0 disk
|-sda1 8:1 0 400G 0 part
|-sda2 8:2 0 300G 0 part <----------
|-sda3 8:3 0 300G 0 part
|-sda4 8:4 0 300G 0 part
`-sda5 8:5 0 300G 0 part <----------
sdb 8:16 0 223.6G 0 disk
`-sdb1 8:17 0 223.6G 0 part
root@lkp-ivb-d04 ~# lsblk -f
NAME FSTYPE FSVER LABEL UUID FSAVAIL FSUSE% MOUNTPOINT
sda
|-sda1 btrfs 1c70720c-3bc1-4cda-b623-7eeebdf0eace
|-sda2 xfs f03ce528-b832-4844-8a14-65977d07ecf2 <--------
|-sda3
|-sda4
`-sda5 xfs e95d9e0e-46a3-4fe6-8b4c-19bc1e2b2dfe <--------
sdb
`-sdb1 ocfs2 0.90 single_run a218e812-7152-4a71-a666-2379ff94dd40
>
> Cheers,
>
> Dave.
> --
> Dave Chinner
> [email protected]