Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1460371 > unrolled thread

Re: [PATCH] time,virt: resync steal time when guest & host lose sync

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-11 12:20 +0200
    Re: [PATCH] time,virt: resync steal time when guest & host lose sync Rik van Riel <riel@redhat.com> - 2016-08-12 04:50 +0200
      Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-12 09:10 +0200
        Re: [PATCH] time,virt: resync steal time when guest & host lose  sync Rik van Riel <riel@redhat.com> - 2016-08-12 18:00 +0200
          Re: [PATCH] time,virt: resync steal time when guest & host lose sync Frederic Weisbecker <fweisbec@gmail.com> - 2016-08-13 17:40 +0200
          Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-15 11:00 +0200
            Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-15 13:40 +0200
            Re: [PATCH] time,virt: resync steal time when guest & host lose sync Rik van Riel <riel@redhat.com> - 2016-08-15 17:10 +0200
              Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-16 00:20 +0200
              Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-16 03:40 +0200
                Re: [PATCH] time,virt: resync steal time when guest & host lose sync Rik van Riel <riel@redhat.com> - 2016-08-16 04:20 +0200
                  Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-16 09:00 +0200
                    Re: [PATCH] time,virt: resync steal time when guest & host lose sync Rik van Riel <riel@redhat.com> - 2016-08-16 16:20 +0200
                      Re: [PATCH] time,virt: resync steal time when guest & host lose sync Wanpeng Li <kernellwp@gmail.com> - 2016-08-17 01:10 +0200

#1460371 — Re: [PATCH] time,virt: resync steal time when guest & host lose sync

2016-08-11 0:52 GMT+08:00 Rik van Riel <riel@redhat.com>:
> On Wed, 10 Aug 2016 07:39:08 +0800
> Wanpeng Li <kernellwp@gmail.com> wrote:
>
>> The regression is caused by your commit "sched,time: Count actually
>> elapsed irq & softirq time".
>
> Wanpeng, does this patch fix your issue?

I test this against kvm guest (nohz_full, four vCPUs running on one
pCPU, four cpuhog processes running on four vCPUs).
before this fix patch:
vCPU0's st is 100%, other vCPUs' st are ~75%.
after this fix patch:
all vCPUs' st are ~85%.
However, w/o commit "sched,time: Count actually elapsed irq & softirq
time", all vCPUs' st are ~75%.

Regards,
Wanpeng Li

[toc] | [next] | [standalone]

#1460908

[Multipart message — attachments visible in raw view] — view raw

On Thu, 2016-08-11 at 18:11 +0800, Wanpeng Li wrote:
> 2016-08-11 0:52 GMT+08:00 Rik van Riel <riel@redhat.com>:
> > On Wed, 10 Aug 2016 07:39:08 +0800
> > Wanpeng Li <kernellwp@gmail.com> wrote:
> > 
> > > The regression is caused by your commit "sched,time: Count
> > > actually
> > > elapsed irq & softirq time".
> > 
> > Wanpeng, does this patch fix your issue?
> 
> I test this against kvm guest (nohz_full, four vCPUs running on one
> pCPU, four cpuhog processes running on four vCPUs).
> before this fix patch:
> vCPU0's st is 100%, other vCPUs' st are ~75%.
> after this fix patch:
> all vCPUs' st are ~85%.
> However, w/o commit "sched,time: Count actually elapsed irq & softirq
> time", all vCPUs' st are ~75%.

If you pass ULONG_MAX as the maxtime argument to
steal_account_process_time(), does the steal time
get accounted properly at 75%?

If that is the case, I have a hypothesis:
1) The guest is running so much slower when sharing
   a CPU 4 ways, that it is accounting only ~90% of
   wall clock time as CPU time, due to missing the
   other 10% or so of clock ticks.
2) account_process_tick() only ever processes one tick
   at a time - if it gets called only 90x a second for
   a 100Hz guest, but all the steal time recorded by
   the host is fully accounted (ULONG_MAX limit), then
   that could make up for lost/skipped timer ticks.
3) not accounting "extra" steal time (beyond the amount
   of time accounted by account_process_tick) would reduce
   the total amount of time that gets accounted if there
   are missed ticks, taking time away from user/system/etc

Does the above make sense?

Am I overlooking some mechanism through which lost/skipped
ticks are made up for in the kernel?  I looked through the
code in kernel/time/ briefly, but did not spot it...

-- 

All Rights Reversed.

[toc] | [prev] | [next] | [standalone]

#1460976

