2021-06-22 07:40:51

by Sachin Sant

[permalink] [raw]
Subject: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

While booting 5.13.0-rc7-next-20210621 on a PowerVM LPAR following warning
is seen

[ 30.922154] ------------[ cut here ]------------
[ 30.922201] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
[ 30.922219] WARNING: CPU: 6 PID: 762 at kernel/sched/fair.c:3277 update_blocked_averages+0x758/0x780
[ 30.922259] Modules linked in: pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables sd_mod t10_pi sg fuse
[ 30.922309] CPU: 6 PID: 762 Comm: augenrules Not tainted 5.13.0-rc7-next-20210621 #1
[ 30.922329] NIP: c0000000001b27e8 LR: c0000000001b27e4 CTR: c0000000007cfda0
[ 30.922344] REGS: c000000023fcb660 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621)
[ 30.922359] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE> CR: 48488224 XER: 00000005
[ 30.922394] CFAR: c00000000014d120 IRQMASK: 1
GPR00: c0000000001b27e4 c000000023fcb900 c000000002a08400 0000000000000048
GPR04: 00000000ffff7fff c000000023fcb5c0 0000000000000027 c000000f6fdd7e18
GPR08: 0000000000000023 0000000000000001 0000000000000027 c0000000028a6650
GPR12: 0000000000008000 c000000f6fff7680 c000000f6fe62600 0000000000000032
GPR16: 00000007331a989a c000000f6fe62600 c0000000238a6800 0000000000000001
GPR20: 0000000000000000 c000000002a4dfe0 0000000000000000 0000000000000006
GPR24: 0000000000000000 c000000f6fe63010 0000000000000001 c000000f6fe62680
GPR28: 0000000000000006 c0000000238a69c0 0000000000000000 c000000f6fe62600
[ 30.922569] NIP [c0000000001b27e8] update_blocked_averages+0x758/0x780
[ 30.922599] LR [c0000000001b27e4] update_blocked_averages+0x754/0x780
[ 30.922624] Call Trace:
[ 30.922631] [c000000023fcb900] [c0000000001b27e4] update_blocked_averages+0x754/0x780 (unreliable)
[ 30.922653] [c000000023fcba20] [c0000000001bd668] newidle_balance+0x258/0x5c0
[ 30.922674] [c000000023fcbab0] [c0000000001bdaac] pick_next_task_fair+0x7c/0x4d0
[ 30.922692] [c000000023fcbb10] [c000000000dcd31c] __schedule+0x15c/0x1780
[ 30.922708] [c000000023fcbc50] [c0000000001a5a04] do_task_dead+0x64/0x70
[ 30.922726] [c000000023fcbc80] [c000000000156338] do_exit+0x848/0xcc0
[ 30.922743] [c000000023fcbd50] [c000000000156884] do_group_exit+0x64/0xe0
[ 30.922758] [c000000023fcbd90] [c000000000156924] sys_exit_group+0x24/0x30
[ 30.922774] [c000000023fcbdb0] [c0000000000310c0] system_call_exception+0x150/0x2d0
[ 30.922792] [c000000023fcbe10] [c00000000000cc5c] system_call_common+0xec/0x278
[ 30.922808] --- interrupt: c00 at 0x7fffb3acddcc
[ 30.922821] NIP: 00007fffb3acddcc LR: 00007fffb3a27f04 CTR: 0000000000000000
[ 30.922833] REGS: c000000023fcbe80 TRAP: 0c00 Not tainted (5.13.0-rc7-next-20210621)
[ 30.922847] MSR: 800000000280f033 <SF,VEC,VSX,EE,PR,FP,ME,IR,DR,RI,LE> CR: 28444202 XER: 00000000
[ 30.922882] IRQMASK: 0
GPR00: 00000000000000ea 00007fffc8f21780 00007fffb3bf7100 0000000000000000
GPR04: 0000000000000000 0000000155f142f0 0000000000000000 00007fffb3d23740
GPR08: fffffffffbad2a87 0000000000000000 0000000000000000 0000000000000000
GPR12: 0000000000000000 00007fffb3d2aeb0 0000000116be95e0 0000000000000032
GPR16: 0000000000000000 00007fffc8f21cd8 000000000000002d 0000000000000024
GPR20: 00007fffc8f21cd4 00007fffb3bf4f98 0000000000000001 0000000000000001
GPR24: 00007fffb3bf0950 0000000000000000 0000000000000000 0000000000000001
GPR28: 0000000000000000 0000000000000000 00007fffb3d23ec0 0000000000000000
[ 30.923023] NIP [00007fffb3acddcc] 0x7fffb3acddcc
[ 30.923035] LR [00007fffb3a27f04] 0x7fffb3a27f04
[ 30.923045] --- interrupt: c00
[ 30.923052] Instruction dump:
[ 30.923061] 3863be48 9be97ae6 4bf9a8f9 60000000 0fe00000 4bfff980 e9210070 e8610088
[ 30.923088] 39400001 99490003 4bf9a8d9 60000000 <0fe00000> 4bfffc24 3d22fff5 89297ae3
[ 30.923113] ---[ end trace ed07974d2149c499 ]—

This warning was introduced with commit 9e077b52d86a
sched/pelt: Check that *_avg are null when *_sum are

next-20210618 was good.

Thanks
-Sachin


2021-06-22 07:51:02

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

Hi Sachin,

On Tue, 22 Jun 2021 at 09:39, Sachin Sant <[email protected]> wrote:
>
> While booting 5.13.0-rc7-next-20210621 on a PowerVM LPAR following warning
> is seen
>
> [ 30.922154] ------------[ cut here ]------------
> [ 30.922201] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
> [ 30.922219] WARNING: CPU: 6 PID: 762 at kernel/sched/fair.c:3277 update_blocked_averages+0x758/0x780
> [ 30.922259] Modules linked in: pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables sd_mod t10_pi sg fuse
> [ 30.922309] CPU: 6 PID: 762 Comm: augenrules Not tainted 5.13.0-rc7-next-20210621 #1
> [ 30.922329] NIP: c0000000001b27e8 LR: c0000000001b27e4 CTR: c0000000007cfda0
> [ 30.922344] REGS: c000000023fcb660 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621)
> [ 30.922359] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE> CR: 48488224 XER: 00000005
> [ 30.922394] CFAR: c00000000014d120 IRQMASK: 1
> GPR00: c0000000001b27e4 c000000023fcb900 c000000002a08400 0000000000000048
> GPR04: 00000000ffff7fff c000000023fcb5c0 0000000000000027 c000000f6fdd7e18
> GPR08: 0000000000000023 0000000000000001 0000000000000027 c0000000028a6650
> GPR12: 0000000000008000 c000000f6fff7680 c000000f6fe62600 0000000000000032
> GPR16: 00000007331a989a c000000f6fe62600 c0000000238a6800 0000000000000001
> GPR20: 0000000000000000 c000000002a4dfe0 0000000000000000 0000000000000006
> GPR24: 0000000000000000 c000000f6fe63010 0000000000000001 c000000f6fe62680
> GPR28: 0000000000000006 c0000000238a69c0 0000000000000000 c000000f6fe62600
> [ 30.922569] NIP [c0000000001b27e8] update_blocked_averages+0x758/0x780
> [ 30.922599] LR [c0000000001b27e4] update_blocked_averages+0x754/0x780
> [ 30.922624] Call Trace:
> [ 30.922631] [c000000023fcb900] [c0000000001b27e4] update_blocked_averages+0x754/0x780 (unreliable)
> [ 30.922653] [c000000023fcba20] [c0000000001bd668] newidle_balance+0x258/0x5c0
> [ 30.922674] [c000000023fcbab0] [c0000000001bdaac] pick_next_task_fair+0x7c/0x4d0
> [ 30.922692] [c000000023fcbb10] [c000000000dcd31c] __schedule+0x15c/0x1780
> [ 30.922708] [c000000023fcbc50] [c0000000001a5a04] do_task_dead+0x64/0x70
> [ 30.922726] [c000000023fcbc80] [c000000000156338] do_exit+0x848/0xcc0
> [ 30.922743] [c000000023fcbd50] [c000000000156884] do_group_exit+0x64/0xe0
> [ 30.922758] [c000000023fcbd90] [c000000000156924] sys_exit_group+0x24/0x30
> [ 30.922774] [c000000023fcbdb0] [c0000000000310c0] system_call_exception+0x150/0x2d0
> [ 30.922792] [c000000023fcbe10] [c00000000000cc5c] system_call_common+0xec/0x278
> [ 30.922808] --- interrupt: c00 at 0x7fffb3acddcc
> [ 30.922821] NIP: 00007fffb3acddcc LR: 00007fffb3a27f04 CTR: 0000000000000000
> [ 30.922833] REGS: c000000023fcbe80 TRAP: 0c00 Not tainted (5.13.0-rc7-next-20210621)
> [ 30.922847] MSR: 800000000280f033 <SF,VEC,VSX,EE,PR,FP,ME,IR,DR,RI,LE> CR: 28444202 XER: 00000000
> [ 30.922882] IRQMASK: 0
> GPR00: 00000000000000ea 00007fffc8f21780 00007fffb3bf7100 0000000000000000
> GPR04: 0000000000000000 0000000155f142f0 0000000000000000 00007fffb3d23740
> GPR08: fffffffffbad2a87 0000000000000000 0000000000000000 0000000000000000
> GPR12: 0000000000000000 00007fffb3d2aeb0 0000000116be95e0 0000000000000032
> GPR16: 0000000000000000 00007fffc8f21cd8 000000000000002d 0000000000000024
> GPR20: 00007fffc8f21cd4 00007fffb3bf4f98 0000000000000001 0000000000000001
> GPR24: 00007fffb3bf0950 0000000000000000 0000000000000000 0000000000000001
> GPR28: 0000000000000000 0000000000000000 00007fffb3d23ec0 0000000000000000
> [ 30.923023] NIP [00007fffb3acddcc] 0x7fffb3acddcc
> [ 30.923035] LR [00007fffb3a27f04] 0x7fffb3a27f04
> [ 30.923045] --- interrupt: c00
> [ 30.923052] Instruction dump:
> [ 30.923061] 3863be48 9be97ae6 4bf9a8f9 60000000 0fe00000 4bfff980 e9210070 e8610088
> [ 30.923088] 39400001 99490003 4bf9a8d9 60000000 <0fe00000> 4bfffc24 3d22fff5 89297ae3
> [ 30.923113] ---[ end trace ed07974d2149c499 ]—
>
> This warning was introduced with commit 9e077b52d86a
> sched/pelt: Check that *_avg are null when *_sum are

