2021-06-01 15:55:02

by Vincent Guittot

[permalink] [raw]
Subject: [PATCH] sched/pelt: check that *_avg are null when *_sum are

Check that we never break the rule that pelt's avg values are null if
pelt's sum are.

Signed-off-by: Vincent Guittot <[email protected]>
---

This is what I used for patch [email protected]

kernel/sched/fair.c | 9 +++++++++
1 file changed, 9 insertions(+)

diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index a2c30e52de76..c17feadeafcc 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -8021,6 +8021,15 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
if (cfs_rq->avg.runnable_sum)
return false;

+ /*
+ * _avg must be null when _sum are null because _avg = _sum / divider
+ * Make sure that rounding and/or propagation of PELT values never
+ * break this.
+ */
+ SCHED_WARN_ON(cfs_rq->avg.load_avg ||
+ cfs_rq->avg.util_avg ||
+ cfs_rq->avg.runnable_avg);
+
return true;
}

--
2.17.1


2021-06-02 06:46:30

by Oliver Sang

[permalink] [raw]
Subject: [sched/pelt] e906550aca: WARNING:at_kernel/sched/fair.c:#update_blocked_averages



Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: e906550aca3882139a60277aa00ce2979de80a42 ("[PATCH] sched/pelt: check that *_avg are null when *_sum are")
url: https://github.com/0day-ci/linux/commits/Vincent-Guittot/sched-pelt-check-that-_avg-are-null-when-_sum-are/20210601-235524
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git 475ea6c60279e9f2ddf7e4cf2648cd8ae0608361

in testcase: ltp
version: ltp-x86_64-14c1f76-1_20210522
with following parameters:

disk: 1HDD
fs: btrfs
test: io
ucode: 0x21

test-description: The LTP testsuite contains a collection of tools for testing the Linux kernel and related features.
test-url: http://linux-test-project.github.io/


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]>