2016-08-12 10:44 GMT+08:00 Rik van Riel <riel@redhat.com>:
> On Thu, 2016-08-11 at 18:11 +0800, Wanpeng Li wrote:
>> 2016-08-11 0:52 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> > On Wed, 10 Aug 2016 07:39:08 +0800
>> > Wanpeng Li <kernellwp@gmail.com> wrote:
>> >
>> > > The regression is caused by your commit "sched,time: Count
>> > > actually
>> > > elapsed irq & softirq time".
>> >
>> > Wanpeng, does this patch fix your issue?
>>
>> I test this against kvm guest (nohz_full, four vCPUs running on one
>> pCPU, four cpuhog processes running on four vCPUs).
>> before this fix patch:
>> vCPU0's st is 100%, other vCPUs' st are ~75%.
>> after this fix patch:
>> all vCPUs' st are ~85%.
>> However, w/o commit "sched,time: Count actually elapsed irq & softirq
>> time", all vCPUs' st are ~75%.
>
> If you pass ULONG_MAX as the maxtime argument to
> steal_account_process_time(), does the steal time
> get accounted properly at 75%?

Yes.

>
> If that is the case, I have a hypothesis:
> 1) The guest is running so much slower when sharing
>    a CPU 4 ways, that it is accounting only ~90% of
>    wall clock time as CPU time, due to missing the
>    other 10% or so of clock ticks.
> 2) account_process_tick() only ever processes one tick
>    at a time - if it gets called only 90x a second for
>    a 100Hz guest, but all the steal time recorded by
>    the host is fully accounted (ULONG_MAX limit), then
>    that could make up for lost/skipped timer ticks.
> 3) not accounting "extra" steal time (beyond the amount
>    of time accounted by account_process_tick) would reduce
>    the total amount of time that gets accounted if there
>    are missed ticks, taking time away from user/system/etc
>
> Does the above make sense?
>
> Am I overlooking some mechanism through which lost/skipped
> ticks are made up for in the kernel?  I looked through the
> code in kernel/time/ briefly, but did not spot it...
>
> --
>
> All Rights Reversed.

[toc] | [prev] | [next] | [standalone]

#1461283 — Re: [PATCH] time,virt: resync steal time when guest & host lose sync

On Fri, 12 Aug 2016 15:09:00 +0800
Wanpeng Li <kernellwp@gmail.com> wrote:
> 2016-08-12 10:44 GMT+08:00 Rik van Riel <riel@redhat.com>:

> > If you pass ULONG_MAX as the maxtime argument to
> > steal_account_process_time(), does the steal time
> > get accounted properly at 75%?  
> 
> Yes.

I talked with Paolo this morning, and it turns out that if a guest
misses several timer ticks in a row, they will simply get lost.

That means the functions calling steal_account_process_time may not
know how much CPU time has passed since the last time it was called,
but steal_account_process_time will get a good idea on how much time
the host spent running something else.

Removing the limit, and documenting why, seems like the right way to
fix this bug.

Wanpeng, does the patch below work for you?

Everybody else, does this patch look acceptable?

---8<---
Subject: time,virt: do not limit steal_account_process_time

When a guest is interrupted for a longer amount of time, missed clock
ticks are not redelivered later. Because of that, we should not limit
the amount of steal time accounted to the amount of time that the
calling functions think have passed.

Instead, simply let steal_account_process_time account however much
steal time the host told us elapsed. This can make up timer ticks
that were missed when the host scheduled somebody else.

Signed-off-by: Rik van Riel <riel@redhat.com>
Reported-by: Wanpeng Li <kernellwp@gmail.com>
---
 kernel/sched/cputime.c | 13 +++++++++----
 1 file changed, 9 insertions(+), 4 deletions(-)

diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index 1934f658c036..6f15274940fb 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -263,7 +263,12 @@ void account_idle_time(cputime_t cputime)
 		cpustat[CPUTIME_IDLE] += (__force u64) cputime;
 }
 