Yes. That was exactly the purpose of the patch. There is one last
remaining part which could generate this. I'm going to prepare a patch

Thanks

>
> next-20210618 was good.
>
> Thanks
> -Sachin

2021-06-22 14:33:46

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

Le mardi 22 juin 2021 à 09:49:31 (+0200), Vincent Guittot a écrit :
> Hi Sachin,
>
> On Tue, 22 Jun 2021 at 09:39, Sachin Sant <[email protected]> wrote:
> >
> > While booting 5.13.0-rc7-next-20210621 on a PowerVM LPAR following warning
> > is seen
> >
> > [ 30.922154] ------------[ cut here ]------------
> > [ 30.922201] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
> > [ 30.922219] WARNING: CPU: 6 PID: 762 at kernel/sched/fair.c:3277 update_blocked_averages+0x758/0x780
> > [ 30.922259] Modules linked in: pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables sd_mod t10_pi sg fuse
> > [ 30.922309] CPU: 6 PID: 762 Comm: augenrules Not tainted 5.13.0-rc7-next-20210621 #1
> > [ 30.922329] NIP: c0000000001b27e8 LR: c0000000001b27e4 CTR: c0000000007cfda0
> > [ 30.922344] REGS: c000000023fcb660 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621)
> > [ 30.922359] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE> CR: 48488224 XER: 00000005
> > [ 30.922394] CFAR: c00000000014d120 IRQMASK: 1
> > GPR00: c0000000001b27e4 c000000023fcb900 c000000002a08400 0000000000000048
> > GPR04: 00000000ffff7fff c000000023fcb5c0 0000000000000027 c000000f6fdd7e18
> > GPR08: 0000000000000023 0000000000000001 0000000000000027 c0000000028a6650
> > GPR12: 0000000000008000 c000000f6fff7680 c000000f6fe62600 0000000000000032
> > GPR16: 00000007331a989a c000000f6fe62600 c0000000238a6800 0000000000000001
> > GPR20: 0000000000000000 c000000002a4dfe0 0000000000000000 0000000000000006
> > GPR24: 0000000000000000 c000000f6fe63010 0000000000000001 c000000f6fe62680
> > GPR28: 0000000000000006 c0000000238a69c0 0000000000000000 c000000f6fe62600
> > [ 30.922569] NIP [c0000000001b27e8] update_blocked_averages+0x758/0x780
> > [ 30.922599] LR [c0000000001b27e4] update_blocked_averages+0x754/0x780
> > [ 30.922624] Call Trace:
> > [ 30.922631] [c000000023fcb900] [c0000000001b27e4] update_blocked_averages+0x754/0x780 (unreliable)
> > [ 30.922653] [c000000023fcba20] [c0000000001bd668] newidle_balance+0x258/0x5c0
> > [ 30.922674] [c000000023fcbab0] [c0000000001bdaac] pick_next_task_fair+0x7c/0x4d0
> > [ 30.922692] [c000000023fcbb10] [c000000000dcd31c] __schedule+0x15c/0x1780
> > [ 30.922708] [c000000023fcbc50] [c0000000001a5a04] do_task_dead+0x64/0x70
> > [ 30.922726] [c000000023fcbc80] [c000000000156338] do_exit+0x848/0xcc0
> > [ 30.922743] [c000000023fcbd50] [c000000000156884] do_group_exit+0x64/0xe0
> > [ 30.922758] [c000000023fcbd90] [c000000000156924] sys_exit_group+0x24/0x30
> > [ 30.922774] [c000000023fcbdb0] [c0000000000310c0] system_call_exception+0x150/0x2d0
> > [ 30.922792] [c000000023fcbe10] [c00000000000cc5c] system_call_common+0xec/0x278
> > [ 30.922808] --- interrupt: c00 at 0x7fffb3acddcc
> > [ 30.922821] NIP: 00007fffb3acddcc LR: 00007fffb3a27f04 CTR: 0000000000000000
> > [ 30.922833] REGS: c000000023fcbe80 TRAP: 0c00 Not tainted (5.13.0-rc7-next-20210621)
> > [ 30.922847] MSR: 800000000280f033 <SF,VEC,VSX,EE,PR,FP,ME,IR,DR,RI,LE> CR: 28444202 XER: 00000000
> > [ 30.922882] IRQMASK: 0
> > GPR00: 00000000000000ea 00007fffc8f21780 00007fffb3bf7100 0000000000000000
> > GPR04: 0000000000000000 0000000155f142f0 0000000000000000 00007fffb3d23740
> > GPR08: fffffffffbad2a87 0000000000000000 0000000000000000 0000000000000000
> > GPR12: 0000000000000000 00007fffb3d2aeb0 0000000116be95e0 0000000000000032
> > GPR16: 0000000000000000 00007fffc8f21cd8 000000000000002d 0000000000000024
> > GPR20: 00007fffc8f21cd4 00007fffb3bf4f98 0000000000000001 0000000000000001
> > GPR24: 00007fffb3bf0950 0000000000000000 0000000000000000 0000000000000001
> > GPR28: 0000000000000000 0000000000000000 00007fffb3d23ec0 0000000000000000
> > [ 30.923023] NIP [00007fffb3acddcc] 0x7fffb3acddcc
> > [ 30.923035] LR [00007fffb3a27f04] 0x7fffb3a27f04
> > [ 30.923045] --- interrupt: c00
> > [ 30.923052] Instruction dump:
> > [ 30.923061] 3863be48 9be97ae6 4bf9a8f9 60000000 0fe00000 4bfff980 e9210070 e8610088
> > [ 30.923088] 39400001 99490003 4bf9a8d9 60000000 <0fe00000> 4bfffc24 3d22fff5 89297ae3
> > [ 30.923113] ---[ end trace ed07974d2149c499 ]—
> >
> > This warning was introduced with commit 9e077b52d86a
> > sched/pelt: Check that *_avg are null when *_sum are
>
> Yes. That was exactly the purpose of the patch. There is one last
> remaining part which could generate this. I'm going to prepare a patch

Could you try the patch below ? I have been able to reproduce the problem locally and this
fix it on my system:

diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index 8cc27b847ad8..da91db1c137f 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -3037,8 +3037,9 @@ enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
static inline void
dequeue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
{
+ u32 divider = get_pelt_divider(&se->avg);
sub_positive(&cfs_rq->avg.load_avg, se->avg.load_avg);
- sub_positive(&cfs_rq->avg.load_sum, se_weight(se) * se->avg.load_sum);
+ cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
}
#else
static inline void


>
> Thanks
>
> >
> > next-20210618 was good.
> >
> > Thanks
> > -Sachin

2021-06-22 16:01:39

by Sachin Sant

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

>> On Tue, 22 Jun 2021 at 09:39, Sachin Sant <[email protected]> wrote:
>>>
>>> While booting 5.13.0-rc7-next-20210621 on a PowerVM LPAR following warning
>>> is seen
>>>
>>> [ 30.922154] ------------[ cut here ]------------
>>> [ 30.922201] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
>>> [ 30.922219] WARNING: CPU: 6 PID: 762 at kernel/sched/fair.c:3277 update_blocked_averages+0x758/0x780
>>
>> Yes. That was exactly the purpose of the patch. There is one last
>> remaining part which could generate this. I'm going to prepare a patch
>
> Could you try the patch below ? I have been able to reproduce the problem locally and this
> fix it on my system:
>
I can recreate the issue with this patch.

Starting Terminate Plymouth Boot Screen...
Starting Hold until boot process finishes up...
[FAILED] Failed to start Crash recovery kernel arming.
See 'systemctl status kdump.service' for details.
[ 10.737913] ------------[ cut here ]------------
[ 10.737960] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
[ 10.737976] WARNING: CPU: 27 PID: 146 at kernel/sched/fair.c:3279 update_blocked_averages+0x758/0x780
[ 10.738010] Modules linked in: stp llc rfkill sunrpc pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
[ 10.738089] CPU: 27 PID: 146 Comm: ksoftirqd/27 Not tainted 5.13.0-rc7-next-20210621-dirty #2
[ 10.738103] NIP: c0000000001b2768 LR: c0000000001b2764 CTR: c000000000729120
[ 10.738116] REGS: c000000015973840 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
[ 10.738130] MSR: 800000000282b033 <SF,VEC,VSX,EE,FP,ME,IR,DR,RI,LE> CR: 48000224 XER: 00000005
[ 10.738161] CFAR: c00000000014d120 IRQMASK: 1
[ 10.738161] GPR00: c0000000001b2764 c000000015973ae0 c0000000029bb900 0000000000000048
[ 10.738161] GPR04: 00000000fffeffff c0000000159737a0 0000000000000027 c00000154f9f7e18
[ 10.738161] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
[ 10.738161] GPR12: 0000000000000000 c00000154ffd7e80 c00000154fa82580 000000000000b78a
[ 10.738161] GPR16: 000000028007883c 00000000000002ed c000000038d31000 0000000000000000
[ 10.738161] GPR20: 0000000000000000 c0000000029fdfe0 0000000000000000 000000000000037b
[ 10.738161] GPR24: 0000000000000000 c00000154fa82f90 0000000000000001 c00000003d4ca400
[ 10.738161] GPR28: 00000000000002ed c000000038d311c0 c000000038d31100 0000000000000000
[ 10.738281] NIP [c0000000001b2768] update_blocked_averages+0x758/0x780
[ 10.738290] LR [c0000000001b2764] update_blocked_averages+0x754/0x780
[ 10.738299] Call Trace:
[ 10.738303] [c000000015973ae0] [c0000000001b2764] update_blocked_averages+0x754/0x780 (unreliable)
[ 10.738315] [c000000015973c00] [c0000000001be720] run_rebalance_domains+0xa0/0xd0
[ 10.738326] [c000000015973c30] [c000000000cf9acc] __do_softirq+0x15c/0x3d4
[ 10.738337] [c000000015973d20] [c000000000158464] run_ksoftirqd+0x64/0x90
[ 10.738346] [c000000015973d40] [c00000000018fd24] smpboot_thread_fn+0x204/0x270
[ 10.738357] [c000000015973da0] [c000000000189770] kthread+0x190/0x1a0
[ 10.738367] [c000000015973e10] [c00000000000ceec] ret_from_kernel_thread+0x5c/0x70
[ 10.738381] Instruction dump:
[ 10.738388] 3863c808 9be9eefe 4bf9a979 60000000 0fe00000 4bfff980 e9210070 e8610088
[ 10.738410] 39400001 99490003 4bf9a959 60000000 <0fe00000> 4bfffc24 3d22fff6 8929eefb
[ 10.738431] ---[ end trace 9ca80b55840c53f0 ]—