kern :warn : [ 40.989618] WARNING: CPU: 2 PID: 253 at kernel/sched/fair.c:8029 update_blocked_averages (kbuild/src/consumer/kernel/sched/fair.c:8029 kbuild/src/consumer/kernel/sched/fair.c:8065 kbuild/src/consumer/kernel/sched/fair.c:8152)
kern :warn : [ 40.989920] Modules linked in: btrfs blake2b_generic xor zstd_compress raid6_pq libcrc32c sd_mod t10_pi sg intel_rapl_msr intel_rapl_common i915 vfio_mdev vfio_iommu_type1 vfio x86_pkg_temp_thermal intel_powerclamp coretemp mdev crct10dif_pclmul intel_gtt crc32_pclmul crc32c_intel drm_kms_helper ghash_clmulni_intel rapl ahci libahci intel_cstate syscopyarea sysfillrect sysimgblt fb_sys_fops mei_me mei ipmi_devintf usb_storage ipmi_msghandler libata drm intel_uncore video ip_tables
kern :warn : [ 40.990633] CPU: 2 PID: 253 Comm: systemd-logind Not tainted 5.13.0-rc1-00127-ge906550aca38 #1
kern :warn : [ 40.990772] Hardware name: Hewlett-Packard p6-1451cx/2ADA, BIOS 8.15 02/05/2013
kern :warn : [ 40.990890] RIP: 0010:update_blocked_averages (kbuild/src/consumer/kernel/sched/fair.c:8029 kbuild/src/consumer/kernel/sched/fair.c:8065 kbuild/src/consumer/kernel/sched/fair.c:8152)
kern :warn : [ 40.990981] Code: a0 a0 55 82 c6 05 eb 90 c6 01 01 e8 ae 0a b5 00 0f 0b e9 e6 f9 ff ff 48 c7 c7 30 a5 55 82 c6 05 c9 90 c6 01 01 e8 94 0a b5 00 <0f> 0b e9 1b fc ff ff 80 3d bf 90 c6 01 00 0f 85 5b ff ff ff 48 c7
All code
========
0: a0 a0 55 82 c6 05 eb movabs 0xc690eb05c68255a0,%al
7: 90 c6
9: 01 01 add %eax,(%rcx)
b: e8 ae 0a b5 00 callq 0xb50abe
10: 0f 0b ud2
12: e9 e6 f9 ff ff jmpq 0xfffffffffffff9fd
17: 48 c7 c7 30 a5 55 82 mov $0xffffffff8255a530,%rdi
1e: c6 05 c9 90 c6 01 01 movb $0x1,0x1c690c9(%rip) # 0x1c690ee
25: e8 94 0a b5 00 callq 0xb50abe
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 1b fc ff ff jmpq 0xfffffffffffffc4c
31: 80 3d bf 90 c6 01 00 cmpb $0x0,0x1c690bf(%rip) # 0x1c690f7
38: 0f 85 5b ff ff ff jne 0xffffffffffffff99
3e: 48 rex.W
3f: c7 .byte 0xc7

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 1b fc ff ff jmpq 0xfffffffffffffc22
7: 80 3d bf 90 c6 01 00 cmpb $0x0,0x1c690bf(%rip) # 0x1c690cd
e: 0f 85 5b ff ff ff jne 0xffffffffffffff6f
14: 48 rex.W
15: c7 .byte 0xc7
kern :warn : [ 40.991275] RSP: 0018:ffffc900005c7b90 EFLAGS: 00010086
kern :warn : [ 40.991361] RAX: 0000000000000000 RBX: ffff8881b2ace000 RCX: 0000000000000027
kern :warn : [ 40.991475] RDX: 0000000000000027 RSI: 00000000ffff7fff RDI: ffff88821fb17bf8
kern :warn : [ 40.991589] RBP: ffff88821fb2b680 R08: ffff88821fb17bf0 R09: ffffc900005c79b0
kern :warn : [ 40.991704] R10: 0000000000000001 R11: 0000000000000001 R12: ffff88821b4ee600
kern :warn : [ 40.991818] R13: 0000000000000000 R14: 0000000000000000 R15: ffff8881b2ace140
kern :warn : [ 40.991932] FS: 00007fce7e462980(0000) GS:ffff88821fb00000(0000) knlGS:0000000000000000
kern :warn : [ 40.992062] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
kern :warn : [ 40.992155] CR2: 0000555c466762f8 CR3: 000000021a9d8005 CR4: 00000000001706e0
kern :warn : [ 40.992269] Call Trace:
kern :warn : [ 40.992314] newidle_balance (kbuild/src/consumer/arch/x86/include/asm/preempt.h:80 kbuild/src/consumer/include/linux/rcupdate.h:68 kbuild/src/consumer/include/linux/rcupdate.h:655 kbuild/src/consumer/kernel/sched/fair.c:10667)
kern :warn : [ 40.992382] pick_next_task_fair (kbuild/src/consumer/kernel/sched/fair.c:7219)
kern :warn : [ 40.992453] pick_next_task (kbuild/src/consumer/kernel/sched/core.c:5322 kbuild/src/consumer/kernel/sched/core.c:5429)
kern :warn : [ 40.992518] ? dequeue_task_fair (kbuild/src/consumer/kernel/sched/fair.c:5589)
kern :warn : [ 40.992588] __schedule (kbuild/src/consumer/kernel/sched/core.c:5921)
kern :warn : [ 40.992649] schedule (kbuild/src/consumer/arch/x86/include/asm/preempt.h:85 (discriminator 1) kbuild/src/consumer/kernel/sched/core.c:6037 (discriminator 1))
kern :warn : [ 40.992705] schedule_hrtimeout_range_clock (kbuild/src/consumer/kernel/time/hrtimer.c:2074 (discriminator 1))
kern :warn : [ 40.992791] ? ep_done_scan (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/fs/eventpoll.c:661)
kern :warn : [ 40.992856] ep_poll (kbuild/src/consumer/fs/eventpoll.c:1848)
kern :warn : [ 40.992911] ? finish_wait (kbuild/src/consumer/kernel/sched/wait.c:403)
kern :warn : [ 40.992973] do_epoll_wait (kbuild/src/consumer/fs/eventpoll.c:2226)
kern :warn : [ 40.993035] __x64_sys_epoll_wait (kbuild/src/consumer/fs/eventpoll.c:2233)
kern :warn : [ 40.993105] ? syscall_trace_enter+0x99/0x1c0
kern :warn : [ 40.993187] do_syscall_64 (kbuild/src/consumer/arch/x86/entry/common.c:47)
kern :warn : [ 40.993249] entry_SYSCALL_64_after_hwframe (kbuild/src/consumer/arch/x86/entry/entry_64.S:112)
kern :warn : [ 40.993333] RIP: 0033:0x7fce7f5c77b7
kern :warn : [ 40.993394] Code: 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 8d 05 49 6f 0c 00 41 89 ca 8b 00 85 c0 75 10 b8 e8 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 59 c3 41 55 41 89 cd 41 54 41 89 d4 55 48 89
All code
========
0: 83 c8 ff or $0xffffffff,%eax
3: c3 retq
4: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
b: 00 00 00
e: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
13: 48 8d 05 49 6f 0c 00 lea 0xc6f49(%rip),%rax # 0xc6f63
1a: 41 89 ca mov %ecx,%r10d
1d: 8b 00 mov (%rax),%eax
1f: 85 c0 test %eax,%eax
21: 75 10 jne 0x33
23: b8 e8 00 00 00 mov $0xe8,%eax
28: 0f 05 syscall
2a:* 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax <-- trapping instruction
30: 77 59 ja 0x8b
32: c3 retq
33: 41 55 push %r13
35: 41 89 cd mov %ecx,%r13d
38: 41 54 push %r12
3a: 41 89 d4 mov %edx,%r12d
3d: 55 push %rbp
3e: 48 rex.W
3f: 89 .byte 0x89

