[RT] WARNING at hrtimer_start_range_ns
From: Juri Lelli
Date: Wed Jun 15 2022 - 10:54:17 EST
Hi,
QE reported splats with signatures similar to the following (edited)
when running blktests/nvmeof-mp [1] cases.
--->8---
[ 329.284321] WARNING: CPU: 0 PID: 4830 at kernel/time/hrtimer.c:1294 hrtimer_start_range_ns+0xa0/0xb0
[ 329.286298] Modules linked in: nvme_rdma(E) nvme_fabrics(E) nvme(E) nvmet_rdma(E) ...
[ 329.286354] Unloaded tainted modules: intel_uncore_frequency(E):2 isst_if_mbox_msr(E):2 ...
[ 329.296991] CPU: 0 PID: 4830 Comm: multipathd Kdump: loaded Tainted: G E -------- --- 5.19.0-0.rc1.9886142c7a22.16.test.eln120.x86_64+rt #2
[ 329.298861] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 329.299798] RIP: 0010:hrtimer_start_range_ns+0xa0/0xb0
[ 329.300533] Code: 41 5d 41 5e 41 5f e9 df b4 94 00 be 01 00 00 00 48 89 df e8 82 f0 ff ff eb d8 49 8b 7d 00 48 89 c6 e8 c4 b4 94 00 f3 90 eb 91 <0f> 0b eb 8d 66 66 2e 0f 1f 84 00 00 00 00 00 90 0f 1f 44 00 00 80
[ 329.303087] RSP: 0018:ffffb4c180a1bd18 EFLAGS: 00010202
[ 329.303817] RAX: 0000000000000001 RBX: ffffb4c180a1bd80 RCX: 0000000000000001
[ 329.304828] RDX: 000000000000c300 RSI: 00000000000003e8 RDI: ffffb4c180a1bd80
[ 329.305759] RBP: 00000000000003e8 R08: 00000000000003e8 R09: 0000000000000000
[ 329.306637] R10: 0000000000000000 R11: 0000000000000001 R12: 000000000000c350
[ 329.307510] R13: 00007efd462b3540 R14: 0000000000000001 R15: 0000000000000000
[ 329.308384] FS: 00007efd462b5600(0000) GS:ffff8d30bbc00000(0000) knlGS:0000000000000000
[ 329.309368] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 329.310071] CR2: 00007efd4628f000 CR3: 000000011ba62004 CR4: 00000000007706f0
[ 329.310939] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 329.311811] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 329.312680] PKRU: 55555554
[ 329.313022] Call Trace:
[ 329.313352] <TASK>
[ 329.313632] read_events+0xd5/0x180
[ 329.314086] ? fget+0x79/0xa0
[ 329.314519] ? __hrtimer_init+0xe0/0xe0
[ 329.315056] do_io_getevents+0x71/0xd0
[ 329.315580] __x64_sys_io_getevents+0x58/0xc0
[ 329.316130] do_syscall_64+0x5b/0x80
[ 329.316590] ? syscall_exit_to_user_mode+0x12/0x30
[ 329.317192] ? do_syscall_64+0x67/0x80
[ 329.317669] ? do_syscall_64+0x67/0x80
[ 329.318139] ? do_syscall_64+0x67/0x80
[ 329.318666] ? syscall_exit_to_user_mode+0x12/0x30
[ 329.319337] ? do_syscall_64+0x67/0x80
[ 329.319851] ? do_syscall_64+0x67/0x80
[ 329.320396] ? syscall_exit_to_user_mode+0x12/0x30
[ 329.321062] ? do_syscall_64+0x67/0x80
[ 329.321540] ? __irq_exit_rcu+0x72/0x160
[ 329.322042] entry_SYSCALL_64_after_hwframe+0x46/0xb0
[ 329.322671] RIP: 0033:0x7efd477feecd
[ 329.323128] Code: ff c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 23 7f 1b 00 f7 d8 64 89 01 48
[ 329.325462] RSP: 002b:00007efd462b34b8 EFLAGS: 00000246 ORIG_RAX: 00000000000000d0
[ 329.326388] RAX: ffffffffffffffda RBX: 00007efd462b5300 RCX: 00007efd477feecd
[ 329.326962] nvme nvme0: Removing ctrl: NQN "nvme-test"
[ 329.327885] RDX: 0000000000000080 RSI: 0000000000000001 RDI: 00007efd4628f000
[ 329.328760] RBP: 00007efd4628f000 R08: 00007efd462b45a0 R09: 0000000000000000
[ 329.329631] R10: 00007efd462b3540 R11: 0000000000000246 R12: 0000000000000001
[ 329.330506] R13: 0000000000000000 R14: 0000000000000080 R15: 00007efd462b3540
[ 329.331390] </TASK>
--->8---
My understanding is that we have
fs/aio.c::read_events
wait_event_interruptible_hrtimeout
__wait_event_hrtimeout
hrtimer_init_sleeper_on_stack <- this might mode |=HRTIMER_MODE_HARD on RT
hrtimer_start_range_ns
WARN_ON_ONCE(!(mode & HRTIMER_MODE_HARD) ^ !timer->is_hard)
fires since the latter doesn't see the change of mode done by
init_sleeper
The attached patch seems to cure the problem, although I'm not entirely
sure it's the cleanest fix (if I'm right at all about it :).
Thanks,
Juri
1 - https://github.com/yizhanglinux/blktests/tree/nvme-rdma-tcp/tests/nvmeof-mp
--->8---