[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <8ff30c5d-b8ac-4825-874a-d73931b85014@ovn.org>
Date: Tue, 10 Dec 2024 01:34:36 +0100
From: Ilya Maximets <i.maximets@....org>
To: Peter Zijlstra <peterz@...radead.org>,
Vineeth Remanan Pillai <vineeth@...byteword.org>
Cc: i.maximets@....org, Joel Fernandes <joel@...lfernandes.org>,
LKML <linux-kernel@...r.kernel.org>, Ingo Molnar <mingo@...hat.com>,
Juri Lelli <juri.lelli@...hat.com>,
Vincent Guittot <vincent.guittot@...aro.org>, vineethrp@...gle.com,
shraash@...gle.com, marcel.ziswiler@...ethink.co.uk
Subject: Re: [v6.12] WARNING: at kernel/sched/deadline.c:1995
enqueue_dl_entity (task blocked for more than 28262 seconds)
On 12/9/24 13:56, Peter Zijlstra wrote:
>
> Does something like the below make sense?
>
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index d380bffee2ef..abebeb67de4e 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -664,6 +664,7 @@ struct sched_dl_entity {
> unsigned int dl_non_contending : 1;
> unsigned int dl_overrun : 1;
> unsigned int dl_server : 1;
> + unsigned int dl_server_active : 1;
> unsigned int dl_defer : 1;
> unsigned int dl_defer_armed : 1;
> unsigned int dl_defer_running : 1;
> diff --git a/kernel/sched/deadline.c b/kernel/sched/deadline.c
> index d9d5a702f1a6..e2b542f684db 100644
> --- a/kernel/sched/deadline.c
> +++ b/kernel/sched/deadline.c
> @@ -1647,6 +1647,7 @@ void dl_server_start(struct sched_dl_entity *dl_se)
> if (!dl_se->dl_runtime)
> return;
>
> + dl_se->dl_server_active = 1;
> enqueue_dl_entity(dl_se, ENQUEUE_WAKEUP);
> if (!dl_task(dl_se->rq->curr) || dl_entity_preempt(dl_se, &rq->curr->dl))
> resched_curr(dl_se->rq);
> @@ -1661,6 +1662,7 @@ void dl_server_stop(struct sched_dl_entity *dl_se)
> hrtimer_try_to_cancel(&dl_se->dl_timer);
> dl_se->dl_defer_armed = 0;
> dl_se->dl_throttled = 0;
> + dl_se->dl_server_active = 0;
> }
>
> void dl_server_init(struct sched_dl_entity *dl_se, struct rq *rq,
> @@ -2420,8 +2422,10 @@ static struct task_struct *__pick_task_dl(struct rq *rq)
> if (dl_server(dl_se)) {
> p = dl_se->server_pick_task(dl_se);
> if (!p) {
> - dl_se->dl_yielded = 1;
> - update_curr_dl_se(rq, dl_se, 0);
> + if (dl_se->dl_server_active) {
> + dl_se->dl_yielded = 1;
> + update_curr_dl_se(rq, dl_se, 0);
> + }
> goto again;
> }
> rq->dl_server = dl_se;
And I tried this one on top of v6.12, but got a warning after about 1 minute (lucky?).
Funny this one is also on CPU 15, but it's a coincidense, it happened on different
CPUs before.
Dec 9 18:11:10 kernel: clocksource: Long readout interval, skipping watchdog check: cs_nsec: 1194465656 wd_nsec: 1194465705
Dec 9 18:11:10 kernel: ------------[ cut here ]------------
Dec 9 18:11:10 kernel: WARNING: CPU: 15 PID: 7389 at kernel/sched/deadline.c:1997 enqueue_dl_entity (kernel/sched/deadline.c:1997 (discriminator 1))
Dec 9 18:11:10 kernel: Modules linked in: vport_vxlan vxlan vport_gre ip_gre ip_tunnel gre vport_geneve geneve ip6_udp_tunnel udp_tunnel openvswitch nf_conncount nf_nat ib_core esp4 veth nfnetlink_cttimeout nfnetlink nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 int
el_rapl_msr intel_rapl_common rfkill intel_uncore_frequency_common skx_edac_common nfit libnvdimm kvm_intel kvm rapl vfat fat iTCO_wdt virtio_gpu iTCO_vendor_support virtio_dma_buf i2c_i801 drm_shmem_helper virtio_balloon pcspkr i2c_smbus drm_kms_helper lpc_ich joydev d
rm xfs libcrc32c crct10dif_pclmul ahci crc32_pclmul libahci virtio_net crc32c_intel libata ghash_clmulni_intel net_failover virtio_console virtio_blk failover serio_raw sunrpc dm_mirror dm_region_hash dm_log dm_mod fuse [last unloaded: ip6_udp_tunnel]
Dec 9 18:11:10 kernel: CPU: 15 UID: 0 PID: 7389 Comm: revalidator42 Kdump: loaded Not tainted 6.12.0+ #78
Dec 9 18:11:10 kernel: Hardware name: Red Hat KVM/RHEL, BIOS 1.16.1-1.el9 04/01/2014
Dec 9 18:11:10 kernel: RIP: 0010:enqueue_dl_entity (kernel/sched/deadline.c:1997 (discriminator 1))
Dec 9 18:11:10 kernel: Code: 0a 00 00 0f b6 45 54 e9 d9 fc ff ff 45 85 ed 0f 84 5e fd ff ff 5b 44 89 e6 48 89 ef 5d 41 5c 41 5d 41 5e 41 5f e9 8b c4 ff ff <0f> 0b e9 b2 f9 ff ff 0f 0b e9 14 fb ff ff 8b 83 b0 0a 00 00 48 8b
All code
========
0: 0a 00 or (%rax),%al
2: 00 0f add %cl,(%rdi)
4: b6 45 mov $0x45,%dh
6: 54 push %rsp
7: e9 d9 fc ff ff jmpq 0xfffffffffffffce5
c: 45 85 ed test %r13d,%r13d
f: 0f 84 5e fd ff ff je 0xfffffffffffffd73
15: 5b pop %rbx
16: 44 89 e6 mov %r12d,%esi
19: 48 89 ef mov %rbp,%rdi
1c: 5d pop %rbp
1d: 41 5c pop %r12
1f: 41 5d pop %r13
21: 41 5e pop %r14
23: 41 5f pop %r15
25: e9 8b c4 ff ff jmpq 0xffffffffffffc4b5
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 b2 f9 ff ff jmpq 0xfffffffffffff9e3
31: 0f 0b ud2
33: e9 14 fb ff ff jmpq 0xfffffffffffffb4c
38: 8b 83 b0 0a 00 00 mov 0xab0(%rbx),%eax
3e: 48 rex.W
3f: 8b .byte 0x8b
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 b2 f9 ff ff jmpq 0xfffffffffffff9b9
7: 0f 0b ud2
9: e9 14 fb ff ff jmpq 0xfffffffffffffb22
e: 8b 83 b0 0a 00 00 mov 0xab0(%rbx),%eax
14: 48 rex.W
15: 8b .byte 0x8b
Dec 9 18:11:10 kernel: RSP: 0018:ffffb03601d336f8 EFLAGS: 00010086
Dec 9 18:11:10 kernel: RAX: 0000000000000001 RBX: ffff9ee93f1b65e8 RCX: 0000000000000001
Dec 9 18:11:10 kernel: RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff9ee93f1b65e8
Dec 9 18:11:10 kernel: RBP: ffff9ee93f1b65e8 R08: 0000000000000000 R09: 0000000000000000
Dec 9 18:11:10 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
Dec 9 18:11:10 kernel: R13: 0000000000000001 R14: 00000000002dc6c0 R15: 0000000000000000
Dec 9 18:11:10 kernel: FS: 00007effb172e640(0000) GS:ffff9ee93f180000(0000) knlGS:0000000000000000
Dec 9 18:11:10 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Dec 9 18:11:10 kernel: CR2: 0000720000080000 CR3: 000000010d86a005 CR4: 0000000000772ef0
Dec 9 18:11:10 kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Dec 9 18:11:10 kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Dec 9 18:11:10 kernel: PKRU: 55555554
Dec 9 18:11:10 kernel: Call Trace:
Dec 9 18:11:10 kernel: <TASK>
Dec 9 18:11:10 kernel: ? __warn (kernel/panic.c:748)
Dec 9 18:11:10 kernel: ? enqueue_dl_entity (kernel/sched/deadline.c:1997 (discriminator 1))
Dec 9 18:11:10 kernel: ? report_bug (lib/bug.c:201 lib/bug.c:219)
Dec 9 18:11:10 kernel: ? handle_bug (arch/x86/kernel/traps.c:285)
Dec 9 18:11:10 kernel: ? exc_invalid_op (arch/x86/kernel/traps.c:309 (discriminator 1))
Dec 9 18:11:10 kernel: ? asm_exc_invalid_op (./arch/x86/include/asm/idtentry.h:621)
Dec 9 18:11:10 kernel: ? enqueue_dl_entity (kernel/sched/deadline.c:1997 (discriminator 1))
Dec 9 18:11:10 kernel: dl_server_start (kernel/sched/deadline.c:1652)
Dec 9 18:11:10 kernel: enqueue_task_fair (kernel/sched/sched.h:2745 kernel/sched/fair.c:7048)
Dec 9 18:11:10 kernel: enqueue_task (kernel/sched/core.c:2020)
Dec 9 18:11:10 kernel: activate_task (kernel/sched/core.c:2069)
Dec 9 18:11:10 kernel: sched_balance_rq (kernel/sched/fair.c:9642 kernel/sched/fair.c:9676 kernel/sched/fair.c:11753)
Dec 9 18:11:10 kernel: sched_balance_newidle (kernel/sched/fair.c:12799)
Dec 9 18:11:10 kernel: pick_next_task_fair (kernel/sched/fair.c:8950)
Dec 9 18:11:10 kernel: __pick_next_task (kernel/sched/core.c:5972)
Dec 9 18:11:10 kernel: __schedule (kernel/sched/core.c:6647)
Dec 9 18:11:10 kernel: ? plist_add (./include/linux/list.h:150 ./include/linux/list.h:183 lib/plist.c:111)
Dec 9 18:11:10 kernel: schedule (./arch/x86/include/asm/preempt.h:84 kernel/sched/core.c:6771 kernel/sched/core.c:6785)
Dec 9 18:11:10 kernel: futex_wait_queue (kernel/futex/waitwake.c:372 (discriminator 2))
Dec 9 18:11:10 kernel: __futex_wait (kernel/futex/waitwake.c:672)
Dec 9 18:11:10 kernel: ? __pfx_futex_wake_mark (kernel/futex/waitwake.c:135)
Dec 9 18:11:10 kernel: futex_wait (kernel/futex/waitwake.c:700)
Dec 9 18:11:10 kernel: do_futex (kernel/futex/syscalls.c:131)
Dec 9 18:11:10 kernel: __x64_sys_futex (kernel/futex/syscalls.c:179 kernel/futex/syscalls.c:160 kernel/futex/syscalls.c:160)
Dec 9 18:11:10 kernel: ? kvm_sched_clock_read (arch/x86/kernel/kvmclock.c:91)
Dec 9 18:11:10 kernel: ? sched_clock (./arch/x86/include/asm/preempt.h:94 arch/x86/kernel/tsc.c:285)
Dec 9 18:11:10 kernel: ? sched_clock_cpu (kernel/sched/clock.c:394)
Dec 9 18:11:10 kernel: ? raw_spin_rq_lock_nested (./arch/x86/include/asm/preempt.h:84 kernel/sched/core.c:600)
Dec 9 18:11:10 kernel: do_syscall_64 (arch/x86/entry/common.c:52 arch/x86/entry/common.c:83)
Dec 9 18:11:10 kernel: ? _raw_spin_unlock (./arch/x86/include/asm/paravirt.h:589 ./arch/x86/include/asm/qspinlock.h:57 ./include/linux/spinlock.h:204 ./include/linux/spinlock_api_smp.h:142 kernel/locking/spinlock.c:186)
Dec 9 18:11:10 kernel: ? finish_task_switch.isra.0 (./arch/x86/include/asm/irqflags.h:42 ./arch/x86/include/asm/irqflags.h:97 kernel/sched/sched.h:1518 kernel/sched/core.c:5082 kernel/sched/core.c:5200)
Dec 9 18:11:10 kernel: ? __schedule (kernel/sched/core.c:6699)
Dec 9 18:11:10 kernel: ? schedule (./arch/x86/include/asm/preempt.h:84 kernel/sched/core.c:6771 kernel/sched/core.c:6785)
Dec 9 18:11:10 kernel: ? futex_wait_queue (kernel/futex/waitwake.c:372 (discriminator 2))
Dec 9 18:11:10 kernel: ? __futex_wait (kernel/futex/waitwake.c:672)
Dec 9 18:11:10 kernel: ? __pfx_futex_wake_mark (kernel/futex/waitwake.c:135)
Dec 9 18:11:10 kernel: ? futex_wait (kernel/futex/waitwake.c:700)
Dec 9 18:11:10 kernel: ? do_futex (kernel/futex/syscalls.c:131)
Dec 9 18:11:10 kernel: ? rseq_get_rseq_cs (kernel/rseq.c:161)
Dec 9 18:11:10 kernel: ? rseq_ip_fixup (kernel/rseq.c:257 kernel/rseq.c:291)
Dec 9 18:11:10 kernel: ? do_futex (kernel/futex/syscalls.c:131)
Dec 9 18:11:10 kernel: ? syscall_exit_to_user_mode (./arch/x86/include/asm/entry-common.h:58 ./arch/x86/include/asm/entry-common.h:65 ./include/linux/entry-common.h:330 kernel/entry/common.c:207 kernel/entry/common.c:218)
Dec 9 18:11:10 kernel: ? do_syscall_64 (arch/x86/entry/common.c:102)
Dec 9 18:11:10 kernel: ? clear_bhb_loop (arch/x86/entry/entry_64.S:1539)
Dec 9 18:11:10 kernel: ? clear_bhb_loop (arch/x86/entry/entry_64.S:1539)
Dec 9 18:11:10 kernel: ? clear_bhb_loop (arch/x86/entry/entry_64.S:1539)
Dec 9 18:11:10 kernel: entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:130)
Dec 9 18:11:10 kernel: RIP: 0033:0x7effd0a86a80
Dec 9 18:11:10 kernel: Code: 41 89 f0 83 f8 02 74 0b b8 02 00 00 00 87 07 85 c0 74 47 90 44 89 c6 45 31 d2 ba 02 00 00 00 b8 ca 00 00 00 40 80 f6 80 0f 05 <48> 3d 00 f0 ff ff 76 d6 83 c0 0b 83 f8 0b 77 0b ba 81 08 00 00 48
All code
========
0: 41 89 f0 mov %esi,%r8d
3: 83 f8 02 cmp $0x2,%eax
6: 74 0b je 0x13
8: b8 02 00 00 00 mov $0x2,%eax
d: 87 07 xchg %eax,(%rdi)
f: 85 c0 test %eax,%eax
11: 74 47 je 0x5a
13: 90 nop
14: 44 89 c6 mov %r8d,%esi
17: 45 31 d2 xor %r10d,%r10d
1a: ba 02 00 00 00 mov $0x2,%edx
1f: b8 ca 00 00 00 mov $0xca,%eax
24: 40 80 f6 80 xor $0x80,%sil
28: 0f 05 syscall
2a:* 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax <-- trapping instruction
30: 76 d6 jbe 0x8
32: 83 c0 0b add $0xb,%eax
35: 83 f8 0b cmp $0xb,%eax
38: 77 0b ja 0x45
3a: ba 81 08 00 00 mov $0x881,%edx
3f: 48 rex.W
Code starting with the faulting instruction
===========================================
0: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax
6: 76 d6 jbe 0xffffffffffffffde
8: 83 c0 0b add $0xb,%eax
b: 83 f8 0b cmp $0xb,%eax
e: 77 0b ja 0x1b
10: ba 81 08 00 00 mov $0x881,%edx
15: 48 rex.W
Dec 9 18:11:10 kernel: RSP: 002b:00007effb172a528 EFLAGS: 00000282 ORIG_RAX: 00000000000000ca
Dec 9 18:11:10 kernel: RAX: ffffffffffffffda RBX: 00007effb172e640 RCX: 00007effd0a86a80
Dec 9 18:11:10 kernel: RDX: 0000000000000002 RSI: 0000000000000080 RDI: 000000000171a3c0
Dec 9 18:11:10 kernel: RBP: 00007effb172a5e0 R08: 0000000000000000 R09: 00002effb172a89c
Dec 9 18:11:10 kernel: R10: 0000000000000000 R11: 0000000000000282 R12: 00007effb172e640
Dec 9 18:11:10 kernel: R13: 000000000000000b R14: 00007effd0a89a50 R15: 0000000000000000
Dec 9 18:11:10 kernel: </TASK>
Dec 9 18:11:10 kernel: ---[ end trace 0000000000000000 ]---
Powered by blists - more mailing lists