Code starting with the faulting instruction
===========================================
0: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax
6: 77 59 ja 0x61
8: c3 retq
9: 41 55 push %r13
b: 41 89 cd mov %ecx,%r13d
e: 41 54 push %r12
10: 41 89 d4 mov %edx,%r12d
13: 55 push %rbp
14: 48 rex.W
15: 89 .byte 0x89
kern :warn : [ 40.993687] RSP: 002b:00007ffffe994368 EFLAGS: 00000246 ORIG_RAX: 00000000000000e8
kern :warn : [ 40.993809] RAX: ffffffffffffffda RBX: 000055e5ff172d60 RCX: 00007fce7f5c77b7
kern :warn : [ 40.993923] RDX: 000000000000000f RSI: 00007ffffe994370 RDI: 0000000000000004
kern :warn : [ 40.994038] RBP: 00007ffffe994520 R08: 000000000000034f R09: 00007ffffe994370
kern :warn : [ 40.994152] R10: 00000000ffffffff R11: 0000000000000246 R12: ffffffffffffffff
kern :warn : [ 40.994266] R13: 0000000000000001 R14: 00007ffffe994618 R15: 00007ffffe994370
kern :warn : [ 40.994381] ---[ end trace 794dc830ae459150 ]---
user :notice: [ 41.030869] Setting up libpython3-stdlib:amd64 (3.7.3-1) ...

user :notice: [ 41.032091] Setting up python3 (3.7.3-1) ...

user :notice: [ 41.036890] running python rtupdate hooks for python3.7...

user :notice: [ 41.039334] running python post-rtupdate hooks for python3.7...

user :notice: [ 41.118424] Setting up libf2fs-format4:amd64 (1.11.0-1.1) ...

user :notice: [ 41.119823] Processing triggers for systemd (241-7~deb10u4) ...

user :notice: [ 41.228905] Processing triggers for libc-bin (2.28-10) ...

user :notice: [ 41.237592] Processing triggers for mime-support (3.62) ...

user :notice: [ 41.248818] Processing triggers for dbus (1.12.16-1) ...

user :notice: [ 47.365583] 2 Jun 05:10:21 ntpdate[2337]: step time server 192.168.1.200 offset 2795.016514 sec

kern :info : [ 47.378243] netpoll: netconsole: local port 6665
kern :info : [ 47.378326] netpoll: netconsole: local IPv4 address 0.0.0.0
kern :info : [ 47.378417] netpoll: netconsole: interface 'eth0'
kern :info : [ 47.378494] netpoll: netconsole: remote port 6679
kern :info : [ 47.378570] netpoll: netconsole: remote IPv4 address 192.168.3.200
kern :info : [ 47.378681] netpoll: netconsole: remote ethernet address ff:ff:ff:ff:ff:ff
kern :info : [ 47.378798] netpoll: netconsole: local IP 192.168.3.102
kern :info : [ 47.378931] printk: console [netcon0] enabled
kern :info : [ 47.379012] netconsole: network logging started
kern :info : [ 47.392683] BTRFS info (device sda1): disk space caching is enabled
kern :info : [ 47.392797] BTRFS info (device sda1): has skinny extents
kern :info : [ 47.405066] BTRFS info (device sda1): enabling ssd optimizations
user :notice: [ 47.410266] /lkp/lkp/src/bin/run-lkp