Thanks
-Sachin

> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> index 8cc27b847ad8..da91db1c137f 100644
> --- a/kernel/sched/fair.c
> +++ b/kernel/sched/fair.c
> @@ -3037,8 +3037,9 @@ enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> static inline void
> dequeue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> {
> + u32 divider = get_pelt_divider(&se->avg);
> sub_positive(&cfs_rq->avg.load_avg, se->avg.load_avg);
> - sub_positive(&cfs_rq->avg.load_sum, se_weight(se) * se->avg.load_sum);
> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
> }
> #else
> static inline void
>

2021-06-23 07:23:16

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

Hi Sachin,

Le mardi 22 juin 2021 à 21:29:36 (+0530), Sachin Sant a écrit :
> >> On Tue, 22 Jun 2021 at 09:39, Sachin Sant <[email protected]> wrote:
> >>>
> >>> While booting 5.13.0-rc7-next-20210621 on a PowerVM LPAR following warning
> >>> is seen
> >>>
> >>> [ 30.922154] ------------[ cut here ]------------
> >>> [ 30.922201] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
> >>> [ 30.922219] WARNING: CPU: 6 PID: 762 at kernel/sched/fair.c:3277 update_blocked_averages+0x758/0x780
> >>
> >> Yes. That was exactly the purpose of the patch. There is one last
> >> remaining part which could generate this. I'm going to prepare a patch
> >
> > Could you try the patch below ? I have been able to reproduce the problem locally and this
> > fix it on my system:
> >
> I can recreate the issue with this patch.

ok, so your problem seem to be different from my assumption. Could you try
the patch below on top of the previous one ?

This will help us to confirm that the problem comes from load_avg and that
it's linked to the cfs load_avg and it's not a problem happening earlier in
the update of PELT.


diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index da91db1c137f..8a6566f945a0 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -3030,8 +3030,9 @@ account_entity_dequeue(struct cfs_rq *cfs_rq, struct sched_entity *se)
static inline void
enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
{
+ u32 divider = get_pelt_divider(&se->avg);
cfs_rq->avg.load_avg += se->avg.load_avg;
- cfs_rq->avg.load_sum += se_weight(se) * se->avg.load_sum;
+ cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
}

static inline void
@@ -3304,9 +3305,9 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
* 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);
+ SCHED_WARN_ON(cfs_rq->avg.load_avg);
+ SCHED_WARN_ON(cfs_rq->avg.util_avg);
+ SCHED_WARN_ON(cfs_rq->avg.runnable_avg);

return true;
}


>
> Starting Terminate Plymouth Boot Screen...
> Starting Hold until boot process finishes up...
> [FAILED] Failed to start Crash recovery kernel arming.
> See 'systemctl status kdump.service' for details.
> [ 10.737913] ------------[ cut here ]------------
> [ 10.737960] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
> [ 10.737976] WARNING: CPU: 27 PID: 146 at kernel/sched/fair.c:3279 update_blocked_averages+0x758/0x780
> [ 10.738010] Modules linked in: stp llc rfkill sunrpc pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
> [ 10.738089] CPU: 27 PID: 146 Comm: ksoftirqd/27 Not tainted 5.13.0-rc7-next-20210621-dirty #2
> [ 10.738103] NIP: c0000000001b2768 LR: c0000000001b2764 CTR: c000000000729120
> [ 10.738116] REGS: c000000015973840 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
> [ 10.738130] MSR: 800000000282b033 <SF,VEC,VSX,EE,FP,ME,IR,DR,RI,LE> CR: 48000224 XER: 00000005
> [ 10.738161] CFAR: c00000000014d120 IRQMASK: 1
> [ 10.738161] GPR00: c0000000001b2764 c000000015973ae0 c0000000029bb900 0000000000000048
> [ 10.738161] GPR04: 00000000fffeffff c0000000159737a0 0000000000000027 c00000154f9f7e18
> [ 10.738161] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
> [ 10.738161] GPR12: 0000000000000000 c00000154ffd7e80 c00000154fa82580 000000000000b78a
> [ 10.738161] GPR16: 000000028007883c 00000000000002ed c000000038d31000 0000000000000000
> [ 10.738161] GPR20: 0000000000000000 c0000000029fdfe0 0000000000000000 000000000000037b
> [ 10.738161] GPR24: 0000000000000000 c00000154fa82f90 0000000000000001 c00000003d4ca400
> [ 10.738161] GPR28: 00000000000002ed c000000038d311c0 c000000038d31100 0000000000000000
> [ 10.738281] NIP [c0000000001b2768] update_blocked_averages+0x758/0x780
> [ 10.738290] LR [c0000000001b2764] update_blocked_averages+0x754/0x780
> [ 10.738299] Call Trace:
> [ 10.738303] [c000000015973ae0] [c0000000001b2764] update_blocked_averages+0x754/0x780 (unreliable)
> [ 10.738315] [c000000015973c00] [c0000000001be720] run_rebalance_domains+0xa0/0xd0
> [ 10.738326] [c000000015973c30] [c000000000cf9acc] __do_softirq+0x15c/0x3d4
> [ 10.738337] [c000000015973d20] [c000000000158464] run_ksoftirqd+0x64/0x90
> [ 10.738346] [c000000015973d40] [c00000000018fd24] smpboot_thread_fn+0x204/0x270
> [ 10.738357] [c000000015973da0] [c000000000189770] kthread+0x190/0x1a0
> [ 10.738367] [c000000015973e10] [c00000000000ceec] ret_from_kernel_thread+0x5c/0x70
> [ 10.738381] Instruction dump:
> [ 10.738388] 3863c808 9be9eefe 4bf9a979 60000000 0fe00000 4bfff980 e9210070 e8610088
> [ 10.738410] 39400001 99490003 4bf9a959 60000000 <0fe00000> 4bfffc24 3d22fff6 8929eefb
> [ 10.738431] ---[ end trace 9ca80b55840c53f0 ]—
>
> Thanks
> -Sachin
>
> > diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> > index 8cc27b847ad8..da91db1c137f 100644
> > --- a/kernel/sched/fair.c
> > +++ b/kernel/sched/fair.c
> > @@ -3037,8 +3037,9 @@ enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> > static inline void
> > dequeue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> > {
> > + u32 divider = get_pelt_divider(&se->avg);
> > sub_positive(&cfs_rq->avg.load_avg, se->avg.load_avg);
> > - sub_positive(&cfs_rq->avg.load_sum, se_weight(se) * se->avg.load_sum);
> > + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
> > }
> > #else
> > static inline void
> >

2021-06-23 08:00:28

by Sachin Sant

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot


>>> Could you try the patch below ? I have been able to reproduce the problem locally and this
>>> fix it on my system:
>>>
>> I can recreate the issue with this patch.
>
> ok, so your problem seem to be different from my assumption. Could you try
> the patch below on top of the previous one ?
>
> This will help us to confirm that the problem comes from load_avg and that
> it's linked to the cfs load_avg and it's not a problem happening earlier in
> the update of PELT.
>

Indeed. With both the patches applied I see following warning related to load_avg

