* Problem With XFS + KVM
@ 2021-03-04 22:34 ` Chaitanya Kulkarni
0 siblings, 0 replies; 8+ messages in thread
From: Chaitanya Kulkarni @ 2021-03-04 22:34 UTC (permalink / raw)
To: kvm, linux-xfs; +Cc: linux-nvme
Hi,
I'm running fio verification job with XFS formatted file system on 5.12-rc1
with NVMeOF file backend target inside QEMU test machine.
I'm getting a following message intermittently it is happening since
yesterday.
This can be easily reproduces with runing block tests nvme/011 :-
nvme/011 (run data verification fio job on NVMeOF file-backed ns) [failed]
runtime 270.553s ... 268.552s
something found in dmesg:
[ 340.781752] run blktests nvme/011 at 2021-03-04 14:22:34
[ 340.857161] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 340.890225] nvmet: creating controller 1 for subsystem
blktests-subsystem-1 for NQN
nqn.2014-08.org.nvmexpress:uuid:e4cfc949-8f19-4db2-a232-ab360b79204a.
[ 340.892477] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for
full support of multi-port devices.
[ 340.892937] nvme nvme0: creating 64 I/O queues.
[ 340.913759] nvme nvme0: new ctrl: "blktests-subsystem-1"
[ 586.495375] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 587.766464] ------------[ cut here ]------------
[ 587.766535] raw_local_irq_restore() called with IRQs enabled
[ 587.766561] WARNING: CPU: 14 PID: 12543 at
kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
...
(See '/root/blktests/results/nodev/nvme/011.dmesg' for the entire
message)
Please let me know what kind of more details I can provide to resolve
this issue.
Here is the dmesg outout :-
------------[ cut here ]------------
[ 587.766535] raw_local_irq_restore() called with IRQs enabled
[ 587.766561] WARNING: CPU: 14 PID: 12543 at
kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
[ 587.766571] Modules linked in: nvme_loop nvme_fabrics nvmet nvme_core
loop xt_CHECKSUM xt_MASQUERADE tun bridge stp llc ip6t_rpfilter
ipt_REJECT nf_reject_ipv4 ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set
nfnetlink ebtable_nat ebtable_broute ip6table_nat ip6table_mangle
ip6table_security ip6table_raw iptable_nat nf_nat nf_conntrack
nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_security
iptable_raw ebtable_filter ebtables ip6table_filter ip6_tables rfkill
iptable_filter intel_rapl_msr intel_rapl_common kvm_amd ccp kvm btrfs
irqbypass crct10dif_pclmul crc32_pclmul blake2b_generic
ghash_clmulni_intel xor zstd_compress ppdev bochs_drm drm_vram_helper
aesni_intel drm_ttm_helper ttm crypto_simd cryptd drm_kms_helper
syscopyarea sysfillrect sysimgblt fb_sys_fops raid6_pq drm i2c_piix4 sg
parport_pc joydev i2c_core parport pcspkr nfsd auth_rpcgss nfs_acl lockd
grace sunrpc ip_tables xfs libcrc32c sd_mod ata_generic pata_acpi
virtio_net net_failover failover ata_piix virtio_pci
[ 587.766786] crc32c_intel virtio_pci_modern_dev libata virtio_ring
serio_raw t10_pi virtio floppy dm_mirror dm_region_hash dm_log dm_mod
[last unloaded: nvme_core]
[ 587.766819] CPU: 14 PID: 12543 Comm: rm Not tainted 5.12.0-rc1nvme+ #165
[ 587.766823] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
[ 587.766826] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
[ 587.766831] Code: 24 48 c7 c7 e0 f2 0f 82 e8 80 c3 fb ff 80 3d 15 1c
09 01 00 74 01 c3 48 c7 c7 70 6c 10 82 c6 05 04 1c 09 01 01 e8 cc c2 fb
ff <0f> 0b c3 55 53 44 8b 05 63 b4 0c 01 65 48 8b 1c 25 40 7e 01 00 45
[ 587.766835] RSP: 0018:ffffc900086cf990 EFLAGS: 00010286
[ 587.766840] RAX: 0000000000000000 RBX: 0000000000000003 RCX:
0000000000000027
[ 587.766843] RDX: 0000000000000000 RSI: ffff8897d37e8a30 RDI:
ffff8897d37e8a38
[ 587.766846] RBP: ffff888138764888 R08: 0000000000000001 R09:
0000000000000001
[ 587.766848] R10: 000000009f0f619c R11: 00000000b7972d21 R12:
0000000000000200
[ 587.766851] R13: 0000000000000001 R14: 0000000000000100 R15:
00000000003c0000
[ 587.766855] FS: 00007f6992aec740(0000) GS:ffff8897d3600000(0000)
knlGS:0000000000000000
[ 587.766858] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 587.766860] CR2: 0000000000bcf1c8 CR3: 00000017d29e8000 CR4:
00000000003506e0
[ 587.766864] Call Trace:
[ 587.766867] kvm_wait+0x8c/0x90
[ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
[ 587.766893] do_raw_spin_lock+0xb1/0xc0
[ 587.766898] _raw_spin_lock+0x61/0x70
[ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
[ 587.766975] xfs_alloc_compute_aligned+0x3d/0xd0 [xfs]
[ 587.767027] xfs_alloc_ag_vextent_size+0x18f/0x930 [xfs]
[ 587.767085] xfs_alloc_ag_vextent+0x11e/0x140 [xfs]
[ 587.767133] xfs_alloc_fix_freelist+0x1fb/0x4c0 [xfs]
[ 587.767201] xfs_free_extent_fix_freelist+0x64/0xb0 [xfs]
[ 587.767262] __xfs_free_extent+0x58/0x170 [xfs]
[ 587.767317] xfs_trans_free_extent+0x53/0x140 [xfs]
[ 587.767391] xfs_extent_free_finish_item+0x23/0x40 [xfs]
[ 587.767493] xfs_defer_finish_noroll+0x222/0x800 [xfs]
[ 587.767553] xfs_defer_finish+0x13/0x70 [xfs]
[ 587.767607] xfs_itruncate_extents_flags+0xd4/0x340 [xfs]
[ 587.767673] xfs_inactive_truncate+0xa3/0xf0 [xfs]
[ 587.767735] xfs_inactive+0xb5/0x140 [xfs]
[ 587.767796] xfs_fs_destroy_inode+0xc1/0x240 [xfs]
[ 587.767858] destroy_inode+0x3b/0x70
[ 587.767868] do_unlinkat+0x280/0x330
[ 587.767881] do_syscall_64+0x33/0x40
[ 587.767886] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 587.767893] RIP: 0033:0x7f699261dfad
[ 587.767898] Code: e1 0e 2d 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f
1f 84 00 00 00 00 00 0f 1f 44 00 00 48 63 d2 48 63 ff b8 07 01 00 00 0f
05 <48> 3d 00 f0 ff ff 77 02 f3 c3 48 8b 15 aa 0e 2d 00 f7 d8 64 89 02
[ 587.767901] RSP: 002b:00007ffd1f7ea248 EFLAGS: 00000206 ORIG_RAX:
0000000000000107
[ 587.767906] RAX: ffffffffffffffda RBX: 0000000000bcf2f0 RCX:
00007f699261dfad
[ 587.767908] RDX: 0000000000000000 RSI: 0000000000bce0c0 RDI:
ffffffffffffff9c
[ 587.767911] RBP: 0000000000000000 R08: 0000000000000000 R09:
0000000000000000
[ 587.767913] R10: 00007ffd1f7e9ec0 R11: 0000000000000206 R12:
0000000000bce05c
[ 587.767916] R13: 00007ffd1f7ea3b0 R14: 0000000000bcf2f0 R15:
0000000000000000
[ 587.767938] irq event stamp: 771691
[ 587.767941] hardirqs last enabled at (771697): [<ffffffff81121db9>]
console_unlock+0x4e9/0x610
[ 587.767948] hardirqs last disabled at (771702): [<ffffffff81121d32>]
console_unlock+0x462/0x610
[ 587.767952] softirqs last enabled at (770516): [<ffffffffa0249ae7>]
xfs_buf_find.isra.27+0x657/0xb90 [xfs]
[ 587.768011] softirqs last disabled at (770514): [<ffffffffa02497c5>]
xfs_buf_find.isra.27+0x335/0xb90 [xfs]
[ 587.768070] ---[ end trace 4eaf6d15d7cbe576 ]---
[ 609.672358] run blktests nvme/012 at 2021-03-04 14:27:03
[ 609.745797] loop0: detected capacity change from 0 to 2097152
[ 609.764592] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 609.800956] nvmet: creating controller 1 for subsystem
blktests-subsystem-1 for NQN
nqn.2014-08.org.nvmexpress:uuid:e4cfc949-8f19-4db2-a232-ab360b79204a.
[ 609.802545] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for full
support of multi-port devices.
[ 609.802909] nvme nvme0: creating 64 I/O queues.
[ 609.823959] nvme nvme0: new ctrl: "blktests-subsystem-1"
[ 611.525467] XFS (nvme0n1): Mounting V5 Filesystem
[ 611.534398] XFS (nvme0n1): Ending clean mount
[ 611.534715] xfs filesystem being mounted at /mnt/blktests supports
timestamps until 2038 (0x7fffffff)
-ck
^ permalink raw reply [flat|nested] 8+ messages in thread
* Problem With XFS + KVM
@ 2021-03-04 22:34 ` Chaitanya Kulkarni
0 siblings, 0 replies; 8+ messages in thread
From: Chaitanya Kulkarni @ 2021-03-04 22:34 UTC (permalink / raw)
To: kvm, linux-xfs; +Cc: linux-nvme
Hi,
I'm running fio verification job with XFS formatted file system on 5.12-rc1
with NVMeOF file backend target inside QEMU test machine.
I'm getting a following message intermittently it is happening since
yesterday.
This can be easily reproduces with runing block tests nvme/011 :-
nvme/011 (run data verification fio job on NVMeOF file-backed ns) [failed]
runtime 270.553s ... 268.552s
something found in dmesg:
[ 340.781752] run blktests nvme/011 at 2021-03-04 14:22:34
[ 340.857161] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 340.890225] nvmet: creating controller 1 for subsystem
blktests-subsystem-1 for NQN
nqn.2014-08.org.nvmexpress:uuid:e4cfc949-8f19-4db2-a232-ab360b79204a.
[ 340.892477] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for
full support of multi-port devices.
[ 340.892937] nvme nvme0: creating 64 I/O queues.
[ 340.913759] nvme nvme0: new ctrl: "blktests-subsystem-1"
[ 586.495375] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
[ 587.766464] ------------[ cut here ]------------
[ 587.766535] raw_local_irq_restore() called with IRQs enabled
[ 587.766561] WARNING: CPU: 14 PID: 12543 at
kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
...
(See '/root/blktests/results/nodev/nvme/011.dmesg' for the entire
message)
Please let me know what kind of more details I can provide to resolve
this issue.
Here is the dmesg outout :-
------------[ cut here ]------------
[ 587.766535] raw_local_irq_restore() called with IRQs enabled
[ 587.766561] WARNING: CPU: 14 PID: 12543 at
kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
[ 587.766571] Modules linked in: nvme_loop nvme_fabrics nvmet nvme_core
loop xt_CHECKSUM xt_MASQUERADE tun bridge stp llc ip6t_rpfilter
ipt_REJECT nf_reject_ipv4 ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set
nfnetlink ebtable_nat ebtable_broute ip6table_nat ip6table_mangle
ip6table_security ip6table_raw iptable_nat nf_nat nf_conntrack
nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_security
iptable_raw ebtable_filter ebtables ip6table_filter ip6_tables rfkill
iptable_filter intel_rapl_msr intel_rapl_common kvm_amd ccp kvm btrfs
irqbypass crct10dif_pclmul crc32_pclmul blake2b_generic
ghash_clmulni_intel xor zstd_compress ppdev bochs_drm drm_vram_helper
aesni_intel drm_ttm_helper ttm crypto_simd cryptd drm_kms_helper
syscopyarea sysfillrect sysimgblt fb_sys_fops raid6_pq drm i2c_piix4 sg
parport_pc joydev i2c_core parport pcspkr nfsd auth_rpcgss nfs_acl lockd
grace sunrpc ip_tables xfs libcrc32c sd_mod ata_generic pata_acpi
virtio_net net_failover failover ata_piix virtio_pci
[ 587.766786] crc32c_intel virtio_pci_modern_dev libata virtio_ring
serio_raw t10_pi virtio floppy dm_mirror dm_region_hash dm_log dm_mod
[last unloaded: nvme_core]
[ 587.766819] CPU: 14 PID: 12543 Comm: rm Not tainted 5.12.0-rc1nvme+ #165
[ 587.766823] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
[ 587.766826] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
[ 587.766831] Code: 24 48 c7 c7 e0 f2 0f 82 e8 80 c3 fb ff 80 3d 15 1c
09 01 00 74 01 c3 48 c7 c7 70 6c 10 82 c6 05 04 1c 09 01 01 e8 cc c2 fb
ff <0f> 0b c3 55 53 44 8b 05 63 b4 0c 01 65 48 8b 1c 25 40 7e 01 00 45
[ 587.766835] RSP: 0018:ffffc900086cf990 EFLAGS: 00010286
[ 587.766840] RAX: 0000000000000000 RBX: 0000000000000003 RCX:
0000000000000027
[ 587.766843] RDX: 0000000000000000 RSI: ffff8897d37e8a30 RDI:
ffff8897d37e8a38
[ 587.766846] RBP: ffff888138764888 R08: 0000000000000001 R09:
0000000000000001
[ 587.766848] R10: 000000009f0f619c R11: 00000000b7972d21 R12:
0000000000000200
[ 587.766851] R13: 0000000000000001 R14: 0000000000000100 R15:
00000000003c0000
[ 587.766855] FS: 00007f6992aec740(0000) GS:ffff8897d3600000(0000)
knlGS:0000000000000000
[ 587.766858] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 587.766860] CR2: 0000000000bcf1c8 CR3: 00000017d29e8000 CR4:
00000000003506e0
[ 587.766864] Call Trace:
[ 587.766867] kvm_wait+0x8c/0x90
[ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
[ 587.766893] do_raw_spin_lock+0xb1/0xc0
[ 587.766898] _raw_spin_lock+0x61/0x70
[ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
[ 587.766975] xfs_alloc_compute_aligned+0x3d/0xd0 [xfs]
[ 587.767027] xfs_alloc_ag_vextent_size+0x18f/0x930 [xfs]
[ 587.767085] xfs_alloc_ag_vextent+0x11e/0x140 [xfs]
[ 587.767133] xfs_alloc_fix_freelist+0x1fb/0x4c0 [xfs]
[ 587.767201] xfs_free_extent_fix_freelist+0x64/0xb0 [xfs]
[ 587.767262] __xfs_free_extent+0x58/0x170 [xfs]
[ 587.767317] xfs_trans_free_extent+0x53/0x140 [xfs]
[ 587.767391] xfs_extent_free_finish_item+0x23/0x40 [xfs]
[ 587.767493] xfs_defer_finish_noroll+0x222/0x800 [xfs]
[ 587.767553] xfs_defer_finish+0x13/0x70 [xfs]
[ 587.767607] xfs_itruncate_extents_flags+0xd4/0x340 [xfs]
[ 587.767673] xfs_inactive_truncate+0xa3/0xf0 [xfs]
[ 587.767735] xfs_inactive+0xb5/0x140 [xfs]
[ 587.767796] xfs_fs_destroy_inode+0xc1/0x240 [xfs]
[ 587.767858] destroy_inode+0x3b/0x70
[ 587.767868] do_unlinkat+0x280/0x330
[ 587.767881] do_syscall_64+0x33/0x40
[ 587.767886] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 587.767893] RIP: 0033:0x7f699261dfad
[ 587.767898] Code: e1 0e 2d 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f
1f 84 00 00 00 00 00 0f 1f 44 00 00 48 63 d2 48 63 ff b8 07 01 00 00 0f
05 <48> 3d 00 f0 ff ff 77 02 f3 c3 48 8b 15 aa 0e 2d 00 f7 d8 64 89 02
[ 587.767901] RSP: 002b:00007ffd1f7ea248 EFLAGS: 00000206 ORIG_RAX:
0000000000000107
[ 587.767906] RAX: ffffffffffffffda RBX: 0000000000bcf2f0 RCX:
00007f699261dfad
[ 587.767908] RDX: 0000000000000000 RSI: 0000000000bce0c0 RDI:
ffffffffffffff9c
[ 587.767911] RBP: 0000000000000000 R08: 0000000000000000 R09:
0000000000000000
[ 587.767913] R10: 00007ffd1f7e9ec0 R11: 0000000000000206 R12:
0000000000bce05c
[ 587.767916] R13: 00007ffd1f7ea3b0 R14: 0000000000bcf2f0 R15:
0000000000000000
[ 587.767938] irq event stamp: 771691
[ 587.767941] hardirqs last enabled at (771697): [<ffffffff81121db9>]
console_unlock+0x4e9/0x610
[ 587.767948] hardirqs last disabled at (771702): [<ffffffff81121d32>]
console_unlock+0x462/0x610
[ 587.767952] softirqs last enabled at (770516): [<ffffffffa0249ae7>]
xfs_buf_find.isra.27+0x657/0xb90 [xfs]
[ 587.768011] softirqs last disabled at (770514): [<ffffffffa02497c5>]
xfs_buf_find.isra.27+0x335/0xb90 [xfs]
[ 587.768070] ---[ end trace 4eaf6d15d7cbe576 ]---
[ 609.672358] run blktests nvme/012 at 2021-03-04 14:27:03
[ 609.745797] loop0: detected capacity change from 0 to 2097152
[ 609.764592] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 609.800956] nvmet: creating controller 1 for subsystem
blktests-subsystem-1 for NQN
nqn.2014-08.org.nvmexpress:uuid:e4cfc949-8f19-4db2-a232-ab360b79204a.
[ 609.802545] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for full
support of multi-port devices.
[ 609.802909] nvme nvme0: creating 64 I/O queues.
[ 609.823959] nvme nvme0: new ctrl: "blktests-subsystem-1"
[ 611.525467] XFS (nvme0n1): Mounting V5 Filesystem
[ 611.534398] XFS (nvme0n1): Ending clean mount
[ 611.534715] xfs filesystem being mounted at /mnt/blktests supports
timestamps until 2038 (0x7fffffff)
-ck
_______________________________________________
Linux-nvme mailing list
Linux-nvme@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-nvme
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: Problem With XFS + KVM
2021-03-04 22:34 ` Chaitanya Kulkarni
@ 2021-03-04 23:13 ` Dave Chinner
-1 siblings, 0 replies; 8+ messages in thread
From: Dave Chinner @ 2021-03-04 23:13 UTC (permalink / raw)
To: Chaitanya Kulkarni; +Cc: kvm, linux-xfs, linux-nvme
On Thu, Mar 04, 2021 at 10:34:29PM +0000, Chaitanya Kulkarni wrote:
> Hi,
>
> I'm running fio verification job with XFS formatted file system on 5.12-rc1
> with NVMeOF file backend target inside QEMU test machine.
>
> I'm getting a following message intermittently it is happening since
> yesterday.
> This can be easily reproduces with runing block tests nvme/011 :-
>
> nvme/011 (run data verification fio job on NVMeOF file-backed ns) [failed]
> runtime 270.553s ... 268.552s
> something found in dmesg:
> [ 340.781752] run blktests nvme/011 at 2021-03-04 14:22:34
> [ 340.857161] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
> [ 340.890225] nvmet: creating controller 1 for subsystem
> blktests-subsystem-1 for NQN
> nqn.2014-08.org.nvmexpress:uuid:e4cfc949-8f19-4db2-a232-ab360b79204a.
> [ 340.892477] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for
> full support of multi-port devices.
> [ 340.892937] nvme nvme0: creating 64 I/O queues.
> [ 340.913759] nvme nvme0: new ctrl: "blktests-subsystem-1"
> [ 586.495375] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
> [ 587.766464] ------------[ cut here ]------------
> [ 587.766535] raw_local_irq_restore() called with IRQs enabled
> [ 587.766561] WARNING: CPU: 14 PID: 12543 at
> kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
> ...
> (See '/root/blktests/results/nodev/nvme/011.dmesg' for the entire
> message)
>
> Please let me know what kind of more details I can provide to resolve
> this issue.
>
> Here is the dmesg outout :-
>
> ------------[ cut here ]------------
> [ 587.766535] raw_local_irq_restore() called with IRQs enabled
.....
> [ 587.766819] CPU: 14 PID: 12543 Comm: rm Not tainted 5.12.0-rc1nvme+ #165
> [ 587.766823] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
> [ 587.766826] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
> [ 587.766831] Code: 24 48 c7 c7 e0 f2 0f 82 e8 80 c3 fb ff 80 3d 15 1c
> 09 01 00 74 01 c3 48 c7 c7 70 6c 10 82 c6 05 04 1c 09 01 01 e8 cc c2 fb
> ff <0f> 0b c3 55 53 44 8b 05 63 b4 0c 01 65 48 8b 1c 25 40 7e 01 00 45
> [ 587.766835] RSP: 0018:ffffc900086cf990 EFLAGS: 00010286
> [ 587.766840] RAX: 0000000000000000 RBX: 0000000000000003 RCX:
> 0000000000000027
> [ 587.766843] RDX: 0000000000000000 RSI: ffff8897d37e8a30 RDI:
> ffff8897d37e8a38
> [ 587.766846] RBP: ffff888138764888 R08: 0000000000000001 R09:
> 0000000000000001
> [ 587.766848] R10: 000000009f0f619c R11: 00000000b7972d21 R12:
> 0000000000000200
> [ 587.766851] R13: 0000000000000001 R14: 0000000000000100 R15:
> 00000000003c0000
> [ 587.766855] FS: 00007f6992aec740(0000) GS:ffff8897d3600000(0000)
> knlGS:0000000000000000
> [ 587.766858] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 587.766860] CR2: 0000000000bcf1c8 CR3: 00000017d29e8000 CR4:
> 00000000003506e0
> [ 587.766864] Call Trace:
> [ 587.766867] kvm_wait+0x8c/0x90
> [ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
> [ 587.766893] do_raw_spin_lock+0xb1/0xc0
> [ 587.766898] _raw_spin_lock+0x61/0x70
> [ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
That looks like a KVM or local_irq_save()/local_irq_restore problem.
kvm_wait() does:
static void kvm_wait(u8 *ptr, u8 val)
{
unsigned long flags;
if (in_nmi())
return;
local_irq_save(flags);
if (READ_ONCE(*ptr) != val)
goto out;
/*
* halt until it's our turn and kicked. Note that we do safe halt
* for irq enabled case to avoid hang when lock info is overwritten
* in irq spinlock slowpath and no spurious interrupt occur to save us.
*/
if (arch_irqs_disabled_flags(flags))
halt();
else
safe_halt();
out:
local_irq_restore(flags);
}
And the warning is coming from the local_irq_restore() call
indicating that interrupts are not disabled when they should be.
The interrupt state is being modified entirely within the kvm_wait()
code here, so none of the high level XFS code has any influence on
behaviour here.
Cheers,
Dave.
--
Dave Chinner
david@fromorbit.com
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: Problem With XFS + KVM
@ 2021-03-04 23:13 ` Dave Chinner
0 siblings, 0 replies; 8+ messages in thread
From: Dave Chinner @ 2021-03-04 23:13 UTC (permalink / raw)
To: Chaitanya Kulkarni; +Cc: kvm, linux-xfs, linux-nvme
On Thu, Mar 04, 2021 at 10:34:29PM +0000, Chaitanya Kulkarni wrote:
> Hi,
>
> I'm running fio verification job with XFS formatted file system on 5.12-rc1
> with NVMeOF file backend target inside QEMU test machine.
>
> I'm getting a following message intermittently it is happening since
> yesterday.
> This can be easily reproduces with runing block tests nvme/011 :-
>
> nvme/011 (run data verification fio job on NVMeOF file-backed ns) [failed]
> runtime 270.553s ... 268.552s
> something found in dmesg:
> [ 340.781752] run blktests nvme/011 at 2021-03-04 14:22:34
> [ 340.857161] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
> [ 340.890225] nvmet: creating controller 1 for subsystem
> blktests-subsystem-1 for NQN
> nqn.2014-08.org.nvmexpress:uuid:e4cfc949-8f19-4db2-a232-ab360b79204a.
> [ 340.892477] nvme nvme0: Please enable CONFIG_NVME_MULTIPATH for
> full support of multi-port devices.
> [ 340.892937] nvme nvme0: creating 64 I/O queues.
> [ 340.913759] nvme nvme0: new ctrl: "blktests-subsystem-1"
> [ 586.495375] nvme nvme0: Removing ctrl: NQN "blktests-subsystem-1"
> [ 587.766464] ------------[ cut here ]------------
> [ 587.766535] raw_local_irq_restore() called with IRQs enabled
> [ 587.766561] WARNING: CPU: 14 PID: 12543 at
> kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
> ...
> (See '/root/blktests/results/nodev/nvme/011.dmesg' for the entire
> message)
>
> Please let me know what kind of more details I can provide to resolve
> this issue.
>
> Here is the dmesg outout :-
>
> ------------[ cut here ]------------
> [ 587.766535] raw_local_irq_restore() called with IRQs enabled
.....
> [ 587.766819] CPU: 14 PID: 12543 Comm: rm Not tainted 5.12.0-rc1nvme+ #165
> [ 587.766823] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
> [ 587.766826] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
> [ 587.766831] Code: 24 48 c7 c7 e0 f2 0f 82 e8 80 c3 fb ff 80 3d 15 1c
> 09 01 00 74 01 c3 48 c7 c7 70 6c 10 82 c6 05 04 1c 09 01 01 e8 cc c2 fb
> ff <0f> 0b c3 55 53 44 8b 05 63 b4 0c 01 65 48 8b 1c 25 40 7e 01 00 45
> [ 587.766835] RSP: 0018:ffffc900086cf990 EFLAGS: 00010286
> [ 587.766840] RAX: 0000000000000000 RBX: 0000000000000003 RCX:
> 0000000000000027
> [ 587.766843] RDX: 0000000000000000 RSI: ffff8897d37e8a30 RDI:
> ffff8897d37e8a38
> [ 587.766846] RBP: ffff888138764888 R08: 0000000000000001 R09:
> 0000000000000001
> [ 587.766848] R10: 000000009f0f619c R11: 00000000b7972d21 R12:
> 0000000000000200
> [ 587.766851] R13: 0000000000000001 R14: 0000000000000100 R15:
> 00000000003c0000
> [ 587.766855] FS: 00007f6992aec740(0000) GS:ffff8897d3600000(0000)
> knlGS:0000000000000000
> [ 587.766858] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 587.766860] CR2: 0000000000bcf1c8 CR3: 00000017d29e8000 CR4:
> 00000000003506e0
> [ 587.766864] Call Trace:
> [ 587.766867] kvm_wait+0x8c/0x90
> [ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
> [ 587.766893] do_raw_spin_lock+0xb1/0xc0
> [ 587.766898] _raw_spin_lock+0x61/0x70
> [ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
That looks like a KVM or local_irq_save()/local_irq_restore problem.
kvm_wait() does:
static void kvm_wait(u8 *ptr, u8 val)
{
unsigned long flags;
if (in_nmi())
return;
local_irq_save(flags);
if (READ_ONCE(*ptr) != val)
goto out;
/*
* halt until it's our turn and kicked. Note that we do safe halt
* for irq enabled case to avoid hang when lock info is overwritten
* in irq spinlock slowpath and no spurious interrupt occur to save us.
*/
if (arch_irqs_disabled_flags(flags))
halt();
else
safe_halt();
out:
local_irq_restore(flags);
}
And the warning is coming from the local_irq_restore() call
indicating that interrupts are not disabled when they should be.
The interrupt state is being modified entirely within the kvm_wait()
code here, so none of the high level XFS code has any influence on
behaviour here.
Cheers,
Dave.
--
Dave Chinner
david@fromorbit.com
_______________________________________________
Linux-nvme mailing list
Linux-nvme@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-nvme
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: Problem With XFS + KVM
2021-03-04 23:13 ` Dave Chinner
@ 2021-03-04 23:32 ` Chaitanya Kulkarni
-1 siblings, 0 replies; 8+ messages in thread
From: Chaitanya Kulkarni @ 2021-03-04 23:32 UTC (permalink / raw)
To: Dave Chinner; +Cc: kvm, linux-xfs, linux-nvme
On 3/4/21 15:14, Dave Chinner wrote:
>> 00000000003506e0
>> [ 587.766864] Call Trace:
>> [ 587.766867] kvm_wait+0x8c/0x90
>> [ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
>> [ 587.766893] do_raw_spin_lock+0xb1/0xc0
>> [ 587.766898] _raw_spin_lock+0x61/0x70
>> [ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
> That looks like a KVM or local_irq_save()/local_irq_restore problem.
> kvm_wait() does:
>
> static void kvm_wait(u8 *ptr, u8 val)
> {
> unsigned long flags;
>
> if (in_nmi())
> return;
>
> local_irq_save(flags);
>
> if (READ_ONCE(*ptr) != val)
> goto out;
>
> /*
> * halt until it's our turn and kicked. Note that we do safe halt
> * for irq enabled case to avoid hang when lock info is overwritten
> * in irq spinlock slowpath and no spurious interrupt occur to save us.
> */
> if (arch_irqs_disabled_flags(flags))
> halt();
> else
> safe_halt();
>
> out:
> local_irq_restore(flags);
> }
>
> And the warning is coming from the local_irq_restore() call
> indicating that interrupts are not disabled when they should be.
> The interrupt state is being modified entirely within the kvm_wait()
> code here, so none of the high level XFS code has any influence on
> behaviour here.
>
> Cheers,
>
> Dave.
> -- Dave Chinner david@fromorbit.com
Thanks a lot for the response Dave, that is what I thought, just wasn't
sure.
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: Problem With XFS + KVM
@ 2021-03-04 23:32 ` Chaitanya Kulkarni
0 siblings, 0 replies; 8+ messages in thread
From: Chaitanya Kulkarni @ 2021-03-04 23:32 UTC (permalink / raw)
To: Dave Chinner; +Cc: kvm, linux-xfs, linux-nvme
On 3/4/21 15:14, Dave Chinner wrote:
>> 00000000003506e0
>> [ 587.766864] Call Trace:
>> [ 587.766867] kvm_wait+0x8c/0x90
>> [ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
>> [ 587.766893] do_raw_spin_lock+0xb1/0xc0
>> [ 587.766898] _raw_spin_lock+0x61/0x70
>> [ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
> That looks like a KVM or local_irq_save()/local_irq_restore problem.
> kvm_wait() does:
>
> static void kvm_wait(u8 *ptr, u8 val)
> {
> unsigned long flags;
>
> if (in_nmi())
> return;
>
> local_irq_save(flags);
>
> if (READ_ONCE(*ptr) != val)
> goto out;
>
> /*
> * halt until it's our turn and kicked. Note that we do safe halt
> * for irq enabled case to avoid hang when lock info is overwritten
> * in irq spinlock slowpath and no spurious interrupt occur to save us.
> */
> if (arch_irqs_disabled_flags(flags))
> halt();
> else
> safe_halt();
>
> out:
> local_irq_restore(flags);
> }
>
> And the warning is coming from the local_irq_restore() call
> indicating that interrupts are not disabled when they should be.
> The interrupt state is being modified entirely within the kvm_wait()
> code here, so none of the high level XFS code has any influence on
> behaviour here.
>
> Cheers,
>
> Dave.
> -- Dave Chinner david@fromorbit.com
Thanks a lot for the response Dave, that is what I thought, just wasn't
sure.
_______________________________________________
Linux-nvme mailing list
Linux-nvme@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-nvme
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: Problem With XFS + KVM
2021-03-04 23:32 ` Chaitanya Kulkarni
@ 2021-03-04 23:51 ` Sean Christopherson
-1 siblings, 0 replies; 8+ messages in thread
From: Sean Christopherson @ 2021-03-04 23:51 UTC (permalink / raw)
To: Chaitanya Kulkarni; +Cc: Dave Chinner, kvm, linux-xfs, linux-nvme
On Thu, Mar 04, 2021, Chaitanya Kulkarni wrote:
> On 3/4/21 15:14, Dave Chinner wrote:
> >> 00000000003506e0
> >> [ 587.766864] Call Trace:
> >> [ 587.766867] kvm_wait+0x8c/0x90
> >> [ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
> >> [ 587.766893] do_raw_spin_lock+0xb1/0xc0
> >> [ 587.766898] _raw_spin_lock+0x61/0x70
> >> [ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
> > That looks like a KVM or local_irq_save()/local_irq_restore problem.
> > kvm_wait() does:
> >
> > static void kvm_wait(u8 *ptr, u8 val)
> > {
> > unsigned long flags;
> >
> > if (in_nmi())
> > return;
> >
> > local_irq_save(flags);
> >
> > if (READ_ONCE(*ptr) != val)
> > goto out;
> >
> > /*
> > * halt until it's our turn and kicked. Note that we do safe halt
> > * for irq enabled case to avoid hang when lock info is overwritten
> > * in irq spinlock slowpath and no spurious interrupt occur to save us.
> > */
> > if (arch_irqs_disabled_flags(flags))
> > halt();
> > else
> > safe_halt();
> >
> > out:
> > local_irq_restore(flags);
> > }
> >
> > And the warning is coming from the local_irq_restore() call
> > indicating that interrupts are not disabled when they should be.
> > The interrupt state is being modified entirely within the kvm_wait()
> > code here, so none of the high level XFS code has any influence on
> > behaviour here.
> >
> > Cheers,
> >
> > Dave.
> > -- Dave Chinner david@fromorbit.com
>
> Thanks a lot for the response Dave, that is what I thought, just wasn't
> sure.
Yep, Wanpeng posted a patch for this.
https://lkml.kernel.org/r/1614057902-23774-1-git-send-email-wanpengli@tencent.com
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: Problem With XFS + KVM
@ 2021-03-04 23:51 ` Sean Christopherson
0 siblings, 0 replies; 8+ messages in thread
From: Sean Christopherson @ 2021-03-04 23:51 UTC (permalink / raw)
To: Chaitanya Kulkarni; +Cc: Dave Chinner, kvm, linux-xfs, linux-nvme
On Thu, Mar 04, 2021, Chaitanya Kulkarni wrote:
> On 3/4/21 15:14, Dave Chinner wrote:
> >> 00000000003506e0
> >> [ 587.766864] Call Trace:
> >> [ 587.766867] kvm_wait+0x8c/0x90
> >> [ 587.766876] __pv_queued_spin_lock_slowpath+0x265/0x2a0
> >> [ 587.766893] do_raw_spin_lock+0xb1/0xc0
> >> [ 587.766898] _raw_spin_lock+0x61/0x70
> >> [ 587.766904] xfs_extent_busy_trim+0x2f/0x200 [xfs]
> > That looks like a KVM or local_irq_save()/local_irq_restore problem.
> > kvm_wait() does:
> >
> > static void kvm_wait(u8 *ptr, u8 val)
> > {
> > unsigned long flags;
> >
> > if (in_nmi())
> > return;
> >
> > local_irq_save(flags);
> >
> > if (READ_ONCE(*ptr) != val)
> > goto out;
> >
> > /*
> > * halt until it's our turn and kicked. Note that we do safe halt
> > * for irq enabled case to avoid hang when lock info is overwritten
> > * in irq spinlock slowpath and no spurious interrupt occur to save us.
> > */
> > if (arch_irqs_disabled_flags(flags))
> > halt();
> > else
> > safe_halt();
> >
> > out:
> > local_irq_restore(flags);
> > }
> >
> > And the warning is coming from the local_irq_restore() call
> > indicating that interrupts are not disabled when they should be.
> > The interrupt state is being modified entirely within the kvm_wait()
> > code here, so none of the high level XFS code has any influence on
> > behaviour here.
> >
> > Cheers,
> >
> > Dave.
> > -- Dave Chinner david@fromorbit.com
>
> Thanks a lot for the response Dave, that is what I thought, just wasn't
> sure.
Yep, Wanpeng posted a patch for this.
https://lkml.kernel.org/r/1614057902-23774-1-git-send-email-wanpengli@tencent.com
_______________________________________________
Linux-nvme mailing list
Linux-nvme@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-nvme
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2021-03-04 23:52 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-03-04 22:34 Problem With XFS + KVM Chaitanya Kulkarni
2021-03-04 22:34 ` Chaitanya Kulkarni
2021-03-04 23:13 ` Dave Chinner
2021-03-04 23:13 ` Dave Chinner
2021-03-04 23:32 ` Chaitanya Kulkarni
2021-03-04 23:32 ` Chaitanya Kulkarni
2021-03-04 23:51 ` Sean Christopherson
2021-03-04 23:51 ` Sean Christopherson
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.