-static __always_inline cputime_t steal_account_process_time(cputime_t maxtime)
+/*
+ * When a guest is interrupted for a longer amount of time, missed clock
+ * ticks are not redelivered later. Due to that, this function may on
+ * occasion account more time than the calling functions think elapsed.
+ */
+static __always_inline cputime_t steal_account_process_time(void)
 {
 #ifdef CONFIG_PARAVIRT
 	if (static_key_false(&paravirt_steal_enabled)) {
@@ -273,7 +278,7 @@ static __always_inline cputime_t steal_account_process_time(cputime_t maxtime)
 		steal = paravirt_steal_clock(smp_processor_id());
 		steal -= this_rq()->prev_steal_time;
 
-		steal_cputime = min(nsecs_to_cputime(steal), maxtime);
+		steal_cputime = nsecs_to_cputime(steal);
 		account_steal_time(steal_cputime);
 		this_rq()->prev_steal_time += cputime_to_nsecs(steal_cputime);
 
@@ -290,7 +295,7 @@ static inline cputime_t account_other_time(cputime_t max)
 {
 	cputime_t accounted;
 
-	accounted = steal_account_process_time(max);
+	accounted = steal_account_process_time();
 
 	if (accounted < max)
 		accounted += irqtime_account_hi_update(max - accounted);
@@ -486,7 +491,7 @@ void account_process_tick(struct task_struct *p, int user_tick)
 	}
 
 	cputime = cputime_one_jiffy;
-	steal = steal_account_process_time(cputime);
+	steal = steal_account_process_time();
 
 	if (steal >= cputime)
 		return;

[toc] | [prev] | [next] | [standalone]

#1461631

On Fri, Aug 12, 2016 at 11:58:03AM -0400, Rik van Riel wrote:
> On Fri, 12 Aug 2016 15:09:00 +0800
> Wanpeng Li <kernellwp@gmail.com> wrote:
> > 2016-08-12 10:44 GMT+08:00 Rik van Riel <riel@redhat.com>:
> 
> > > If you pass ULONG_MAX as the maxtime argument to
> > > steal_account_process_time(), does the steal time
> > > get accounted properly at 75%?  
> > 
> > Yes.
> 
> I talked with Paolo this morning, and it turns out that if a guest
> misses several timer ticks in a row, they will simply get lost.
> 
> That means the functions calling steal_account_process_time may not
> know how much CPU time has passed since the last time it was called,
> but steal_account_process_time will get a good idea on how much time
> the host spent running something else.
> 
> Removing the limit, and documenting why, seems like the right way to
> fix this bug.
> 
> Wanpeng, does the patch below work for you?
> 
> Everybody else, does this patch look acceptable?
> 
> ---8<---
> Subject: time,virt: do not limit steal_account_process_time
> 
> When a guest is interrupted for a longer amount of time, missed clock
> ticks are not redelivered later. Because of that, we should not limit
> the amount of steal time accounted to the amount of time that the
> calling functions think have passed.
> 
> Instead, simply let steal_account_process_time account however much
> steal time the host told us elapsed. This can make up timer ticks
> that were missed when the host scheduled somebody else.
> 
> Signed-off-by: Rik van Riel <riel@redhat.com>
> Reported-by: Wanpeng Li <kernellwp@gmail.com>

I much prefer this version. After all, even if that time spent in
host is very large, it's still stolen time and we want to account it.

Thanks.

[toc] | [prev] | [next] | [standalone]

#1462646

2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
[...]
> Wanpeng, does the patch below work for you?

It will break steal time for full dynticks guest, and there is a
calltrace of thread_group_cputime_adjusted call stack, RIP is
cputime_adjust+0xff/0x130.

>
> Everybody else, does this patch look acceptable?
>
> ---8<---
> Subject: time,virt: do not limit steal_account_process_time
>
> When a guest is interrupted for a longer amount of time, missed clock
> ticks are not redelivered later. Because of that, we should not limit

Interesting, so do we need to add a feature like lapic timer
interrrupt coalescing in kvm? There is a RTC interrupt coalescing in
qemu to handle the scenario you mentioned for windows guest, if we
need a similar feature for linux guest? Paolo, Radim? I can try it if
you think it's valuable. :)

Regards,
Wanpeng Li

[toc] | [prev] | [next] | [standalone]

#1462721

2016-08-15 16:53 GMT+08:00 Wanpeng Li <kernellwp@gmail.com>:
> 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
> [...]
>> Wanpeng, does the patch below work for you?
>
> It will break steal time for full dynticks guest, and there is a
> calltrace of thread_group_cputime_adjusted call stack, RIP is
> cputime_adjust+0xff/0x130.

I have a patch on hand, will send out soon. :)

Regards,
Wanpeng Li

[toc] | [prev] | [next] | [standalone]

#1462863

[Multipart message — attachments visible in raw view] — view raw

On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
> 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
> [...]
> > Wanpeng, does the patch below work for you?
> 
> It will break steal time for full dynticks guest, and there is a
> calltrace of thread_group_cputime_adjusted call stack, RIP is
> cputime_adjust+0xff/0x130.

How?  This patch is equivalent to passing ULONG_MAX to
steal_account_process_time, which you tried to no ill
effect before.

Do you have the full call trace?

> > Subject: time,virt: do not limit steal_account_process_time
> > 
> > When a guest is interrupted for a longer amount of time, missed
> > clock
> > ticks are not redelivered later. Because of that, we should not
> > limit
> 
> Interesting, so do we need to add a feature like lapic timer
> interrrupt coalescing in kvm? There is a RTC interrupt coalescing in
> qemu to handle the scenario you mentioned for windows guest, if we
> need a similar feature for linux guest? Paolo, Radim? I can try it if
> you think it's valuable. :)
> 
> Regards,
> Wanpeng Li
-- 

All Rights Reversed.

[toc] | [prev] | [next] | [standalone]

#1463219

2016-08-15 23:00 GMT+08:00 Rik van Riel <riel@redhat.com>:
> On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
>> 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> [...]
>> > Wanpeng, does the patch below work for you?
>>
>> It will break steal time for full dynticks guest, and there is a
>> calltrace of thread_group_cputime_adjusted call stack, RIP is
>> cputime_adjust+0xff/0x130.
>
> How?  This patch is equivalent to passing ULONG_MAX to
> steal_account_process_time, which you tried to no ill
> effect before.

https://lkml.org/lkml/2016/8/15/217 I sent out a patch yesterday which
can fix the regression. Your patch breaks full dynticks guest since
vtime doesn't depend on clock ticks, so we should keep the max cputime
limit for it as my patch description mentioned, remove the limit for
vtime results in the calltrace. My patch does what Paolo suggested
https://lkml.org/lkml/2016/8/12/380 for lost ticks scenario.

Regards,
Wanpeng Li

[toc] | [prev] | [next] | [standalone]

#1463330

2016-08-15 23:00 GMT+08:00 Rik van Riel <riel@redhat.com>:
> On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
>> 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> [...]
>> > Wanpeng, does the patch below work for you?
>>
>> It will break steal time for full dynticks guest, and there is a
>> calltrace of thread_group_cputime_adjusted call stack, RIP is
>> cputime_adjust+0xff/0x130.
>
> How?  This patch is equivalent to passing ULONG_MAX to
> steal_account_process_time, which you tried to no ill
> effect before.

https://lkml.org/lkml/2016/6/8/404/ Paolo original suggested to add
the max cputime limit to the vtime, when the cpu is running in nohz
full mode and stop the tick, jiffies will be updated depends on clock
source instead of clock event device in
guest(tick_nohz_update_jiffies() callsite, ktime_get()), so it will
not be affected by lost clock ticks, my patch keeps the limit for
vtime and remove the limit to non-vtime. However, your patch removes
the limit for both scenarios and results in the below calltrace for
vtime.

>
> Do you have the full call trace?

[    6.929856] divide error: 0000 [#1] SMP
[    6.934217] Modules linked in:
[    6.937759] CPU: 3 PID: 57 Comm: kworker/u8:1 Not tainted 4.7.0+ #36
[    6.946105] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS Bochs 01/01/2011
[    6.953951] Workqueue: events_unbound call_usermodehelper_exec_work
[    6.965726] task: ffff8e22b9785040 task.stack: ffff8e22b8b64000
[    6.970820] RIP: 0010:[<ffffffff870c7b4f>]  [<ffffffff870c7b4f>]
cputime_adjust+0xff/0x130
[    6.981841] RSP: 0000:ffff8e22b8b67b78  EFLAGS: 00010887
[    6.985946] RAX: a528afff5ad75000 RBX: ffff8e222e243c18 RCX: ffff8e22b8b67c28
[    7.001166] RDX: 0000000000000000 RSI: 0000000000000296 RDI: 0000000000000000
[    7.008758] RBP: ffff8e22b8b67ba8 R08: 00000000ffffffff R09: 00000000a528b000
[    7.015653] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000014a516
[    7.021376] R13: ffff8e22b8b67bb8 R14: ffff8e222e243c28 R15: ffff8e22b8b67c20
[    7.035498] FS:  0000000000000000(0000) GS:ffff8e22bac00000(0000)
knlGS:0000000000000000
[    7.054809] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    7.066571] CR2: 00000000ffffffff CR3: 000000007ae06000 CR4: 00000000001406e0
[    7.075162] Stack:
[    7.090141]  ffff8e22b8b67c28 ffff8e222e371ac0 ffff8e22b8b67c20
ffff8e22b8b67c28
[    7.108512]  ffff8e222e371ac0 ffff8e22b8b67cc0 ffff8e22b8b67be8
ffffffff870c8c01
[    7.123025]  00000000000e0471 fffffffffffdcf32 000000000014a516
ffff8e22b9785040
[    7.140622] Call Trace:
[    7.153076]  [<ffffffff870c8c01>] thread_group_cputime_adjusted+0x41/0x50
[    7.160807]  [<ffffffff870913bf>] wait_consider_task+0xa4f/0xff0
[    7.176449]  [<ffffffff87090fc1>] ? wait_consider_task+0x651/0xff0
[    7.186281]  [<ffffffff87091a3f>] ? do_wait+0xdf/0x320
[    7.226606]  [<ffffffff87091a7b>] do_wait+0x11b/0x320
[    7.239670]  [<ffffffff87093014>] SyS_wait4+0x64/0xc0
[    7.245385]  [<ffffffff87090180>] ? task_stopped_code+0x50/0x50
[    7.255924]  [<ffffffff870a8470>] call_usermodehelper_exec_work+0x70/0xb0
[    7.263011]  [<ffffffff870acbd0>] process_one_work+0x1e0/0x670
[    7.273051]  [<ffffffff870acb51>] ? process_one_work+0x161/0x670
[    7.277991]  [<ffffffff870ad18b>] worker_thread+0x12b/0x4a0
[    7.286920]  [<ffffffff870ad060>] ? process_one_work+0x670/0x670
[    7.291745]  [<ffffffff870b4011>] kthread+0x101/0x120
[    7.296878]  [<ffffffff878c94cf>] ret_from_fork+0x1f/0x40
[    7.306511]  [<ffffffff870b3f10>] ? kthread_create_on_node+0x250/0x250
[    7.311985] Code: 4d 39 c8 76 c1 4c 89 d0 48 c1 e8 20 48 85 c0 74
ca 4c 89 c0 49 d1 ea 4d 89 c8 48 d1 e8 49 89 c1 eb 9f 44 89 c8 31 d2
49 0f af c0 <49> f7 f2 4d 89 e2 48 39 f8 48 0f 42 c7 49 29 c2 4d 39 d3
76 0b
[    7.357565] RIP  [<ffffffff870c7b4f>] cputime_adjust+0xff/0x130
[    7.364633]  RSP <ffff8e22b8b67b78>
[    7.373247] ---[ end trace 76ca7475a22c5d43 ]---

[toc] | [prev] | [next] | [standalone]

#1463346

[Multipart message — attachments visible in raw view] — view raw

On Tue, 2016-08-16 at 09:31 +0800, Wanpeng Li wrote:
> 2016-08-15 23:00 GMT+08:00 Rik van Riel <riel@redhat.com>:
> > On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
> > > 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
> > > [...]
> > > > Wanpeng, does the patch below work for you?
> > > 
> > > It will break steal time for full dynticks guest, and there is a
> > > calltrace of thread_group_cputime_adjusted call stack, RIP is
> > > cputime_adjust+0xff/0x130.
> > 
> > How?  This patch is equivalent to passing ULONG_MAX to
> > steal_account_process_time, which you tried to no ill
> > effect before.
> 
> https://lkml.org/lkml/2016/6/8/404/ Paolo original suggested to add
> the max cputime limit to the vtime, when the cpu is running in nohz
> full mode and stop the tick, jiffies will be updated depends on clock
> source instead of clock event device in
> guest(tick_nohz_update_jiffies() callsite, ktime_get()), so it will
> not be affected by lost clock ticks, my patch keeps the limit for
> vtime and remove the limit to non-vtime. However, your patch removes
> the limit for both scenarios and results in the below calltrace for
> vtime.

I understand what it does.

What I would like to understand is WHY enforcing the limit
is the right thing when using vtime, and the wrong thing
in all other scenarios.

Can you explain why you change the limit to ULONG_MAX in
three call sites, but not in the last one?

What is different about the first three, versus the last
one?

Are you sure it should be changed in three places, and
not in eg. two?

This seems like something we should try to understand,
rather than patch up haphazardly.

The changelog of your patch could use an explanation of
why the change is the correct way to go.

> > 
> > Do you have the full call trace?

OK, so you are seeing a divide by zero in cputime_adjust.

Specifically, this would be scale_stime getting passed
a (utime + stime) that adds up to 0. Stranger still, that
only gets called if neither utime or stime is 0, meaning
that one of utime or stime is negative, at the exact same
magnitude as the other.

Looking at thread_group_cputime(), I see some room for
rounding errors.

        do {
                seq = nextseq;
                flags = read_seqbegin_or_lock_irqsave(&sig->stats_lock, 
&seq);
                times->utime = sig->utime;
                times->stime = sig->stime;
                times->sum_exec_runtime = sig->sum_sched_runtime;

                for_each_thread(tsk, t) {
                        task_cputime(t, &utime, &stime);
                        times->utime += utime;
                        times->stime += stime;
                        times->sum_exec_runtime +=
task_sched_runtime(t);
                }
                /* If lockless access failed, take the lock. */
                nextseq = 1;
        } while (need_seqretry(&sig->stats_lock, seq));

Specifically, task_cputime calls vtime_delta, which works
off jiffies, while task_sched_runtime works straight off
the sched clock.

I can see how this would lead to a non-zero ->sum_exec_runtime,
while ->utime and/or ->stime are still at zero. This is fine.

What I do not see is how ->utime or ->stime could end up negative,
which is what would be needed to hit that divide by zero.

Unless I am overlooking something...

This would be a good thing to debug.

> [    6.929856] divide error: 0000 [#1] SMP
> [    6.934217] Modules linked in:
> [    6.937759] CPU: 3 PID: 57 Comm: kworker/u8:1 Not tainted 4.7.0+
> #36
> [    6.946105] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS Bochs 01/01/2011
> [    6.953951] Workqueue: events_unbound
> call_usermodehelper_exec_work
> [    6.965726] task: ffff8e22b9785040 task.stack: ffff8e22b8b64000
> [    6.970820] RIP: 0010:[<ffffffff870c7b4f>]  [<ffffffff870c7b4f>]
> cputime_adjust+0xff/0x130
> [    6.981841] RSP: 0000:ffff8e22b8b67b78  EFLAGS: 00010887
> [    6.985946] RAX: a528afff5ad75000 RBX: ffff8e222e243c18 RCX:
> ffff8e22b8b67c28
> [    7.001166] RDX: 0000000000000000 RSI: 0000000000000296 RDI:
> 0000000000000000
> [    7.008758] RBP: ffff8e22b8b67ba8 R08: 00000000ffffffff R09:
> 00000000a528b000
> [    7.015653] R10: 0000000000000000 R11: 0000000000000000 R12:
> 000000000014a516
> [    7.021376] R13: ffff8e22b8b67bb8 R14: ffff8e222e243c28 R15:
> ffff8e22b8b67c20
> [    7.035498] FS:  0000000000000000(0000) GS:ffff8e22bac00000(0000)
> knlGS:0000000000000000
> [    7.054809] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [    7.066571] CR2: 00000000ffffffff CR3: 000000007ae06000 CR4:
> 00000000001406e0
> [    7.075162] Stack:
> [    7.090141]  ffff8e22b8b67c28 ffff8e222e371ac0 ffff8e22b8b67c20
> ffff8e22b8b67c28
> [    7.108512]  ffff8e222e371ac0 ffff8e22b8b67cc0 ffff8e22b8b67be8
> ffffffff870c8c01
> [    7.123025]  00000000000e0471 fffffffffffdcf32 000000000014a516
> ffff8e22b9785040
> [    7.140622] Call Trace:
> [    7.153076]  [<ffffffff870c8c01>]
> thread_group_cputime_adjusted+0x41/0x50
> [    7.160807]  [<ffffffff870913bf>] wait_consider_task+0xa4f/0xff0
> [    7.176449]  [<ffffffff87090fc1>] ? wait_consider_task+0x651/0xff0
> [    7.186281]  [<ffffffff87091a3f>] ? do_wait+0xdf/0x320
> [    7.226606]  [<ffffffff87091a7b>] do_wait+0x11b/0x320
> [    7.239670]  [<ffffffff87093014>] SyS_wait4+0x64/0xc0
> [    7.245385]  [<ffffffff87090180>] ? task_stopped_code+0x50/0x50
> [    7.255924]  [<ffffffff870a8470>]
> call_usermodehelper_exec_work+0x70/0xb0
> [    7.263011]  [<ffffffff870acbd0>] process_one_work+0x1e0/0x670
> [    7.273051]  [<ffffffff870acb51>] ? process_one_work+0x161/0x670
> [    7.277991]  [<ffffffff870ad18b>] worker_thread+0x12b/0x4a0
> [    7.286920]  [<ffffffff870ad060>] ? process_one_work+0x670/0x670
> [    7.291745]  [<ffffffff870b4011>] kthread+0x101/0x120
> [    7.296878]  [<ffffffff878c94cf>] ret_from_fork+0x1f/0x40
> [    7.306511]  [<ffffffff870b3f10>] ?
> kthread_create_on_node+0x250/0x250
> [    7.311985] Code: 4d 39 c8 76 c1 4c 89 d0 48 c1 e8 20 48 85 c0 74
> ca 4c 89 c0 49 d1 ea 4d 89 c8 48 d1 e8 49 89 c1 eb 9f 44 89 c8 31 d2
> 49 0f af c0 <49> f7 f2 4d 89 e2 48 39 f8 48 0f 42 c7 49 29 c2 4d 39
> d3
> 76 0b
> [    7.357565] RIP  [<ffffffff870c7b4f>] cputime_adjust+0xff/0x130
> [    7.364633]  RSP <ffff8e22b8b67b78>
> [    7.373247] ---[ end trace 76ca7475a22c5d43 ]---
-- 

All Rights Reversed.

[toc] | [prev] | [next] | [standalone]

#1463465

2016-08-16 10:11 GMT+08:00 Rik van Riel <riel@redhat.com>:
> On Tue, 2016-08-16 at 09:31 +0800, Wanpeng Li wrote:
>> 2016-08-15 23:00 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> > On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
>> > > 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> > > [...]
>> > > > Wanpeng, does the patch below work for you?
>> > >
>> > > It will break steal time for full dynticks guest, and there is a
>> > > calltrace of thread_group_cputime_adjusted call stack, RIP is
>> > > cputime_adjust+0xff/0x130.
>> >
>> > How?  This patch is equivalent to passing ULONG_MAX to
>> > steal_account_process_time, which you tried to no ill
>> > effect before.
>>
>> https://lkml.org/lkml/2016/6/8/404/ Paolo original suggested to add
>> the max cputime limit to the vtime, when the cpu is running in nohz
>> full mode and stop the tick, jiffies will be updated depends on clock
>> source instead of clock event device in
>> guest(tick_nohz_update_jiffies() callsite, ktime_get()), so it will
>> not be affected by lost clock ticks, my patch keeps the limit for
>> vtime and remove the limit to non-vtime. However, your patch removes
>> the limit for both scenarios and results in the below calltrace for
>> vtime.
>
> I understand what it does.
>
> What I would like to understand is WHY enforcing the limit
> is the right thing when using vtime, and the wrong thing
> in all other scenarios.

I observed that function get_vtime_delta() underflow which means that
delta < other when debugging your bugfix patch, I believe that is why
Paolo suggested to add the max cputime limit to vtime, he also pointed
out the potentional underflow before
https://lkml.org/lkml/2016/6/8/404/

>
> Can you explain why you change the limit to ULONG_MAX in
> three call sites, but not in the last one?
>
> What is different about the first three, versus the last
> one?
>
> Are you sure it should be changed in three places, and
> not in eg. two?
>
> This seems like something we should try to understand,
> rather than patch up haphazardly.
>
> The changelog of your patch could use an explanation of
> why the change is the correct way to go.
>
>> >
>> > Do you have the full call trace?
>
> OK, so you are seeing a divide by zero in cputime_adjust.
>
> Specifically, this would be scale_stime getting passed
> a (utime + stime) that adds up to 0. Stranger still, that
> only gets called if neither utime or stime is 0, meaning
> that one of utime or stime is negative, at the exact same
> magnitude as the other.
>
> Looking at thread_group_cputime(), I see some room for
> rounding errors.
>
>         do {
>                 seq = nextseq;
>                 flags = read_seqbegin_or_lock_irqsave(&sig->stats_lock,
> &seq);
>                 times->utime = sig->utime;
>                 times->stime = sig->stime;
>                 times->sum_exec_runtime = sig->sum_sched_runtime;
>
>                 for_each_thread(tsk, t) {
>                         task_cputime(t, &utime, &stime);
>                         times->utime += utime;
>                         times->stime += stime;
>                         times->sum_exec_runtime +=
> task_sched_runtime(t);
>                 }
>                 /* If lockless access failed, take the lock. */
>                 nextseq = 1;
>         } while (need_seqretry(&sig->stats_lock, seq));
>
> Specifically, task_cputime calls vtime_delta, which works
> off jiffies, while task_sched_runtime works straight off
> the sched clock.

I try to replace task_sched_runtime() by t->se.sum_exec_runtime just
for testing (refer to Commit d670ec13178d0 "posix-cpu-timers: Cure SMP
wobbles"), divide zero still appear.

>
> I can see how this would lead to a non-zero ->sum_exec_runtime,
> while ->utime and/or ->stime are still at zero. This is fine.
>
> What I do not see is how ->utime or ->stime could end up negative,
> which is what would be needed to hit that divide by zero.

stime is negative since underflow incurred in function
get_vtime_delta(), however, it is u64, so it is a very big number, and
the total is 0 after for loop in scale_time(), but not 0 before that.

Regards,
Wanpeng Li

[toc] | [prev] | [next] | [standalone]

#1463843

[Multipart message — attachments visible in raw view] — view raw

On Tue, 2016-08-16 at 14:54 +0800, Wanpeng Li wrote:
> 2016-08-16 10:11 GMT+08:00 Rik van Riel <riel@redhat.com>:
> > On Tue, 2016-08-16 at 09:31 +0800, Wanpeng Li wrote:
> > > 2016-08-15 23:00 GMT+08:00 Rik van Riel <riel@redhat.com>:
> > > > On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
> > > > > 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
> > > > > [...]
> > > > > > Wanpeng, does the patch below work for you?
> > > > > 
> > > > > It will break steal time for full dynticks guest, and there
> > > > > is a
> > > > > calltrace of thread_group_cputime_adjusted call stack, RIP is
> > > > > cputime_adjust+0xff/0x130.
> > > > 
> > > > How?  This patch is equivalent to passing ULONG_MAX to
> > > > steal_account_process_time, which you tried to no ill
> > > > effect before.
> > > 
> > > https://lkml.org/lkml/2016/6/8/404/ Paolo original suggested to
> > > add
> > > the max cputime limit to the vtime, when the cpu is running in
> > > nohz
> > > full mode and stop the tick, jiffies will be updated depends on
> > > clock
> > > source instead of clock event device in
> > > guest(tick_nohz_update_jiffies() callsite, ktime_get()), so it
> > > will
> > > not be affected by lost clock ticks, my patch keeps the limit for
> > > vtime and remove the limit to non-vtime. However, your patch
> > > removes
> > > the limit for both scenarios and results in the below calltrace
> > > for
> > > vtime.
> > 
> > I understand what it does.
> > 
> > What I would like to understand is WHY enforcing the limit
> > is the right thing when using vtime, and the wrong thing
> > in all other scenarios.
> 
> I observed that function get_vtime_delta() underflow which means that
> delta < other when debugging your bugfix patch, I believe that is why
> Paolo suggested to add the max cputime limit to vtime, he also
> pointed
> out the potentional underflow before
> https://lkml.org/lkml/2016/6/8/404/

Looking at get_vtime_delta() I can see exactly how the underflow
can happen.  The interval returned by account_other_time() is NOT
rounded down to the nearest jiffy, while the base interval it is
subtracted from is.

Furthermore, even if we did not have that rounding issue, a guest
could get preempted in-between determining delta, and calling
account_other_time(), which could also cause the issue.

Could you re-send your patch with a comment in get_vtime_delta(),
as well as the changelog, explaining exactly why account_other_time()
should be limited from get_vtime_delta(), but not from the other
three call sites?

Documentation could save future developers a bunch of debugging
time on this code.

thanks,

Rik
-- 

All Rights Reversed.

[toc] | [prev] | [next] | [standalone]

#1464229

2016-08-16 22:01 GMT+08:00 Rik van Riel <riel@redhat.com>:
> On Tue, 2016-08-16 at 14:54 +0800, Wanpeng Li wrote:
>> 2016-08-16 10:11 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> > On Tue, 2016-08-16 at 09:31 +0800, Wanpeng Li wrote:
>> > > 2016-08-15 23:00 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> > > > On Mon, 2016-08-15 at 16:53 +0800, Wanpeng Li wrote:
>> > > > > 2016-08-12 23:58 GMT+08:00 Rik van Riel <riel@redhat.com>:
>> > > > > [...]
>> > > > > > Wanpeng, does the patch below work for you?
>> > > > >
>> > > > > It will break steal time for full dynticks guest, and there
>> > > > > is a
>> > > > > calltrace of thread_group_cputime_adjusted call stack, RIP is
>> > > > > cputime_adjust+0xff/0x130.
>> > > >
>> > > > How?  This patch is equivalent to passing ULONG_MAX to
>> > > > steal_account_process_time, which you tried to no ill
>> > > > effect before.
>> > >
>> > > https://lkml.org/lkml/2016/6/8/404/ Paolo original suggested to
>> > > add
>> > > the max cputime limit to the vtime, when the cpu is running in
>> > > nohz
>> > > full mode and stop the tick, jiffies will be updated depends on
>> > > clock
>> > > source instead of clock event device in
>> > > guest(tick_nohz_update_jiffies() callsite, ktime_get()), so it
>> > > will
>> > > not be affected by lost clock ticks, my patch keeps the limit for
>> > > vtime and remove the limit to non-vtime. However, your patch
>> > > removes
>> > > the limit for both scenarios and results in the below calltrace
>> > > for
>> > > vtime.
>> >
>> > I understand what it does.
>> >
>> > What I would like to understand is WHY enforcing the limit
>> > is the right thing when using vtime, and the wrong thing
>> > in all other scenarios.
>>
>> I observed that function get_vtime_delta() underflow which means that
>> delta < other when debugging your bugfix patch, I believe that is why
>> Paolo suggested to add the max cputime limit to vtime, he also
>> pointed
>> out the potentional underflow before
>> https://lkml.org/lkml/2016/6/8/404/
>
> Looking at get_vtime_delta() I can see exactly how the underflow
> can happen.  The interval returned by account_other_time() is NOT
> rounded down to the nearest jiffy, while the base interval it is
> subtracted from is.
>
> Furthermore, even if we did not have that rounding issue, a guest
> could get preempted in-between determining delta, and calling
> account_other_time(), which could also cause the issue.
>
> Could you re-send your patch with a comment in get_vtime_delta(),
> as well as the changelog, explaining exactly why account_other_time()
> should be limited from get_vtime_delta(), but not from the other
> three call sites?
>
> Documentation could save future developers a bunch of debugging
> time on this code.

Will do. Thanks for bearing with me through such a long discussion,
I'm very happy we finally come to an agreement. :)

Regards,
Wanpeng Li

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web