Starting NTP client/server...
Starting VDO volume services...
[ 9.029054] ------------[ cut here ]------------
[ 9.029084] cfs_rq->avg.load_avg
[ 9.029111] WARNING: CPU: 21 PID: 1169 at kernel/sched/fair.c:3282 update_blocked_averages+0x760/0x830
[ 9.029151] Modules linked in: pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
[ 9.029233] CPU: 21 PID: 1169 Comm: grep Not tainted 5.13.0-rc7-next-20210621-dirty #3
[ 9.029246] NIP: c0000000001b6150 LR: c0000000001b614c CTR: c000000000728f40
[ 9.029259] REGS: c00000000e177650 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
[ 9.029271] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE> CR: 48088224 XER: 00000005
[ 9.029296] CFAR: c00000000014d120 IRQMASK: 1
[ 9.029296] GPR00: c0000000001b614c c00000000e1778f0 c0000000029bb900 0000000000000014
[ 9.029296] GPR04: 00000000fffeffff c00000000e1775b0 0000000000000027 c00000154f637e18
[ 9.029296] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
[ 9.029296] GPR12: 0000000000008000 c00000154ffe0e80 000000000000b820 000000021a2c6864
[ 9.029296] GPR16: c0000000482cc000 c00000154f6c2580 0000000000000001 0000000000000000
[ 9.029296] GPR20: c00000000291a7f9 c0000000482cc100 0000000000000000 000000000000020d
[ 9.029296] GPR24: 0000000000000000 c00000154f6c2f90 0000000000000001 c000000030b84400
[ 9.029296] GPR28: 000000000000020d c0000000482cc1c0 0000000000000338 0000000000000000
[ 9.029481] NIP [c0000000001b6150] update_blocked_averages+0x760/0x830
[ 9.029494] LR [c0000000001b614c] update_blocked_averages+0x75c/0x830
[ 9.029508] Call Trace:
[ 9.029515] [c00000000e1778f0] [c0000000001b614c] update_blocked_averages+0x75c/0x830 (unreliable)
[ 9.029533] [c00000000e177a20] [c0000000001bd388] newidle_balance+0x258/0x5c0
[ 9.029542] [c00000000e177ab0] [c0000000001bd7cc] pick_next_task_fair+0x7c/0x4c0
[ 9.029574] [c00000000e177b10] [c000000000cee3dc] __schedule+0x15c/0x1780
[ 9.029599] [c00000000e177c50] [c0000000001a5984] do_task_dead+0x64/0x70
[ 9.029622] [c00000000e177c80] [c000000000156338] do_exit+0x848/0xcc0
[ 9.029646] [c00000000e177d50] [c000000000156884] do_group_exit+0x64/0xe0
[ 9.029666] [c00000000e177d90] [c000000000156924] sys_exit_group+0x24/0x30
[ 9.029688] [c00000000e177db0] [c0000000000310c0] system_call_exception+0x150/0x2d0
Startin[ 9.029710] [gc00000000e177e10 Hardware Monito] [c00000000000_common+0xec/0x2lling Sensors...
78
[ 9.029743] --- interrupt: c00 at 0x7fff943fddcc
[ 9.029758] NIP: 00007fff943fddcc LR: 00007fff94357f04 CTR: 0000000000000000
[ 9.029786] REGS: c00000000e177e80 TRAP: 0c00 Not tainted (5.13.0-rc7-next-20210621-dirty)
[ 9.029798] MSR: 800000000280f033 <SF,VEC,VSX,EE,PR,FP,ME,IR,DR,RI,LE> CR: 28000402 XER: 00000000
[ 9.029825] IRQMASK: 0
[ 9.029825] GPR00: 00000000000000ea 00007ffff59c0170 00007fff94527100 0000000000000001
[ 9.029825] GPR04: 0000000000000000 0000000000000000 0000000000000001 0000000000000000
[ 9.029825] GPR08: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 9.029825] GPR12: 0000000000000000 00007fff9466af00 0000000000000000 0000000000000000
[ 9.029825] GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 9.029825] GPR20: 0000000000000000 00007fff94524f98 0000000000000002 0000000000000001
[ 9.029825] GPR24: 00007fff94520950 0000000000000000 0000000000000001 0000000000000001
[ 9.029825] GPR28: 0000000000000000 0000000000000000 00007fff94663f10 0000000000000001
[ 9.029935] NIP [00007fff943fddcc] 0x7fff943fddcc
[ 9.029944] LR [00007fff94357f04] 0x7fff94357f04
[ 9.029952] --- interrupt: c00
[ 9.029959] Instruction dump:
[ 9.029966] 0fe00000 4bfffc64 60000000 60000000 89340007 2f890000 409efc38 e8610098
[ 9.029987] 39200001 99340007 4bf96f71 60000000 <0fe00000> 4bfffc1c 60000000 60000000
[ 9.030013] ---[ end trace 3d7e3a29c9539d96 ]---
Starting Authorization Manager…

Thanks
-Sachin


>
> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> index da91db1c137f..8a6566f945a0 100644
> --- a/kernel/sched/fair.c
> +++ b/kernel/sched/fair.c
> @@ -3030,8 +3030,9 @@ account_entity_dequeue(struct cfs_rq *cfs_rq, struct sched_entity *se)
> static inline void
> enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> {
> + u32 divider = get_pelt_divider(&se->avg);
> cfs_rq->avg.load_avg += se->avg.load_avg;
> - cfs_rq->avg.load_sum += se_weight(se) * se->avg.load_sum;
> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
> }
>
> static inline void
> @@ -3304,9 +3305,9 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
> * 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);
> + SCHED_WARN_ON(cfs_rq->avg.load_avg);
> + SCHED_WARN_ON(cfs_rq->avg.util_avg);
> + SCHED_WARN_ON(cfs_rq->avg.runnable_avg);
>
> return true;
> }
>
>
>>
>> Starting Terminate Plymouth Boot Screen...
>> Starting Hold until boot process finishes up...
>> [FAILED] Failed to start Crash recovery kernel arming.
>> See 'systemctl status kdump.service' for details.
>> [ 10.737913] ------------[ cut here ]------------
>> [ 10.737960] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
>> [ 10.737976] WARNING: CPU: 27 PID: 146 at kernel/sched/fair.c:3279 update_blocked_averages+0x758/0x780
>> [ 10.738010] Modules linked in: stp llc rfkill sunrpc pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
>> [ 10.738089] CPU: 27 PID: 146 Comm: ksoftirqd/27 Not tainted 5.13.0-rc7-next-20210621-dirty #2
>> [ 10.738103] NIP: c0000000001b2768 LR: c0000000001b2764 CTR: c000000000729120
>> [ 10.738116] REGS: c000000015973840 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
>> [ 10.738130] MSR: 800000000282b033 <SF,VEC,VSX,EE,FP,ME,IR,DR,RI,LE> CR: 48000224 XER: 00000005
>> [ 10.738161] CFAR: c00000000014d120 IRQMASK: 1
>> [ 10.738161] GPR00: c0000000001b2764 c000000015973ae0 c0000000029bb900 0000000000000048
>> [ 10.738161] GPR04: 00000000fffeffff c0000000159737a0 0000000000000027 c00000154f9f7e18
>> [ 10.738161] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
>> [ 10.738161] GPR12: 0000000000000000 c00000154ffd7e80 c00000154fa82580 000000000000b78a
>> [ 10.738161] GPR16: 000000028007883c 00000000000002ed c000000038d31000 0000000000000000
>> [ 10.738161] GPR20: 0000000000000000 c0000000029fdfe0 0000000000000000 000000000000037b
>> [ 10.738161] GPR24: 0000000000000000 c00000154fa82f90 0000000000000001 c00000003d4ca400
>> [ 10.738161] GPR28: 00000000000002ed c000000038d311c0 c000000038d31100 0000000000000000
>> [ 10.738281] NIP [c0000000001b2768] update_blocked_averages+0x758/0x780
>> [ 10.738290] LR [c0000000001b2764] update_blocked_averages+0x754/0x780
>> [ 10.738299] Call Trace:
>> [ 10.738303] [c000000015973ae0] [c0000000001b2764] update_blocked_averages+0x754/0x780 (unreliable)
>> [ 10.738315] [c000000015973c00] [c0000000001be720] run_rebalance_domains+0xa0/0xd0
>> [ 10.738326] [c000000015973c30] [c000000000cf9acc] __do_softirq+0x15c/0x3d4
>> [ 10.738337] [c000000015973d20] [c000000000158464] run_ksoftirqd+0x64/0x90
>> [ 10.738346] [c000000015973d40] [c00000000018fd24] smpboot_thread_fn+0x204/0x270
>> [ 10.738357] [c000000015973da0] [c000000000189770] kthread+0x190/0x1a0
>> [ 10.738367] [c000000015973e10] [c00000000000ceec] ret_from_kernel_thread+0x5c/0x70
>> [ 10.738381] Instruction dump:
>> [ 10.738388] 3863c808 9be9eefe 4bf9a979 60000000 0fe00000 4bfff980 e9210070 e8610088
>> [ 10.738410] 39400001 99490003 4bf9a959 60000000 <0fe00000> 4bfffc24 3d22fff6 8929eefb
>> [ 10.738431] ---[ end trace 9ca80b55840c53f0 ]—
>>
>> Thanks
>> -Sachin
>>
>>> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
>>> index 8cc27b847ad8..da91db1c137f 100644
>>> --- a/kernel/sched/fair.c
>>> +++ b/kernel/sched/fair.c
>>> @@ -3037,8 +3037,9 @@ enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
>>> static inline void
>>> dequeue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
>>> {
>>> + u32 divider = get_pelt_divider(&se->avg);
>>> sub_positive(&cfs_rq->avg.load_avg, se->avg.load_avg);
>>> - sub_positive(&cfs_rq->avg.load_sum, se_weight(se) * se->avg.load_sum);
>>> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
>>> }
>>> #else
>>> static inline void

2021-06-23 10:24:30

by Sachin Sant

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot



> On 23-Jun-2021, at 1:28 PM, Sachin Sant <[email protected]> wrote:
>
>
>>>> Could you try the patch below ? I have been able to reproduce the problem locally and this
>>>> fix it on my system:
>>>>
>>> I can recreate the issue with this patch.
>>
>> ok, so your problem seem to be different from my assumption. Could you try
>> the patch below on top of the previous one ?
>>
>> This will help us to confirm that the problem comes from load_avg and that
>> it's linked to the cfs load_avg and it's not a problem happening earlier in
>> the update of PELT.
>>
>
> Indeed. With both the patches applied I see following warning related to load_avg

I left the machine running for sometime. Then attempted a kernel compile.
I subsequently saw warnings triggered for util_avg as well as runnable_avg

[ 8371.964935] ------------[ cut here ]------------
[ 8371.964958] cfs_rq->avg.util_avg
[ 8371.964969] WARNING: CPU: 16 PID: 479551 at kernel/sched/fair.c:3283 update_blocked_averages+0x700/0x830
……..
……..
[ 8664.754506] ------------[ cut here ]------------
[ 8664.754569] cfs_rq->avg.runnable_avg
[ 8664.754583] WARNING: CPU: 23 PID: 125 at kernel/sched/fair.c:3284 update_blocked_averages+0x730/0x830
…….

