Hi all, When using WALT for EAS scheduler( android common 4.4 code base with commit fe09418d6f88b55920c576166b6e6a5ad456920f ), I met “WALT wallclock appears to have gone backwards or reset” WARNING. This warring is very hard to duplicate, and I met two times totally (for one time: wallclock is 64090104834350 and rq->window_start is 64255280000001 , windown_start is wrong). I am wondering is there anyone else meet similar issue as me? Or is this one known issue ? Thanks very much! Gang
05-24 16:20:29.351 <4> [14863.154614] c4 15486 (stressapptest) WALT wallclock appears to have gone backwards or reset 05-24 16:20:29.351 <4> [14863.162970] c4 15486 (stressapptest) ------------[ cut here ]------------ 05-24 16:20:29.351 <4> [14863.169745] c4 15486 (stressapptest) WARNING: at /home/build/farmland/adroid8.1/kernel/linux/kernel/sched/walt.c:212 05-24 16:20:29.351 <4> [14863.180237] c4 15486 (stressapptest) Modules linked in: 05-24 16:20:29.351 <4> [14863.183289] c4 15486 (stressapptest) 05-24 16:20:29.351 <4> [14863.186942] c4 15486 (stressapptest) CPU: 4 PID: 15486 Comm: stressapptest Not tainted 4.4.114+ #1 05-24 16:20:29.351 <4> [14863.195884] c4 15486 (stressapptest) Hardware name: ASR AQUILAC EVB (DT) 05-24 16:20:29.351 <4> [14863.202563] c4 15486 (stressapptest) task: ffffffc07d19a880 task.stack: ffffffc064f88000 05-24 16:20:29.351 <4> [14863.210640] c4 15486 (stressapptest) PC is at walt_update_task_ravg+0x260/0x6ec 05-24 16:20:29.351 <4> [14863.217931] c4 15486 (stressapptest) LR is at walt_update_task_ravg+0x260/0x6ec 05-24 16:20:29.351 <4> [14863.225219] c4 15486 (stressapptest) pc : [<ffffff80080f89d8>] lr : [<ffffff80080f89d8>] pstate: 600001c5 05-24 16:20:29.351 <4> [14863.234759] c4 15486 (stressapptest) sp : ffffffc0bbf48d90 05-24 16:20:29.351 <4> [14863.240227] c4 15486 (stressapptest) x29: ffffffc0bbf48d90 x28: ffffffc07d19a880 05-24 16:20:29.351 <4> [14863.245530] c4 15486 (stressapptest) x27: 00000d84990dad13 x26: ffffff800966c000 05-24 16:20:29.351 <4> [14863.250842] c4 15486 (stressapptest) x25: ffffff800957f000 x24: 0000000000000000 05-24 16:20:29.351 <4> [14863.256128] c4 15486 (stressapptest) x23: 0000000000000004 x22: 00000d84990dad13 05-24 16:20:29.351 <4> [14863.261415] c4 15486 (stressapptest) x21: ffffffc07d19a880 x20: ffffffc0bbf4f600 05-24 16:20:29.351 <4> [14863.266712] c4 15486 (stressapptest) x19: 0000000000000000 x18: 0000000000000000 05-24 16:20:29.351 <4> [14863.272006] c4 15486 (stressapptest) x17: 0000000000000000 x16: 0000000000000000 05-24 16:20:29.351 <4> [14863.277301] c4 15486 (stressapptest) x15: 0000000000000000 x14: 7420737261657070 05-24 16:20:29.351 <4> [14863.282597] c4 15486 (stressapptest) x13: 61206b636f6c636c x12: 6c617720544c4157 05-24 16:20:29.351 <4> [14863.287893] c4 15486 (stressapptest) x11: 2029747365747070 x10: 6173736572747328 05-24 16:20:29.351 <4> [14863.293205] c4 15486 (stressapptest) x9 : 2036383435312034 x8 : ffffff80083317d4 05-24 16:20:29.351 <4> [14863.298501] c4 15486 (stressapptest) x7 : ffffff80095c5650 x6 : 000000000000005f 05-24 16:20:29.351 <4> [14863.303795] c4 15486 (stressapptest) x5 : 0000000000000000 x4 : 0000000000000000 05-24 16:20:29.351 <4> [14863.309091] c4 15486 (stressapptest) x3 : 0000000000000000 x2 : cb88537fdc8ba672 05-24 16:20:29.351 <4> [14863.314377] c4 15486 (stressapptest) x1 : cb88537fdc8ba672 x0 : 000000000000004f
static void update_window_start(struct rq *rq, u64 wallclock) { s64 delta; int nr_windows;
delta = wallclock - rq->window_start; /* If the MPM global timer is cleared, set delta as 0 to avoid kernel BUG happening */ if (delta < 0) { delta = 0; WARN_ONCE(1, "WALT wallclock appears to have gone backwards or reset\n"); }
if (delta < walt_ravg_window) return;
nr_windows = div64_u64(delta, walt_ravg_window); rq->window_start += (u64)nr_windows * (u64)walt_ravg_window;
rq->cum_window_demand = rq->cumulative_runnable_avg; }
Hi Gang,
On Tue, Jul 03, 2018 at 08:28:58AM +0000, Wu Gang(吴刚) wrote:
Hi all, When using WALT for EAS scheduler( android common 4.4 code base with commit fe09418d6f88b55920c576166b6e6a5ad456920f ), I met “WALT wallclock appears to have gone backwards or reset” WARNING. This warring is very hard to duplicate, and I met two times totally (for one time: wallclock is 64090104834350 and rq->window_start is 64255280000001 , windown_start is wrong). I am wondering is there anyone else meet similar issue as me? Or is this one known issue ?
I'm not really working on WALT, so I'd like to leave your question for others who are familiar with WALT.
As a side topic, I just want to remind one thing is the timer roll back issue might be impacted by hardware (e.g. CPU architecture timer), for example, if you are using CA73 CPUs, maybe the patch series [1] will be important. As far as I know, this patch series have been merged into mainline kernel, but it's absent for Android kernel 4.4 and 4.9.
[1] https://patchwork.kernel.org/patch/9634759/
Thanks, Leo Yan
05-24 16:20:29.351 <4> [14863.154614] c4 15486 (stressapptest) WALT wallclock appears to have gone backwards or reset 05-24 16:20:29.351 <4> [14863.162970] c4 15486 (stressapptest) ------------[ cut here ]------------ 05-24 16:20:29.351 <4> [14863.169745] c4 15486 (stressapptest) WARNING: at /home/build/farmland/adroid8.1/kernel/linux/kernel/sched/walt.c:212 05-24 16:20:29.351 <4> [14863.180237] c4 15486 (stressapptest) Modules linked in: 05-24 16:20:29.351 <4> [14863.183289] c4 15486 (stressapptest) 05-24 16:20:29.351 <4> [14863.186942] c4 15486 (stressapptest) CPU: 4 PID: 15486 Comm: stressapptest Not tainted 4.4.114+ #1 05-24 16:20:29.351 <4> [14863.195884] c4 15486 (stressapptest) Hardware name: ASR AQUILAC EVB (DT) 05-24 16:20:29.351 <4> [14863.202563] c4 15486 (stressapptest) task: ffffffc07d19a880 task.stack: ffffffc064f88000 05-24 16:20:29.351 <4> [14863.210640] c4 15486 (stressapptest) PC is at walt_update_task_ravg+0x260/0x6ec 05-24 16:20:29.351 <4> [14863.217931] c4 15486 (stressapptest) LR is at walt_update_task_ravg+0x260/0x6ec 05-24 16:20:29.351 <4> [14863.225219] c4 15486 (stressapptest) pc : [<ffffff80080f89d8>] lr : [<ffffff80080f89d8>] pstate: 600001c5 05-24 16:20:29.351 <4> [14863.234759] c4 15486 (stressapptest) sp : ffffffc0bbf48d90 05-24 16:20:29.351 <4> [14863.240227] c4 15486 (stressapptest) x29: ffffffc0bbf48d90 x28: ffffffc07d19a880 05-24 16:20:29.351 <4> [14863.245530] c4 15486 (stressapptest) x27: 00000d84990dad13 x26: ffffff800966c000 05-24 16:20:29.351 <4> [14863.250842] c4 15486 (stressapptest) x25: ffffff800957f000 x24: 0000000000000000 05-24 16:20:29.351 <4> [14863.256128] c4 15486 (stressapptest) x23: 0000000000000004 x22: 00000d84990dad13 05-24 16:20:29.351 <4> [14863.261415] c4 15486 (stressapptest) x21: ffffffc07d19a880 x20: ffffffc0bbf4f600 05-24 16:20:29.351 <4> [14863.266712] c4 15486 (stressapptest) x19: 0000000000000000 x18: 0000000000000000 05-24 16:20:29.351 <4> [14863.272006] c4 15486 (stressapptest) x17: 0000000000000000 x16: 0000000000000000 05-24 16:20:29.351 <4> [14863.277301] c4 15486 (stressapptest) x15: 0000000000000000 x14: 7420737261657070 05-24 16:20:29.351 <4> [14863.282597] c4 15486 (stressapptest) x13: 61206b636f6c636c x12: 6c617720544c4157 05-24 16:20:29.351 <4> [14863.287893] c4 15486 (stressapptest) x11: 2029747365747070 x10: 6173736572747328 05-24 16:20:29.351 <4> [14863.293205] c4 15486 (stressapptest) x9 : 2036383435312034 x8 : ffffff80083317d4 05-24 16:20:29.351 <4> [14863.298501] c4 15486 (stressapptest) x7 : ffffff80095c5650 x6 : 000000000000005f 05-24 16:20:29.351 <4> [14863.303795] c4 15486 (stressapptest) x5 : 0000000000000000 x4 : 0000000000000000 05-24 16:20:29.351 <4> [14863.309091] c4 15486 (stressapptest) x3 : 0000000000000000 x2 : cb88537fdc8ba672 05-24 16:20:29.351 <4> [14863.314377] c4 15486 (stressapptest) x1 : cb88537fdc8ba672 x0 : 000000000000004f
static void update_window_start(struct rq *rq, u64 wallclock) { s64 delta; int nr_windows;
delta = wallclock - rq->window_start; /* If the MPM global timer is cleared, set delta as 0 to avoid kernel BUG happening */ if (delta < 0) { delta = 0; WARN_ONCE(1, "WALT wallclock appears to have gone backwards or reset\n"); } if (delta < walt_ravg_window) return; nr_windows = div64_u64(delta, walt_ravg_window); rq->window_start += (u64)nr_windows * (u64)walt_ravg_window; rq->cum_window_demand = rq->cumulative_runnable_avg;}
eas-dev mailing list eas-dev@lists.linaro.org https://lists.linaro.org/mailman/listinfo/eas-dev
Hi Leo, Thanks very much for your suggestion and reminding . It is very helpful for us. I will apply your mentioned patch and verify. Thanks Gang
-----Original Message----- From: leo.yan@linaro.org [mailto:leo.yan@linaro.org] Sent: 2018年7月3日 19:52 To: Wu Gang(吴刚) gangwu@asrmicro.com Cc: eas-dev@lists.linaro.org Subject: Re: [Eas-dev] "WALT wallclock appears to have gone backwards or reset" warring question. Thanks!
Hi Gang,
On Tue, Jul 03, 2018 at 08:28:58AM +0000, Wu Gang(吴刚) wrote:
Hi all, When using WALT for EAS scheduler( android common 4.4 code base with commit fe09418d6f88b55920c576166b6e6a5ad456920f ), I met “WALT wallclock appears to have gone backwards or reset” WARNING. This warring is very hard to duplicate, and I met two times totally (for one time: wallclock is 64090104834350 and rq->window_start is 64255280000001 , windown_start is wrong). I am wondering is there anyone else meet similar issue as me? Or is this one known issue ?
I'm not really working on WALT, so I'd like to leave your question for others who are familiar with WALT.
As a side topic, I just want to remind one thing is the timer roll back issue might be impacted by hardware (e.g. CPU architecture timer), for example, if you are using CA73 CPUs, maybe the patch series [1] will be important. As far as I know, this patch series have been merged into mainline kernel, but it's absent for Android kernel 4.4 and 4.9.
[1] https://patchwork.kernel.org/patch/9634759/
Thanks, Leo Yan
05-24 16:20:29.351 <4> [14863.154614] c4 15486 (stressapptest) WALT wallclock appears to have gone backwards or reset 05-24 16:20:29.351 <4> [14863.162970] c4 15486 (stressapptest) ------------[ cut here ]------------ 05-24 16:20:29.351 <4> [14863.169745] c4 15486 (stressapptest) WARNING: at /home/build/farmland/adroid8.1/kernel/linux/kernel/sched/walt.c:212 05-24 16:20:29.351 <4> [14863.180237] c4 15486 (stressapptest) Modules linked in: 05-24 16:20:29.351 <4> [14863.183289] c4 15486 (stressapptest) 05-24 16:20:29.351 <4> [14863.186942] c4 15486 (stressapptest) CPU: 4 PID: 15486 Comm: stressapptest Not tainted 4.4.114+ #1 05-24 16:20:29.351 <4> [14863.195884] c4 15486 (stressapptest) Hardware name: ASR AQUILAC EVB (DT) 05-24 16:20:29.351 <4> [14863.202563] c4 15486 (stressapptest) task: ffffffc07d19a880 task.stack: ffffffc064f88000 05-24 16:20:29.351 <4> [14863.210640] c4 15486 (stressapptest) PC is at walt_update_task_ravg+0x260/0x6ec 05-24 16:20:29.351 <4> [14863.217931] c4 15486 (stressapptest) LR is at walt_update_task_ravg+0x260/0x6ec 05-24 16:20:29.351 <4> [14863.225219] c4 15486 (stressapptest) pc : [<ffffff80080f89d8>] lr : [<ffffff80080f89d8>] pstate: 600001c5 05-24 16:20:29.351 <4> [14863.234759] c4 15486 (stressapptest) sp : ffffffc0bbf48d90 05-24 16:20:29.351 <4> [14863.240227] c4 15486 (stressapptest) x29: ffffffc0bbf48d90 x28: ffffffc07d19a880 05-24 16:20:29.351 <4> [14863.245530] c4 15486 (stressapptest) x27: 00000d84990dad13 x26: ffffff800966c000 05-24 16:20:29.351 <4> [14863.250842] c4 15486 (stressapptest) x25: ffffff800957f000 x24: 0000000000000000 05-24 16:20:29.351 <4> [14863.256128] c4 15486 (stressapptest) x23: 0000000000000004 x22: 00000d84990dad13 05-24 16:20:29.351 <4> [14863.261415] c4 15486 (stressapptest) x21: ffffffc07d19a880 x20: ffffffc0bbf4f600 05-24 16:20:29.351 <4> [14863.266712] c4 15486 (stressapptest) x19: 0000000000000000 x18: 0000000000000000 05-24 16:20:29.351 <4> [14863.272006] c4 15486 (stressapptest) x17: 0000000000000000 x16: 0000000000000000 05-24 16:20:29.351 <4> [14863.277301] c4 15486 (stressapptest) x15: 0000000000000000 x14: 7420737261657070 05-24 16:20:29.351 <4> [14863.282597] c4 15486 (stressapptest) x13: 61206b636f6c636c x12: 6c617720544c4157 05-24 16:20:29.351 <4> [14863.287893] c4 15486 (stressapptest) x11: 2029747365747070 x10: 6173736572747328 05-24 16:20:29.351 <4> [14863.293205] c4 15486 (stressapptest) x9 : 2036383435312034 x8 : ffffff80083317d4 05-24 16:20:29.351 <4> [14863.298501] c4 15486 (stressapptest) x7 : ffffff80095c5650 x6 : 000000000000005f 05-24 16:20:29.351 <4> [14863.303795] c4 15486 (stressapptest) x5 : 0000000000000000 x4 : 0000000000000000 05-24 16:20:29.351 <4> [14863.309091] c4 15486 (stressapptest) x3 : 0000000000000000 x2 : cb88537fdc8ba672 05-24 16:20:29.351 <4> [14863.314377] c4 15486 (stressapptest) x1 : cb88537fdc8ba672 x0 : 000000000000004f
static void update_window_start(struct rq *rq, u64 wallclock) { s64 delta; int nr_windows;
delta = wallclock - rq->window_start; /* If the MPM global timer is cleared, set delta as 0 to avoid kernel BUG happening */ if (delta < 0) { delta = 0; WARN_ONCE(1, "WALT wallclock appears to have gone backwards or reset\n"); } if (delta < walt_ravg_window) return; nr_windows = div64_u64(delta, walt_ravg_window); rq->window_start += (u64)nr_windows * (u64)walt_ravg_window; rq->cum_window_demand = rq->cumulative_runnable_avg;}
eas-dev mailing list eas-dev@lists.linaro.org https://lists.linaro.org/mailman/listinfo/eas-dev
-
leo.yan＠linaro.org -
Wu Gang(吴刚)