kern :info : [ 48.300364] device-mapper: uevent: version 1.0.3
kern :info : [ 48.300513] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: [email protected]
kern :info : [ 48.626173] BTRFS: device fsid 38013e90-db69-4082-b755-a238335d3736 devid 1 transid 5 /dev/sdb1 scanned by mkfs.btrfs (2445)
kern :info : [ 48.635047] BTRFS info (device sdb1): disk space caching is enabled
kern :info : [ 48.635160] BTRFS info (device sdb1): has skinny extents
kern :info : [ 48.635259] BTRFS info (device sdb1): flagging fs with big metadata feature
kern :info : [ 48.638422] BTRFS info (device sdb1): checking UUID tree
kern :err : [ 48.698828] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back
kern :err : [ 48.699060] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back
kern :err : [ 48.722029] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back
kern :err : [ 48.722246] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back
kern :err : [ 48.745168] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back
kern :err : [ 48.745381] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back
kern :err : [ 48.768242] x86/PAT: bmc-watchdog:2518 map pfn expected mapping type uncached-minus for [mem 0xd8d1e000-0xd8d1efff], got write-back


To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
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
bin/lkp run generated-yaml-file



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (12.46 kB)
config-5.13.0-rc1-00127-ge906550aca38 (176.80 kB)
job-script (5.88 kB)
kmsg.xz (20.66 kB)
ltp (6.95 kB)
job.yaml (4.82 kB)
reproduce (209.00 B)
Download all attachments

2021-06-03 10:44:24

by Dietmar Eggemann

[permalink] [raw]
Subject: Re: [PATCH] sched/pelt: check that *_avg are null when *_sum are

On 01/06/2021 17:53, Vincent Guittot wrote:
> Check that we never break the rule that pelt's avg values are null if
> pelt's sum are.
>
> Signed-off-by: Vincent Guittot <[email protected]>
> ---
>
> This is what I used for patch [email protected]
>
> kernel/sched/fair.c | 9 +++++++++
> 1 file changed, 9 insertions(+)
>
> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> index a2c30e52de76..c17feadeafcc 100644
> --- a/kernel/sched/fair.c
> +++ b/kernel/sched/fair.c
> @@ -8021,6 +8021,15 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
> if (cfs_rq->avg.runnable_sum)
> return false;
>
> + /*
> + * _avg must be null when _sum are null because _avg = _sum / divider
> + * Make sure that rounding and/or propagation of PELT values never
> + * break this.
> + */
> + SCHED_WARN_ON(cfs_rq->avg.load_avg ||
> + cfs_rq->avg.util_avg ||
> + cfs_rq->avg.runnable_avg);
> +
> return true;
> }

Reviewed-by: Dietmar Eggemann <[email protected]>

2021-06-03 10:52:55

by Dietmar Eggemann

[permalink] [raw]
Subject: Re: [sched/pelt] e906550aca: WARNING:at_kernel/sched/fair.c:#update_blocked_averages

On 02/06/2021 08:45, kernel test robot wrote:

[...]

> kern :warn : [ 40.989618] WARNING: CPU: 2 PID: 253 at kernel/sched/fair.c:8029 update_blocked_averages (kbuild/src/consumer/kernel/sched/fair.c:8029 kbuild/src/consumer/kernel/sched/fair.c:8065 kbuild/src/consumer/kernel/sched/fair.c:8152)

Hit something like this on my Ubuntu i7-7567U as well.

With more debugging:

[ 7.388006] WARNING: CPU: 1 PID: 926 at kernel/sched/fair.c:8029 update_blocked_averages+0x30d/0x7e0
...
[ 7.388167] path=/autogroup-2 load_avg=1 util_avg=0 runnable_avg=1

IMHO, this is because this patch needs:

(1) sched/pelt: ensure that *_sum is always synced with *_avg (2021-06-03 Vincent Guittot)

https://lkml.kernel.org/r/[email protected]

(2) sched/fair: Keep load_avg and load_sum synced (2021-06-03 Vincent Guittot)

tip/sched/urgent 7c7ad626d9a0

Using both patches underneath makes this warning go away.

2021-06-03 11:02:21

by Vincent Guittot

[permalink] [raw]
Subject: Re: [sched/pelt] e906550aca: WARNING:at_kernel/sched/fair.c:#update_blocked_averages

Hi Dietmar,

On Thu, 3 Jun 2021 at 12:50, Dietmar Eggemann <[email protected]> wrote:
>
> On 02/06/2021 08:45, kernel test robot wrote:
>
> [...]
>
> > kern :warn : [ 40.989618] WARNING: CPU: 2 PID: 253 at kernel/sched/fair.c:8029 update_blocked_averages (kbuild/src/consumer/kernel/sched/fair.c:8029 kbuild/src/consumer/kernel/sched/fair.c:8065 kbuild/src/consumer/kernel/sched/fair.c:8152)
>
> Hit something like this on my Ubuntu i7-7567U as well.