>
> Starting NTP client/server...
> Starting VDO volume services...
> [ 9.029054] ------------[ cut here ]------------
> [ 9.029084] cfs_rq->avg.load_avg
> [ 9.029111] WARNING: CPU: 21 PID: 1169 at kernel/sched/fair.c:3282 update_blocked_averages+0x760/0x830
> [ 9.029151] Modules linked in: pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
> [ 9.029233] CPU: 21 PID: 1169 Comm: grep Not tainted 5.13.0-rc7-next-20210621-dirty #3
> [ 9.029246] NIP: c0000000001b6150 LR: c0000000001b614c CTR: c000000000728f40
> [ 9.029259] REGS: c00000000e177650 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
> [ 9.029271] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE> CR: 48088224 XER: 00000005
> [ 9.029296] CFAR: c00000000014d120 IRQMASK: 1
> [ 9.029296] GPR00: c0000000001b614c c00000000e1778f0 c0000000029bb900 0000000000000014
> [ 9.029296] GPR04: 00000000fffeffff c00000000e1775b0 0000000000000027 c00000154f637e18
> [ 9.029296] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
> [ 9.029296] GPR12: 0000000000008000 c00000154ffe0e80 000000000000b820 000000021a2c6864
> [ 9.029296] GPR16: c0000000482cc000 c00000154f6c2580 0000000000000001 0000000000000000
> [ 9.029296] GPR20: c00000000291a7f9 c0000000482cc100 0000000000000000 000000000000020d
> [ 9.029296] GPR24: 0000000000000000 c00000154f6c2f90 0000000000000001 c000000030b84400
> [ 9.029296] GPR28: 000000000000020d c0000000482cc1c0 0000000000000338 0000000000000000
> [ 9.029481] NIP [c0000000001b6150] update_blocked_averages+0x760/0x830
> [ 9.029494] LR [c0000000001b614c] update_blocked_averages+0x75c/0x830
> [ 9.029508] Call Trace:
> [ 9.029515] [c00000000e1778f0] [c0000000001b614c] update_blocked_averages+0x75c/0x830 (unreliable)
> [ 9.029533] [c00000000e177a20] [c0000000001bd388] newidle_balance+0x258/0x5c0
> [ 9.029542] [c00000000e177ab0] [c0000000001bd7cc] pick_next_task_fair+0x7c/0x4c0
> [ 9.029574] [c00000000e177b10] [c000000000cee3dc] __schedule+0x15c/0x1780
> [ 9.029599] [c00000000e177c50] [c0000000001a5984] do_task_dead+0x64/0x70
> [ 9.029622] [c00000000e177c80] [c000000000156338] do_exit+0x848/0xcc0
> [ 9.029646] [c00000000e177d50] [c000000000156884] do_group_exit+0x64/0xe0
> [ 9.029666] [c00000000e177d90] [c000000000156924] sys_exit_group+0x24/0x30
> [ 9.029688] [c00000000e177db0] [c0000000000310c0] system_call_exception+0x150/0x2d0
> Startin[ 9.029710] [gc00000000e177e10 Hardware Monito] [c00000000000_common+0xec/0x2lling Sensors...
> 78
> [ 9.029743] --- interrupt: c00 at 0x7fff943fddcc
> [ 9.029758] NIP: 00007fff943fddcc LR: 00007fff94357f04 CTR: 0000000000000000
> [ 9.029786] REGS: c00000000e177e80 TRAP: 0c00 Not tainted (5.13.0-rc7-next-20210621-dirty)
> [ 9.029798] MSR: 800000000280f033 <SF,VEC,VSX,EE,PR,FP,ME,IR,DR,RI,LE> CR: 28000402 XER: 00000000
> [ 9.029825] IRQMASK: 0
> [ 9.029825] GPR00: 00000000000000ea 00007ffff59c0170 00007fff94527100 0000000000000001
> [ 9.029825] GPR04: 0000000000000000 0000000000000000 0000000000000001 0000000000000000
> [ 9.029825] GPR08: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> [ 9.029825] GPR12: 0000000000000000 00007fff9466af00 0000000000000000 0000000000000000
> [ 9.029825] GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> [ 9.029825] GPR20: 0000000000000000 00007fff94524f98 0000000000000002 0000000000000001
> [ 9.029825] GPR24: 00007fff94520950 0000000000000000 0000000000000001 0000000000000001
> [ 9.029825] GPR28: 0000000000000000 0000000000000000 00007fff94663f10 0000000000000001
> [ 9.029935] NIP [00007fff943fddcc] 0x7fff943fddcc
> [ 9.029944] LR [00007fff94357f04] 0x7fff94357f04
> [ 9.029952] --- interrupt: c00
> [ 9.029959] Instruction dump:
> [ 9.029966] 0fe00000 4bfffc64 60000000 60000000 89340007 2f890000 409efc38 e8610098
> [ 9.029987] 39200001 99340007 4bf96f71 60000000 <0fe00000> 4bfffc1c 60000000 60000000
> [ 9.030013] ---[ end trace 3d7e3a29c9539d96 ]---
> Starting Authorization Manager…
>
> Thanks
> -Sachin
>
>
>>
>> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
>> index da91db1c137f..8a6566f945a0 100644
>> --- a/kernel/sched/fair.c
>> +++ b/kernel/sched/fair.c
>> @@ -3030,8 +3030,9 @@ account_entity_dequeue(struct cfs_rq *cfs_rq, struct sched_entity *se)
>> static inline void
>> enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
>> {
>> + u32 divider = get_pelt_divider(&se->avg);
>> cfs_rq->avg.load_avg += se->avg.load_avg;
>> - cfs_rq->avg.load_sum += se_weight(se) * se->avg.load_sum;
>> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
>> }
>>
>> static inline void
>> @@ -3304,9 +3305,9 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
>> * 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);
>> + SCHED_WARN_ON(cfs_rq->avg.load_avg);
>> + SCHED_WARN_ON(cfs_rq->avg.util_avg);
>> + SCHED_WARN_ON(cfs_rq->avg.runnable_avg);
>>
>> return true;
>> }
>>
>>
>>>
>>> Starting Terminate Plymouth Boot Screen...
>>> Starting Hold until boot process finishes up...
>>> [FAILED] Failed to start Crash recovery kernel arming.
>>> See 'systemctl status kdump.service' for details.
>>> [ 10.737913] ------------[ cut here ]------------
>>> [ 10.737960] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
>>> [ 10.737976] WARNING: CPU: 27 PID: 146 at kernel/sched/fair.c:3279 update_blocked_averages+0x758/0x780
>>> [ 10.738010] Modules linked in: stp llc rfkill sunrpc pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
>>> [ 10.738089] CPU: 27 PID: 146 Comm: ksoftirqd/27 Not tainted 5.13.0-rc7-next-20210621-dirty #2
>>> [ 10.738103] NIP: c0000000001b2768 LR: c0000000001b2764 CTR: c000000000729120
>>> [ 10.738116] REGS: c000000015973840 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
>>> [ 10.738130] MSR: 800000000282b033 <SF,VEC,VSX,EE,FP,ME,IR,DR,RI,LE> CR: 48000224 XER: 00000005
>>> [ 10.738161] CFAR: c00000000014d120 IRQMASK: 1
>>> [ 10.738161] GPR00: c0000000001b2764 c000000015973ae0 c0000000029bb900 0000000000000048
>>> [ 10.738161] GPR04: 00000000fffeffff c0000000159737a0 0000000000000027 c00000154f9f7e18
>>> [ 10.738161] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
>>> [ 10.738161] GPR12: 0000000000000000 c00000154ffd7e80 c00000154fa82580 000000000000b78a
>>> [ 10.738161] GPR16: 000000028007883c 00000000000002ed c000000038d31000 0000000000000000
>>> [ 10.738161] GPR20: 0000000000000000 c0000000029fdfe0 0000000000000000 000000000000037b
>>> [ 10.738161] GPR24: 0000000000000000 c00000154fa82f90 0000000000000001 c00000003d4ca400
>>> [ 10.738161] GPR28: 00000000000002ed c000000038d311c0 c000000038d31100 0000000000000000
>>> [ 10.738281] NIP [c0000000001b2768] update_blocked_averages+0x758/0x780
>>> [ 10.738290] LR [c0000000001b2764] update_blocked_averages+0x754/0x780
>>> [ 10.738299] Call Trace:
>>> [ 10.738303] [c000000015973ae0] [c0000000001b2764] update_blocked_averages+0x754/0x780 (unreliable)
>>> [ 10.738315] [c000000015973c00] [c0000000001be720] run_rebalance_domains+0xa0/0xd0
>>> [ 10.738326] [c000000015973c30] [c000000000cf9acc] __do_softirq+0x15c/0x3d4
>>> [ 10.738337] [c000000015973d20] [c000000000158464] run_ksoftirqd+0x64/0x90
>>> [ 10.738346] [c000000015973d40] [c00000000018fd24] smpboot_thread_fn+0x204/0x270
>>> [ 10.738357] [c000000015973da0] [c000000000189770] kthread+0x190/0x1a0
>>> [ 10.738367] [c000000015973e10] [c00000000000ceec] ret_from_kernel_thread+0x5c/0x70
>>> [ 10.738381] Instruction dump:
>>> [ 10.738388] 3863c808 9be9eefe 4bf9a979 60000000 0fe00000 4bfff980 e9210070 e8610088
>>> [ 10.738410] 39400001 99490003 4bf9a959 60000000 <0fe00000> 4bfffc24 3d22fff6 8929eefb
>>> [ 10.738431] ---[ end trace 9ca80b55840c53f0 ]—
>>>
>>> Thanks
>>> -Sachin
>>>
>>>> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
>>>> index 8cc27b847ad8..da91db1c137f 100644
>>>> --- a/kernel/sched/fair.c
>>>> +++ b/kernel/sched/fair.c
>>>> @@ -3037,8 +3037,9 @@ enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
>>>> static inline void
>>>> dequeue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
>>>> {
>>>> + u32 divider = get_pelt_divider(&se->avg);
>>>> sub_positive(&cfs_rq->avg.load_avg, se->avg.load_avg);
>>>> - sub_positive(&cfs_rq->avg.load_sum, se_weight(se) * se->avg.load_sum);
>>>> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
>>>> }
>>>> #else
>>>> static inline void
>

