lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<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

Powered by Openwall GNU/*/Linux Powered by OpenVZ