Thanks for having a look at this.

>
> With more debugging:
>
> [ 7.388006] WARNING: CPU: 1 PID: 926 at kernel/sched/fair.c:8029 update_blocked_averages+0x30d/0x7e0
> ...
> [ 7.388167] path=/autogroup-2 load_avg=1 util_avg=0 runnable_avg=1
>
> IMHO, this is because this patch needs:
>
> (1) sched/pelt: ensure that *_sum is always synced with *_avg (2021-06-03 Vincent Guittot)
>
> https://lkml.kernel.org/r/[email protected]
>
> (2) sched/fair: Keep load_avg and load_sum synced (2021-06-03 Vincent Guittot)
>
> tip/sched/urgent 7c7ad626d9a0
>
> Using both patches underneath makes this warning go away.

I haven't spent time on this but that's also my 1st guess for the root cause

Regards,
Vincent

>

2021-06-03 11:11:42

by Odin Ugedal

[permalink] [raw]
Subject: Re: [PATCH] sched/pelt: check that *_avg are null when *_sum are

Hi,

Is there an idea to add tg_load_avg_contrib as well, to avoid
regressions where that is not set to zero?

Otherwise:

Acked-by: Odin Ugedal <[email protected]>

2021-06-03 12:49:56

by Vincent Guittot

[permalink] [raw]
Subject: Re: [PATCH] sched/pelt: check that *_avg are null when *_sum are

On Thu, 3 Jun 2021 at 13:06, Odin Ugedal <[email protected]> wrote:
>
> Hi,
>
> Is there an idea to add tg_load_avg_contrib as well, to avoid
> regressions where that is not set to zero?

TBH I wondered while preparing this patch if tg_load_avg_contrib
should be checked as well but I came to the conclusion that we should
keep this looking at PELT metrics only. If tg_load_avg_contrib != 0
but load_avg ==0, it means that we failed to update
tg_load_avg_contrib somewhere else

>
> Otherwise:
>
> Acked-by: Odin Ugedal <[email protected]>

2021-06-03 14:36:38

by Odin Ugedal

[permalink] [raw]
Subject: Re: [PATCH] sched/pelt: check that *_avg are null when *_sum are

> TBH I wondered while preparing this patch if tg_load_avg_contrib
> should be checked as well but I came to the conclusion that we should
> keep this looking at PELT metrics only. If tg_load_avg_contrib != 0
> but load_avg ==0, it means that we failed to update
> tg_load_avg_contrib somewhere else

Ahh, that sounds good. Agree.

Thanks
Odin

2021-06-18 09:32:52

by tip-bot2 for Jacob Pan

[permalink] [raw]
Subject: [tip: sched/core] sched/pelt: Check that *_avg are null when *_sum are

The following commit has been merged into the sched/core branch of tip:

Commit-ID: 9e077b52d86ac364a295b05c916c7478a16865b2
Gitweb: https://git.kernel.org/tip/9e077b52d86ac364a295b05c916c7478a16865b2
Author: Vincent Guittot <[email protected]>
AuthorDate: Tue, 01 Jun 2021 17:53:28 +02:00
Committer: Peter Zijlstra <[email protected]>
CommitterDate: Thu, 17 Jun 2021 14:11:42 +02:00

sched/pelt: Check that *_avg are null when *_sum are

Check that we never break the rule that pelt's avg values are null if
pelt's sum are.

Signed-off-by: Vincent Guittot <[email protected]>
Signed-off-by: Peter Zijlstra (Intel) <[email protected]>
Reviewed-by: Dietmar Eggemann <[email protected]>
Acked-by: Odin Ugedal <[email protected]>
Link: https://lore.kernel.org/r/[email protected]
---
kernel/sched/fair.c | 9 +++++++++
1 file changed, 9 insertions(+)

diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index ce625bf..198514d 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -8026,6 +8026,15 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
if (cfs_rq->avg.runnable_sum)
return false;

+ /*
+ * _avg must be null when _sum are null because _avg = _sum / divider
+ * Make sure that rounding and/or propagation of PELT values never
+ * break this.
+ */
+ SCHED_WARN_ON(cfs_rq->avg.load_avg ||
+ cfs_rq->avg.util_avg ||
+ cfs_rq->avg.runnable_avg);
+
return true;
}