2021-06-23 12:09:59

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

Le mercredi 23 juin 2021 à 15:52:59 (+0530), Sachin Sant a écrit :
>
>
> > On 23-Jun-2021, at 1:28 PM, Sachin Sant <[email protected]> wrote:
> >
> >
> >>>> Could you try the patch below ? I have been able to reproduce the problem locally and this
> >>>> fix it on my system:
> >>>>
> >>> I can recreate the issue with this patch.
> >>
> >> ok, so your problem seem to be different from my assumption. Could you try
> >> the patch below on top of the previous one ?
> >>
> >> This will help us to confirm that the problem comes from load_avg and that
> >> it's linked to the cfs load_avg and it's not a problem happening earlier in
> >> the update of PELT.
> >>
> >
> > Indeed. With both the patches applied I see following warning related to load_avg
>
> I left the machine running for sometime. Then attempted a kernel compile.
> I subsequently saw warnings triggered for util_avg as well as runnable_avg
>
> [ 8371.964935] ------------[ cut here ]------------
> [ 8371.964958] cfs_rq->avg.util_avg
> [ 8371.964969] WARNING: CPU: 16 PID: 479551 at kernel/sched/fair.c:3283 update_blocked_averages+0x700/0x830
> ……..
> ……..
> [ 8664.754506] ------------[ cut here ]------------
> [ 8664.754569] cfs_rq->avg.runnable_avg
> [ 8664.754583] WARNING: CPU: 23 PID: 125 at kernel/sched/fair.c:3284 update_blocked_averages+0x730/0x830
> …….
>

Ok. This becomes even more weird. Could you share your config file and more details about
you setup ?

Have you applied the patch below ?
https://lore.kernel.org/lkml/[email protected]/

Regarding the load_avg warning, I can see possible problem during attach. Could you add
the patch below. The load_avg warning seems to happen during boot and sched_entity
creation.

---
kernel/sched/fair.c | 7 ++++---
1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index 8a6566f945a0..5e86139524c2 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -3753,11 +3753,12 @@ static void attach_entity_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *s

se->avg.runnable_sum = se->avg.runnable_avg * divider;

- se->avg.load_sum = divider;
if (se_weight(se)) {
se->avg.load_sum =
- div_u64(se->avg.load_avg * se->avg.load_sum, se_weight(se));
- }
+ div_u64(se->avg.load_avg * divider, se_weight(se));
+ } else {
+ se->avg.load_avg = 0;
+ }

enqueue_load_avg(cfs_rq, se);
cfs_rq->avg.util_avg += se->avg.util_avg;
--
2.17.1


> >
> > Starting NTP client/server...
> > Starting VDO volume services...
> > [ 9.029054] ------------[ cut here ]------------
> > [ 9.029084] cfs_rq->avg.load_avg
> > [ 9.029111] WARNING: CPU: 21 PID: 1169 at kernel/sched/fair.c:3282 update_blocked_averages+0x760/0x830
> > [ 9.029151] Modules linked in: pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
> > [ 9.029233] CPU: 21 PID: 1169 Comm: grep Not tainted 5.13.0-rc7-next-20210621-dirty #3
> > [ 9.029246] NIP: c0000000001b6150 LR: c0000000001b614c CTR: c000000000728f40
> > [ 9.029259] REGS: c00000000e177650 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
> > [ 9.029271] MSR: 8000000000029033 <SF,EE,ME,IR,DR,RI,LE> CR: 48088224 XER: 00000005
> > [ 9.029296] CFAR: c00000000014d120 IRQMASK: 1
> > [ 9.029296] GPR00: c0000000001b614c c00000000e1778f0 c0000000029bb900 0000000000000014
> > [ 9.029296] GPR04: 00000000fffeffff c00000000e1775b0 0000000000000027 c00000154f637e18
> > [ 9.029296] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
> > [ 9.029296] GPR12: 0000000000008000 c00000154ffe0e80 000000000000b820 000000021a2c6864
> > [ 9.029296] GPR16: c0000000482cc000 c00000154f6c2580 0000000000000001 0000000000000000
> > [ 9.029296] GPR20: c00000000291a7f9 c0000000482cc100 0000000000000000 000000000000020d
> > [ 9.029296] GPR24: 0000000000000000 c00000154f6c2f90 0000000000000001 c000000030b84400
> > [ 9.029296] GPR28: 000000000000020d c0000000482cc1c0 0000000000000338 0000000000000000
> > [ 9.029481] NIP [c0000000001b6150] update_blocked_averages+0x760/0x830
> > [ 9.029494] LR [c0000000001b614c] update_blocked_averages+0x75c/0x830
> > [ 9.029508] Call Trace:
> > [ 9.029515] [c00000000e1778f0] [c0000000001b614c] update_blocked_averages+0x75c/0x830 (unreliable)
> > [ 9.029533] [c00000000e177a20] [c0000000001bd388] newidle_balance+0x258/0x5c0
> > [ 9.029542] [c00000000e177ab0] [c0000000001bd7cc] pick_next_task_fair+0x7c/0x4c0
> > [ 9.029574] [c00000000e177b10] [c000000000cee3dc] __schedule+0x15c/0x1780
> > [ 9.029599] [c00000000e177c50] [c0000000001a5984] do_task_dead+0x64/0x70
> > [ 9.029622] [c00000000e177c80] [c000000000156338] do_exit+0x848/0xcc0
> > [ 9.029646] [c00000000e177d50] [c000000000156884] do_group_exit+0x64/0xe0
> > [ 9.029666] [c00000000e177d90] [c000000000156924] sys_exit_group+0x24/0x30
> > [ 9.029688] [c00000000e177db0] [c0000000000310c0] system_call_exception+0x150/0x2d0
> > Startin[ 9.029710] [gc00000000e177e10 Hardware Monito] [c00000000000_common+0xec/0x2lling Sensors...
> > 78
> > [ 9.029743] --- interrupt: c00 at 0x7fff943fddcc
> > [ 9.029758] NIP: 00007fff943fddcc LR: 00007fff94357f04 CTR: 0000000000000000
> > [ 9.029786] REGS: c00000000e177e80 TRAP: 0c00 Not tainted (5.13.0-rc7-next-20210621-dirty)
> > [ 9.029798] MSR: 800000000280f033 <SF,VEC,VSX,EE,PR,FP,ME,IR,DR,RI,LE> CR: 28000402 XER: 00000000
> > [ 9.029825] IRQMASK: 0
> > [ 9.029825] GPR00: 00000000000000ea 00007ffff59c0170 00007fff94527100 0000000000000001
> > [ 9.029825] GPR04: 0000000000000000 0000000000000000 0000000000000001 0000000000000000
> > [ 9.029825] GPR08: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> > [ 9.029825] GPR12: 0000000000000000 00007fff9466af00 0000000000000000 0000000000000000
> > [ 9.029825] GPR16: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> > [ 9.029825] GPR20: 0000000000000000 00007fff94524f98 0000000000000002 0000000000000001
> > [ 9.029825] GPR24: 00007fff94520950 0000000000000000 0000000000000001 0000000000000001
> > [ 9.029825] GPR28: 0000000000000000 0000000000000000 00007fff94663f10 0000000000000001
> > [ 9.029935] NIP [00007fff943fddcc] 0x7fff943fddcc
> > [ 9.029944] LR [00007fff94357f04] 0x7fff94357f04
> > [ 9.029952] --- interrupt: c00
> > [ 9.029959] Instruction dump:
> > [ 9.029966] 0fe00000 4bfffc64 60000000 60000000 89340007 2f890000 409efc38 e8610098
> > [ 9.029987] 39200001 99340007 4bf96f71 60000000 <0fe00000> 4bfffc1c 60000000 60000000
> > [ 9.030013] ---[ end trace 3d7e3a29c9539d96 ]---
> > Starting Authorization Manager…
> >
> > Thanks
> > -Sachin
> >
> >
> >>
> >> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> >> index da91db1c137f..8a6566f945a0 100644
> >> --- a/kernel/sched/fair.c
> >> +++ b/kernel/sched/fair.c
> >> @@ -3030,8 +3030,9 @@ account_entity_dequeue(struct cfs_rq *cfs_rq, struct sched_entity *se)
> >> static inline void
> >> enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> >> {
> >> + u32 divider = get_pelt_divider(&se->avg);
> >> cfs_rq->avg.load_avg += se->avg.load_avg;
> >> - cfs_rq->avg.load_sum += se_weight(se) * se->avg.load_sum;
> >> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
> >> }
> >>
> >> static inline void
> >> @@ -3304,9 +3305,9 @@ static inline bool cfs_rq_is_decayed(struct cfs_rq *cfs_rq)
> >> * 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);
> >> + SCHED_WARN_ON(cfs_rq->avg.load_avg);
> >> + SCHED_WARN_ON(cfs_rq->avg.util_avg);
> >> + SCHED_WARN_ON(cfs_rq->avg.runnable_avg);
> >>
> >> return true;
> >> }
> >>
> >>
> >>>
> >>> Starting Terminate Plymouth Boot Screen...
> >>> Starting Hold until boot process finishes up...
> >>> [FAILED] Failed to start Crash recovery kernel arming.
> >>> See 'systemctl status kdump.service' for details.
> >>> [ 10.737913] ------------[ cut here ]------------
> >>> [ 10.737960] cfs_rq->avg.load_avg || cfs_rq->avg.util_avg || cfs_rq->avg.runnable_avg
> >>> [ 10.737976] WARNING: CPU: 27 PID: 146 at kernel/sched/fair.c:3279 update_blocked_averages+0x758/0x780
> >>> [ 10.738010] Modules linked in: stp llc rfkill sunrpc pseries_rng xts vmx_crypto uio_pdrv_genirq uio sch_fq_codel ip_tables xfs libcrc32c sr_mod sd_mod cdrom t10_pi sg ibmvscsi ibmveth scsi_transport_srp dm_mirror dm_region_hash dm_log dm_mod fuse
> >>> [ 10.738089] CPU: 27 PID: 146 Comm: ksoftirqd/27 Not tainted 5.13.0-rc7-next-20210621-dirty #2
> >>> [ 10.738103] NIP: c0000000001b2768 LR: c0000000001b2764 CTR: c000000000729120
> >>> [ 10.738116] REGS: c000000015973840 TRAP: 0700 Not tainted (5.13.0-rc7-next-20210621-dirty)
> >>> [ 10.738130] MSR: 800000000282b033 <SF,VEC,VSX,EE,FP,ME,IR,DR,RI,LE> CR: 48000224 XER: 00000005
> >>> [ 10.738161] CFAR: c00000000014d120 IRQMASK: 1
> >>> [ 10.738161] GPR00: c0000000001b2764 c000000015973ae0 c0000000029bb900 0000000000000048
> >>> [ 10.738161] GPR04: 00000000fffeffff c0000000159737a0 0000000000000027 c00000154f9f7e18
> >>> [ 10.738161] GPR08: 0000000000000023 0000000000000001 0000000000000027 c00000167f1d7fe8
> >>> [ 10.738161] GPR12: 0000000000000000 c00000154ffd7e80 c00000154fa82580 000000000000b78a
> >>> [ 10.738161] GPR16: 000000028007883c 00000000000002ed c000000038d31000 0000000000000000
> >>> [ 10.738161] GPR20: 0000000000000000 c0000000029fdfe0 0000000000000000 000000000000037b
> >>> [ 10.738161] GPR24: 0000000000000000 c00000154fa82f90 0000000000000001 c00000003d4ca400
> >>> [ 10.738161] GPR28: 00000000000002ed c000000038d311c0 c000000038d31100 0000000000000000
> >>> [ 10.738281] NIP [c0000000001b2768] update_blocked_averages+0x758/0x780
> >>> [ 10.738290] LR [c0000000001b2764] update_blocked_averages+0x754/0x780
> >>> [ 10.738299] Call Trace:
> >>> [ 10.738303] [c000000015973ae0] [c0000000001b2764] update_blocked_averages+0x754/0x780 (unreliable)
> >>> [ 10.738315] [c000000015973c00] [c0000000001be720] run_rebalance_domains+0xa0/0xd0
> >>> [ 10.738326] [c000000015973c30] [c000000000cf9acc] __do_softirq+0x15c/0x3d4
> >>> [ 10.738337] [c000000015973d20] [c000000000158464] run_ksoftirqd+0x64/0x90
> >>> [ 10.738346] [c000000015973d40] [c00000000018fd24] smpboot_thread_fn+0x204/0x270
> >>> [ 10.738357] [c000000015973da0] [c000000000189770] kthread+0x190/0x1a0
> >>> [ 10.738367] [c000000015973e10] [c00000000000ceec] ret_from_kernel_thread+0x5c/0x70
> >>> [ 10.738381] Instruction dump:
> >>> [ 10.738388] 3863c808 9be9eefe 4bf9a979 60000000 0fe00000 4bfff980 e9210070 e8610088
> >>> [ 10.738410] 39400001 99490003 4bf9a959 60000000 <0fe00000> 4bfffc24 3d22fff6 8929eefb
> >>> [ 10.738431] ---[ end trace 9ca80b55840c53f0 ]—
> >>>
> >>> Thanks
> >>> -Sachin
> >>>
> >>>> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> >>>> index 8cc27b847ad8..da91db1c137f 100644
> >>>> --- a/kernel/sched/fair.c
> >>>> +++ b/kernel/sched/fair.c
> >>>> @@ -3037,8 +3037,9 @@ enqueue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> >>>> static inline void
> >>>> dequeue_load_avg(struct cfs_rq *cfs_rq, struct sched_entity *se)
> >>>> {
> >>>> + u32 divider = get_pelt_divider(&se->avg);
> >>>> sub_positive(&cfs_rq->avg.load_avg, se->avg.load_avg);
> >>>> - sub_positive(&cfs_rq->avg.load_sum, se_weight(se) * se->avg.load_sum);
> >>>> + cfs_rq->avg.load_sum = cfs_rq->avg.load_avg * divider;
> >>>> }
> >>>> #else
> >>>> static inline void
> >
>

2021-06-23 12:21:27

by Odin Ugedal

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

Hi,

Wouldn't the attached diff below also help when load is removed,
Vincent? Isn't there a theoretical chance that x_sum ends up at zero
while x_load ends up as a positive value (without this patch)? Can
post as a separate patch if it works for Sachin.


diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
index bfaa6e1f6067..def48bc2e90b 100644
--- a/kernel/sched/fair.c
+++ b/kernel/sched/fair.c
@@ -3688,15 +3688,15 @@ update_cfs_rq_load_avg(u64 now, struct cfs_rq *cfs_rq)

r = removed_load;
sub_positive(&sa->load_avg, r);
- sub_positive(&sa->load_sum, r * divider);
+ sa->load_sum = sa->load_avg * divider;

r = removed_util;
sub_positive(&sa->util_avg, r);
- sub_positive(&sa->util_sum, r * divider);
+ sa->util_sum = sa->util_avg * divider;

r = removed_runnable;
sub_positive(&sa->runnable_avg, r);
- sub_positive(&sa->runnable_sum, r * divider);
+ sa->runnable_sum = sa->runnable_avg * divider;

/*
* removed_runnable is the unweighted version of
removed_load so we

2021-06-23 12:26:05

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

On Wed, 23 Jun 2021 at 14:18, Odin Ugedal <[email protected]> wrote:
>
> Hi,
>
> Wouldn't the attached diff below also help when load is removed,
> Vincent? Isn't there a theoretical chance that x_sum ends up at zero
> while x_load ends up as a positive value (without this patch)? Can
> post as a separate patch if it works for Sachin.

In theory it should not because _sum should be always larger or equal
to _avg * divider. Otherwise, it means that we have something wrong
somewhere else

>
>
> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> index bfaa6e1f6067..def48bc2e90b 100644
> --- a/kernel/sched/fair.c
> +++ b/kernel/sched/fair.c
> @@ -3688,15 +3688,15 @@ update_cfs_rq_load_avg(u64 now, struct cfs_rq *cfs_rq)
>
> r = removed_load;
> sub_positive(&sa->load_avg, r);
> - sub_positive(&sa->load_sum, r * divider);
> + sa->load_sum = sa->load_avg * divider;
>
> r = removed_util;
> sub_positive(&sa->util_avg, r);
> - sub_positive(&sa->util_sum, r * divider);
> + sa->util_sum = sa->util_avg * divider;
>
> r = removed_runnable;
> sub_positive(&sa->runnable_avg, r);
> - sub_positive(&sa->runnable_sum, r * divider);
> + sa->runnable_sum = sa->runnable_avg * divider;
>
> /*
> * removed_runnable is the unweighted version of
> removed_load so we

2021-06-23 12:40:09

by Odin Ugedal

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

ons. 23. jun. 2021 kl. 14:22 skrev Vincent Guittot <[email protected]>:
>
> In theory it should not because _sum should be always larger or equal
> to _avg * divider. Otherwise, it means that we have something wrong
> somewhere else

Yeah, that might be the case. Still trying to wrap my head around
this. I might be wrong, but isn't there a possibility
that avg->period_contrib is increasing in PELTs accumulate_sum,
without _sum is increasing. This makes the pelt divider increase,
making the statement "_sum should be always larger or equal to _avg *"
false? Or am I missing something obvious here?

Still unable to reproduce what Sachin is reporting tho.

Odin

2021-06-23 13:57:49

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

On Wed, 23 Jun 2021 at 14:37, Odin Ugedal <[email protected]> wrote:
>
> ons. 23. jun. 2021 kl. 14:22 skrev Vincent Guittot <[email protected]>:
> >
> > In theory it should not because _sum should be always larger or equal
> > to _avg * divider. Otherwise, it means that we have something wrong
> > somewhere else
>
> Yeah, that might be the case. Still trying to wrap my head around
> this. I might be wrong, but isn't there a possibility
> that avg->period_contrib is increasing in PELTs accumulate_sum,
> without _sum is increasing. This makes the pelt divider increase,
> making the statement "_sum should be always larger or equal to _avg *"
> false? Or am I missing something obvious here?

The pelt value of sched_entity is synced with cfs and its contrib
before being removed.
Then, we start to remove this load in update_cfs_rq_load_avg() before
calling __update_load_avg_cfs_rq so contrib should not have change and
we should be safe

>
> Still unable to reproduce what Sachin is reporting tho.
>
> Odin

2021-06-23 15:15:45

by Odin Ugedal

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

ons. 23. jun. 2021 kl. 15:56 skrev Vincent Guittot <[email protected]>:
>
>
> The pelt value of sched_entity is synced with cfs and its contrib
> before being removed.


Hmm. Not sure what you mean by sched_entity here, since this is only
taking the "removed" load_avg
and removing it from cfs_rq, together with (removed.load_avg *
divider) from load_sum. (Although. ".removed" comes from
a sched entity)

> Then, we start to remove this load in update_cfs_rq_load_avg() before
> calling __update_load_avg_cfs_rq so contrib should not have change and
> we should be safe

For what it is worth, I am now able to reproduce it (maybe
CONFIG_HZ=300/250 is the thing) as reported by Sachin,
and my patch makes it disappear. Without my patch I see situations
where _sum is zero while _avg is eg. 1 or 2 or 14 (in that range).
This happens for both load, runnable and util.

Lets see what Sachin reports back.

Thanks
Odin

2021-06-23 15:26:45

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

On Wed, 23 Jun 2021 at 17:13, Odin Ugedal <[email protected]> wrote:
>
> ons. 23. jun. 2021 kl. 15:56 skrev Vincent Guittot <[email protected]>:
> >
> >
> > The pelt value of sched_entity is synced with cfs and its contrib
> > before being removed.
>
>
> Hmm. Not sure what you mean by sched_entity here, since this is only
> taking the "removed" load_avg
> and removing it from cfs_rq, together with (removed.load_avg *
> divider) from load_sum. (Although. ".removed" comes from
> a sched entity)

The sched_entity's load_avg that is put in removed.load, is sync with
the cfs_rq PELT signal, which includes contrib, before being added to
removed.load.

>
> > Then, we start to remove this load in update_cfs_rq_load_avg() before
> > calling __update_load_avg_cfs_rq so contrib should not have change and
> > we should be safe
>
> For what it is worth, I am now able to reproduce it (maybe
> CONFIG_HZ=300/250 is the thing) as reported by Sachin,
> and my patch makes it disappear. Without my patch I see situations
> where _sum is zero while _avg is eg. 1 or 2 or 14 (in that range).

hmm, so there is something wrong in the propagation

> This happens for both load, runnable and util.
>
> Lets see what Sachin reports back.
>
> Thanks
> Odin

2021-06-23 16:47:30

by Sachin Sant

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot


> Ok. This becomes even more weird. Could you share your config file and more details about
> you setup ?
>
> Have you applied the patch below ?
> https://lore.kernel.org/lkml/[email protected]/
>
> Regarding the load_avg warning, I can see possible problem during attach. Could you add
> the patch below. The load_avg warning seems to happen during boot and sched_entity
> creation.
>

Here is a summary of my testing.

I have a POWER box with PowerVM hypervisor. On this box I have a logical partition(LPAR) or guest
(allocated with 32 cpus 90G memory) running linux-next.

I started with a clean slate.
Moved to linux-next 5.13.0-rc7-next-20210622 as base code.
Applied patch #1 from Vincent which contains changes to dequeue_load_avg()
Applied patch #2 from Vincent which contains changes to enqueue_load_avg()
Applied patch #3 from Vincent which contains changes to attach_entity_load_avg()
Applied patch #4 from https://lore.kernel.org/lkml/[email protected]/

With these changes applied I was still able to recreate the issue. I could see kernel warning
during boot.

I then applied patch #5 from Odin which contains changes to update_cfs_rq_load_avg()

With all the 5 patches applied I was able to boot the kernel without any warning messages.
I also ran scheduler related tests from ltp (./runltp -f sched) . All tests including cfs_bandwidth01
ran successfully. No kernel warnings were observed.

Have also attached .config in case it is useful. config has CONFIG_HZ_100=y

Thanks
-Sachin


Attachments:
config_next_powerpc.txt (182.57 kB)

2021-06-23 16:56:41

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

On Wed, 23 Jun 2021 at 18:46, Sachin Sant <[email protected]> wrote:
>
>
> > Ok. This becomes even more weird. Could you share your config file and more details about
> > you setup ?
> >
> > Have you applied the patch below ?
> > https://lore.kernel.org/lkml/[email protected]/
> >
> > Regarding the load_avg warning, I can see possible problem during attach. Could you add
> > the patch below. The load_avg warning seems to happen during boot and sched_entity
> > creation.
> >
>
> Here is a summary of my testing.
>
> I have a POWER box with PowerVM hypervisor. On this box I have a logical partition(LPAR) or guest
> (allocated with 32 cpus 90G memory) running linux-next.
>
> I started with a clean slate.
> Moved to linux-next 5.13.0-rc7-next-20210622 as base code.
> Applied patch #1 from Vincent which contains changes to dequeue_load_avg()
> Applied patch #2 from Vincent which contains changes to enqueue_load_avg()
> Applied patch #3 from Vincent which contains changes to attach_entity_load_avg()
> Applied patch #4 from https://lore.kernel.org/lkml/[email protected]/
>
> With these changes applied I was still able to recreate the issue. I could see kernel warning
> during boot.
>
> I then applied patch #5 from Odin which contains changes to update_cfs_rq_load_avg()
>
> With all the 5 patches applied I was able to boot the kernel without any warning messages.
> I also ran scheduler related tests from ltp (./runltp -f sched) . All tests including cfs_bandwidth01
> ran successfully. No kernel warnings were observed.

ok so Odin's patch fixes the problem which highlights that we
overestimate _sum or don't sync _avg and _sum correctly

I'm going to look at this further

>
> Have also attached .config in case it is useful. config has CONFIG_HZ_100=y

Thanks, i will have a look

>
> Thanks
> -Sachin
>

2021-06-23 17:29:14

by Vincent Guittot

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

On Wed, 23 Jun 2021 at 18:55, Vincent Guittot
<[email protected]> wrote:
>
> On Wed, 23 Jun 2021 at 18:46, Sachin Sant <[email protected]> wrote:
> >
> >
> > > Ok. This becomes even more weird. Could you share your config file and more details about
> > > you setup ?
> > >
> > > Have you applied the patch below ?
> > > https://lore.kernel.org/lkml/[email protected]/
> > >
> > > Regarding the load_avg warning, I can see possible problem during attach. Could you add
> > > the patch below. The load_avg warning seems to happen during boot and sched_entity
> > > creation.
> > >
> >
> > Here is a summary of my testing.
> >
> > I have a POWER box with PowerVM hypervisor. On this box I have a logical partition(LPAR) or guest
> > (allocated with 32 cpus 90G memory) running linux-next.
> >
> > I started with a clean slate.
> > Moved to linux-next 5.13.0-rc7-next-20210622 as base code.
> > Applied patch #1 from Vincent which contains changes to dequeue_load_avg()
> > Applied patch #2 from Vincent which contains changes to enqueue_load_avg()
> > Applied patch #3 from Vincent which contains changes to attach_entity_load_avg()
> > Applied patch #4 from https://lore.kernel.org/lkml/[email protected]/
> >
> > With these changes applied I was still able to recreate the issue. I could see kernel warning
> > during boot.
> >
> > I then applied patch #5 from Odin which contains changes to update_cfs_rq_load_avg()
> >
> > With all the 5 patches applied I was able to boot the kernel without any warning messages.
> > I also ran scheduler related tests from ltp (./runltp -f sched) . All tests including cfs_bandwidth01
> > ran successfully. No kernel warnings were observed.
>
> ok so Odin's patch fixes the problem which highlights that we
> overestimate _sum or don't sync _avg and _sum correctly
>
> I'm going to look at this further

The problem is "_avg * divider" makes the assumption that all pending
contrib are not null contributions whereas they can be null.

Odin patch is the right way to fix this. Other patches should not be
useful for your problem

>
> >
> > Have also attached .config in case it is useful. config has CONFIG_HZ_100=y
>
> Thanks, i will have a look
>
> >
> > Thanks
> > -Sachin
> >

2021-06-23 17:38:46

by Odin Ugedal

[permalink] [raw]
Subject: Re: [powerpc][next-20210621] WARNING at kernel/sched/fair.c:3277 during boot

ons. 23. jun. 2021 kl. 19:27 skrev Vincent Guittot <[email protected]>:
>
> On Wed, 23 Jun 2021 at 18:55, Vincent Guittot
> <[email protected]> wrote:
> >
> > On Wed, 23 Jun 2021 at 18:46, Sachin Sant <[email protected]> wrote:
> > >
> > >
> > > > Ok. This becomes even more weird. Could you share your config file and more details about
> > > > you setup ?
> > > >
> > > > Have you applied the patch below ?
> > > > https://lore.kernel.org/lkml/[email protected]/
> > > >
> > > > Regarding the load_avg warning, I can see possible problem during attach. Could you add
> > > > the patch below. The load_avg warning seems to happen during boot and sched_entity
> > > > creation.
> > > >
> > >
> > > Here is a summary of my testing.
> > >
> > > I have a POWER box with PowerVM hypervisor. On this box I have a logical partition(LPAR) or guest
> > > (allocated with 32 cpus 90G memory) running linux-next.
> > >
> > > I started with a clean slate.
> > > Moved to linux-next 5.13.0-rc7-next-20210622 as base code.
> > > Applied patch #1 from Vincent which contains changes to dequeue_load_avg()
> > > Applied patch #2 from Vincent which contains changes to enqueue_load_avg()
> > > Applied patch #3 from Vincent which contains changes to attach_entity_load_avg()
> > > Applied patch #4 from https://lore.kernel.org/lkml/[email protected]/
> > >
> > > With these changes applied I was still able to recreate the issue. I could see kernel warning
> > > during boot.
> > >
> > > I then applied patch #5 from Odin which contains changes to update_cfs_rq_load_avg()
> > >
> > > With all the 5 patches applied I was able to boot the kernel without any warning messages.
> > > I also ran scheduler related tests from ltp (./runltp -f sched) . All tests including cfs_bandwidth01
> > > ran successfully. No kernel warnings were observed.
> >
> > ok so Odin's patch fixes the problem which highlights that we
> > overestimate _sum or don't sync _avg and _sum correctly
> >
> > I'm going to look at this further
>
> The problem is "_avg * divider" makes the assumption that all pending
> contrib are not null contributions whereas they can be null.

Yeah.

> Odin patch is the right way to fix this. Other patches should not be
> useful for your problem

Ack. As I see it, given how PELT works now, it is the only way to
mitigate it (without doing a lot of extra PELT stuff).
Will post it as a patch together with a proper message later today or tomorrow.

>
> >
> > >
> > > Have also attached .config in case it is useful. config has CONFIG_HZ_100=y
> >
> > Thanks, i will have a look
> >
> > >
> > > Thanks
> > > -Sachin
> > >

Thanks for reporting Sachin!

Thanks
Odin