Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Mon, May 15, 2017 at 04:17:10PM +0800, Wanpeng Li wrote:
> Ping,

Sorry for the late answer, I was focused on some other bugs.

So since my ideas weren't even clear on that issue yet, I took your
patch and enhanced the code around. I just posted a new series
with it, please have a look.

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Mon, May 15, 2017 at 04:17:10PM +0800, Wanpeng Li wrote:
> Ping,

Sorry for the late answer, I was focused on some other bugs.

So since my ideas weren't even clear on that issue yet, I took your
patch and enhanced the code around. I just posted a new series
with it, please have a look.

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

Ping,
2017-05-02 18:01 GMT+08:00 Wanpeng Li :
> Cc Paolo,
> 2017-04-13 21:32 GMT+08:00 Frederic Weisbecker :
>> On Thu, Apr 13, 2017 at 12:31:12PM +0800, Wanpeng Li wrote:
>>> 2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
>>> > On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
>>> >> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
>>> >> > It's not different from the current jiffies based stuff at all. Same
>>> >> > failure mode.
>>> >>
>>> >> Yes you're right, I got confused again. So to fix this we could do our 
>>> >> snapshots
>>> >> at a frequency lower than HZ but still high enough to avoid overhead.
>>> >>
>>> >> Something like TICK_NSEC / 2 ?
>>> >
>>> > If you are using TSC anyway then you can do proper accumulation for both
>>> > system and user and only account the data when the accumulation is more
>>> > than a jiffie.
>>>
>>> So I implement it as below:
>>>
>>> - HZ=1000.
>>>   1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>>   2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
>>> - HZ=250
>>>1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>>2) Luzi's testcase, 100% idle
>>>
>>> So the codes below still not work correctly for HZ=250, any suggestions?
>>
>> Right, so first lets reorder that code a bit so we can see clear inside :-)
>>
>>>
>>> -->8-
>>>
>>> diff --git a/include/linux/sched.h b/include/linux/sched.h
>>> index d67eee8..6a11771 100644
>>> --- a/include/linux/sched.h
>>> +++ b/include/linux/sched.h
>>> @@ -668,6 +668,8 @@ struct task_struct {
>>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>>  seqcount_tvtime_seqcount;
>>>  unsigned long longvtime_snap;
>>> +u64vtime_acct_utime;
>>> +u64vtime_acct_stime;
>>
>> You need to accumulate guest and steal time as well.
>>
>
> Hi Frederic,
>
> Sorry for the delay since I'm too busy recently, I just add guest time
> and idle time accumulations as below, the code work as we expected for
> native kernel, however, the testcase fails when it runs in kvm guest.
> Top shows ~99% sys for Luzi's testcase "./acct-bug 1 995" which we
> expect 95% user  and %5 idle. In addition, what's the design idea of
> steal time accumluation in your mind? Pass the tsk parameter in the
> function get_vtime_delta() down to the function
> steal_account_process_time()?
>
> -->8-
>
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index 4cf9a59..56815cd 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -672,6 +672,10 @@ struct task_struct {
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  seqcount_tvtime_seqcount;
>  unsigned long longvtime_snap;
> +u64vtime_acct_utime;
> +u64vtime_acct_stime;
> +u64vtime_acct_idle_time;
> +u64vtime_acct_guest_time;
>  enum {
>  /* Task is sleeping or running in a CPU with VTIME inactive: */
>  VTIME_INACTIVE = 0,
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..2d950c6 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,19 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +unsigned long long clock;
>
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> +clock = sched_clock();
> +if (clock < tsk->vtime_snap)
>  return 0;
>
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +return clock - tsk->vtime_snap;
>  }
>
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk);
> +u64 other;
>
>  /*
>   * Unlike tick based timing, vtime based timing never has lost
> @@ -696,17 +697,16 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>   * elapsed time. Limit account_other_time to prevent rounding
>   * errors from causing elapsed vtime to go negative.
>   */
> -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
>  other = account_other_time(delta);
>  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> -tsk->vtime_snap = now;
> +tsk->vtime_snap += delta;
>
>  return delta - other;
>  }
>
>  static void __vtime_account_system(struct task_struct *tsk)
>  {
> -account_system_time(tsk, irq_count(), get_vtime_delta(tsk));
> +account_system_time(tsk, irq_count(), tsk->vtime_acct_stime);
>  }
>
>  void vtime_account_system(struct task_struct *tsk)
> @@ -715,7 +715,11 @@ void 

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

Ping,
2017-05-02 18:01 GMT+08:00 Wanpeng Li :
> Cc Paolo,
> 2017-04-13 21:32 GMT+08:00 Frederic Weisbecker :
>> On Thu, Apr 13, 2017 at 12:31:12PM +0800, Wanpeng Li wrote:
>>> 2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
>>> > On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
>>> >> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
>>> >> > It's not different from the current jiffies based stuff at all. Same
>>> >> > failure mode.
>>> >>
>>> >> Yes you're right, I got confused again. So to fix this we could do our 
>>> >> snapshots
>>> >> at a frequency lower than HZ but still high enough to avoid overhead.
>>> >>
>>> >> Something like TICK_NSEC / 2 ?
>>> >
>>> > If you are using TSC anyway then you can do proper accumulation for both
>>> > system and user and only account the data when the accumulation is more
>>> > than a jiffie.
>>>
>>> So I implement it as below:
>>>
>>> - HZ=1000.
>>>   1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>>   2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
>>> - HZ=250
>>>1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>>2) Luzi's testcase, 100% idle
>>>
>>> So the codes below still not work correctly for HZ=250, any suggestions?
>>
>> Right, so first lets reorder that code a bit so we can see clear inside :-)
>>
>>>
>>> -->8-
>>>
>>> diff --git a/include/linux/sched.h b/include/linux/sched.h
>>> index d67eee8..6a11771 100644
>>> --- a/include/linux/sched.h
>>> +++ b/include/linux/sched.h
>>> @@ -668,6 +668,8 @@ struct task_struct {
>>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>>  seqcount_tvtime_seqcount;
>>>  unsigned long longvtime_snap;
>>> +u64vtime_acct_utime;
>>> +u64vtime_acct_stime;
>>
>> You need to accumulate guest and steal time as well.
>>
>
> Hi Frederic,
>
> Sorry for the delay since I'm too busy recently, I just add guest time
> and idle time accumulations as below, the code work as we expected for
> native kernel, however, the testcase fails when it runs in kvm guest.
> Top shows ~99% sys for Luzi's testcase "./acct-bug 1 995" which we
> expect 95% user  and %5 idle. In addition, what's the design idea of
> steal time accumluation in your mind? Pass the tsk parameter in the
> function get_vtime_delta() down to the function
> steal_account_process_time()?
>
> -->8-
>
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index 4cf9a59..56815cd 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -672,6 +672,10 @@ struct task_struct {
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  seqcount_tvtime_seqcount;
>  unsigned long longvtime_snap;
> +u64vtime_acct_utime;
> +u64vtime_acct_stime;
> +u64vtime_acct_idle_time;
> +u64vtime_acct_guest_time;
>  enum {
>  /* Task is sleeping or running in a CPU with VTIME inactive: */
>  VTIME_INACTIVE = 0,
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..2d950c6 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,19 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +unsigned long long clock;
>
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> +clock = sched_clock();
> +if (clock < tsk->vtime_snap)
>  return 0;
>
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +return clock - tsk->vtime_snap;
>  }
>
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk);
> +u64 other;
>
>  /*
>   * Unlike tick based timing, vtime based timing never has lost
> @@ -696,17 +697,16 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>   * elapsed time. Limit account_other_time to prevent rounding
>   * errors from causing elapsed vtime to go negative.
>   */
> -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
>  other = account_other_time(delta);
>  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> -tsk->vtime_snap = now;
> +tsk->vtime_snap += delta;
>
>  return delta - other;
>  }
>
>  static void __vtime_account_system(struct task_struct *tsk)
>  {
> -account_system_time(tsk, irq_count(), get_vtime_delta(tsk));
> +account_system_time(tsk, irq_count(), tsk->vtime_acct_stime);
>  }
>
>  void vtime_account_system(struct task_struct *tsk)
> @@ -715,7 +715,11 @@ void vtime_account_system(struct task_struct *tsk)
>  return;
>
>  

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

Cc Paolo,
2017-04-13 21:32 GMT+08:00 Frederic Weisbecker :
> On Thu, Apr 13, 2017 at 12:31:12PM +0800, Wanpeng Li wrote:
>> 2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
>> > On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
>> >> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
>> >> > It's not different from the current jiffies based stuff at all. Same
>> >> > failure mode.
>> >>
>> >> Yes you're right, I got confused again. So to fix this we could do our 
>> >> snapshots
>> >> at a frequency lower than HZ but still high enough to avoid overhead.
>> >>
>> >> Something like TICK_NSEC / 2 ?
>> >
>> > If you are using TSC anyway then you can do proper accumulation for both
>> > system and user and only account the data when the accumulation is more
>> > than a jiffie.
>>
>> So I implement it as below:
>>
>> - HZ=1000.
>>   1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>   2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
>> - HZ=250
>>1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>2) Luzi's testcase, 100% idle
>>
>> So the codes below still not work correctly for HZ=250, any suggestions?
>
> Right, so first lets reorder that code a bit so we can see clear inside :-)
>
>>
>> -->8-
>>
>> diff --git a/include/linux/sched.h b/include/linux/sched.h
>> index d67eee8..6a11771 100644
>> --- a/include/linux/sched.h
>> +++ b/include/linux/sched.h
>> @@ -668,6 +668,8 @@ struct task_struct {
>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>  seqcount_tvtime_seqcount;
>>  unsigned long longvtime_snap;
>> +u64vtime_acct_utime;
>> +u64vtime_acct_stime;
>
> You need to accumulate guest and steal time as well.
>

Hi Frederic,

Sorry for the delay since I'm too busy recently, I just add guest time
and idle time accumulations as below, the code work as we expected for
native kernel, however, the testcase fails when it runs in kvm guest.
Top shows ~99% sys for Luzi's testcase "./acct-bug 1 995" which we
expect 95% user  and %5 idle. In addition, what's the design idea of
steal time accumluation in your mind? Pass the tsk parameter in the
function get_vtime_delta() down to the function
steal_account_process_time()?

-->8-

diff --git a/include/linux/sched.h b/include/linux/sched.h
index 4cf9a59..56815cd 100644
--- a/include/linux/sched.h
+++ b/include/linux/sched.h
@@ -672,6 +672,10 @@ struct task_struct {
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 seqcount_tvtime_seqcount;
 unsigned long longvtime_snap;
+u64vtime_acct_utime;
+u64vtime_acct_stime;
+u64vtime_acct_idle_time;
+u64vtime_acct_guest_time;
 enum {
 /* Task is sleeping or running in a CPU with VTIME inactive: */
 VTIME_INACTIVE = 0,
diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..2d950c6 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -676,18 +676,19 @@ void thread_group_cputime_adjusted(struct
task_struct *p, u64 *ut, u64 *st)
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 static u64 vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
+unsigned long long clock;

-if (time_before(now, (unsigned long)tsk->vtime_snap))
+clock = sched_clock();
+if (clock < tsk->vtime_snap)
 return 0;

-return jiffies_to_nsecs(now - tsk->vtime_snap);
+return clock - tsk->vtime_snap;
 }

 static u64 get_vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
-u64 delta, other;
+u64 delta = vtime_delta(tsk);
+u64 other;

 /*
  * Unlike tick based timing, vtime based timing never has lost
@@ -696,17 +697,16 @@ static u64 get_vtime_delta(struct task_struct *tsk)
  * elapsed time. Limit account_other_time to prevent rounding
  * errors from causing elapsed vtime to go negative.
  */
-delta = jiffies_to_nsecs(now - tsk->vtime_snap);
 other = account_other_time(delta);
 WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
-tsk->vtime_snap = now;
+tsk->vtime_snap += delta;

 return delta - other;
 }

 static void __vtime_account_system(struct task_struct *tsk)
 {
-account_system_time(tsk, irq_count(), get_vtime_delta(tsk));
+account_system_time(tsk, irq_count(), tsk->vtime_acct_stime);
 }

 void vtime_account_system(struct task_struct *tsk)
@@ -715,7 +715,11 @@ void vtime_account_system(struct task_struct *tsk)
 return;

 write_seqcount_begin(>vtime_seqcount);
-__vtime_account_system(tsk);
+tsk->vtime_acct_stime += get_vtime_delta(tsk);
+if (tsk->vtime_acct_stime >= TICK_NSEC) {
+__vtime_account_system(tsk);

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

Cc Paolo,
2017-04-13 21:32 GMT+08:00 Frederic Weisbecker :
> On Thu, Apr 13, 2017 at 12:31:12PM +0800, Wanpeng Li wrote:
>> 2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
>> > On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
>> >> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
>> >> > It's not different from the current jiffies based stuff at all. Same
>> >> > failure mode.
>> >>
>> >> Yes you're right, I got confused again. So to fix this we could do our 
>> >> snapshots
>> >> at a frequency lower than HZ but still high enough to avoid overhead.
>> >>
>> >> Something like TICK_NSEC / 2 ?
>> >
>> > If you are using TSC anyway then you can do proper accumulation for both
>> > system and user and only account the data when the accumulation is more
>> > than a jiffie.
>>
>> So I implement it as below:
>>
>> - HZ=1000.
>>   1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>   2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
>> - HZ=250
>>1) two cpu hogs on cpu in nohz_full mode, 100% user time
>>2) Luzi's testcase, 100% idle
>>
>> So the codes below still not work correctly for HZ=250, any suggestions?
>
> Right, so first lets reorder that code a bit so we can see clear inside :-)
>
>>
>> -->8-
>>
>> diff --git a/include/linux/sched.h b/include/linux/sched.h
>> index d67eee8..6a11771 100644
>> --- a/include/linux/sched.h
>> +++ b/include/linux/sched.h
>> @@ -668,6 +668,8 @@ struct task_struct {
>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>  seqcount_tvtime_seqcount;
>>  unsigned long longvtime_snap;
>> +u64vtime_acct_utime;
>> +u64vtime_acct_stime;
>
> You need to accumulate guest and steal time as well.
>

Hi Frederic,

Sorry for the delay since I'm too busy recently, I just add guest time
and idle time accumulations as below, the code work as we expected for
native kernel, however, the testcase fails when it runs in kvm guest.
Top shows ~99% sys for Luzi's testcase "./acct-bug 1 995" which we
expect 95% user  and %5 idle. In addition, what's the design idea of
steal time accumluation in your mind? Pass the tsk parameter in the
function get_vtime_delta() down to the function
steal_account_process_time()?

-->8-

diff --git a/include/linux/sched.h b/include/linux/sched.h
index 4cf9a59..56815cd 100644
--- a/include/linux/sched.h
+++ b/include/linux/sched.h
@@ -672,6 +672,10 @@ struct task_struct {
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 seqcount_tvtime_seqcount;
 unsigned long longvtime_snap;
+u64vtime_acct_utime;
+u64vtime_acct_stime;
+u64vtime_acct_idle_time;
+u64vtime_acct_guest_time;
 enum {
 /* Task is sleeping or running in a CPU with VTIME inactive: */
 VTIME_INACTIVE = 0,
diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..2d950c6 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -676,18 +676,19 @@ void thread_group_cputime_adjusted(struct
task_struct *p, u64 *ut, u64 *st)
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 static u64 vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
+unsigned long long clock;

-if (time_before(now, (unsigned long)tsk->vtime_snap))
+clock = sched_clock();
+if (clock < tsk->vtime_snap)
 return 0;

-return jiffies_to_nsecs(now - tsk->vtime_snap);
+return clock - tsk->vtime_snap;
 }

 static u64 get_vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
-u64 delta, other;
+u64 delta = vtime_delta(tsk);
+u64 other;

 /*
  * Unlike tick based timing, vtime based timing never has lost
@@ -696,17 +697,16 @@ static u64 get_vtime_delta(struct task_struct *tsk)
  * elapsed time. Limit account_other_time to prevent rounding
  * errors from causing elapsed vtime to go negative.
  */
-delta = jiffies_to_nsecs(now - tsk->vtime_snap);
 other = account_other_time(delta);
 WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
-tsk->vtime_snap = now;
+tsk->vtime_snap += delta;

 return delta - other;
 }

 static void __vtime_account_system(struct task_struct *tsk)
 {
-account_system_time(tsk, irq_count(), get_vtime_delta(tsk));
+account_system_time(tsk, irq_count(), tsk->vtime_acct_stime);
 }

 void vtime_account_system(struct task_struct *tsk)
@@ -715,7 +715,11 @@ void vtime_account_system(struct task_struct *tsk)
 return;

 write_seqcount_begin(>vtime_seqcount);
-__vtime_account_system(tsk);
+tsk->vtime_acct_stime += get_vtime_delta(tsk);
+if (tsk->vtime_acct_stime >= TICK_NSEC) {
+__vtime_account_system(tsk);
+tsk->vtime_acct_stime = 0;
+

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Apr 13, 2017 at 12:31:12PM +0800, Wanpeng Li wrote:
> 2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
> > On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
> >> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> >> > It's not different from the current jiffies based stuff at all. Same
> >> > failure mode.
> >>
> >> Yes you're right, I got confused again. So to fix this we could do our 
> >> snapshots
> >> at a frequency lower than HZ but still high enough to avoid overhead.
> >>
> >> Something like TICK_NSEC / 2 ?
> >
> > If you are using TSC anyway then you can do proper accumulation for both
> > system and user and only account the data when the accumulation is more
> > than a jiffie.
> 
> So I implement it as below:
> 
> - HZ=1000.
>   1) two cpu hogs on cpu in nohz_full mode, 100% user time
>   2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
> - HZ=250
>1) two cpu hogs on cpu in nohz_full mode, 100% user time
>2) Luzi's testcase, 100% idle
> 
> So the codes below still not work correctly for HZ=250, any suggestions?

Right, so first lets reorder that code a bit so we can see clear inside :-)

> 
> -->8-
> 
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index d67eee8..6a11771 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -668,6 +668,8 @@ struct task_struct {
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  seqcount_tvtime_seqcount;
>  unsigned long longvtime_snap;
> +u64vtime_acct_utime;
> +u64vtime_acct_stime;

You need to accumulate guest and steal time as well.

>  enum {
>  /* Task is sleeping or running in a CPU with VTIME inactive: */
>  VTIME_INACTIVE = 0,
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f8e54ba 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -674,20 +674,41 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #endif /* !CONFIG_VIRT_CPU_ACCOUNTING_NATIVE */
> 
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
> -static u64 vtime_delta(struct task_struct *tsk)
> +static u64 vtime_delta(struct task_struct *tsk, bool user)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 delta, ret = 0;
> 
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> -return 0;
> +delta = sched_clock() - tsk->vtime_snap;
> 
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +if (is_idle_task(tsk)) {
> +if (delta >= TICK_NSEC)
> +ret = delta;
> +} else {
> +if (user) {
> +tsk->vtime_acct_utime += delta;
> +if (tsk->vtime_acct_utime >= TICK_NSEC)
> +ret = tsk->vtime_acct_utime;
> +} else {
> +tsk->vtime_acct_stime += delta;
> +if (tsk->vtime_acct_utime >= TICK_NSEC)
> +ret = tsk->vtime_acct_stime;
> +}

We already have vtime_account_idle, vtime_account_user, etc...
The accumulation should be done by these functions that know what and where
to account. vtime_delta() should really just return the difference against 
vtime_snap,
it's too low level to care about these details.

> +}
> +
> +return ret;
>  }
> 
> -static u64 get_vtime_delta(struct task_struct *tsk)
> +static u64 get_vtime_delta(struct task_struct *tsk, bool user)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk, user);
> +u64 other;
> +
> +if (!is_idle_task(tsk)) {
> +if (user)
> +tsk->vtime_acct_utime = 0;
> +else
> +tsk->vtime_acct_stime = 0;
> +}

Like vtime_delta(), get_vtime_delta() shouldn't touch these accumulators.
Reset and accounting really should be done by the upper level functions
vtime_account_*()

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Apr 13, 2017 at 12:31:12PM +0800, Wanpeng Li wrote:
> 2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
> > On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
> >> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> >> > It's not different from the current jiffies based stuff at all. Same
> >> > failure mode.
> >>
> >> Yes you're right, I got confused again. So to fix this we could do our 
> >> snapshots
> >> at a frequency lower than HZ but still high enough to avoid overhead.
> >>
> >> Something like TICK_NSEC / 2 ?
> >
> > If you are using TSC anyway then you can do proper accumulation for both
> > system and user and only account the data when the accumulation is more
> > than a jiffie.
> 
> So I implement it as below:
> 
> - HZ=1000.
>   1) two cpu hogs on cpu in nohz_full mode, 100% user time
>   2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
> - HZ=250
>1) two cpu hogs on cpu in nohz_full mode, 100% user time
>2) Luzi's testcase, 100% idle
> 
> So the codes below still not work correctly for HZ=250, any suggestions?

Right, so first lets reorder that code a bit so we can see clear inside :-)

> 
> -->8-
> 
> diff --git a/include/linux/sched.h b/include/linux/sched.h
> index d67eee8..6a11771 100644
> --- a/include/linux/sched.h
> +++ b/include/linux/sched.h
> @@ -668,6 +668,8 @@ struct task_struct {
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  seqcount_tvtime_seqcount;
>  unsigned long longvtime_snap;
> +u64vtime_acct_utime;
> +u64vtime_acct_stime;

You need to accumulate guest and steal time as well.

>  enum {
>  /* Task is sleeping or running in a CPU with VTIME inactive: */
>  VTIME_INACTIVE = 0,
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f8e54ba 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -674,20 +674,41 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #endif /* !CONFIG_VIRT_CPU_ACCOUNTING_NATIVE */
> 
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
> -static u64 vtime_delta(struct task_struct *tsk)
> +static u64 vtime_delta(struct task_struct *tsk, bool user)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 delta, ret = 0;
> 
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> -return 0;
> +delta = sched_clock() - tsk->vtime_snap;
> 
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +if (is_idle_task(tsk)) {
> +if (delta >= TICK_NSEC)
> +ret = delta;
> +} else {
> +if (user) {
> +tsk->vtime_acct_utime += delta;
> +if (tsk->vtime_acct_utime >= TICK_NSEC)
> +ret = tsk->vtime_acct_utime;
> +} else {
> +tsk->vtime_acct_stime += delta;
> +if (tsk->vtime_acct_utime >= TICK_NSEC)
> +ret = tsk->vtime_acct_stime;
> +}

We already have vtime_account_idle, vtime_account_user, etc...
The accumulation should be done by these functions that know what and where
to account. vtime_delta() should really just return the difference against 
vtime_snap,
it's too low level to care about these details.

> +}
> +
> +return ret;
>  }
> 
> -static u64 get_vtime_delta(struct task_struct *tsk)
> +static u64 get_vtime_delta(struct task_struct *tsk, bool user)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk, user);
> +u64 other;
> +
> +if (!is_idle_task(tsk)) {
> +if (user)
> +tsk->vtime_acct_utime = 0;
> +else
> +tsk->vtime_acct_stime = 0;
> +}

Like vtime_delta(), get_vtime_delta() shouldn't touch these accumulators.
Reset and accounting really should be done by the upper level functions
vtime_account_*()

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
> On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
>> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
>> > It's not different from the current jiffies based stuff at all. Same
>> > failure mode.
>>
>> Yes you're right, I got confused again. So to fix this we could do our 
>> snapshots
>> at a frequency lower than HZ but still high enough to avoid overhead.
>>
>> Something like TICK_NSEC / 2 ?
>
> If you are using TSC anyway then you can do proper accumulation for both
> system and user and only account the data when the accumulation is more
> than a jiffie.

So I implement it as below:

- HZ=1000.
  1) two cpu hogs on cpu in nohz_full mode, 100% user time
  2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
- HZ=250
   1) two cpu hogs on cpu in nohz_full mode, 100% user time
   2) Luzi's testcase, 100% idle

So the codes below still not work correctly for HZ=250, any suggestions?

-->8-

diff --git a/include/linux/sched.h b/include/linux/sched.h
index d67eee8..6a11771 100644
--- a/include/linux/sched.h
+++ b/include/linux/sched.h
@@ -668,6 +668,8 @@ struct task_struct {
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 seqcount_tvtime_seqcount;
 unsigned long longvtime_snap;
+u64vtime_acct_utime;
+u64vtime_acct_stime;
 enum {
 /* Task is sleeping or running in a CPU with VTIME inactive: */
 VTIME_INACTIVE = 0,
diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..f8e54ba 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -674,20 +674,41 @@ void thread_group_cputime_adjusted(struct
task_struct *p, u64 *ut, u64 *st)
 #endif /* !CONFIG_VIRT_CPU_ACCOUNTING_NATIVE */

 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
-static u64 vtime_delta(struct task_struct *tsk)
+static u64 vtime_delta(struct task_struct *tsk, bool user)
 {
-unsigned long now = READ_ONCE(jiffies);
+u64 delta, ret = 0;

-if (time_before(now, (unsigned long)tsk->vtime_snap))
-return 0;
+delta = sched_clock() - tsk->vtime_snap;

-return jiffies_to_nsecs(now - tsk->vtime_snap);
+if (is_idle_task(tsk)) {
+if (delta >= TICK_NSEC)
+ret = delta;
+} else {
+if (user) {
+tsk->vtime_acct_utime += delta;
+if (tsk->vtime_acct_utime >= TICK_NSEC)
+ret = tsk->vtime_acct_utime;
+} else {
+tsk->vtime_acct_stime += delta;
+if (tsk->vtime_acct_utime >= TICK_NSEC)
+ret = tsk->vtime_acct_stime;
+}
+}
+
+return ret;
 }

-static u64 get_vtime_delta(struct task_struct *tsk)
+static u64 get_vtime_delta(struct task_struct *tsk, bool user)
 {
-unsigned long now = READ_ONCE(jiffies);
-u64 delta, other;
+u64 delta = vtime_delta(tsk, user);
+u64 other;
+
+if (!is_idle_task(tsk)) {
+if (user)
+tsk->vtime_acct_utime = 0;
+else
+tsk->vtime_acct_stime = 0;
+}

 /*
  * Unlike tick based timing, vtime based timing never has lost
@@ -696,22 +717,21 @@ static u64 get_vtime_delta(struct task_struct *tsk)
  * elapsed time. Limit account_other_time to prevent rounding
  * errors from causing elapsed vtime to go negative.
  */
-delta = jiffies_to_nsecs(now - tsk->vtime_snap);
 other = account_other_time(delta);
 WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
-tsk->vtime_snap = now;
+tsk->vtime_snap += delta;

 return delta - other;
 }

 static void __vtime_account_system(struct task_struct *tsk)
 {
-account_system_time(tsk, irq_count(), get_vtime_delta(tsk));
+account_system_time(tsk, irq_count(), get_vtime_delta(tsk, false));
 }

 void vtime_account_system(struct task_struct *tsk)
 {
-if (!vtime_delta(tsk))
+if (!vtime_delta(tsk, false))
 return;

 write_seqcount_begin(>vtime_seqcount);
@@ -723,15 +743,15 @@ void vtime_account_user(struct task_struct *tsk)
 {
 write_seqcount_begin(>vtime_seqcount);
 tsk->vtime_snap_whence = VTIME_SYS;
-if (vtime_delta(tsk))
-account_user_time(tsk, get_vtime_delta(tsk));
+if (vtime_delta(tsk, true))
+account_user_time(tsk, get_vtime_delta(tsk, true));
 write_seqcount_end(>vtime_seqcount);
 }

 void vtime_user_enter(struct task_struct *tsk)
 {
 write_seqcount_begin(>vtime_seqcount);
-if (vtime_delta(tsk))
+if (vtime_delta(tsk, false))
 __vtime_account_system(tsk);
 tsk->vtime_snap_whence = VTIME_USER;
 write_seqcount_end(>vtime_seqcount);
@@ -747,7 +767,7 @@ void vtime_guest_enter(struct task_struct *tsk)
  * that can thus safely catch up with a tickless delta.
  */
 write_seqcount_begin(>vtime_seqcount);
-if (vtime_delta(tsk))
+if (vtime_delta(tsk, false))
 

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-04-12 22:57 GMT+08:00 Thomas Gleixner :
> On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
>> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
>> > It's not different from the current jiffies based stuff at all. Same
>> > failure mode.
>>
>> Yes you're right, I got confused again. So to fix this we could do our 
>> snapshots
>> at a frequency lower than HZ but still high enough to avoid overhead.
>>
>> Something like TICK_NSEC / 2 ?
>
> If you are using TSC anyway then you can do proper accumulation for both
> system and user and only account the data when the accumulation is more
> than a jiffie.

So I implement it as below:

- HZ=1000.
  1) two cpu hogs on cpu in nohz_full mode, 100% user time
  2) Luzi's testcase, ~95% user time, ~5% idle time (as we expected)
- HZ=250
   1) two cpu hogs on cpu in nohz_full mode, 100% user time
   2) Luzi's testcase, 100% idle

So the codes below still not work correctly for HZ=250, any suggestions?

-->8-

diff --git a/include/linux/sched.h b/include/linux/sched.h
index d67eee8..6a11771 100644
--- a/include/linux/sched.h
+++ b/include/linux/sched.h
@@ -668,6 +668,8 @@ struct task_struct {
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 seqcount_tvtime_seqcount;
 unsigned long longvtime_snap;
+u64vtime_acct_utime;
+u64vtime_acct_stime;
 enum {
 /* Task is sleeping or running in a CPU with VTIME inactive: */
 VTIME_INACTIVE = 0,
diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..f8e54ba 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -674,20 +674,41 @@ void thread_group_cputime_adjusted(struct
task_struct *p, u64 *ut, u64 *st)
 #endif /* !CONFIG_VIRT_CPU_ACCOUNTING_NATIVE */

 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
-static u64 vtime_delta(struct task_struct *tsk)
+static u64 vtime_delta(struct task_struct *tsk, bool user)
 {
-unsigned long now = READ_ONCE(jiffies);
+u64 delta, ret = 0;

-if (time_before(now, (unsigned long)tsk->vtime_snap))
-return 0;
+delta = sched_clock() - tsk->vtime_snap;

-return jiffies_to_nsecs(now - tsk->vtime_snap);
+if (is_idle_task(tsk)) {
+if (delta >= TICK_NSEC)
+ret = delta;
+} else {
+if (user) {
+tsk->vtime_acct_utime += delta;
+if (tsk->vtime_acct_utime >= TICK_NSEC)
+ret = tsk->vtime_acct_utime;
+} else {
+tsk->vtime_acct_stime += delta;
+if (tsk->vtime_acct_utime >= TICK_NSEC)
+ret = tsk->vtime_acct_stime;
+}
+}
+
+return ret;
 }

-static u64 get_vtime_delta(struct task_struct *tsk)
+static u64 get_vtime_delta(struct task_struct *tsk, bool user)
 {
-unsigned long now = READ_ONCE(jiffies);
-u64 delta, other;
+u64 delta = vtime_delta(tsk, user);
+u64 other;
+
+if (!is_idle_task(tsk)) {
+if (user)
+tsk->vtime_acct_utime = 0;
+else
+tsk->vtime_acct_stime = 0;
+}

 /*
  * Unlike tick based timing, vtime based timing never has lost
@@ -696,22 +717,21 @@ static u64 get_vtime_delta(struct task_struct *tsk)
  * elapsed time. Limit account_other_time to prevent rounding
  * errors from causing elapsed vtime to go negative.
  */
-delta = jiffies_to_nsecs(now - tsk->vtime_snap);
 other = account_other_time(delta);
 WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
-tsk->vtime_snap = now;
+tsk->vtime_snap += delta;

 return delta - other;
 }

 static void __vtime_account_system(struct task_struct *tsk)
 {
-account_system_time(tsk, irq_count(), get_vtime_delta(tsk));
+account_system_time(tsk, irq_count(), get_vtime_delta(tsk, false));
 }

 void vtime_account_system(struct task_struct *tsk)
 {
-if (!vtime_delta(tsk))
+if (!vtime_delta(tsk, false))
 return;

 write_seqcount_begin(>vtime_seqcount);
@@ -723,15 +743,15 @@ void vtime_account_user(struct task_struct *tsk)
 {
 write_seqcount_begin(>vtime_seqcount);
 tsk->vtime_snap_whence = VTIME_SYS;
-if (vtime_delta(tsk))
-account_user_time(tsk, get_vtime_delta(tsk));
+if (vtime_delta(tsk, true))
+account_user_time(tsk, get_vtime_delta(tsk, true));
 write_seqcount_end(>vtime_seqcount);
 }

 void vtime_user_enter(struct task_struct *tsk)
 {
 write_seqcount_begin(>vtime_seqcount);
-if (vtime_delta(tsk))
+if (vtime_delta(tsk, false))
 __vtime_account_system(tsk);
 tsk->vtime_snap_whence = VTIME_USER;
 write_seqcount_end(>vtime_seqcount);
@@ -747,7 +767,7 @@ void vtime_guest_enter(struct task_struct *tsk)
  * that can thus safely catch up with a tickless delta.
  */
 write_seqcount_begin(>vtime_seqcount);
-if (vtime_delta(tsk))
+if (vtime_delta(tsk, false))
 

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Wed, Apr 12, 2017 at 04:57:58PM +0200, Thomas Gleixner wrote:
> On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
> > On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> > > It's not different from the current jiffies based stuff at all. Same
> > > failure mode.
> > 
> > Yes you're right, I got confused again. So to fix this we could do our 
> > snapshots
> > at a frequency lower than HZ but still high enough to avoid overhead.
> > 
> > Something like TICK_NSEC / 2 ?
> 
> If you are using TSC anyway then you can do proper accumulation for both
> system and user and only account the data when the accumulation is more
> than a jiffie.

Sounds nice, and accumulation shouldn't introduce too much overhead. Let's try 
that.

Thanks.

> 
> Thanks,
> 
>   tglx
> 

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Wed, Apr 12, 2017 at 04:57:58PM +0200, Thomas Gleixner wrote:
> On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
> > On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> > > It's not different from the current jiffies based stuff at all. Same
> > > failure mode.
> > 
> > Yes you're right, I got confused again. So to fix this we could do our 
> > snapshots
> > at a frequency lower than HZ but still high enough to avoid overhead.
> > 
> > Something like TICK_NSEC / 2 ?
> 
> If you are using TSC anyway then you can do proper accumulation for both
> system and user and only account the data when the accumulation is more
> than a jiffie.

Sounds nice, and accumulation shouldn't introduce too much overhead. Let's try 
that.

Thanks.

> 
> Thanks,
> 
>   tglx
> 

Re: [BUG nohz]: wrong user and system time accounting

[Thomas Gleixner]

On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> > It's not different from the current jiffies based stuff at all. Same
> > failure mode.
> 
> Yes you're right, I got confused again. So to fix this we could do our 
> snapshots
> at a frequency lower than HZ but still high enough to avoid overhead.
> 
> Something like TICK_NSEC / 2 ?

If you are using TSC anyway then you can do proper accumulation for both
system and user and only account the data when the accumulation is more
than a jiffie.

Thanks,

tglx

Re: [BUG nohz]: wrong user and system time accounting

[Thomas Gleixner]

On Wed, 12 Apr 2017, Frederic Weisbecker wrote:
> On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> > It's not different from the current jiffies based stuff at all. Same
> > failure mode.
> 
> Yes you're right, I got confused again. So to fix this we could do our 
> snapshots
> at a frequency lower than HZ but still high enough to avoid overhead.
> 
> Something like TICK_NSEC / 2 ?

If you are using TSC anyway then you can do proper accumulation for both
system and user and only account the data when the accumulation is more
than a jiffie.

Thanks,

tglx

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> On Thu, 30 Mar 2017, Wanpeng Li wrote:
> > diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> > index f3778e2b..f1ee393 100644
> > --- a/kernel/sched/cputime.c
> > +++ b/kernel/sched/cputime.c
> > @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> > task_struct *p, u64 *ut, u64 *st)
> >  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
> >  static u64 vtime_delta(struct task_struct *tsk)
> >  {
> > -unsigned long now = READ_ONCE(jiffies);
> > +u64 now = local_clock();
> > +u64 delta;
> > +
> > +delta = now - tsk->vtime_snap;
> > 
> > -if (time_before(now, (unsigned long)tsk->vtime_snap))
> > +if (delta < TICK_NSEC)
> >  return 0;
> > 
> > -return jiffies_to_nsecs(now - tsk->vtime_snap);
> > +return jiffies_to_nsecs(delta / TICK_NSEC);
> 
> So you replaced a jiffies based approach with a jiffies based approach.
> 
> >  }
> > 
> >  static u64 get_vtime_delta(struct task_struct *tsk)
> >  {
> > -unsigned long now = READ_ONCE(jiffies);
> > -u64 delta, other;
> > +u64 delta = vtime_delta(tsk);
> > +u64 other;
> > 
> >  /*
> >   * Unlike tick based timing, vtime based timing never has lost
> > @@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
> >   * elapsed time. Limit account_other_time to prevent rounding
> >   * errors from causing elapsed vtime to go negative.
> >   */
> > -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
> >  other = account_other_time(delta);
> >  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> > -tsk->vtime_snap = now;
> > +tsk->vtime_snap += delta;
> 
> Here is how it works^Wfails
> 
>  For simplicity tsk->vtime_snap starts at 0
>  HZ = 1000
> 
> CPU0 CPU1
>  sysexit()
>account_system()
>  now == 0
>  delta = vtime_delta()<- 0ns
>  tsk->vtime_snap += delta;== 0ns
> 
>  busy_loop(995us)
> 
>  sysenter()
>now == 996us
>account_user()
>  delta = vtime_delta()<- 0ns
>  tsk->vtime_snap += delta == 0ns
>  
>  sysexit()
>account_system()
>  now == 1001us
>  delta = vtime_delta()<- 1000ns
> 
>   Gets accounted to system
> 
>  tsk->vtime_snap += delta;== 1000ns
> 
> It's not different from the current jiffies based stuff at all. Same
> failure mode.

Yes you're right, I got confused again. So to fix this we could do our snapshots
at a frequency lower than HZ but still high enough to avoid overhead.

Something like TICK_NSEC / 2 ?

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Tue, Apr 11, 2017 at 04:22:48PM +0200, Thomas Gleixner wrote:
> On Thu, 30 Mar 2017, Wanpeng Li wrote:
> > diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> > index f3778e2b..f1ee393 100644
> > --- a/kernel/sched/cputime.c
> > +++ b/kernel/sched/cputime.c
> > @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> > task_struct *p, u64 *ut, u64 *st)
> >  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
> >  static u64 vtime_delta(struct task_struct *tsk)
> >  {
> > -unsigned long now = READ_ONCE(jiffies);
> > +u64 now = local_clock();
> > +u64 delta;
> > +
> > +delta = now - tsk->vtime_snap;
> > 
> > -if (time_before(now, (unsigned long)tsk->vtime_snap))
> > +if (delta < TICK_NSEC)
> >  return 0;
> > 
> > -return jiffies_to_nsecs(now - tsk->vtime_snap);
> > +return jiffies_to_nsecs(delta / TICK_NSEC);
> 
> So you replaced a jiffies based approach with a jiffies based approach.
> 
> >  }
> > 
> >  static u64 get_vtime_delta(struct task_struct *tsk)
> >  {
> > -unsigned long now = READ_ONCE(jiffies);
> > -u64 delta, other;
> > +u64 delta = vtime_delta(tsk);
> > +u64 other;
> > 
> >  /*
> >   * Unlike tick based timing, vtime based timing never has lost
> > @@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
> >   * elapsed time. Limit account_other_time to prevent rounding
> >   * errors from causing elapsed vtime to go negative.
> >   */
> > -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
> >  other = account_other_time(delta);
> >  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> > -tsk->vtime_snap = now;
> > +tsk->vtime_snap += delta;
> 
> Here is how it works^Wfails
> 
>  For simplicity tsk->vtime_snap starts at 0
>  HZ = 1000
> 
> CPU0 CPU1
>  sysexit()
>account_system()
>  now == 0
>  delta = vtime_delta()<- 0ns
>  tsk->vtime_snap += delta;== 0ns
> 
>  busy_loop(995us)
> 
>  sysenter()
>now == 996us
>account_user()
>  delta = vtime_delta()<- 0ns
>  tsk->vtime_snap += delta == 0ns
>  
>  sysexit()
>account_system()
>  now == 1001us
>  delta = vtime_delta()<- 1000ns
> 
>   Gets accounted to system
> 
>  tsk->vtime_snap += delta;== 1000ns
> 
> It's not different from the current jiffies based stuff at all. Same
> failure mode.

Yes you're right, I got confused again. So to fix this we could do our snapshots
at a frequency lower than HZ but still high enough to avoid overhead.

Something like TICK_NSEC / 2 ?

Re: [BUG nohz]: wrong user and system time accounting

[Thomas Gleixner]

On Thu, 30 Mar 2017, Wanpeng Li wrote:
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f1ee393 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 now = local_clock();
> +u64 delta;
> +
> +delta = now - tsk->vtime_snap;
> 
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> +if (delta < TICK_NSEC)
>  return 0;
> 
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +return jiffies_to_nsecs(delta / TICK_NSEC);

So you replaced a jiffies based approach with a jiffies based approach.

>  }
> 
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk);
> +u64 other;
> 
>  /*
>   * Unlike tick based timing, vtime based timing never has lost
> @@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>   * elapsed time. Limit account_other_time to prevent rounding
>   * errors from causing elapsed vtime to go negative.
>   */
> -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
>  other = account_other_time(delta);
>  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> -tsk->vtime_snap = now;
> +tsk->vtime_snap += delta;

Here is how it works^Wfails

   For simplicity tsk->vtime_snap starts at 0
   HZ = 1000

CPU0   CPU1
   sysexit()
 account_system()
   now == 0
   delta = vtime_delta()<- 0ns
   tsk->vtime_snap += delta;== 0ns

   busy_loop(995us)

   sysenter()
 now == 996us
 account_user()
   delta = vtime_delta()<- 0ns
   tsk->vtime_snap += delta == 0ns
   
   sysexit()
 account_system()
   now == 1001us
   delta = vtime_delta()<- 1000ns

    Gets accounted to system

   tsk->vtime_snap += delta;== 1000ns

It's not different from the current jiffies based stuff at all. Same
failure mode.

Thanks,

tglx

Re: [BUG nohz]: wrong user and system time accounting

[Thomas Gleixner]

On Thu, 30 Mar 2017, Wanpeng Li wrote:
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f1ee393 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 now = local_clock();
> +u64 delta;
> +
> +delta = now - tsk->vtime_snap;
> 
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> +if (delta < TICK_NSEC)
>  return 0;
> 
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +return jiffies_to_nsecs(delta / TICK_NSEC);

So you replaced a jiffies based approach with a jiffies based approach.

>  }
> 
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk);
> +u64 other;
> 
>  /*
>   * Unlike tick based timing, vtime based timing never has lost
> @@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>   * elapsed time. Limit account_other_time to prevent rounding
>   * errors from causing elapsed vtime to go negative.
>   */
> -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
>  other = account_other_time(delta);
>  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> -tsk->vtime_snap = now;
> +tsk->vtime_snap += delta;

Here is how it works^Wfails

   For simplicity tsk->vtime_snap starts at 0
   HZ = 1000

CPU0   CPU1
   sysexit()
 account_system()
   now == 0
   delta = vtime_delta()<- 0ns
   tsk->vtime_snap += delta;== 0ns

   busy_loop(995us)

   sysenter()
 now == 996us
 account_user()
   delta = vtime_delta()<- 0ns
   tsk->vtime_snap += delta == 0ns
   
   sysexit()
 account_system()
   now == 1001us
   delta = vtime_delta()<- 1000ns

    Gets accounted to system

   tsk->vtime_snap += delta;== 1000ns

It's not different from the current jiffies based stuff at all. Same
failure mode.

Thanks,

tglx

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-04-11 19:36 GMT+08:00 Peter Zijlstra :
> On Tue, Apr 11, 2017 at 07:03:17PM +0800, Wanpeng Li wrote:
>> 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
>> > On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
>>
>> [...]
>>
>> >
>> >>
>> >> -->8-
>> >>
>> >> use nanosecond granularity to check deltas but only perform an actual
>> >> cputime update when that delta >= TICK_NSEC.
>> >>
>> >> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
>> >> index f3778e2b..f1ee393 100644
>> >> --- a/kernel/sched/cputime.c
>> >> +++ b/kernel/sched/cputime.c
>> >> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
>> >> task_struct *p, u64 *ut, u64 *st)
>> >>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>> >>  static u64 vtime_delta(struct task_struct *tsk)
>> >>  {
>> >> -unsigned long now = READ_ONCE(jiffies);
>> >> +u64 now = local_clock();
>> >
>> > I fear we need a global clock, because the reader (task_cputime()) needs
>> > to compute the delta and therefore use the same clock from any CPU.
>> >
>> > Or we can use the local_clock() but the reader must access the same.
>> >
>> > So there would be vtime_delta_writer() which uses local_clock and stores
>> > the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
>> > vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
>> > is protected by vtime_seqcount as well.
>> >
>> > Although those sched_clock_cpu() things seem to only matter when the
>> > sched_clock() is unstable. And that stability is a condition for nohz_full
>> > to work anyway. So probably sched_clock() alone would be enough.
>>
>> I observed ~60% user time and ~40% sys time when replace local_clock()
>> above by sched_clock()(two cpu hogs on the cpu in nohz_full mode). In
>> addition, Luiz's testcast ./acct-bug 1 995 will show 100% idle time.
>> If keep local_clock() in vtime_delta(), cpu hogs testcase will
>> success. However, Luiz's testcase still show 100% idle time.
>
> Assuming a stable TSC, there should be no difference between
> local_clock() and sched_clock().

So it is weird. I did't see any unstable tsc dump in dmesg.

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-04-11 19:36 GMT+08:00 Peter Zijlstra :
> On Tue, Apr 11, 2017 at 07:03:17PM +0800, Wanpeng Li wrote:
>> 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
>> > On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
>>
>> [...]
>>
>> >
>> >>
>> >> -->8-
>> >>
>> >> use nanosecond granularity to check deltas but only perform an actual
>> >> cputime update when that delta >= TICK_NSEC.
>> >>
>> >> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
>> >> index f3778e2b..f1ee393 100644
>> >> --- a/kernel/sched/cputime.c
>> >> +++ b/kernel/sched/cputime.c
>> >> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
>> >> task_struct *p, u64 *ut, u64 *st)
>> >>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>> >>  static u64 vtime_delta(struct task_struct *tsk)
>> >>  {
>> >> -unsigned long now = READ_ONCE(jiffies);
>> >> +u64 now = local_clock();
>> >
>> > I fear we need a global clock, because the reader (task_cputime()) needs
>> > to compute the delta and therefore use the same clock from any CPU.
>> >
>> > Or we can use the local_clock() but the reader must access the same.
>> >
>> > So there would be vtime_delta_writer() which uses local_clock and stores
>> > the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
>> > vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
>> > is protected by vtime_seqcount as well.
>> >
>> > Although those sched_clock_cpu() things seem to only matter when the
>> > sched_clock() is unstable. And that stability is a condition for nohz_full
>> > to work anyway. So probably sched_clock() alone would be enough.
>>
>> I observed ~60% user time and ~40% sys time when replace local_clock()
>> above by sched_clock()(two cpu hogs on the cpu in nohz_full mode). In
>> addition, Luiz's testcast ./acct-bug 1 995 will show 100% idle time.
>> If keep local_clock() in vtime_delta(), cpu hogs testcase will
>> success. However, Luiz's testcase still show 100% idle time.
>
> Assuming a stable TSC, there should be no difference between
> local_clock() and sched_clock().

So it is weird. I did't see any unstable tsc dump in dmesg.

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Peter Zijlstra]

On Tue, Apr 11, 2017 at 07:03:17PM +0800, Wanpeng Li wrote:
> 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
> 
> [...]
> 
> >
> >>
> >> -->8-
> >>
> >> use nanosecond granularity to check deltas but only perform an actual
> >> cputime update when that delta >= TICK_NSEC.
> >>
> >> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> >> index f3778e2b..f1ee393 100644
> >> --- a/kernel/sched/cputime.c
> >> +++ b/kernel/sched/cputime.c
> >> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> >> task_struct *p, u64 *ut, u64 *st)
> >>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
> >>  static u64 vtime_delta(struct task_struct *tsk)
> >>  {
> >> -unsigned long now = READ_ONCE(jiffies);
> >> +u64 now = local_clock();
> >
> > I fear we need a global clock, because the reader (task_cputime()) needs
> > to compute the delta and therefore use the same clock from any CPU.
> >
> > Or we can use the local_clock() but the reader must access the same.
> >
> > So there would be vtime_delta_writer() which uses local_clock and stores
> > the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
> > vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
> > is protected by vtime_seqcount as well.
> >
> > Although those sched_clock_cpu() things seem to only matter when the
> > sched_clock() is unstable. And that stability is a condition for nohz_full
> > to work anyway. So probably sched_clock() alone would be enough.
> 
> I observed ~60% user time and ~40% sys time when replace local_clock()
> above by sched_clock()(two cpu hogs on the cpu in nohz_full mode). In
> addition, Luiz's testcast ./acct-bug 1 995 will show 100% idle time.
> If keep local_clock() in vtime_delta(), cpu hogs testcase will
> success. However, Luiz's testcase still show 100% idle time.

Assuming a stable TSC, there should be no difference between
local_clock() and sched_clock().

Re: [BUG nohz]: wrong user and system time accounting

[Peter Zijlstra]

On Tue, Apr 11, 2017 at 07:03:17PM +0800, Wanpeng Li wrote:
> 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
> 
> [...]
> 
> >
> >>
> >> -->8-
> >>
> >> use nanosecond granularity to check deltas but only perform an actual
> >> cputime update when that delta >= TICK_NSEC.
> >>
> >> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> >> index f3778e2b..f1ee393 100644
> >> --- a/kernel/sched/cputime.c
> >> +++ b/kernel/sched/cputime.c
> >> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> >> task_struct *p, u64 *ut, u64 *st)
> >>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
> >>  static u64 vtime_delta(struct task_struct *tsk)
> >>  {
> >> -unsigned long now = READ_ONCE(jiffies);
> >> +u64 now = local_clock();
> >
> > I fear we need a global clock, because the reader (task_cputime()) needs
> > to compute the delta and therefore use the same clock from any CPU.
> >
> > Or we can use the local_clock() but the reader must access the same.
> >
> > So there would be vtime_delta_writer() which uses local_clock and stores
> > the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
> > vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
> > is protected by vtime_seqcount as well.
> >
> > Although those sched_clock_cpu() things seem to only matter when the
> > sched_clock() is unstable. And that stability is a condition for nohz_full
> > to work anyway. So probably sched_clock() alone would be enough.
> 
> I observed ~60% user time and ~40% sys time when replace local_clock()
> above by sched_clock()(two cpu hogs on the cpu in nohz_full mode). In
> addition, Luiz's testcast ./acct-bug 1 995 will show 100% idle time.
> If keep local_clock() in vtime_delta(), cpu hogs testcase will
> success. However, Luiz's testcase still show 100% idle time.

Assuming a stable TSC, there should be no difference between
local_clock() and sched_clock().

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:

[...]

>
>>
>> -->8-
>>
>> use nanosecond granularity to check deltas but only perform an actual
>> cputime update when that delta >= TICK_NSEC.
>>
>> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
>> index f3778e2b..f1ee393 100644
>> --- a/kernel/sched/cputime.c
>> +++ b/kernel/sched/cputime.c
>> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
>> task_struct *p, u64 *ut, u64 *st)
>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>  static u64 vtime_delta(struct task_struct *tsk)
>>  {
>> -unsigned long now = READ_ONCE(jiffies);
>> +u64 now = local_clock();
>
> I fear we need a global clock, because the reader (task_cputime()) needs
> to compute the delta and therefore use the same clock from any CPU.
>
> Or we can use the local_clock() but the reader must access the same.
>
> So there would be vtime_delta_writer() which uses local_clock and stores
> the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
> vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
> is protected by vtime_seqcount as well.
>
> Although those sched_clock_cpu() things seem to only matter when the
> sched_clock() is unstable. And that stability is a condition for nohz_full
> to work anyway. So probably sched_clock() alone would be enough.

I observed ~60% user time and ~40% sys time when replace local_clock()
above by sched_clock()(two cpu hogs on the cpu in nohz_full mode). In
addition, Luiz's testcast ./acct-bug 1 995 will show 100% idle time.
If keep local_clock() in vtime_delta(), cpu hogs testcase will
success. However, Luiz's testcase still show 100% idle time.

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:

[...]

>
>>
>> -->8-
>>
>> use nanosecond granularity to check deltas but only perform an actual
>> cputime update when that delta >= TICK_NSEC.
>>
>> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
>> index f3778e2b..f1ee393 100644
>> --- a/kernel/sched/cputime.c
>> +++ b/kernel/sched/cputime.c
>> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
>> task_struct *p, u64 *ut, u64 *st)
>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>  static u64 vtime_delta(struct task_struct *tsk)
>>  {
>> -unsigned long now = READ_ONCE(jiffies);
>> +u64 now = local_clock();
>
> I fear we need a global clock, because the reader (task_cputime()) needs
> to compute the delta and therefore use the same clock from any CPU.
>
> Or we can use the local_clock() but the reader must access the same.
>
> So there would be vtime_delta_writer() which uses local_clock and stores
> the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
> vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
> is protected by vtime_seqcount as well.
>
> Although those sched_clock_cpu() things seem to only matter when the
> sched_clock() is unstable. And that stability is a condition for nohz_full
> to work anyway. So probably sched_clock() alone would be enough.

I observed ~60% user time and ~40% sys time when replace local_clock()
above by sched_clock()(two cpu hogs on the cpu in nohz_full mode). In
addition, Luiz's testcast ./acct-bug 1 995 will show 100% idle time.
If keep local_clock() in vtime_delta(), cpu hogs testcase will
success. However, Luiz's testcase still show 100% idle time.

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Tue, 2017-04-04 at 13:36 -0400, Luiz Capitulino wrote:
> 
> On further debugging this, I realized that I had overlooked
> something:
> the timer interrupt in this trace is not the tick, but cyclictest's
> timer
> (remember that the test-case consists of pinning cyclictest and a
> task
> hogging the CPU to the same CPU).
> 
> I'm running cyclictest with -i 200. If I increase this to -i 1000,
> then
> I seem unable to reproduce the issue (caution: even with -i 200 it
> doesn't always happen. But it does usually happen after I restart the
> test-case a few times. However, I've never been able to reproduce
> with -i 1000).
> 
> Now, if it's really cyclictest that's causing the timer interrupts to
> get aligned, I guess this might not have a solution? (note: I haven't
> been able to reproduce this on bare-metal).

With any sample (tick) based timekeeping, it is possible
to construct workloads that avoid the sampling and result
in skewed statistics as a result.

However, given that local users can already DoS the system
in all kinds of ways, skewed statistics are probably not
that high up on the list of importance.

If there were a way to do accurate accounting (true vtime
accounting) without increasing the overhead of every
syscall and interrupt noticeably, that might be worth it,
but syscall overhead is likely to be a more important
factor than the accuracy of statistics.

I don't know if doing TSC reads and subtraction/addition
only, and delaying the conversion to cputime until a later
point would slow down system calls measurably, compared
with reading jiffies and comparing it against a cached
value of jiffies, nor do I know whether spending time
implementing and testing that would be worthwhile :)

-- 
All rights reversed


signature.asc
Description: This is a digitally signed message part

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Tue, 2017-04-04 at 13:36 -0400, Luiz Capitulino wrote:
> 
> On further debugging this, I realized that I had overlooked
> something:
> the timer interrupt in this trace is not the tick, but cyclictest's
> timer
> (remember that the test-case consists of pinning cyclictest and a
> task
> hogging the CPU to the same CPU).
> 
> I'm running cyclictest with -i 200. If I increase this to -i 1000,
> then
> I seem unable to reproduce the issue (caution: even with -i 200 it
> doesn't always happen. But it does usually happen after I restart the
> test-case a few times. However, I've never been able to reproduce
> with -i 1000).
> 
> Now, if it's really cyclictest that's causing the timer interrupts to
> get aligned, I guess this might not have a solution? (note: I haven't
> been able to reproduce this on bare-metal).

With any sample (tick) based timekeeping, it is possible
to construct workloads that avoid the sampling and result
in skewed statistics as a result.

However, given that local users can already DoS the system
in all kinds of ways, skewed statistics are probably not
that high up on the list of importance.

If there were a way to do accurate accounting (true vtime
accounting) without increasing the overhead of every
syscall and interrupt noticeably, that might be worth it,
but syscall overhead is likely to be a more important
factor than the accuracy of statistics.

I don't know if doing TSC reads and subtraction/addition
only, and delaying the conversion to cputime until a later
point would slow down system calls measurably, compared
with reading jiffies and comparing it against a cached
value of jiffies, nor do I know whether spending time
implementing and testing that would be worthwhile :)

-- 
All rights reversed


signature.asc
Description: This is a digitally signed message part

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Mon, 3 Apr 2017 15:06:13 -0400
Luiz Capitulino  wrote:

> On Mon, 3 Apr 2017 17:23:17 +0200
> Frederic Weisbecker  wrote:
> 
> > Do you observe aligned ticks with trace events (hrtimer_expire_entry)?
> > 
> > You might want to enforce the global clock to trace that:
> > 
> > echo "global" > /sys/kernel/debug/tracing/trace_clock  
> 
> I've used the same trace points & debugging code I've been using to debug
> this issue, and this what I'm seeing:
> 
> stress-25757 [002]  2742.717507: function: 
> enter_from_user_mode <-- apic_timer_interrupt
> stress-25757 [002]  2742.717508: function: 
> __context_tracking_exit <-- enter_from_user_mode
> stress-25757 [002]  2742.717508: bprint:   vtime_delta: 
> diff=0 (now=4297409970 vtime_snap=4297409970)
> stress-25757 [002]  2742.717509: function: 
> smp_apic_timer_interrupt <-- apic_timer_interrupt
> stress-25757 [002]  2742.717509: function: irq_enter <-- 
> smp_apic_timer_interrupt
> stress-25757 [002]  2742.717510: hrtimer_expire_entry: 
> hrtimer=0xc900039fbe58 function=hrtimer_wakeup now=2742674000776
> stress-25757 [002]  2742.717514: function: irq_exit <-- 
> smp_apic_timer_interrupt
> cyclictest-25760 [002]  2742.717518: function: 
> vtime_account_system <-- vtime_common_task_switch
> cyclictest-25760 [002]  2742.717518: bprint:   vtime_delta: 
> diff=100 (now=4297409971 vtime_snap=4297409970)
> cyclictest-25760 [002]  2742.717519: function: 
> __vtime_account_system <-- vtime_account_system
> cyclictest-25760 [002]  2742.717519: bprint:   get_vtime_delta: 
> vtime_snap=4297409970 now=4297409971
> cyclictest-25760 [002]  2742.717520: function: 
> account_system_time <-- __vtime_account_system
> cyclictest-25760 [002]  2742.717520: bprint:   
> account_system_time: cputime=961981
> cyclictest-25760 [002]  2742.717521: function: 
> __context_tracking_enter <-- do_syscall_64
> cyclictest-25760 [002]  2742.717522: function: vtime_user_enter 
> <-- __context_tracking_enter
> cyclictest-25760 [002]  2742.717522: bprint:   vtime_delta: 
> diff=0 (now=4297409971 vtime_snap=4297409971)
> 
> CPU2 shows 98% system time while the other CPUs (from CPU3 to CPU7)
> show 98% user time (they're all running the same workload).

On further debugging this, I realized that I had overlooked something:
the timer interrupt in this trace is not the tick, but cyclictest's timer
(remember that the test-case consists of pinning cyclictest and a task
hogging the CPU to the same CPU).

I'm running cyclictest with -i 200. If I increase this to -i 1000, then
I seem unable to reproduce the issue (caution: even with -i 200 it
doesn't always happen. But it does usually happen after I restart the
test-case a few times. However, I've never been able to reproduce
with -i 1000).

Now, if it's really cyclictest that's causing the timer interrupts to
get aligned, I guess this might not have a solution? (note: I haven't
been able to reproduce this on bare-metal).

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Mon, 3 Apr 2017 15:06:13 -0400
Luiz Capitulino  wrote:

> On Mon, 3 Apr 2017 17:23:17 +0200
> Frederic Weisbecker  wrote:
> 
> > Do you observe aligned ticks with trace events (hrtimer_expire_entry)?
> > 
> > You might want to enforce the global clock to trace that:
> > 
> > echo "global" > /sys/kernel/debug/tracing/trace_clock  
> 
> I've used the same trace points & debugging code I've been using to debug
> this issue, and this what I'm seeing:
> 
> stress-25757 [002]  2742.717507: function: 
> enter_from_user_mode <-- apic_timer_interrupt
> stress-25757 [002]  2742.717508: function: 
> __context_tracking_exit <-- enter_from_user_mode
> stress-25757 [002]  2742.717508: bprint:   vtime_delta: 
> diff=0 (now=4297409970 vtime_snap=4297409970)
> stress-25757 [002]  2742.717509: function: 
> smp_apic_timer_interrupt <-- apic_timer_interrupt
> stress-25757 [002]  2742.717509: function: irq_enter <-- 
> smp_apic_timer_interrupt
> stress-25757 [002]  2742.717510: hrtimer_expire_entry: 
> hrtimer=0xc900039fbe58 function=hrtimer_wakeup now=2742674000776
> stress-25757 [002]  2742.717514: function: irq_exit <-- 
> smp_apic_timer_interrupt
> cyclictest-25760 [002]  2742.717518: function: 
> vtime_account_system <-- vtime_common_task_switch
> cyclictest-25760 [002]  2742.717518: bprint:   vtime_delta: 
> diff=100 (now=4297409971 vtime_snap=4297409970)
> cyclictest-25760 [002]  2742.717519: function: 
> __vtime_account_system <-- vtime_account_system
> cyclictest-25760 [002]  2742.717519: bprint:   get_vtime_delta: 
> vtime_snap=4297409970 now=4297409971
> cyclictest-25760 [002]  2742.717520: function: 
> account_system_time <-- __vtime_account_system
> cyclictest-25760 [002]  2742.717520: bprint:   
> account_system_time: cputime=961981
> cyclictest-25760 [002]  2742.717521: function: 
> __context_tracking_enter <-- do_syscall_64
> cyclictest-25760 [002]  2742.717522: function: vtime_user_enter 
> <-- __context_tracking_enter
> cyclictest-25760 [002]  2742.717522: bprint:   vtime_delta: 
> diff=0 (now=4297409971 vtime_snap=4297409971)
> 
> CPU2 shows 98% system time while the other CPUs (from CPU3 to CPU7)
> show 98% user time (they're all running the same workload).

On further debugging this, I realized that I had overlooked something:
the timer interrupt in this trace is not the tick, but cyclictest's timer
(remember that the test-case consists of pinning cyclictest and a task
hogging the CPU to the same CPU).

I'm running cyclictest with -i 200. If I increase this to -i 1000, then
I seem unable to reproduce the issue (caution: even with -i 200 it
doesn't always happen. But it does usually happen after I restart the
test-case a few times. However, I've never been able to reproduce
with -i 1000).

Now, if it's really cyclictest that's causing the timer interrupts to
get aligned, I guess this might not have a solution? (note: I haven't
been able to reproduce this on bare-metal).

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Mon, 2017-04-03 at 16:40 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 30, 2017 at 03:35:22PM +0200, Mike Galbraith wrote:

> Nohz_full is already bad for powersavings anyway. CPU 0 always ticks :-)

OTOH, if a nohz_full set is doing what it was born to do, CPU0 tick
spikes won't be noticeable on your (pegged/glowing) watt meter :)

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Mon, 2017-04-03 at 16:40 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 30, 2017 at 03:35:22PM +0200, Mike Galbraith wrote:

> Nohz_full is already bad for powersavings anyway. CPU 0 always ticks :-)

OTOH, if a nohz_full set is doing what it was born to do, CPU0 tick
spikes won't be noticeable on your (pegged/glowing) watt meter :)

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Mon, 3 Apr 2017 17:23:17 +0200
Frederic Weisbecker  wrote:

> Do you observe aligned ticks with trace events (hrtimer_expire_entry)?
> 
> You might want to enforce the global clock to trace that:
> 
> echo "global" > /sys/kernel/debug/tracing/trace_clock

I've used the same trace points & debugging code I've been using to debug
this issue, and this what I'm seeing:

stress-25757 [002]  2742.717507: function: enter_from_user_mode 
<-- apic_timer_interrupt
stress-25757 [002]  2742.717508: function: 
__context_tracking_exit <-- enter_from_user_mode
stress-25757 [002]  2742.717508: bprint:   vtime_delta: diff=0 
(now=4297409970 vtime_snap=4297409970)
stress-25757 [002]  2742.717509: function: 
smp_apic_timer_interrupt <-- apic_timer_interrupt
stress-25757 [002]  2742.717509: function: irq_enter <-- 
smp_apic_timer_interrupt
stress-25757 [002]  2742.717510: hrtimer_expire_entry: 
hrtimer=0xc900039fbe58 function=hrtimer_wakeup now=2742674000776
stress-25757 [002]  2742.717514: function: irq_exit <-- 
smp_apic_timer_interrupt
cyclictest-25760 [002]  2742.717518: function: vtime_account_system 
<-- vtime_common_task_switch
cyclictest-25760 [002]  2742.717518: bprint:   vtime_delta: 
diff=100 (now=4297409971 vtime_snap=4297409970)
cyclictest-25760 [002]  2742.717519: function: 
__vtime_account_system <-- vtime_account_system
cyclictest-25760 [002]  2742.717519: bprint:   get_vtime_delta: 
vtime_snap=4297409970 now=4297409971
cyclictest-25760 [002]  2742.717520: function: account_system_time 
<-- __vtime_account_system
cyclictest-25760 [002]  2742.717520: bprint:   account_system_time: 
cputime=961981
cyclictest-25760 [002]  2742.717521: function: 
__context_tracking_enter <-- do_syscall_64
cyclictest-25760 [002]  2742.717522: function: vtime_user_enter <-- 
__context_tracking_enter
cyclictest-25760 [002]  2742.717522: bprint:   vtime_delta: diff=0 
(now=4297409971 vtime_snap=4297409971)

CPU2 shows 98% system time while the other CPUs (from CPU3 to CPU7)
show 98% user time (they're all running the same workload).

What's happening here is:

1. Timer interrupt
2. Transition from user-space to kernel-space, vtimer_delta()
   returns zero
3. Context switch from hog application to cyclictest
4. This time vtime_delta() returns != zero, which implies
   jiffies was updated between steps 2 and 3

This seems to be the pattern that accounts incorrectly,
and seem to suggest that the ticks are aligned because
this repeats over and over.

Please, let me know if you want me to run a different
trace-cmd command-line.

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Mon, 3 Apr 2017 17:23:17 +0200
Frederic Weisbecker  wrote:

> Do you observe aligned ticks with trace events (hrtimer_expire_entry)?
> 
> You might want to enforce the global clock to trace that:
> 
> echo "global" > /sys/kernel/debug/tracing/trace_clock

I've used the same trace points & debugging code I've been using to debug
this issue, and this what I'm seeing:

stress-25757 [002]  2742.717507: function: enter_from_user_mode 
<-- apic_timer_interrupt
stress-25757 [002]  2742.717508: function: 
__context_tracking_exit <-- enter_from_user_mode
stress-25757 [002]  2742.717508: bprint:   vtime_delta: diff=0 
(now=4297409970 vtime_snap=4297409970)
stress-25757 [002]  2742.717509: function: 
smp_apic_timer_interrupt <-- apic_timer_interrupt
stress-25757 [002]  2742.717509: function: irq_enter <-- 
smp_apic_timer_interrupt
stress-25757 [002]  2742.717510: hrtimer_expire_entry: 
hrtimer=0xc900039fbe58 function=hrtimer_wakeup now=2742674000776
stress-25757 [002]  2742.717514: function: irq_exit <-- 
smp_apic_timer_interrupt
cyclictest-25760 [002]  2742.717518: function: vtime_account_system 
<-- vtime_common_task_switch
cyclictest-25760 [002]  2742.717518: bprint:   vtime_delta: 
diff=100 (now=4297409971 vtime_snap=4297409970)
cyclictest-25760 [002]  2742.717519: function: 
__vtime_account_system <-- vtime_account_system
cyclictest-25760 [002]  2742.717519: bprint:   get_vtime_delta: 
vtime_snap=4297409970 now=4297409971
cyclictest-25760 [002]  2742.717520: function: account_system_time 
<-- __vtime_account_system
cyclictest-25760 [002]  2742.717520: bprint:   account_system_time: 
cputime=961981
cyclictest-25760 [002]  2742.717521: function: 
__context_tracking_enter <-- do_syscall_64
cyclictest-25760 [002]  2742.717522: function: vtime_user_enter <-- 
__context_tracking_enter
cyclictest-25760 [002]  2742.717522: bprint:   vtime_delta: diff=0 
(now=4297409971 vtime_snap=4297409971)

CPU2 shows 98% system time while the other CPUs (from CPU3 to CPU7)
show 98% user time (they're all running the same workload).

What's happening here is:

1. Timer interrupt
2. Transition from user-space to kernel-space, vtimer_delta()
   returns zero
3. Context switch from hog application to cyclictest
4. This time vtime_delta() returns != zero, which implies
   jiffies was updated between steps 2 and 3

This seems to be the pattern that accounts incorrectly,
and seem to suggest that the ticks are aligned because
this repeats over and over.

Please, let me know if you want me to run a different
trace-cmd command-line.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Fri, Mar 31, 2017 at 11:11:19PM -0400, Luiz Capitulino wrote:
> On Sat, 1 Apr 2017 01:24:54 +0200
> Frederic Weisbecker  wrote:
> 
> > On Fri, Mar 31, 2017 at 04:09:10PM -0400, Luiz Capitulino wrote:
> > > On Thu, 30 Mar 2017 17:25:46 -0400
> > > Luiz Capitulino  wrote:
> > >   
> > > > On Thu, 30 Mar 2017 16:18:17 +0200
> > > > Frederic Weisbecker  wrote:
> > > >   
> > > > > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> > > > > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker 
> > > > > > :  
> > > > > > > If it works, we may want to take that solution, likely less 
> > > > > > > performance sensitive
> > > > > > > than using sched_clock(). In fact sched_clock() is fast, 
> > > > > > > especially as we require it to
> > > > > > > be stable for nohz_full, but using it involves costly conversion 
> > > > > > > back and forth to jiffies.  
> > > > > > 
> > > > > > So both Rik and you agree with the skew tick solution, I will try it
> > > > > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > > > > nohz_full mode or add random offset to all cpus like the codes 
> > > > > > above?  
> > > > > 
> > > > > Lets just keep it to all CPUs for simplicty.
> > > > > Also please add a comment that explains why we need that skew_tick on 
> > > > > nohz_full.
> > > > 
> > > > I've tried all the test-cases we discussed in this thread with 
> > > > skew_tick=1
> > > > and it worked as expected in bare-metal and KVM guests.
> > > > 
> > > > However, I found a test-case that works in bare-metal but show problems
> > > > in KVM guests. It could something that's KVM specific, or it could be
> > > > something that's harder to reproduce in bare-metal.  
> > > 
> > > After discussing some findings on this issue with Rik, I realized that
> > > we don't add the skew when restarting the tick in tick_nohz_restart().
> > > Adding the offset there seems to solve this problem.  
> > 
> > Are you sure? tick_nohz_restart() doesn't seem to override the initial 
> > skew. It
> > always forwards the expiration time on top of the last tick.
> 
> OK, I'll double check. Without my change the bug triggers almost
> instantly with the described reproducer. With my change it didn't
> trig for several minutes (but it does look wrong looking at it now).

Do you observe aligned ticks with trace events (hrtimer_expire_entry)?

You might want to enforce the global clock to trace that:

echo "global" > /sys/kernel/debug/tracing/trace_clock

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Fri, Mar 31, 2017 at 11:11:19PM -0400, Luiz Capitulino wrote:
> On Sat, 1 Apr 2017 01:24:54 +0200
> Frederic Weisbecker  wrote:
> 
> > On Fri, Mar 31, 2017 at 04:09:10PM -0400, Luiz Capitulino wrote:
> > > On Thu, 30 Mar 2017 17:25:46 -0400
> > > Luiz Capitulino  wrote:
> > >   
> > > > On Thu, 30 Mar 2017 16:18:17 +0200
> > > > Frederic Weisbecker  wrote:
> > > >   
> > > > > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> > > > > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker 
> > > > > > :  
> > > > > > > If it works, we may want to take that solution, likely less 
> > > > > > > performance sensitive
> > > > > > > than using sched_clock(). In fact sched_clock() is fast, 
> > > > > > > especially as we require it to
> > > > > > > be stable for nohz_full, but using it involves costly conversion 
> > > > > > > back and forth to jiffies.  
> > > > > > 
> > > > > > So both Rik and you agree with the skew tick solution, I will try it
> > > > > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > > > > nohz_full mode or add random offset to all cpus like the codes 
> > > > > > above?  
> > > > > 
> > > > > Lets just keep it to all CPUs for simplicty.
> > > > > Also please add a comment that explains why we need that skew_tick on 
> > > > > nohz_full.
> > > > 
> > > > I've tried all the test-cases we discussed in this thread with 
> > > > skew_tick=1
> > > > and it worked as expected in bare-metal and KVM guests.
> > > > 
> > > > However, I found a test-case that works in bare-metal but show problems
> > > > in KVM guests. It could something that's KVM specific, or it could be
> > > > something that's harder to reproduce in bare-metal.  
> > > 
> > > After discussing some findings on this issue with Rik, I realized that
> > > we don't add the skew when restarting the tick in tick_nohz_restart().
> > > Adding the offset there seems to solve this problem.  
> > 
> > Are you sure? tick_nohz_restart() doesn't seem to override the initial 
> > skew. It
> > always forwards the expiration time on top of the last tick.
> 
> OK, I'll double check. Without my change the bug triggers almost
> instantly with the described reproducer. With my change it didn't
> trig for several minutes (but it does look wrong looking at it now).

Do you observe aligned ticks with trace events (hrtimer_expire_entry)?

You might want to enforce the global clock to trace that:

echo "global" > /sys/kernel/debug/tracing/trace_clock

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 03:35:22PM +0200, Mike Galbraith wrote:
> On Thu, 2017-03-30 at 09:02 -0400, Rik van Riel wrote:
> > On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:
> 
> > > Also, why does it raise power consumption issues?
> > 
> > On a system without either nohz_full or nohz idle
> > mode, skewed ticks result in CPU cores waking up
> > at different times, and keeping an idle system
> > consuming power for more time than it would if all
> > the ticks happened simultaneously.
> 
> And if your server farm is mostly idle, that power savings may delay
> your bankruptcy proceedings by a whole microsecond ;-)
> 
> Or more seriously, what skew does do on boxen of size X today is
> something for perf to say.  At the time, removal was very bad for my 8
> socket box, and allegedly caused huge SGI beasts in horrific pain.

I see.
Nohz_full is already bad for powersavings anyway. CPU 0 always ticks :-)

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 03:35:22PM +0200, Mike Galbraith wrote:
> On Thu, 2017-03-30 at 09:02 -0400, Rik van Riel wrote:
> > On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:
> 
> > > Also, why does it raise power consumption issues?
> > 
> > On a system without either nohz_full or nohz idle
> > mode, skewed ticks result in CPU cores waking up
> > at different times, and keeping an idle system
> > consuming power for more time than it would if all
> > the ticks happened simultaneously.
> 
> And if your server farm is mostly idle, that power savings may delay
> your bankruptcy proceedings by a whole microsecond ;-)
> 
> Or more seriously, what skew does do on boxen of size X today is
> something for perf to say.  At the time, removal was very bad for my 8
> socket box, and allegedly caused huge SGI beasts in horrific pain.

I see.
Nohz_full is already bad for powersavings anyway. CPU 0 always ticks :-)

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Sat, 1 Apr 2017 01:24:54 +0200
Frederic Weisbecker  wrote:

> On Fri, Mar 31, 2017 at 04:09:10PM -0400, Luiz Capitulino wrote:
> > On Thu, 30 Mar 2017 17:25:46 -0400
> > Luiz Capitulino  wrote:
> >   
> > > On Thu, 30 Mar 2017 16:18:17 +0200
> > > Frederic Weisbecker  wrote:
> > >   
> > > > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> > > > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :  
> > > > > 
> > > > > > If it works, we may want to take that solution, likely less 
> > > > > > performance sensitive
> > > > > > than using sched_clock(). In fact sched_clock() is fast, especially 
> > > > > > as we require it to
> > > > > > be stable for nohz_full, but using it involves costly conversion 
> > > > > > back and forth to jiffies.  
> > > > > 
> > > > > So both Rik and you agree with the skew tick solution, I will try it
> > > > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > > > nohz_full mode or add random offset to all cpus like the codes above? 
> > > > >  
> > > > 
> > > > Lets just keep it to all CPUs for simplicty.
> > > > Also please add a comment that explains why we need that skew_tick on 
> > > > nohz_full.
> > > 
> > > I've tried all the test-cases we discussed in this thread with skew_tick=1
> > > and it worked as expected in bare-metal and KVM guests.
> > > 
> > > However, I found a test-case that works in bare-metal but show problems
> > > in KVM guests. It could something that's KVM specific, or it could be
> > > something that's harder to reproduce in bare-metal.  
> > 
> > After discussing some findings on this issue with Rik, I realized that
> > we don't add the skew when restarting the tick in tick_nohz_restart().
> > Adding the offset there seems to solve this problem.  
> 
> Are you sure? tick_nohz_restart() doesn't seem to override the initial skew. 
> It
> always forwards the expiration time on top of the last tick.

OK, I'll double check. Without my change the bug triggers almost
instantly with the described reproducer. With my change it didn't
trig for several minutes (but it does look wrong looking at it now).

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Sat, 1 Apr 2017 01:24:54 +0200
Frederic Weisbecker  wrote:

> On Fri, Mar 31, 2017 at 04:09:10PM -0400, Luiz Capitulino wrote:
> > On Thu, 30 Mar 2017 17:25:46 -0400
> > Luiz Capitulino  wrote:
> >   
> > > On Thu, 30 Mar 2017 16:18:17 +0200
> > > Frederic Weisbecker  wrote:
> > >   
> > > > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> > > > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :  
> > > > > 
> > > > > > If it works, we may want to take that solution, likely less 
> > > > > > performance sensitive
> > > > > > than using sched_clock(). In fact sched_clock() is fast, especially 
> > > > > > as we require it to
> > > > > > be stable for nohz_full, but using it involves costly conversion 
> > > > > > back and forth to jiffies.  
> > > > > 
> > > > > So both Rik and you agree with the skew tick solution, I will try it
> > > > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > > > nohz_full mode or add random offset to all cpus like the codes above? 
> > > > >  
> > > > 
> > > > Lets just keep it to all CPUs for simplicty.
> > > > Also please add a comment that explains why we need that skew_tick on 
> > > > nohz_full.
> > > 
> > > I've tried all the test-cases we discussed in this thread with skew_tick=1
> > > and it worked as expected in bare-metal and KVM guests.
> > > 
> > > However, I found a test-case that works in bare-metal but show problems
> > > in KVM guests. It could something that's KVM specific, or it could be
> > > something that's harder to reproduce in bare-metal.  
> > 
> > After discussing some findings on this issue with Rik, I realized that
> > we don't add the skew when restarting the tick in tick_nohz_restart().
> > Adding the offset there seems to solve this problem.  
> 
> Are you sure? tick_nohz_restart() doesn't seem to override the initial skew. 
> It
> always forwards the expiration time on top of the last tick.

OK, I'll double check. Without my change the bug triggers almost
instantly with the described reproducer. With my change it didn't
trig for several minutes (but it does look wrong looking at it now).

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Fri, Mar 31, 2017 at 04:09:10PM -0400, Luiz Capitulino wrote:
> On Thu, 30 Mar 2017 17:25:46 -0400
> Luiz Capitulino  wrote:
> 
> > On Thu, 30 Mar 2017 16:18:17 +0200
> > Frederic Weisbecker  wrote:
> > 
> > > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:  
> > > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > > > > If it works, we may want to take that solution, likely less 
> > > > > performance sensitive
> > > > > than using sched_clock(). In fact sched_clock() is fast, especially 
> > > > > as we require it to
> > > > > be stable for nohz_full, but using it involves costly conversion back 
> > > > > and forth to jiffies.
> > > > 
> > > > So both Rik and you agree with the skew tick solution, I will try it
> > > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > > nohz_full mode or add random offset to all cpus like the codes above?   
> > > >  
> > > 
> > > Lets just keep it to all CPUs for simplicty.
> > > Also please add a comment that explains why we need that skew_tick on 
> > > nohz_full.  
> > 
> > I've tried all the test-cases we discussed in this thread with skew_tick=1
> > and it worked as expected in bare-metal and KVM guests.
> > 
> > However, I found a test-case that works in bare-metal but show problems
> > in KVM guests. It could something that's KVM specific, or it could be
> > something that's harder to reproduce in bare-metal.
> 
> After discussing some findings on this issue with Rik, I realized that
> we don't add the skew when restarting the tick in tick_nohz_restart().
> Adding the offset there seems to solve this problem.

Are you sure? tick_nohz_restart() doesn't seem to override the initial skew. It
always forwards the expiration time on top of the last tick.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Fri, Mar 31, 2017 at 04:09:10PM -0400, Luiz Capitulino wrote:
> On Thu, 30 Mar 2017 17:25:46 -0400
> Luiz Capitulino  wrote:
> 
> > On Thu, 30 Mar 2017 16:18:17 +0200
> > Frederic Weisbecker  wrote:
> > 
> > > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:  
> > > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > > > > If it works, we may want to take that solution, likely less 
> > > > > performance sensitive
> > > > > than using sched_clock(). In fact sched_clock() is fast, especially 
> > > > > as we require it to
> > > > > be stable for nohz_full, but using it involves costly conversion back 
> > > > > and forth to jiffies.
> > > > 
> > > > So both Rik and you agree with the skew tick solution, I will try it
> > > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > > nohz_full mode or add random offset to all cpus like the codes above?   
> > > >  
> > > 
> > > Lets just keep it to all CPUs for simplicty.
> > > Also please add a comment that explains why we need that skew_tick on 
> > > nohz_full.  
> > 
> > I've tried all the test-cases we discussed in this thread with skew_tick=1
> > and it worked as expected in bare-metal and KVM guests.
> > 
> > However, I found a test-case that works in bare-metal but show problems
> > in KVM guests. It could something that's KVM specific, or it could be
> > something that's harder to reproduce in bare-metal.
> 
> After discussing some findings on this issue with Rik, I realized that
> we don't add the skew when restarting the tick in tick_nohz_restart().
> Adding the offset there seems to solve this problem.

Are you sure? tick_nohz_restart() doesn't seem to override the initial skew. It
always forwards the expiration time on top of the last tick.

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Thu, 30 Mar 2017 17:25:46 -0400
Luiz Capitulino  wrote:

> On Thu, 30 Mar 2017 16:18:17 +0200
> Frederic Weisbecker  wrote:
> 
> > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:  
> > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > > > If it works, we may want to take that solution, likely less performance 
> > > > sensitive
> > > > than using sched_clock(). In fact sched_clock() is fast, especially as 
> > > > we require it to
> > > > be stable for nohz_full, but using it involves costly conversion back 
> > > > and forth to jiffies.
> > > 
> > > So both Rik and you agree with the skew tick solution, I will try it
> > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > nohz_full mode or add random offset to all cpus like the codes above?
> > 
> > Lets just keep it to all CPUs for simplicty.
> > Also please add a comment that explains why we need that skew_tick on 
> > nohz_full.  
> 
> I've tried all the test-cases we discussed in this thread with skew_tick=1
> and it worked as expected in bare-metal and KVM guests.
> 
> However, I found a test-case that works in bare-metal but show problems
> in KVM guests. It could something that's KVM specific, or it could be
> something that's harder to reproduce in bare-metal.

After discussing some findings on this issue with Rik, I realized that
we don't add the skew when restarting the tick in tick_nohz_restart().
Adding the offset there seems to solve this problem.

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Thu, 30 Mar 2017 17:25:46 -0400
Luiz Capitulino  wrote:

> On Thu, 30 Mar 2017 16:18:17 +0200
> Frederic Weisbecker  wrote:
> 
> > On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:  
> > > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > > > If it works, we may want to take that solution, likely less performance 
> > > > sensitive
> > > > than using sched_clock(). In fact sched_clock() is fast, especially as 
> > > > we require it to
> > > > be stable for nohz_full, but using it involves costly conversion back 
> > > > and forth to jiffies.
> > > 
> > > So both Rik and you agree with the skew tick solution, I will try it
> > > tomorrow. Btw, if we should just add random offset to the cpu in the
> > > nohz_full mode or add random offset to all cpus like the codes above?
> > 
> > Lets just keep it to all CPUs for simplicty.
> > Also please add a comment that explains why we need that skew_tick on 
> > nohz_full.  
> 
> I've tried all the test-cases we discussed in this thread with skew_tick=1
> and it worked as expected in bare-metal and KVM guests.
> 
> However, I found a test-case that works in bare-metal but show problems
> in KVM guests. It could something that's KVM specific, or it could be
> something that's harder to reproduce in bare-metal.

After discussing some findings on this issue with Rik, I realized that
we don't add the skew when restarting the tick in tick_nohz_restart().
Adding the offset there seems to solve this problem.

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Thu, 30 Mar 2017 16:18:17 +0200
Frederic Weisbecker  wrote:

> On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :  
> > > If it works, we may want to take that solution, likely less performance 
> > > sensitive
> > > than using sched_clock(). In fact sched_clock() is fast, especially as we 
> > > require it to
> > > be stable for nohz_full, but using it involves costly conversion back and 
> > > forth to jiffies.  
> > 
> > So both Rik and you agree with the skew tick solution, I will try it
> > tomorrow. Btw, if we should just add random offset to the cpu in the
> > nohz_full mode or add random offset to all cpus like the codes above?  
> 
> Lets just keep it to all CPUs for simplicty.
> Also please add a comment that explains why we need that skew_tick on 
> nohz_full.

I've tried all the test-cases we discussed in this thread with skew_tick=1
and it worked as expected in bare-metal and KVM guests.

However, I found a test-case that works in bare-metal but show problems
in KVM guests. It could something that's KVM specific, or it could be
something that's harder to reproduce in bare-metal.

The reproducer is (not sure all the steps are necessary):

1. Isolate 8 cores in the host with isolcpus= and nohz_full= (and skew_tick=1)

2. Create a KVM guest with 8 vCPUs and pin each vCPU to an isolated
   host core

3. Boot the guest with isolcpus=2,3,4,5,6,7 nohz_full=2,3,4,5,6,7 skew_tick=1

4. Once the guest is booted, run:

# for i in $(seq 2 7); do taskset -c $i hog& ;done
# taskset -c 2,3,4,5,6,7 \
  cyclictest -m -n -q -p95 -D 1m -h60 -i 200 -t 6 -a 2,3,4,5,6,7

  (where hog is a program taking 100% of the CPU, and cyclictest
   is RT's cyclictest)

5. Run top -d1

In a few minutes into this test-case, I see one isolated CPU in the
guest reporting around 95% system time (where the expected is close
to 100% user time, which the others isolated CPUs correctly report).

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Thu, 30 Mar 2017 16:18:17 +0200
Frederic Weisbecker  wrote:

> On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> > 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :  
> > > If it works, we may want to take that solution, likely less performance 
> > > sensitive
> > > than using sched_clock(). In fact sched_clock() is fast, especially as we 
> > > require it to
> > > be stable for nohz_full, but using it involves costly conversion back and 
> > > forth to jiffies.  
> > 
> > So both Rik and you agree with the skew tick solution, I will try it
> > tomorrow. Btw, if we should just add random offset to the cpu in the
> > nohz_full mode or add random offset to all cpus like the codes above?  
> 
> Lets just keep it to all CPUs for simplicty.
> Also please add a comment that explains why we need that skew_tick on 
> nohz_full.

I've tried all the test-cases we discussed in this thread with skew_tick=1
and it worked as expected in bare-metal and KVM guests.

However, I found a test-case that works in bare-metal but show problems
in KVM guests. It could something that's KVM specific, or it could be
something that's harder to reproduce in bare-metal.

The reproducer is (not sure all the steps are necessary):

1. Isolate 8 cores in the host with isolcpus= and nohz_full= (and skew_tick=1)

2. Create a KVM guest with 8 vCPUs and pin each vCPU to an isolated
   host core

3. Boot the guest with isolcpus=2,3,4,5,6,7 nohz_full=2,3,4,5,6,7 skew_tick=1

4. Once the guest is booted, run:

# for i in $(seq 2 7); do taskset -c $i hog& ;done
# taskset -c 2,3,4,5,6,7 \
  cyclictest -m -n -q -p95 -D 1m -h60 -i 200 -t 6 -a 2,3,4,5,6,7

  (where hog is a program taking 100% of the CPU, and cyclictest
   is RT's cyclictest)

5. Run top -d1

In a few minutes into this test-case, I see one isolated CPU in the
guest reporting around 95% system time (where the expected is close
to 100% user time, which the others isolated CPUs correctly report).

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > If it works, we may want to take that solution, likely less performance 
> > sensitive
> > than using sched_clock(). In fact sched_clock() is fast, especially as we 
> > require it to
> > be stable for nohz_full, but using it involves costly conversion back and 
> > forth to jiffies.
> 
> So both Rik and you agree with the skew tick solution, I will try it
> tomorrow. Btw, if we should just add random offset to the cpu in the
> nohz_full mode or add random offset to all cpus like the codes above?

Lets just keep it to all CPUs for simplicty.
Also please add a comment that explains why we need that skew_tick on nohz_full.

Thanks!

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 09:59:54PM +0800, Wanpeng Li wrote:
> 2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> > If it works, we may want to take that solution, likely less performance 
> > sensitive
> > than using sched_clock(). In fact sched_clock() is fast, especially as we 
> > require it to
> > be stable for nohz_full, but using it involves costly conversion back and 
> > forth to jiffies.
> 
> So both Rik and you agree with the skew tick solution, I will try it
> tomorrow. Btw, if we should just add random offset to the cpu in the
> nohz_full mode or add random offset to all cpus like the codes above?

Lets just keep it to all CPUs for simplicty.
Also please add a comment that explains why we need that skew_tick on nohz_full.

Thanks!

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
>> Cc Peterz, Thomas,
>> 2017-03-30 12:27 GMT+08:00 Mike Galbraith :
>> > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
>> >
>> >> In other words, the tick on cpu0 is aligned
>> >> with the tick on the nohz_full cpus, and
>> >> jiffies is advanced while the nohz_full cpus
>> >> with an active tick happen to be in kernel
>> >> mode?
>> >
>> > You really want skew_tick=1, especially on big boxen.
>> >
>> >> Frederic, can you think of any reason why
>> >> the tick on nohz_full CPUs would end up aligned
>> >> with the tick on cpu0, instead of running at some
>> >> random offset?
>> >
>> > (I or low rq->clock bits as crude NOHZ collision avoidance)
>> >
>> >> A random offset, or better yet a somewhat randomized
>> >> tick length to make sure that simultaneous ticks are
>> >> fairly rare and the vtime sampling does not end up
>> >> "in phase" with the jiffies incrementing, could make
>> >> the accounting work right again.
>> >
>> > That improves jitter, especially on big boxen.  I have an 8 socket box
>> > that thinks it's an extra large PC, there, collision avoidance matters
>> > hugely.  I couldn't reproduce bean counting woes, no idea if collision
>> > avoidance will help that.
>>
>> So I implement two methods, one is from Rik's random offset proposal
>> through skew tick, the other one is from Frederic's proposal and it is
>> the same as my original idea through use nanosecond granularity to
>> check deltas but only perform an actual cputime update when that delta
>> >= TICK_NSEC. Both methods can solve the bug which Luiz reported.
>> Peterz, Thomas, any ideas?
>>
>> --->8-
>>
>> skew tick:
>>
>> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
>> index 7fe53be..9981437 100644
>> --- a/kernel/time/tick-sched.c
>> +++ b/kernel/time/tick-sched.c
>> @@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
>>  hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());
>>
>>  /* Offset the tick to avert jiffies_lock contention. */
>> +#ifdef CONFIG_NO_HZ_FULL
>> +if (sched_skew_tick || tick_nohz_full_running) {
>> +#else
>>  if (sched_skew_tick) {
>> +#endif
>
> Please rather use tick_nohz_full_enabled() to avoid ifdeffery.
>
>>  u64 offset = ktime_to_ns(tick_period) >> 1;
>>  do_div(offset, num_possible_cpus());
>>  offset *= smp_processor_id();
>
> If it works, we may want to take that solution, likely less performance 
> sensitive
> than using sched_clock(). In fact sched_clock() is fast, especially as we 
> require it to
> be stable for nohz_full, but using it involves costly conversion back and 
> forth to jiffies.

So both Rik and you agree with the skew tick solution, I will try it
tomorrow. Btw, if we should just add random offset to the cpu in the
nohz_full mode or add random offset to all cpus like the codes above?

Regards,
Wanpeng Li

>
>>
>> -->8-
>>
>> use nanosecond granularity to check deltas but only perform an actual
>> cputime update when that delta >= TICK_NSEC.
>>
>> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
>> index f3778e2b..f1ee393 100644
>> --- a/kernel/sched/cputime.c
>> +++ b/kernel/sched/cputime.c
>> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
>> task_struct *p, u64 *ut, u64 *st)
>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>  static u64 vtime_delta(struct task_struct *tsk)
>>  {
>> -unsigned long now = READ_ONCE(jiffies);
>> +u64 now = local_clock();
>
> I fear we need a global clock, because the reader (task_cputime()) needs
> to compute the delta and therefore use the same clock from any CPU.
>
> Or we can use the local_clock() but the reader must access the same.
>
> So there would be vtime_delta_writer() which uses local_clock and stores
> the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
> vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
> is protected by vtime_seqcount as well.
>
> Although those sched_clock_cpu() things seem to only matter when the
> sched_clock() is unstable. And that stability is a condition for nohz_full
> to work anyway. So probably sched_clock() alone would be enough.
>
> Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 21:38 GMT+08:00 Frederic Weisbecker :
> On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
>> Cc Peterz, Thomas,
>> 2017-03-30 12:27 GMT+08:00 Mike Galbraith :
>> > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
>> >
>> >> In other words, the tick on cpu0 is aligned
>> >> with the tick on the nohz_full cpus, and
>> >> jiffies is advanced while the nohz_full cpus
>> >> with an active tick happen to be in kernel
>> >> mode?
>> >
>> > You really want skew_tick=1, especially on big boxen.
>> >
>> >> Frederic, can you think of any reason why
>> >> the tick on nohz_full CPUs would end up aligned
>> >> with the tick on cpu0, instead of running at some
>> >> random offset?
>> >
>> > (I or low rq->clock bits as crude NOHZ collision avoidance)
>> >
>> >> A random offset, or better yet a somewhat randomized
>> >> tick length to make sure that simultaneous ticks are
>> >> fairly rare and the vtime sampling does not end up
>> >> "in phase" with the jiffies incrementing, could make
>> >> the accounting work right again.
>> >
>> > That improves jitter, especially on big boxen.  I have an 8 socket box
>> > that thinks it's an extra large PC, there, collision avoidance matters
>> > hugely.  I couldn't reproduce bean counting woes, no idea if collision
>> > avoidance will help that.
>>
>> So I implement two methods, one is from Rik's random offset proposal
>> through skew tick, the other one is from Frederic's proposal and it is
>> the same as my original idea through use nanosecond granularity to
>> check deltas but only perform an actual cputime update when that delta
>> >= TICK_NSEC. Both methods can solve the bug which Luiz reported.
>> Peterz, Thomas, any ideas?
>>
>> --->8-
>>
>> skew tick:
>>
>> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
>> index 7fe53be..9981437 100644
>> --- a/kernel/time/tick-sched.c
>> +++ b/kernel/time/tick-sched.c
>> @@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
>>  hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());
>>
>>  /* Offset the tick to avert jiffies_lock contention. */
>> +#ifdef CONFIG_NO_HZ_FULL
>> +if (sched_skew_tick || tick_nohz_full_running) {
>> +#else
>>  if (sched_skew_tick) {
>> +#endif
>
> Please rather use tick_nohz_full_enabled() to avoid ifdeffery.
>
>>  u64 offset = ktime_to_ns(tick_period) >> 1;
>>  do_div(offset, num_possible_cpus());
>>  offset *= smp_processor_id();
>
> If it works, we may want to take that solution, likely less performance 
> sensitive
> than using sched_clock(). In fact sched_clock() is fast, especially as we 
> require it to
> be stable for nohz_full, but using it involves costly conversion back and 
> forth to jiffies.

So both Rik and you agree with the skew tick solution, I will try it
tomorrow. Btw, if we should just add random offset to the cpu in the
nohz_full mode or add random offset to all cpus like the codes above?

Regards,
Wanpeng Li

>
>>
>> -->8-
>>
>> use nanosecond granularity to check deltas but only perform an actual
>> cputime update when that delta >= TICK_NSEC.
>>
>> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
>> index f3778e2b..f1ee393 100644
>> --- a/kernel/sched/cputime.c
>> +++ b/kernel/sched/cputime.c
>> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
>> task_struct *p, u64 *ut, u64 *st)
>>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>>  static u64 vtime_delta(struct task_struct *tsk)
>>  {
>> -unsigned long now = READ_ONCE(jiffies);
>> +u64 now = local_clock();
>
> I fear we need a global clock, because the reader (task_cputime()) needs
> to compute the delta and therefore use the same clock from any CPU.
>
> Or we can use the local_clock() but the reader must access the same.
>
> So there would be vtime_delta_writer() which uses local_clock and stores
> the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
> vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
> is protected by vtime_seqcount as well.
>
> Although those sched_clock_cpu() things seem to only matter when the
> sched_clock() is unstable. And that stability is a condition for nohz_full
> to work anyway. So probably sched_clock() alone would be enough.
>
> Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 09:02:31AM -0400, Rik van Riel wrote:
> On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:
> > On Thu, Mar 30, 2017 at 06:27:31AM +0200, Mike Galbraith wrote:
> > > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> > > 
> > > > A random offset, or better yet a somewhat randomized
> > > > tick length to make sure that simultaneous ticks are
> > > > fairly rare and the vtime sampling does not end up
> > > > "in phase" with the jiffies incrementing, could make
> > > > the accounting work right again.
> > > 
> > > That improves jitter, especially on big boxen.  I have an 8 socket
> > > box
> > > that thinks it's an extra large PC, there, collision avoidance
> > > matters
> > > hugely.  I couldn't reproduce bean counting woes, no idea if
> > > collision
> > > avoidance will help that.
> > 
> > Out of curiosity, where is the main contention between ticks? I
> > indeed
> > know some locks that can be taken on special cases, such as posix cpu
> > timers.
> > 
> > Also, why does it raise power consumption issues?
> 
> On a system without either nohz_full or nohz idle
> mode, skewed ticks result in CPU cores waking up
> at different times, and keeping an idle system
> consuming power for more time than it would if all
> the ticks happened simultaneously.

Ah fair point!

> 
> This is not a factor at all on systems that switch
> off the tick while idle, since the CPU will be busy
> anyway while the tick is enabled.

I see. Thanks!

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 09:02:31AM -0400, Rik van Riel wrote:
> On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:
> > On Thu, Mar 30, 2017 at 06:27:31AM +0200, Mike Galbraith wrote:
> > > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> > > 
> > > > A random offset, or better yet a somewhat randomized
> > > > tick length to make sure that simultaneous ticks are
> > > > fairly rare and the vtime sampling does not end up
> > > > "in phase" with the jiffies incrementing, could make
> > > > the accounting work right again.
> > > 
> > > That improves jitter, especially on big boxen.  I have an 8 socket
> > > box
> > > that thinks it's an extra large PC, there, collision avoidance
> > > matters
> > > hugely.  I couldn't reproduce bean counting woes, no idea if
> > > collision
> > > avoidance will help that.
> > 
> > Out of curiosity, where is the main contention between ticks? I
> > indeed
> > know some locks that can be taken on special cases, such as posix cpu
> > timers.
> > 
> > Also, why does it raise power consumption issues?
> 
> On a system without either nohz_full or nohz idle
> mode, skewed ticks result in CPU cores waking up
> at different times, and keeping an idle system
> consuming power for more time than it would if all
> the ticks happened simultaneously.

Ah fair point!

> 
> This is not a factor at all on systems that switch
> off the tick while idle, since the CPU will be busy
> anyway while the tick is enabled.

I see. Thanks!

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
> Cc Peterz, Thomas,
> 2017-03-30 12:27 GMT+08:00 Mike Galbraith :
> > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> >
> >> In other words, the tick on cpu0 is aligned
> >> with the tick on the nohz_full cpus, and
> >> jiffies is advanced while the nohz_full cpus
> >> with an active tick happen to be in kernel
> >> mode?
> >
> > You really want skew_tick=1, especially on big boxen.
> >
> >> Frederic, can you think of any reason why
> >> the tick on nohz_full CPUs would end up aligned
> >> with the tick on cpu0, instead of running at some
> >> random offset?
> >
> > (I or low rq->clock bits as crude NOHZ collision avoidance)
> >
> >> A random offset, or better yet a somewhat randomized
> >> tick length to make sure that simultaneous ticks are
> >> fairly rare and the vtime sampling does not end up
> >> "in phase" with the jiffies incrementing, could make
> >> the accounting work right again.
> >
> > That improves jitter, especially on big boxen.  I have an 8 socket box
> > that thinks it's an extra large PC, there, collision avoidance matters
> > hugely.  I couldn't reproduce bean counting woes, no idea if collision
> > avoidance will help that.
> 
> So I implement two methods, one is from Rik's random offset proposal
> through skew tick, the other one is from Frederic's proposal and it is
> the same as my original idea through use nanosecond granularity to
> check deltas but only perform an actual cputime update when that delta
> >= TICK_NSEC. Both methods can solve the bug which Luiz reported.
> Peterz, Thomas, any ideas?
> 
> --->8-
> 
> skew tick:
> 
> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> index 7fe53be..9981437 100644
> --- a/kernel/time/tick-sched.c
> +++ b/kernel/time/tick-sched.c
> @@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
>  hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());
> 
>  /* Offset the tick to avert jiffies_lock contention. */
> +#ifdef CONFIG_NO_HZ_FULL
> +if (sched_skew_tick || tick_nohz_full_running) {
> +#else
>  if (sched_skew_tick) {
> +#endif

Please rather use tick_nohz_full_enabled() to avoid ifdeffery.

>  u64 offset = ktime_to_ns(tick_period) >> 1;
>  do_div(offset, num_possible_cpus());
>  offset *= smp_processor_id();

If it works, we may want to take that solution, likely less performance 
sensitive
than using sched_clock(). In fact sched_clock() is fast, especially as we 
require it to
be stable for nohz_full, but using it involves costly conversion back and forth 
to jiffies.

> 
> -->8-
> 
> use nanosecond granularity to check deltas but only perform an actual
> cputime update when that delta >= TICK_NSEC.
> 
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f1ee393 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 now = local_clock();

I fear we need a global clock, because the reader (task_cputime()) needs
to compute the delta and therefore use the same clock from any CPU.

Or we can use the local_clock() but the reader must access the same.

So there would be vtime_delta_writer() which uses local_clock and stores
the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
is protected by vtime_seqcount as well.

Although those sched_clock_cpu() things seem to only matter when the
sched_clock() is unstable. And that stability is a condition for nohz_full
to work anyway. So probably sched_clock() alone would be enough.

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 02:47:11PM +0800, Wanpeng Li wrote:
> Cc Peterz, Thomas,
> 2017-03-30 12:27 GMT+08:00 Mike Galbraith :
> > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> >
> >> In other words, the tick on cpu0 is aligned
> >> with the tick on the nohz_full cpus, and
> >> jiffies is advanced while the nohz_full cpus
> >> with an active tick happen to be in kernel
> >> mode?
> >
> > You really want skew_tick=1, especially on big boxen.
> >
> >> Frederic, can you think of any reason why
> >> the tick on nohz_full CPUs would end up aligned
> >> with the tick on cpu0, instead of running at some
> >> random offset?
> >
> > (I or low rq->clock bits as crude NOHZ collision avoidance)
> >
> >> A random offset, or better yet a somewhat randomized
> >> tick length to make sure that simultaneous ticks are
> >> fairly rare and the vtime sampling does not end up
> >> "in phase" with the jiffies incrementing, could make
> >> the accounting work right again.
> >
> > That improves jitter, especially on big boxen.  I have an 8 socket box
> > that thinks it's an extra large PC, there, collision avoidance matters
> > hugely.  I couldn't reproduce bean counting woes, no idea if collision
> > avoidance will help that.
> 
> So I implement two methods, one is from Rik's random offset proposal
> through skew tick, the other one is from Frederic's proposal and it is
> the same as my original idea through use nanosecond granularity to
> check deltas but only perform an actual cputime update when that delta
> >= TICK_NSEC. Both methods can solve the bug which Luiz reported.
> Peterz, Thomas, any ideas?
> 
> --->8-
> 
> skew tick:
> 
> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> index 7fe53be..9981437 100644
> --- a/kernel/time/tick-sched.c
> +++ b/kernel/time/tick-sched.c
> @@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
>  hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());
> 
>  /* Offset the tick to avert jiffies_lock contention. */
> +#ifdef CONFIG_NO_HZ_FULL
> +if (sched_skew_tick || tick_nohz_full_running) {
> +#else
>  if (sched_skew_tick) {
> +#endif

Please rather use tick_nohz_full_enabled() to avoid ifdeffery.

>  u64 offset = ktime_to_ns(tick_period) >> 1;
>  do_div(offset, num_possible_cpus());
>  offset *= smp_processor_id();

If it works, we may want to take that solution, likely less performance 
sensitive
than using sched_clock(). In fact sched_clock() is fast, especially as we 
require it to
be stable for nohz_full, but using it involves costly conversion back and forth 
to jiffies.

> 
> -->8-
> 
> use nanosecond granularity to check deltas but only perform an actual
> cputime update when that delta >= TICK_NSEC.
> 
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f1ee393 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 now = local_clock();

I fear we need a global clock, because the reader (task_cputime()) needs
to compute the delta and therefore use the same clock from any CPU.

Or we can use the local_clock() but the reader must access the same.

So there would be vtime_delta_writer() which uses local_clock and stores
the current CPU to tsk->vtime_cpu (under the vtime_seqcount). And then
vtime_delta_reader() which calls sched_clock_cpu(tsk->vtime_cpu) which
is protected by vtime_seqcount as well.

Although those sched_clock_cpu() things seem to only matter when the
sched_clock() is unstable. And that stability is a condition for nohz_full
to work anyway. So probably sched_clock() alone would be enough.

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Thu, 2017-03-30 at 09:02 -0400, Rik van Riel wrote:
> On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:

> > Also, why does it raise power consumption issues?
> 
> On a system without either nohz_full or nohz idle
> mode, skewed ticks result in CPU cores waking up
> at different times, and keeping an idle system
> consuming power for more time than it would if all
> the ticks happened simultaneously.

And if your server farm is mostly idle, that power savings may delay
your bankruptcy proceedings by a whole microsecond ;-)

Or more seriously, what skew does do on boxen of size X today is
something for perf to say.  At the time, removal was very bad for my 8
socket box, and allegedly caused huge SGI beasts in horrific pain.

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Thu, 2017-03-30 at 09:02 -0400, Rik van Riel wrote:
> On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:

> > Also, why does it raise power consumption issues?
> 
> On a system without either nohz_full or nohz idle
> mode, skewed ticks result in CPU cores waking up
> at different times, and keeping an idle system
> consuming power for more time than it would if all
> the ticks happened simultaneously.

And if your server farm is mostly idle, that power savings may delay
your bankruptcy proceedings by a whole microsecond ;-)

Or more seriously, what skew does do on boxen of size X today is
something for perf to say.  At the time, removal was very bad for my 8
socket box, and allegedly caused huge SGI beasts in horrific pain.

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Thu, 2017-03-30 at 14:40 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 30, 2017 at 09:58:44AM +0800, Wanpeng Li wrote:

> > There is such a feature skew_tick currently, refer to commit
> > 5307c9556bc (tick: add tick skew boot option), w/ skew_tick=1 boot
> > parameter, the bug disappear, however, the commit also mentioned that
> > it will hurt power consumption.
> 
> Oh, I completely missed that!

It suggests it'll harm power consumption because skew removal allegedly
saved power.  Recalling what removal did to my 8 socket box, I doubt
adding it back costs large boxen anything at all, rather the opposite.

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Thu, 2017-03-30 at 14:40 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 30, 2017 at 09:58:44AM +0800, Wanpeng Li wrote:

> > There is such a feature skew_tick currently, refer to commit
> > 5307c9556bc (tick: add tick skew boot option), w/ skew_tick=1 boot
> > parameter, the bug disappear, however, the commit also mentioned that
> > it will hurt power consumption.
> 
> Oh, I completely missed that!

It suggests it'll harm power consumption because skew removal allegedly
saved power.  Recalling what removal did to my 8 socket box, I doubt
adding it back costs large boxen anything at all, rather the opposite.

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 30, 2017 at 06:27:31AM +0200, Mike Galbraith wrote:
> > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> > 
> > > A random offset, or better yet a somewhat randomized
> > > tick length to make sure that simultaneous ticks are
> > > fairly rare and the vtime sampling does not end up
> > > "in phase" with the jiffies incrementing, could make
> > > the accounting work right again.
> > 
> > That improves jitter, especially on big boxen.  I have an 8 socket
> > box
> > that thinks it's an extra large PC, there, collision avoidance
> > matters
> > hugely.  I couldn't reproduce bean counting woes, no idea if
> > collision
> > avoidance will help that.
> 
> Out of curiosity, where is the main contention between ticks? I
> indeed
> know some locks that can be taken on special cases, such as posix cpu
> timers.
> 
> Also, why does it raise power consumption issues?

On a system without either nohz_full or nohz idle
mode, skewed ticks result in CPU cores waking up
at different times, and keeping an idle system
consuming power for more time than it would if all
the ticks happened simultaneously.

This is not a factor at all on systems that switch
off the tick while idle, since the CPU will be busy
anyway while the tick is enabled.

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Thu, 2017-03-30 at 14:51 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 30, 2017 at 06:27:31AM +0200, Mike Galbraith wrote:
> > On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> > 
> > > A random offset, or better yet a somewhat randomized
> > > tick length to make sure that simultaneous ticks are
> > > fairly rare and the vtime sampling does not end up
> > > "in phase" with the jiffies incrementing, could make
> > > the accounting work right again.
> > 
> > That improves jitter, especially on big boxen.  I have an 8 socket
> > box
> > that thinks it's an extra large PC, there, collision avoidance
> > matters
> > hugely.  I couldn't reproduce bean counting woes, no idea if
> > collision
> > avoidance will help that.
> 
> Out of curiosity, where is the main contention between ticks? I
> indeed
> know some locks that can be taken on special cases, such as posix cpu
> timers.
> 
> Also, why does it raise power consumption issues?

On a system without either nohz_full or nohz idle
mode, skewed ticks result in CPU cores waking up
at different times, and keeping an idle system
consuming power for more time than it would if all
the ticks happened simultaneously.

This is not a factor at all on systems that switch
off the tick while idle, since the CPU will be busy
anyway while the tick is enabled.

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Thu, 2017-03-30 at 00:54 +0200, Frederic Weisbecker wrote:
> (Adding Thomas in Cc)
> 
> On Wed, Mar 29, 2017 at 04:08:45PM -0400, Rik van Riel wrote:
> > 
> > Frederic, can you think of any reason why
> > the tick on nohz_full CPUs would end up aligned
> > with the tick on cpu0, instead of running at some
> > random offset?
> 
> tick_init_jiffy_update() takes that decision to align all ticks.
> 
> I'm not sure why. 

I don't see why that would matter, either.

> I'm not sure that randomizing the tick start per CPU would be a
> right solution. Somewhere in the world you can be sure the tick
> randomization of some nohz_full CPU will coincide with the tick
> of CPU 0 :o)
> 
> Or we could force that tick on nohz_full CPUs to be far from
> CPU 0's tick... I'm not sure such a solution would be accepted
> though.

I am not sure we would have to force things.

Simply getting rid of tick_init_jiffy_update
and scheduling the next tick for "now + tick
period" might have the same effect, when the
tick gets stopped and restarted on nohz_full
CPUs.

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Thu, 2017-03-30 at 00:54 +0200, Frederic Weisbecker wrote:
> (Adding Thomas in Cc)
> 
> On Wed, Mar 29, 2017 at 04:08:45PM -0400, Rik van Riel wrote:
> > 
> > Frederic, can you think of any reason why
> > the tick on nohz_full CPUs would end up aligned
> > with the tick on cpu0, instead of running at some
> > random offset?
> 
> tick_init_jiffy_update() takes that decision to align all ticks.
> 
> I'm not sure why. 

I don't see why that would matter, either.

> I'm not sure that randomizing the tick start per CPU would be a
> right solution. Somewhere in the world you can be sure the tick
> randomization of some nohz_full CPU will coincide with the tick
> of CPU 0 :o)
> 
> Or we could force that tick on nohz_full CPUs to be far from
> CPU 0's tick... I'm not sure such a solution would be accepted
> though.

I am not sure we would have to force things.

Simply getting rid of tick_init_jiffy_update
and scheduling the next tick for "now + tick
period" might have the same effect, when the
tick gets stopped and restarted on nohz_full
CPUs.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 06:27:31AM +0200, Mike Galbraith wrote:
> On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> 
> > A random offset, or better yet a somewhat randomized
> > tick length to make sure that simultaneous ticks are
> > fairly rare and the vtime sampling does not end up
> > "in phase" with the jiffies incrementing, could make
> > the accounting work right again.
> 
> That improves jitter, especially on big boxen.  I have an 8 socket box
> that thinks it's an extra large PC, there, collision avoidance matters
> hugely.  I couldn't reproduce bean counting woes, no idea if collision
> avoidance will help that.

Out of curiosity, where is the main contention between ticks? I indeed
know some locks that can be taken on special cases, such as posix cpu timers.

Also, why does it raise power consumption issues?

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 06:27:31AM +0200, Mike Galbraith wrote:
> On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
> 
> > A random offset, or better yet a somewhat randomized
> > tick length to make sure that simultaneous ticks are
> > fairly rare and the vtime sampling does not end up
> > "in phase" with the jiffies incrementing, could make
> > the accounting work right again.
> 
> That improves jitter, especially on big boxen.  I have an 8 socket box
> that thinks it's an extra large PC, there, collision avoidance matters
> hugely.  I couldn't reproduce bean counting woes, no idea if collision
> avoidance will help that.

Out of curiosity, where is the main contention between ticks? I indeed
know some locks that can be taken on special cases, such as posix cpu timers.

Also, why does it raise power consumption issues?

Thanks.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 09:58:44AM +0800, Wanpeng Li wrote:
> 2017-03-30 4:08 GMT+08:00 Rik van Riel :
> >
> > In other words, the tick on cpu0 is aligned
> > with the tick on the nohz_full cpus, and
> > jiffies is advanced while the nohz_full cpus
> > with an active tick happen to be in kernel
> > mode?
> >
> > Frederic, can you think of any reason why
> > the tick on nohz_full CPUs would end up aligned
> > with the tick on cpu0, instead of running at some
> > random offset?
> >
> > A random offset, or better yet a somewhat randomized
> > tick length to make sure that simultaneous ticks are
> > fairly rare and the vtime sampling does not end up
> > "in phase" with the jiffies incrementing, could make
> > the accounting work right again.
> >
> > Of course, that assumes the above hypothesis is correct :)
> 
> There is such a feature skew_tick currently, refer to commit
> 5307c9556bc (tick: add tick skew boot option), w/ skew_tick=1 boot
> parameter, the bug disappear, however, the commit also mentioned that
> it will hurt power consumption.

Oh, I completely missed that!

> I will try Frederic's proposal which
> is similar to my original idea "how bad would it be to revert to
> sched_clock() instead of jiffies in vtime_delta()? We could use
> nanosecond granularity to check deltas but only perform an actual
> cputime update when that delta >= TICK_NSEC."

Thanks! I hope sched_clock() won't introduce too much overhead.
Otherwise we may want to pick up the skew_tick solution.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 30, 2017 at 09:58:44AM +0800, Wanpeng Li wrote:
> 2017-03-30 4:08 GMT+08:00 Rik van Riel :
> >
> > In other words, the tick on cpu0 is aligned
> > with the tick on the nohz_full cpus, and
> > jiffies is advanced while the nohz_full cpus
> > with an active tick happen to be in kernel
> > mode?
> >
> > Frederic, can you think of any reason why
> > the tick on nohz_full CPUs would end up aligned
> > with the tick on cpu0, instead of running at some
> > random offset?
> >
> > A random offset, or better yet a somewhat randomized
> > tick length to make sure that simultaneous ticks are
> > fairly rare and the vtime sampling does not end up
> > "in phase" with the jiffies incrementing, could make
> > the accounting work right again.
> >
> > Of course, that assumes the above hypothesis is correct :)
> 
> There is such a feature skew_tick currently, refer to commit
> 5307c9556bc (tick: add tick skew boot option), w/ skew_tick=1 boot
> parameter, the bug disappear, however, the commit also mentioned that
> it will hurt power consumption.

Oh, I completely missed that!

> I will try Frederic's proposal which
> is similar to my original idea "how bad would it be to revert to
> sched_clock() instead of jiffies in vtime_delta()? We could use
> nanosecond granularity to check deltas but only perform an actual
> cputime update when that delta >= TICK_NSEC."

Thanks! I hope sched_clock() won't introduce too much overhead.
Otherwise we may want to pick up the skew_tick solution.

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Thu, 2017-03-30 at 19:52 +0800, Wanpeng Li wrote:

> If we should just add random offset to the cpu in the nohz_full mode?

Up to you, whatever works best.  I left the regular skew alone, just
added some noise to scheduler_tick_max_deferment().

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Thu, 2017-03-30 at 19:52 +0800, Wanpeng Li wrote:

> If we should just add random offset to the cpu in the nohz_full mode?

Up to you, whatever works best.  I left the regular skew alone, just
added some noise to scheduler_tick_max_deferment().

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 10:14 GMT+08:00 Luiz Capitulino :
> On Thu, 30 Mar 2017 06:46:30 +0800
> Wanpeng Li  wrote:
>
>> > So! Now we need to find a proper fix :o)
>> >
>> > Hmm, how bad would it be to revert to sched_clock() instead of jiffies in 
>> > vtime_delta()?
>> > We could use nanosecond granularity to check deltas but only perform an 
>> > actual cputime update
>> > when that delta >= TICK_NSEC. That should keep the load ok.
>>
>> Yeah, I mentioned something similar before.
>> https://lkml.org/lkml/2017/3/26/138 However, Rik's commit optimized
>> syscalls by not utilize sched_clock(), so if we should distinguish
>> between syscalls/exceptions and irqs?
>
> Why not use ktime_get()?

I believe ktime_get() is more heavy than local_clock() when sched
clock is stable. So we can cooperate to improve
https://lkml.org/lkml/2017/3/30/456.

Regards,
Wanpeng Li

>
> Here's the solution I was thinking about, it's mostly untested. I'm
> rate limiting below TICK_NSEC because I want to avoid syncing with
> the tick.
>
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..a8b1e85 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,20 @@ void thread_group_cputime_adjusted(struct task_struct 
> *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -   unsigned long now = READ_ONCE(jiffies);
> +   return ktime_sub(ktime_get(), tsk->vtime_snap);
> +}
>
> -   if (time_before(now, (unsigned long)tsk->vtime_snap))
> -   return 0;
> +/* A little bit less than the tick period */
> +#define VTIME_RATE_LIMIT (TICK_NSEC - 20)
>
> -   return jiffies_to_nsecs(now - tsk->vtime_snap);
> +static bool vtime_should_account(struct task_struct *tsk)
> +{
> +   return vtime_delta(tsk) > VTIME_RATE_LIMIT;
>  }
>
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -   unsigned long now = READ_ONCE(jiffies);
> -   u64 delta, other;
> +   u64 delta, other, now = ktime_get();
>
> /*
>  * Unlike tick based timing, vtime based timing never has lost
> @@ -696,7 +698,7 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>  * elapsed time. Limit account_other_time to prevent rounding
>  * errors from causing elapsed vtime to go negative.
>  */
> -   delta = jiffies_to_nsecs(now - tsk->vtime_snap);
> +   delta = ktime_sub(now, tsk->vtime_snap);
> other = account_other_time(delta);
> WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> tsk->vtime_snap = now;
> @@ -711,7 +713,7 @@ static void __vtime_account_system(struct task_struct 
> *tsk)
>
>  void vtime_account_system(struct task_struct *tsk)
>  {
> -   if (!vtime_delta(tsk))
> +   if (!vtime_should_account(tsk))
> return;
>
> write_seqcount_begin(>vtime_seqcount);
> @@ -723,7 +725,7 @@ void vtime_account_user(struct task_struct *tsk)
>  {
> write_seqcount_begin(>vtime_seqcount);
> tsk->vtime_snap_whence = VTIME_SYS;
> -   if (vtime_delta(tsk))
> +   if (vtime_should_account(tsk))
> account_user_time(tsk, get_vtime_delta(tsk));
> write_seqcount_end(>vtime_seqcount);
>  }
> @@ -731,7 +733,7 @@ void vtime_account_user(struct task_struct *tsk)
>  void vtime_user_enter(struct task_struct *tsk)
>  {
> write_seqcount_begin(>vtime_seqcount);
> -   if (vtime_delta(tsk))
> +   if (vtime_should_account(tsk))
> __vtime_account_system(tsk);
> tsk->vtime_snap_whence = VTIME_USER;
> write_seqcount_end(>vtime_seqcount);
> @@ -747,7 +749,7 @@ void vtime_guest_enter(struct task_struct *tsk)
>  * that can thus safely catch up with a tickless delta.
>  */
> write_seqcount_begin(>vtime_seqcount);
> -   if (vtime_delta(tsk))
> +   if (vtime_should_account(tsk))
> __vtime_account_system(tsk);
> current->flags |= PF_VCPU;
> write_seqcount_end(>vtime_seqcount);
> @@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)
>
> write_seqcount_begin(>vtime_seqcount);
> current->vtime_snap_whence = VTIME_SYS;
> -   current->vtime_snap = jiffies;
> +   current->vtime_snap = ktime_get();
> write_seqcount_end(>vtime_seqcount);
>  }
>

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 10:14 GMT+08:00 Luiz Capitulino :
> On Thu, 30 Mar 2017 06:46:30 +0800
> Wanpeng Li  wrote:
>
>> > So! Now we need to find a proper fix :o)
>> >
>> > Hmm, how bad would it be to revert to sched_clock() instead of jiffies in 
>> > vtime_delta()?
>> > We could use nanosecond granularity to check deltas but only perform an 
>> > actual cputime update
>> > when that delta >= TICK_NSEC. That should keep the load ok.
>>
>> Yeah, I mentioned something similar before.
>> https://lkml.org/lkml/2017/3/26/138 However, Rik's commit optimized
>> syscalls by not utilize sched_clock(), so if we should distinguish
>> between syscalls/exceptions and irqs?
>
> Why not use ktime_get()?

I believe ktime_get() is more heavy than local_clock() when sched
clock is stable. So we can cooperate to improve
https://lkml.org/lkml/2017/3/30/456.

Regards,
Wanpeng Li

>
> Here's the solution I was thinking about, it's mostly untested. I'm
> rate limiting below TICK_NSEC because I want to avoid syncing with
> the tick.
>
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..a8b1e85 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,20 @@ void thread_group_cputime_adjusted(struct task_struct 
> *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -   unsigned long now = READ_ONCE(jiffies);
> +   return ktime_sub(ktime_get(), tsk->vtime_snap);
> +}
>
> -   if (time_before(now, (unsigned long)tsk->vtime_snap))
> -   return 0;
> +/* A little bit less than the tick period */
> +#define VTIME_RATE_LIMIT (TICK_NSEC - 20)
>
> -   return jiffies_to_nsecs(now - tsk->vtime_snap);
> +static bool vtime_should_account(struct task_struct *tsk)
> +{
> +   return vtime_delta(tsk) > VTIME_RATE_LIMIT;
>  }
>
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -   unsigned long now = READ_ONCE(jiffies);
> -   u64 delta, other;
> +   u64 delta, other, now = ktime_get();
>
> /*
>  * Unlike tick based timing, vtime based timing never has lost
> @@ -696,7 +698,7 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>  * elapsed time. Limit account_other_time to prevent rounding
>  * errors from causing elapsed vtime to go negative.
>  */
> -   delta = jiffies_to_nsecs(now - tsk->vtime_snap);
> +   delta = ktime_sub(now, tsk->vtime_snap);
> other = account_other_time(delta);
> WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> tsk->vtime_snap = now;
> @@ -711,7 +713,7 @@ static void __vtime_account_system(struct task_struct 
> *tsk)
>
>  void vtime_account_system(struct task_struct *tsk)
>  {
> -   if (!vtime_delta(tsk))
> +   if (!vtime_should_account(tsk))
> return;
>
> write_seqcount_begin(>vtime_seqcount);
> @@ -723,7 +725,7 @@ void vtime_account_user(struct task_struct *tsk)
>  {
> write_seqcount_begin(>vtime_seqcount);
> tsk->vtime_snap_whence = VTIME_SYS;
> -   if (vtime_delta(tsk))
> +   if (vtime_should_account(tsk))
> account_user_time(tsk, get_vtime_delta(tsk));
> write_seqcount_end(>vtime_seqcount);
>  }
> @@ -731,7 +733,7 @@ void vtime_account_user(struct task_struct *tsk)
>  void vtime_user_enter(struct task_struct *tsk)
>  {
> write_seqcount_begin(>vtime_seqcount);
> -   if (vtime_delta(tsk))
> +   if (vtime_should_account(tsk))
> __vtime_account_system(tsk);
> tsk->vtime_snap_whence = VTIME_USER;
> write_seqcount_end(>vtime_seqcount);
> @@ -747,7 +749,7 @@ void vtime_guest_enter(struct task_struct *tsk)
>  * that can thus safely catch up with a tickless delta.
>  */
> write_seqcount_begin(>vtime_seqcount);
> -   if (vtime_delta(tsk))
> +   if (vtime_should_account(tsk))
> __vtime_account_system(tsk);
> current->flags |= PF_VCPU;
> write_seqcount_end(>vtime_seqcount);
> @@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)
>
> write_seqcount_begin(>vtime_seqcount);
> current->vtime_snap_whence = VTIME_SYS;
> -   current->vtime_snap = jiffies;
> +   current->vtime_snap = ktime_get();
> write_seqcount_end(>vtime_seqcount);
>  }
>

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 14:47 GMT+08:00 Wanpeng Li :
> Cc Peterz, Thomas,
> 2017-03-30 12:27 GMT+08:00 Mike Galbraith :
>> On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
>>
>>> In other words, the tick on cpu0 is aligned
>>> with the tick on the nohz_full cpus, and
>>> jiffies is advanced while the nohz_full cpus
>>> with an active tick happen to be in kernel
>>> mode?
>>
>> You really want skew_tick=1, especially on big boxen.
>>
>>> Frederic, can you think of any reason why
>>> the tick on nohz_full CPUs would end up aligned
>>> with the tick on cpu0, instead of running at some
>>> random offset?
>>
>> (I or low rq->clock bits as crude NOHZ collision avoidance)
>>
>>> A random offset, or better yet a somewhat randomized
>>> tick length to make sure that simultaneous ticks are
>>> fairly rare and the vtime sampling does not end up
>>> "in phase" with the jiffies incrementing, could make
>>> the accounting work right again.
>>
>> That improves jitter, especially on big boxen.  I have an 8 socket box
>> that thinks it's an extra large PC, there, collision avoidance matters
>> hugely.  I couldn't reproduce bean counting woes, no idea if collision
>> avoidance will help that.
>
> So I implement two methods, one is from Rik's random offset proposal

If we should just add random offset to the cpu in the nohz_full mode?

> through skew tick, the other one is from Frederic's proposal and it is
> the same as my original idea through use nanosecond granularity to
> check deltas but only perform an actual cputime update when that delta
>>= TICK_NSEC. Both methods can solve the bug which Luiz reported.

This can just solves two cpu hogs running on the cpu in nohz_full
mode. However, Luiz's testcase w/ ./acct-bug 1 995 shows idle 100%.

Regards,
Wanpeng Li

> Peterz, Thomas, any ideas?
>
> --->8-
>
> skew tick:
>
> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> index 7fe53be..9981437 100644
> --- a/kernel/time/tick-sched.c
> +++ b/kernel/time/tick-sched.c
> @@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
>  hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());
>
>  /* Offset the tick to avert jiffies_lock contention. */
> +#ifdef CONFIG_NO_HZ_FULL
> +if (sched_skew_tick || tick_nohz_full_running) {
> +#else
>  if (sched_skew_tick) {
> +#endif
>  u64 offset = ktime_to_ns(tick_period) >> 1;
>  do_div(offset, num_possible_cpus());
>  offset *= smp_processor_id();
>
> -->8-
>
> use nanosecond granularity to check deltas but only perform an actual
> cputime update when that delta >= TICK_NSEC.
>
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f1ee393 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 now = local_clock();
> +u64 delta;
> +
> +delta = now - tsk->vtime_snap;
>
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> +if (delta < TICK_NSEC)
>  return 0;
>
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +return jiffies_to_nsecs(delta / TICK_NSEC);
>  }
>
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk);
> +u64 other;
>
>  /*
>   * Unlike tick based timing, vtime based timing never has lost
> @@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>   * elapsed time. Limit account_other_time to prevent rounding
>   * errors from causing elapsed vtime to go negative.
>   */
> -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
>  other = account_other_time(delta);
>  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> -tsk->vtime_snap = now;
> +tsk->vtime_snap += delta;
>
>  return delta - other;
>  }
> @@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)
>
>  write_seqcount_begin(>vtime_seqcount);
>  current->vtime_snap_whence = VTIME_SYS;
> -current->vtime_snap = jiffies;
> +current->vtime_snap = sched_clock_cpu(smp_processor_id());
>  write_seqcount_end(>vtime_seqcount);
>  }
>
> @@ -787,7 +789,7 @@ void vtime_init_idle(struct task_struct *t, int cpu)
>  local_irq_save(flags);
>  write_seqcount_begin(>vtime_seqcount);
>  t->vtime_snap_whence = VTIME_SYS;
> -t->vtime_snap = jiffies;
> +t->vtime_snap = sched_clock_cpu(cpu);
>  write_seqcount_end(>vtime_seqcount);
>  local_irq_restore(flags);
>  }
>
> Regards,
> Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 14:47 GMT+08:00 Wanpeng Li :
> Cc Peterz, Thomas,
> 2017-03-30 12:27 GMT+08:00 Mike Galbraith :
>> On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
>>
>>> In other words, the tick on cpu0 is aligned
>>> with the tick on the nohz_full cpus, and
>>> jiffies is advanced while the nohz_full cpus
>>> with an active tick happen to be in kernel
>>> mode?
>>
>> You really want skew_tick=1, especially on big boxen.
>>
>>> Frederic, can you think of any reason why
>>> the tick on nohz_full CPUs would end up aligned
>>> with the tick on cpu0, instead of running at some
>>> random offset?
>>
>> (I or low rq->clock bits as crude NOHZ collision avoidance)
>>
>>> A random offset, or better yet a somewhat randomized
>>> tick length to make sure that simultaneous ticks are
>>> fairly rare and the vtime sampling does not end up
>>> "in phase" with the jiffies incrementing, could make
>>> the accounting work right again.
>>
>> That improves jitter, especially on big boxen.  I have an 8 socket box
>> that thinks it's an extra large PC, there, collision avoidance matters
>> hugely.  I couldn't reproduce bean counting woes, no idea if collision
>> avoidance will help that.
>
> So I implement two methods, one is from Rik's random offset proposal

If we should just add random offset to the cpu in the nohz_full mode?

> through skew tick, the other one is from Frederic's proposal and it is
> the same as my original idea through use nanosecond granularity to
> check deltas but only perform an actual cputime update when that delta
>>= TICK_NSEC. Both methods can solve the bug which Luiz reported.

This can just solves two cpu hogs running on the cpu in nohz_full
mode. However, Luiz's testcase w/ ./acct-bug 1 995 shows idle 100%.

Regards,
Wanpeng Li

> Peterz, Thomas, any ideas?
>
> --->8-
>
> skew tick:
>
> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> index 7fe53be..9981437 100644
> --- a/kernel/time/tick-sched.c
> +++ b/kernel/time/tick-sched.c
> @@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
>  hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());
>
>  /* Offset the tick to avert jiffies_lock contention. */
> +#ifdef CONFIG_NO_HZ_FULL
> +if (sched_skew_tick || tick_nohz_full_running) {
> +#else
>  if (sched_skew_tick) {
> +#endif
>  u64 offset = ktime_to_ns(tick_period) >> 1;
>  do_div(offset, num_possible_cpus());
>  offset *= smp_processor_id();
>
> -->8-
>
> use nanosecond granularity to check deltas but only perform an actual
> cputime update when that delta >= TICK_NSEC.
>
> diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
> index f3778e2b..f1ee393 100644
> --- a/kernel/sched/cputime.c
> +++ b/kernel/sched/cputime.c
> @@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
> task_struct *p, u64 *ut, u64 *st)
>  #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
>  static u64 vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> +u64 now = local_clock();
> +u64 delta;
> +
> +delta = now - tsk->vtime_snap;
>
> -if (time_before(now, (unsigned long)tsk->vtime_snap))
> +if (delta < TICK_NSEC)
>  return 0;
>
> -return jiffies_to_nsecs(now - tsk->vtime_snap);
> +return jiffies_to_nsecs(delta / TICK_NSEC);
>  }
>
>  static u64 get_vtime_delta(struct task_struct *tsk)
>  {
> -unsigned long now = READ_ONCE(jiffies);
> -u64 delta, other;
> +u64 delta = vtime_delta(tsk);
> +u64 other;
>
>  /*
>   * Unlike tick based timing, vtime based timing never has lost
> @@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
>   * elapsed time. Limit account_other_time to prevent rounding
>   * errors from causing elapsed vtime to go negative.
>   */
> -delta = jiffies_to_nsecs(now - tsk->vtime_snap);
>  other = account_other_time(delta);
>  WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
> -tsk->vtime_snap = now;
> +tsk->vtime_snap += delta;
>
>  return delta - other;
>  }
> @@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)
>
>  write_seqcount_begin(>vtime_seqcount);
>  current->vtime_snap_whence = VTIME_SYS;
> -current->vtime_snap = jiffies;
> +current->vtime_snap = sched_clock_cpu(smp_processor_id());
>  write_seqcount_end(>vtime_seqcount);
>  }
>
> @@ -787,7 +789,7 @@ void vtime_init_idle(struct task_struct *t, int cpu)
>  local_irq_save(flags);
>  write_seqcount_begin(>vtime_seqcount);
>  t->vtime_snap_whence = VTIME_SYS;
> -t->vtime_snap = jiffies;
> +t->vtime_snap = sched_clock_cpu(cpu);
>  write_seqcount_end(>vtime_seqcount);
>  local_irq_restore(flags);
>  }
>
> Regards,
> Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

Cc Peterz, Thomas,
2017-03-30 12:27 GMT+08:00 Mike Galbraith :
> On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
>
>> In other words, the tick on cpu0 is aligned
>> with the tick on the nohz_full cpus, and
>> jiffies is advanced while the nohz_full cpus
>> with an active tick happen to be in kernel
>> mode?
>
> You really want skew_tick=1, especially on big boxen.
>
>> Frederic, can you think of any reason why
>> the tick on nohz_full CPUs would end up aligned
>> with the tick on cpu0, instead of running at some
>> random offset?
>
> (I or low rq->clock bits as crude NOHZ collision avoidance)
>
>> A random offset, or better yet a somewhat randomized
>> tick length to make sure that simultaneous ticks are
>> fairly rare and the vtime sampling does not end up
>> "in phase" with the jiffies incrementing, could make
>> the accounting work right again.
>
> That improves jitter, especially on big boxen.  I have an 8 socket box
> that thinks it's an extra large PC, there, collision avoidance matters
> hugely.  I couldn't reproduce bean counting woes, no idea if collision
> avoidance will help that.

So I implement two methods, one is from Rik's random offset proposal
through skew tick, the other one is from Frederic's proposal and it is
the same as my original idea through use nanosecond granularity to
check deltas but only perform an actual cputime update when that delta
>= TICK_NSEC. Both methods can solve the bug which Luiz reported.
Peterz, Thomas, any ideas?

--->8-

skew tick:

diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
index 7fe53be..9981437 100644
--- a/kernel/time/tick-sched.c
+++ b/kernel/time/tick-sched.c
@@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
 hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());

 /* Offset the tick to avert jiffies_lock contention. */
+#ifdef CONFIG_NO_HZ_FULL
+if (sched_skew_tick || tick_nohz_full_running) {
+#else
 if (sched_skew_tick) {
+#endif
 u64 offset = ktime_to_ns(tick_period) >> 1;
 do_div(offset, num_possible_cpus());
 offset *= smp_processor_id();

-->8-

use nanosecond granularity to check deltas but only perform an actual
cputime update when that delta >= TICK_NSEC.

diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..f1ee393 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
task_struct *p, u64 *ut, u64 *st)
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 static u64 vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
+u64 now = local_clock();
+u64 delta;
+
+delta = now - tsk->vtime_snap;

-if (time_before(now, (unsigned long)tsk->vtime_snap))
+if (delta < TICK_NSEC)
 return 0;

-return jiffies_to_nsecs(now - tsk->vtime_snap);
+return jiffies_to_nsecs(delta / TICK_NSEC);
 }

 static u64 get_vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
-u64 delta, other;
+u64 delta = vtime_delta(tsk);
+u64 other;

 /*
  * Unlike tick based timing, vtime based timing never has lost
@@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
  * elapsed time. Limit account_other_time to prevent rounding
  * errors from causing elapsed vtime to go negative.
  */
-delta = jiffies_to_nsecs(now - tsk->vtime_snap);
 other = account_other_time(delta);
 WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
-tsk->vtime_snap = now;
+tsk->vtime_snap += delta;

 return delta - other;
 }
@@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)

 write_seqcount_begin(>vtime_seqcount);
 current->vtime_snap_whence = VTIME_SYS;
-current->vtime_snap = jiffies;
+current->vtime_snap = sched_clock_cpu(smp_processor_id());
 write_seqcount_end(>vtime_seqcount);
 }

@@ -787,7 +789,7 @@ void vtime_init_idle(struct task_struct *t, int cpu)
 local_irq_save(flags);
 write_seqcount_begin(>vtime_seqcount);
 t->vtime_snap_whence = VTIME_SYS;
-t->vtime_snap = jiffies;
+t->vtime_snap = sched_clock_cpu(cpu);
 write_seqcount_end(>vtime_seqcount);
 local_irq_restore(flags);
 }

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

Cc Peterz, Thomas,
2017-03-30 12:27 GMT+08:00 Mike Galbraith :
> On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:
>
>> In other words, the tick on cpu0 is aligned
>> with the tick on the nohz_full cpus, and
>> jiffies is advanced while the nohz_full cpus
>> with an active tick happen to be in kernel
>> mode?
>
> You really want skew_tick=1, especially on big boxen.
>
>> Frederic, can you think of any reason why
>> the tick on nohz_full CPUs would end up aligned
>> with the tick on cpu0, instead of running at some
>> random offset?
>
> (I or low rq->clock bits as crude NOHZ collision avoidance)
>
>> A random offset, or better yet a somewhat randomized
>> tick length to make sure that simultaneous ticks are
>> fairly rare and the vtime sampling does not end up
>> "in phase" with the jiffies incrementing, could make
>> the accounting work right again.
>
> That improves jitter, especially on big boxen.  I have an 8 socket box
> that thinks it's an extra large PC, there, collision avoidance matters
> hugely.  I couldn't reproduce bean counting woes, no idea if collision
> avoidance will help that.

So I implement two methods, one is from Rik's random offset proposal
through skew tick, the other one is from Frederic's proposal and it is
the same as my original idea through use nanosecond granularity to
check deltas but only perform an actual cputime update when that delta
>= TICK_NSEC. Both methods can solve the bug which Luiz reported.
Peterz, Thomas, any ideas?

--->8-

skew tick:

diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
index 7fe53be..9981437 100644
--- a/kernel/time/tick-sched.c
+++ b/kernel/time/tick-sched.c
@@ -1198,7 +1198,11 @@ void tick_setup_sched_timer(void)
 hrtimer_set_expires(>sched_timer, tick_init_jiffy_update());

 /* Offset the tick to avert jiffies_lock contention. */
+#ifdef CONFIG_NO_HZ_FULL
+if (sched_skew_tick || tick_nohz_full_running) {
+#else
 if (sched_skew_tick) {
+#endif
 u64 offset = ktime_to_ns(tick_period) >> 1;
 do_div(offset, num_possible_cpus());
 offset *= smp_processor_id();

-->8-

use nanosecond granularity to check deltas but only perform an actual
cputime update when that delta >= TICK_NSEC.

diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..f1ee393 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -676,18 +676,21 @@ void thread_group_cputime_adjusted(struct
task_struct *p, u64 *ut, u64 *st)
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 static u64 vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
+u64 now = local_clock();
+u64 delta;
+
+delta = now - tsk->vtime_snap;

-if (time_before(now, (unsigned long)tsk->vtime_snap))
+if (delta < TICK_NSEC)
 return 0;

-return jiffies_to_nsecs(now - tsk->vtime_snap);
+return jiffies_to_nsecs(delta / TICK_NSEC);
 }

 static u64 get_vtime_delta(struct task_struct *tsk)
 {
-unsigned long now = READ_ONCE(jiffies);
-u64 delta, other;
+u64 delta = vtime_delta(tsk);
+u64 other;

 /*
  * Unlike tick based timing, vtime based timing never has lost
@@ -696,10 +699,9 @@ static u64 get_vtime_delta(struct task_struct *tsk)
  * elapsed time. Limit account_other_time to prevent rounding
  * errors from causing elapsed vtime to go negative.
  */
-delta = jiffies_to_nsecs(now - tsk->vtime_snap);
 other = account_other_time(delta);
 WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
-tsk->vtime_snap = now;
+tsk->vtime_snap += delta;

 return delta - other;
 }
@@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)

 write_seqcount_begin(>vtime_seqcount);
 current->vtime_snap_whence = VTIME_SYS;
-current->vtime_snap = jiffies;
+current->vtime_snap = sched_clock_cpu(smp_processor_id());
 write_seqcount_end(>vtime_seqcount);
 }

@@ -787,7 +789,7 @@ void vtime_init_idle(struct task_struct *t, int cpu)
 local_irq_save(flags);
 write_seqcount_begin(>vtime_seqcount);
 t->vtime_snap_whence = VTIME_SYS;
-t->vtime_snap = jiffies;
+t->vtime_snap = sched_clock_cpu(cpu);
 write_seqcount_end(>vtime_seqcount);
 local_irq_restore(flags);
 }

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:

> In other words, the tick on cpu0 is aligned
> with the tick on the nohz_full cpus, and
> jiffies is advanced while the nohz_full cpus
> with an active tick happen to be in kernel
> mode?

You really want skew_tick=1, especially on big boxen.
 
> Frederic, can you think of any reason why
> the tick on nohz_full CPUs would end up aligned
> with the tick on cpu0, instead of running at some
> random offset?

(I or low rq->clock bits as crude NOHZ collision avoidance)

> A random offset, or better yet a somewhat randomized
> tick length to make sure that simultaneous ticks are
> fairly rare and the vtime sampling does not end up
> "in phase" with the jiffies incrementing, could make
> the accounting work right again.

That improves jitter, especially on big boxen.  I have an 8 socket box
that thinks it's an extra large PC, there, collision avoidance matters
hugely.  I couldn't reproduce bean counting woes, no idea if collision
avoidance will help that.

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Mike Galbraith]

On Wed, 2017-03-29 at 16:08 -0400, Rik van Riel wrote:

> In other words, the tick on cpu0 is aligned
> with the tick on the nohz_full cpus, and
> jiffies is advanced while the nohz_full cpus
> with an active tick happen to be in kernel
> mode?

You really want skew_tick=1, especially on big boxen.
 
> Frederic, can you think of any reason why
> the tick on nohz_full CPUs would end up aligned
> with the tick on cpu0, instead of running at some
> random offset?

(I or low rq->clock bits as crude NOHZ collision avoidance)

> A random offset, or better yet a somewhat randomized
> tick length to make sure that simultaneous ticks are
> fairly rare and the vtime sampling does not end up
> "in phase" with the jiffies incrementing, could make
> the accounting work right again.

That improves jitter, especially on big boxen.  I have an 8 socket box
that thinks it's an extra large PC, there, collision avoidance matters
hugely.  I couldn't reproduce bean counting woes, no idea if collision
avoidance will help that.

-Mike

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Thu, 30 Mar 2017 06:46:30 +0800
Wanpeng Li  wrote:

> > So! Now we need to find a proper fix :o)
> >
> > Hmm, how bad would it be to revert to sched_clock() instead of jiffies in 
> > vtime_delta()?
> > We could use nanosecond granularity to check deltas but only perform an 
> > actual cputime update
> > when that delta >= TICK_NSEC. That should keep the load ok.  
> 
> Yeah, I mentioned something similar before.
> https://lkml.org/lkml/2017/3/26/138 However, Rik's commit optimized
> syscalls by not utilize sched_clock(), so if we should distinguish
> between syscalls/exceptions and irqs?

Why not use ktime_get()?

Here's the solution I was thinking about, it's mostly untested. I'm
rate limiting below TICK_NSEC because I want to avoid syncing with
the tick.

diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..a8b1e85 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -676,18 +676,20 @@ void thread_group_cputime_adjusted(struct task_struct *p, 
u64 *ut, u64 *st)
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 static u64 vtime_delta(struct task_struct *tsk)
 {
-   unsigned long now = READ_ONCE(jiffies);
+   return ktime_sub(ktime_get(), tsk->vtime_snap);
+}
 
-   if (time_before(now, (unsigned long)tsk->vtime_snap))
-   return 0;
+/* A little bit less than the tick period */
+#define VTIME_RATE_LIMIT (TICK_NSEC - 20)
 
-   return jiffies_to_nsecs(now - tsk->vtime_snap);
+static bool vtime_should_account(struct task_struct *tsk)
+{
+   return vtime_delta(tsk) > VTIME_RATE_LIMIT;
 }
 
 static u64 get_vtime_delta(struct task_struct *tsk)
 {
-   unsigned long now = READ_ONCE(jiffies);
-   u64 delta, other;
+   u64 delta, other, now = ktime_get();
 
/*
 * Unlike tick based timing, vtime based timing never has lost
@@ -696,7 +698,7 @@ static u64 get_vtime_delta(struct task_struct *tsk)
 * elapsed time. Limit account_other_time to prevent rounding
 * errors from causing elapsed vtime to go negative.
 */
-   delta = jiffies_to_nsecs(now - tsk->vtime_snap);
+   delta = ktime_sub(now, tsk->vtime_snap);
other = account_other_time(delta);
WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
tsk->vtime_snap = now;
@@ -711,7 +713,7 @@ static void __vtime_account_system(struct task_struct *tsk)
 
 void vtime_account_system(struct task_struct *tsk)
 {
-   if (!vtime_delta(tsk))
+   if (!vtime_should_account(tsk))
return;
 
write_seqcount_begin(>vtime_seqcount);
@@ -723,7 +725,7 @@ void vtime_account_user(struct task_struct *tsk)
 {
write_seqcount_begin(>vtime_seqcount);
tsk->vtime_snap_whence = VTIME_SYS;
-   if (vtime_delta(tsk))
+   if (vtime_should_account(tsk))
account_user_time(tsk, get_vtime_delta(tsk));
write_seqcount_end(>vtime_seqcount);
 }
@@ -731,7 +733,7 @@ void vtime_account_user(struct task_struct *tsk)
 void vtime_user_enter(struct task_struct *tsk)
 {
write_seqcount_begin(>vtime_seqcount);
-   if (vtime_delta(tsk))
+   if (vtime_should_account(tsk))
__vtime_account_system(tsk);
tsk->vtime_snap_whence = VTIME_USER;
write_seqcount_end(>vtime_seqcount);
@@ -747,7 +749,7 @@ void vtime_guest_enter(struct task_struct *tsk)
 * that can thus safely catch up with a tickless delta.
 */
write_seqcount_begin(>vtime_seqcount);
-   if (vtime_delta(tsk))
+   if (vtime_should_account(tsk))
__vtime_account_system(tsk);
current->flags |= PF_VCPU;
write_seqcount_end(>vtime_seqcount);
@@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)
 
write_seqcount_begin(>vtime_seqcount);
current->vtime_snap_whence = VTIME_SYS;
-   current->vtime_snap = jiffies;
+   current->vtime_snap = ktime_get();
write_seqcount_end(>vtime_seqcount);
 }
 

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Thu, 30 Mar 2017 06:46:30 +0800
Wanpeng Li  wrote:

> > So! Now we need to find a proper fix :o)
> >
> > Hmm, how bad would it be to revert to sched_clock() instead of jiffies in 
> > vtime_delta()?
> > We could use nanosecond granularity to check deltas but only perform an 
> > actual cputime update
> > when that delta >= TICK_NSEC. That should keep the load ok.  
> 
> Yeah, I mentioned something similar before.
> https://lkml.org/lkml/2017/3/26/138 However, Rik's commit optimized
> syscalls by not utilize sched_clock(), so if we should distinguish
> between syscalls/exceptions and irqs?

Why not use ktime_get()?

Here's the solution I was thinking about, it's mostly untested. I'm
rate limiting below TICK_NSEC because I want to avoid syncing with
the tick.

diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c
index f3778e2b..a8b1e85 100644
--- a/kernel/sched/cputime.c
+++ b/kernel/sched/cputime.c
@@ -676,18 +676,20 @@ void thread_group_cputime_adjusted(struct task_struct *p, 
u64 *ut, u64 *st)
 #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN
 static u64 vtime_delta(struct task_struct *tsk)
 {
-   unsigned long now = READ_ONCE(jiffies);
+   return ktime_sub(ktime_get(), tsk->vtime_snap);
+}
 
-   if (time_before(now, (unsigned long)tsk->vtime_snap))
-   return 0;
+/* A little bit less than the tick period */
+#define VTIME_RATE_LIMIT (TICK_NSEC - 20)
 
-   return jiffies_to_nsecs(now - tsk->vtime_snap);
+static bool vtime_should_account(struct task_struct *tsk)
+{
+   return vtime_delta(tsk) > VTIME_RATE_LIMIT;
 }
 
 static u64 get_vtime_delta(struct task_struct *tsk)
 {
-   unsigned long now = READ_ONCE(jiffies);
-   u64 delta, other;
+   u64 delta, other, now = ktime_get();
 
/*
 * Unlike tick based timing, vtime based timing never has lost
@@ -696,7 +698,7 @@ static u64 get_vtime_delta(struct task_struct *tsk)
 * elapsed time. Limit account_other_time to prevent rounding
 * errors from causing elapsed vtime to go negative.
 */
-   delta = jiffies_to_nsecs(now - tsk->vtime_snap);
+   delta = ktime_sub(now, tsk->vtime_snap);
other = account_other_time(delta);
WARN_ON_ONCE(tsk->vtime_snap_whence == VTIME_INACTIVE);
tsk->vtime_snap = now;
@@ -711,7 +713,7 @@ static void __vtime_account_system(struct task_struct *tsk)
 
 void vtime_account_system(struct task_struct *tsk)
 {
-   if (!vtime_delta(tsk))
+   if (!vtime_should_account(tsk))
return;
 
write_seqcount_begin(>vtime_seqcount);
@@ -723,7 +725,7 @@ void vtime_account_user(struct task_struct *tsk)
 {
write_seqcount_begin(>vtime_seqcount);
tsk->vtime_snap_whence = VTIME_SYS;
-   if (vtime_delta(tsk))
+   if (vtime_should_account(tsk))
account_user_time(tsk, get_vtime_delta(tsk));
write_seqcount_end(>vtime_seqcount);
 }
@@ -731,7 +733,7 @@ void vtime_account_user(struct task_struct *tsk)
 void vtime_user_enter(struct task_struct *tsk)
 {
write_seqcount_begin(>vtime_seqcount);
-   if (vtime_delta(tsk))
+   if (vtime_should_account(tsk))
__vtime_account_system(tsk);
tsk->vtime_snap_whence = VTIME_USER;
write_seqcount_end(>vtime_seqcount);
@@ -747,7 +749,7 @@ void vtime_guest_enter(struct task_struct *tsk)
 * that can thus safely catch up with a tickless delta.
 */
write_seqcount_begin(>vtime_seqcount);
-   if (vtime_delta(tsk))
+   if (vtime_should_account(tsk))
__vtime_account_system(tsk);
current->flags |= PF_VCPU;
write_seqcount_end(>vtime_seqcount);
@@ -776,7 +778,7 @@ void arch_vtime_task_switch(struct task_struct *prev)
 
write_seqcount_begin(>vtime_seqcount);
current->vtime_snap_whence = VTIME_SYS;
-   current->vtime_snap = jiffies;
+   current->vtime_snap = ktime_get();
write_seqcount_end(>vtime_seqcount);
 }
 

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 4:08 GMT+08:00 Rik van Riel :
> On Wed, 2017-03-29 at 13:16 -0400, Luiz Capitulino wrote:
>> On Tue, 28 Mar 2017 13:24:06 -0400
>> Luiz Capitulino  wrote:
>>
>> >  1. In my tracing I'm seeing that sometimes (always?) the
>> > time interval between two timer interrupts is less than 1ms
>>
>> I think that's the root cause.
>>
>> In this trace, we see the following:
>>
>>  1. On CPU15, we transition from user-space to kernel-space because
>> of a timer interrupt (it's the tick)
>>
>>  2. vtimer_delta() returns 0, because jiffies didn't change since the
>> last accounting
>>
>>  3. While CPU15 is executing in kernel-space, jiffies is updated
>> by CPU0
>>
>>  4. When going back to user-space, vtime_delta() returns non-zero
>> and the whole time is accounted for system time (observe how
>> the cputime parameter in account_system_time() is less than 1ms)
>
> In other words, the tick on cpu0 is aligned
> with the tick on the nohz_full cpus, and
> jiffies is advanced while the nohz_full cpus
> with an active tick happen to be in kernel
> mode?
>
> Frederic, can you think of any reason why
> the tick on nohz_full CPUs would end up aligned
> with the tick on cpu0, instead of running at some
> random offset?
>
> A random offset, or better yet a somewhat randomized
> tick length to make sure that simultaneous ticks are
> fairly rare and the vtime sampling does not end up
> "in phase" with the jiffies incrementing, could make
> the accounting work right again.
>
> Of course, that assumes the above hypothesis is correct :)

There is such a feature skew_tick currently, refer to commit
5307c9556bc (tick: add tick skew boot option), w/ skew_tick=1 boot
parameter, the bug disappear, however, the commit also mentioned that
it will hurt power consumption. I will try Frederic's proposal which
is similar to my original idea "how bad would it be to revert to
sched_clock() instead of jiffies in vtime_delta()? We could use
nanosecond granularity to check deltas but only perform an actual
cputime update when that delta >= TICK_NSEC."

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 4:08 GMT+08:00 Rik van Riel :
> On Wed, 2017-03-29 at 13:16 -0400, Luiz Capitulino wrote:
>> On Tue, 28 Mar 2017 13:24:06 -0400
>> Luiz Capitulino  wrote:
>>
>> >  1. In my tracing I'm seeing that sometimes (always?) the
>> > time interval between two timer interrupts is less than 1ms
>>
>> I think that's the root cause.
>>
>> In this trace, we see the following:
>>
>>  1. On CPU15, we transition from user-space to kernel-space because
>> of a timer interrupt (it's the tick)
>>
>>  2. vtimer_delta() returns 0, because jiffies didn't change since the
>> last accounting
>>
>>  3. While CPU15 is executing in kernel-space, jiffies is updated
>> by CPU0
>>
>>  4. When going back to user-space, vtime_delta() returns non-zero
>> and the whole time is accounted for system time (observe how
>> the cputime parameter in account_system_time() is less than 1ms)
>
> In other words, the tick on cpu0 is aligned
> with the tick on the nohz_full cpus, and
> jiffies is advanced while the nohz_full cpus
> with an active tick happen to be in kernel
> mode?
>
> Frederic, can you think of any reason why
> the tick on nohz_full CPUs would end up aligned
> with the tick on cpu0, instead of running at some
> random offset?
>
> A random offset, or better yet a somewhat randomized
> tick length to make sure that simultaneous ticks are
> fairly rare and the vtime sampling does not end up
> "in phase" with the jiffies incrementing, could make
> the accounting work right again.
>
> Of course, that assumes the above hypothesis is correct :)

There is such a feature skew_tick currently, refer to commit
5307c9556bc (tick: add tick skew boot option), w/ skew_tick=1 boot
parameter, the bug disappear, however, the commit also mentioned that
it will hurt power consumption. I will try Frederic's proposal which
is similar to my original idea "how bad would it be to revert to
sched_clock() instead of jiffies in vtime_delta()? We could use
nanosecond granularity to check deltas but only perform an actual
cputime update when that delta >= TICK_NSEC."

Regards,
Wanpeng Li

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Wed, 29 Mar 2017 23:12:00 +0200
Frederic Weisbecker  wrote:

> On Wed, Mar 29, 2017 at 09:23:57AM -0400, Luiz Capitulino wrote:
> > 
> > There are various reproducers actually. I started off with the simple
> > loop above, then wrote the attach program and then wrote the one
> > you're mentioning:
> > 
> >  http://people.redhat.com/~lcapitul/real-time/acct-bug.c
> > 
> > All of them reproduce the issue 100% of the time for me.  
> 
> > #define _GNU_SOURCE
> > #include 
> > #include 
> > #include 
> > #include 
> > #include 
> > 
> > static int move_to_cpu(int cpu)
> > {
> > cpu_set_t set;
> > 
> > CPU_ZERO();
> > CPU_SET(cpu, );
> > return sched_setaffinity(0, sizeof(set), );
> > }
> > 
> > static void loop(void)
> > {
> > for (;;) ;
> > }
> > 
> > static int fork_hog(int cpu)
> > {
> > int pid;
> > 
> > pid = (int) fork();
> > if (pid == 0) {
> > move_to_cpu(cpu);
> > loop();
> > exit(0);
> > }
> > 
> > return pid;
> > }
> > 
> > int main(int argc, char *argv[])
> > {
> > int i, pid, cpu, nr_procs;
> > 
> > if (argc != 3) {
> > printf("usage: hog < nr-procs > < CPU >\n");
> > exit(1);
> > }
> > 
> > cpu = atoi(argv[2]);
> > nr_procs = atoi(argv[1]);
> > 
> > for (i = 0; i < nr_procs; i++) {
> > pid = fork_hog(cpu);
> > fprintf(stderr, "created hog%d pid=%d\n", i, pid);
> > }
> > 
> > fprintf(stderr, "pausing...\n");
> > pause();
> > 
> > return 0;
> > }  
> 
> I just tried both of these and none seem to show incorrect cputime :-/
> I'm wondering if that bug depends on some hardware.

Are you running on x86? My CPU is:

Intel(R) Xeon(R) CPU E5-2640 v3 @ 2.60GHz

I wonder if this issue depends on the timer used by the hrtimer
subsystem.

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Wed, 29 Mar 2017 23:12:00 +0200
Frederic Weisbecker  wrote:

> On Wed, Mar 29, 2017 at 09:23:57AM -0400, Luiz Capitulino wrote:
> > 
> > There are various reproducers actually. I started off with the simple
> > loop above, then wrote the attach program and then wrote the one
> > you're mentioning:
> > 
> >  http://people.redhat.com/~lcapitul/real-time/acct-bug.c
> > 
> > All of them reproduce the issue 100% of the time for me.  
> 
> > #define _GNU_SOURCE
> > #include 
> > #include 
> > #include 
> > #include 
> > #include 
> > 
> > static int move_to_cpu(int cpu)
> > {
> > cpu_set_t set;
> > 
> > CPU_ZERO();
> > CPU_SET(cpu, );
> > return sched_setaffinity(0, sizeof(set), );
> > }
> > 
> > static void loop(void)
> > {
> > for (;;) ;
> > }
> > 
> > static int fork_hog(int cpu)
> > {
> > int pid;
> > 
> > pid = (int) fork();
> > if (pid == 0) {
> > move_to_cpu(cpu);
> > loop();
> > exit(0);
> > }
> > 
> > return pid;
> > }
> > 
> > int main(int argc, char *argv[])
> > {
> > int i, pid, cpu, nr_procs;
> > 
> > if (argc != 3) {
> > printf("usage: hog < nr-procs > < CPU >\n");
> > exit(1);
> > }
> > 
> > cpu = atoi(argv[2]);
> > nr_procs = atoi(argv[1]);
> > 
> > for (i = 0; i < nr_procs; i++) {
> > pid = fork_hog(cpu);
> > fprintf(stderr, "created hog%d pid=%d\n", i, pid);
> > }
> > 
> > fprintf(stderr, "pausing...\n");
> > pause();
> > 
> > return 0;
> > }  
> 
> I just tried both of these and none seem to show incorrect cputime :-/
> I'm wondering if that bug depends on some hardware.

Are you running on x86? My CPU is:

Intel(R) Xeon(R) CPU E5-2640 v3 @ 2.60GHz

I wonder if this issue depends on the timer used by the hrtimer
subsystem.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

(Adding Thomas in Cc)

On Wed, Mar 29, 2017 at 04:08:45PM -0400, Rik van Riel wrote:
> On Wed, 2017-03-29 at 13:16 -0400, Luiz Capitulino wrote:
> > On Tue, 28 Mar 2017 13:24:06 -0400
> > Luiz Capitulino  wrote:
> > 
> > >  1. In my tracing I'm seeing that sometimes (always?) the
> > > time interval between two timer interrupts is less than 1ms
> > 
> > I think that's the root cause.
> > 
> > In this trace, we see the following:
> > 
> >  1. On CPU15, we transition from user-space to kernel-space because
> > of a timer interrupt (it's the tick)
> > 
> >  2. vtimer_delta() returns 0, because jiffies didn't change since the
> > last accounting
> > 
> >  3. While CPU15 is executing in kernel-space, jiffies is updated
> > by CPU0
> > 
> >  4. When going back to user-space, vtime_delta() returns non-zero
> > and the whole time is accounted for system time (observe how
> > the cputime parameter in account_system_time() is less than 1ms)
> 
> In other words, the tick on cpu0 is aligned
> with the tick on the nohz_full cpus, and
> jiffies is advanced while the nohz_full cpus
> with an active tick happen to be in kernel
> mode?

Ah you found out faster than me :-)

> Frederic, can you think of any reason why
> the tick on nohz_full CPUs would end up aligned
> with the tick on cpu0, instead of running at some
> random offset?

tick_init_jiffy_update() takes that decision to align all ticks.

I'm not sure why. I don't see anything that could depend on that
wide tick synchronization. The jiffies update itself relies on ktime
to check when to update it. So even if the tick fires a bit later
on CPU 1 than on CPU 0, the jiffies updates should stay coherent and
should never exceed 999us delay in the worst case (for HZ=1000)

Now I might overlook something.

> 
> A random offset, or better yet a somewhat randomized
> tick length to make sure that simultaneous ticks are
> fairly rare and the vtime sampling does not end up
> "in phase" with the jiffies incrementing, could make
> the accounting work right again.
> 
> Of course, that assumes the above hypothesis is correct :)

I'm not sure that randomizing the tick start per CPU would be a
right solution. Somewhere in the world you can be sure the tick
randomization of some nohz_full CPU will coincide with the tick
of CPU 0 :o)

Or we could force that tick on nohz_full CPUs to be far from
CPU 0's tick... I'm not sure such a solution would be accepted though.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

(Adding Thomas in Cc)

On Wed, Mar 29, 2017 at 04:08:45PM -0400, Rik van Riel wrote:
> On Wed, 2017-03-29 at 13:16 -0400, Luiz Capitulino wrote:
> > On Tue, 28 Mar 2017 13:24:06 -0400
> > Luiz Capitulino  wrote:
> > 
> > >  1. In my tracing I'm seeing that sometimes (always?) the
> > > time interval between two timer interrupts is less than 1ms
> > 
> > I think that's the root cause.
> > 
> > In this trace, we see the following:
> > 
> >  1. On CPU15, we transition from user-space to kernel-space because
> > of a timer interrupt (it's the tick)
> > 
> >  2. vtimer_delta() returns 0, because jiffies didn't change since the
> > last accounting
> > 
> >  3. While CPU15 is executing in kernel-space, jiffies is updated
> > by CPU0
> > 
> >  4. When going back to user-space, vtime_delta() returns non-zero
> > and the whole time is accounted for system time (observe how
> > the cputime parameter in account_system_time() is less than 1ms)
> 
> In other words, the tick on cpu0 is aligned
> with the tick on the nohz_full cpus, and
> jiffies is advanced while the nohz_full cpus
> with an active tick happen to be in kernel
> mode?

Ah you found out faster than me :-)

> Frederic, can you think of any reason why
> the tick on nohz_full CPUs would end up aligned
> with the tick on cpu0, instead of running at some
> random offset?

tick_init_jiffy_update() takes that decision to align all ticks.

I'm not sure why. I don't see anything that could depend on that
wide tick synchronization. The jiffies update itself relies on ktime
to check when to update it. So even if the tick fires a bit later
on CPU 1 than on CPU 0, the jiffies updates should stay coherent and
should never exceed 999us delay in the worst case (for HZ=1000)

Now I might overlook something.

> 
> A random offset, or better yet a somewhat randomized
> tick length to make sure that simultaneous ticks are
> fairly rare and the vtime sampling does not end up
> "in phase" with the jiffies incrementing, could make
> the accounting work right again.
> 
> Of course, that assumes the above hypothesis is correct :)

I'm not sure that randomizing the tick start per CPU would be a
right solution. Somewhere in the world you can be sure the tick
randomization of some nohz_full CPU will coincide with the tick
of CPU 0 :o)

Or we could force that tick on nohz_full CPUs to be far from
CPU 0's tick... I'm not sure such a solution would be accepted though.

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 6:17 GMT+08:00 Frederic Weisbecker :
> On Wed, Mar 29, 2017 at 01:16:56PM -0400, Luiz Capitulino wrote:
>> On Tue, 28 Mar 2017 13:24:06 -0400
>> Luiz Capitulino  wrote:
>>
>> >  1. In my tracing I'm seeing that sometimes (always?) the
>> > time interval between two timer interrupts is less than 1ms
>>
>> I think that's the root cause.
>>
>> I'm getting traces like this:
>>
>>hog-11980 [015]   341.494491: function: enter_from_user_mode 
>> <-- apic_timer_interrupt
>> -0 [000]   341.494492: function: 
>> smp_apic_timer_interrupt <-- apic_timer_interrupt
>>hog-11980 [015]   341.494492: function: 
>> __context_tracking_exit <-- enter_from_user_mode
>> -0 [000]   341.494492: function: irq_enter <-- 
>> smp_apic_timer_interrupt
>>hog-11980 [015]   341.494492: bprint:   vtime_delta: diff=0 
>> (now=4295008339 vtime_snap=4295008339)
>>hog-11980 [015]   341.494492: function: 
>> smp_apic_timer_interrupt <-- apic_timer_interrupt
>>hog-11980 [015]   341.494492: function: irq_enter <-- 
>> smp_apic_timer_interrupt
>>hog-11980 [015]   341.494493: function: tick_sched_timer <-- 
>> __hrtimer_run_queues
>> -0 [000]   341.494493: function: tick_sched_timer <-- 
>> __hrtimer_run_queues
>> -0 [000]   341.494493: function: 
>> tick_do_update_jiffies64.part.14 <-- tick_sched_do_timer
>> -0 [000]   341.494494: function: do_timer <-- 
>> tick_do_update_jiffies64.part.14
>>hog-11980 [015]   341.494494: function: irq_exit <-- 
>> smp_apic_timer_interrupt
>> -0 [000]   341.494494: bprint:   do_timer: updated 
>> jiffies_64=4295008340 ticks=1
>>hog-11980 [015]   341.494494: function: 
>> __context_tracking_enter <-- prepare_exit_to_usermode
>>hog-11980 [015]   341.494494: function: vtime_user_enter <-- 
>> __context_tracking_enter
>>hog-11980 [015]   341.494495: bprint:   vtime_delta: 
>> diff=100 (now=4295008340 vtime_snap=4295008339)
>>hog-11980 [015]   341.494495: function: 
>> __vtime_account_system <-- vtime_user_enter
>>hog-11980 [015]   341.494495: bprint:   get_vtime_delta: 
>> vtime_snap=4295008339 now=4295008340
>>hog-11980 [015]   341.494495: function: account_system_time 
>> <-- __vtime_account_system
>>hog-11980 [015]   341.494495: bprint:   account_system_time: 
>> cputime=995488
>> -0 [000]   341.494497: function: irq_exit <-- 
>> smp_apic_timer_interrupt
>>
>> In this trace, we see the following:
>>
>>  1. On CPU15, we transition from user-space to kernel-space because
>> of a timer interrupt (it's the tick)
>>
>>  2. vtimer_delta() returns 0, because jiffies didn't change since the
>> last accounting
>>
>>  3. While CPU15 is executing in kernel-space, jiffies is updated
>> by CPU0
>>
>>  4. When going back to user-space, vtime_delta() returns non-zero
>> and the whole time is accounted for system time (observe how
>> the cputime parameter in account_system_time() is less than 1ms)
>
> Aah, so the issue can indeed happen if all CPUs fire their ticks at the same 
> time:
>
>
>  CPU 0 CPU 1
>  - -
>exit_user() // no cputime 
> update
> tick X   update_jiffies
>enter_user() // cputime update
>
>
>exit_user() //no cputime update
> tick X+1 update_jiffies
>enter_user() // cputime update
>
>>
>> That's why my patch from yesterday fixed the issue, it increased the
>> tick period to more than 1ms. So vtime_delta() always evaluate to true
>> when transitioning from user-space to kernel-space (because we spend
>> more than 1ms in user-space between ticks). The patch below achieves
>> the same result by adding 10us to the tick period.
>>
>> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
>> index 7fe53be..00e46df 100644
>> --- a/kernel/time/tick-sched.c
>> +++ b/kernel/time/tick-sched.c
>> @@ -1165,7 +1165,7 @@ static enum hrtimer_restart tick_sched_timer(struct 
>> hrtimer *timer)
>> if (unlikely(ts->tick_stopped))
>> return HRTIMER_NORESTART;
>>
>> -   hrtimer_forward(timer, now, tick_period);
>> +   hrtimer_forward(timer, now, tick_period + 1);
>
> I'm surprised it works though. If the 10us shift was only applied to CPU 0 
> and not the
> others then yes, but if it is applied to all CPUs, the ticks stay 
> synchronized and the
> problem should stay...
>
> Ah wait! It can work because the nohz_full CPUs have their ticks sometimes 
> scheduled
> by 

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-30 6:17 GMT+08:00 Frederic Weisbecker :
> On Wed, Mar 29, 2017 at 01:16:56PM -0400, Luiz Capitulino wrote:
>> On Tue, 28 Mar 2017 13:24:06 -0400
>> Luiz Capitulino  wrote:
>>
>> >  1. In my tracing I'm seeing that sometimes (always?) the
>> > time interval between two timer interrupts is less than 1ms
>>
>> I think that's the root cause.
>>
>> I'm getting traces like this:
>>
>>hog-11980 [015]   341.494491: function: enter_from_user_mode 
>> <-- apic_timer_interrupt
>> -0 [000]   341.494492: function: 
>> smp_apic_timer_interrupt <-- apic_timer_interrupt
>>hog-11980 [015]   341.494492: function: 
>> __context_tracking_exit <-- enter_from_user_mode
>> -0 [000]   341.494492: function: irq_enter <-- 
>> smp_apic_timer_interrupt
>>hog-11980 [015]   341.494492: bprint:   vtime_delta: diff=0 
>> (now=4295008339 vtime_snap=4295008339)
>>hog-11980 [015]   341.494492: function: 
>> smp_apic_timer_interrupt <-- apic_timer_interrupt
>>hog-11980 [015]   341.494492: function: irq_enter <-- 
>> smp_apic_timer_interrupt
>>hog-11980 [015]   341.494493: function: tick_sched_timer <-- 
>> __hrtimer_run_queues
>> -0 [000]   341.494493: function: tick_sched_timer <-- 
>> __hrtimer_run_queues
>> -0 [000]   341.494493: function: 
>> tick_do_update_jiffies64.part.14 <-- tick_sched_do_timer
>> -0 [000]   341.494494: function: do_timer <-- 
>> tick_do_update_jiffies64.part.14
>>hog-11980 [015]   341.494494: function: irq_exit <-- 
>> smp_apic_timer_interrupt
>> -0 [000]   341.494494: bprint:   do_timer: updated 
>> jiffies_64=4295008340 ticks=1
>>hog-11980 [015]   341.494494: function: 
>> __context_tracking_enter <-- prepare_exit_to_usermode
>>hog-11980 [015]   341.494494: function: vtime_user_enter <-- 
>> __context_tracking_enter
>>hog-11980 [015]   341.494495: bprint:   vtime_delta: 
>> diff=100 (now=4295008340 vtime_snap=4295008339)
>>hog-11980 [015]   341.494495: function: 
>> __vtime_account_system <-- vtime_user_enter
>>hog-11980 [015]   341.494495: bprint:   get_vtime_delta: 
>> vtime_snap=4295008339 now=4295008340
>>hog-11980 [015]   341.494495: function: account_system_time 
>> <-- __vtime_account_system
>>hog-11980 [015]   341.494495: bprint:   account_system_time: 
>> cputime=995488
>> -0 [000]   341.494497: function: irq_exit <-- 
>> smp_apic_timer_interrupt
>>
>> In this trace, we see the following:
>>
>>  1. On CPU15, we transition from user-space to kernel-space because
>> of a timer interrupt (it's the tick)
>>
>>  2. vtimer_delta() returns 0, because jiffies didn't change since the
>> last accounting
>>
>>  3. While CPU15 is executing in kernel-space, jiffies is updated
>> by CPU0
>>
>>  4. When going back to user-space, vtime_delta() returns non-zero
>> and the whole time is accounted for system time (observe how
>> the cputime parameter in account_system_time() is less than 1ms)
>
> Aah, so the issue can indeed happen if all CPUs fire their ticks at the same 
> time:
>
>
>  CPU 0 CPU 1
>  - -
>exit_user() // no cputime 
> update
> tick X   update_jiffies
>enter_user() // cputime update
>
>
>exit_user() //no cputime update
> tick X+1 update_jiffies
>enter_user() // cputime update
>
>>
>> That's why my patch from yesterday fixed the issue, it increased the
>> tick period to more than 1ms. So vtime_delta() always evaluate to true
>> when transitioning from user-space to kernel-space (because we spend
>> more than 1ms in user-space between ticks). The patch below achieves
>> the same result by adding 10us to the tick period.
>>
>> diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
>> index 7fe53be..00e46df 100644
>> --- a/kernel/time/tick-sched.c
>> +++ b/kernel/time/tick-sched.c
>> @@ -1165,7 +1165,7 @@ static enum hrtimer_restart tick_sched_timer(struct 
>> hrtimer *timer)
>> if (unlikely(ts->tick_stopped))
>> return HRTIMER_NORESTART;
>>
>> -   hrtimer_forward(timer, now, tick_period);
>> +   hrtimer_forward(timer, now, tick_period + 1);
>
> I'm surprised it works though. If the 10us shift was only applied to CPU 0 
> and not the
> others then yes, but if it is applied to all CPUs, the ticks stay 
> synchronized and the
> problem should stay...
>
> Ah wait! It can work because the nohz_full CPUs have their ticks sometimes 
> scheduled
> by tick_nohz_stop_sched_tick() or tick_nohz_restart_sched_tick() which 

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Wed, Mar 29, 2017 at 09:23:57AM -0400, Luiz Capitulino wrote:
> 
> There are various reproducers actually. I started off with the simple
> loop above, then wrote the attach program and then wrote the one
> you're mentioning:
> 
>  http://people.redhat.com/~lcapitul/real-time/acct-bug.c
> 
> All of them reproduce the issue 100% of the time for me.

> #define _GNU_SOURCE
> #include 
> #include 
> #include 
> #include 
> #include 
> 
> static int move_to_cpu(int cpu)
> {
> cpu_set_t set;
> 
> CPU_ZERO();
> CPU_SET(cpu, );
> return sched_setaffinity(0, sizeof(set), );
> }
> 
> static void loop(void)
> {
> for (;;) ;
> }
> 
> static int fork_hog(int cpu)
> {
> int pid;
> 
> pid = (int) fork();
> if (pid == 0) {
> move_to_cpu(cpu);
> loop();
> exit(0);
> }
> 
> return pid;
> }
> 
> int main(int argc, char *argv[])
> {
> int i, pid, cpu, nr_procs;
> 
>   if (argc != 3) {
>   printf("usage: hog < nr-procs > < CPU >\n");
>   exit(1);
>   }
> 
>   cpu = atoi(argv[2]);
>   nr_procs = atoi(argv[1]);
> 
> for (i = 0; i < nr_procs; i++) {
> pid = fork_hog(cpu);
> fprintf(stderr, "created hog%d pid=%d\n", i, pid);
> }
> 
> fprintf(stderr, "pausing...\n");
> pause();
> 
> return 0;
> }

I just tried both of these and none seem to show incorrect cputime :-/
I'm wondering if that bug depends on some hardware.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Wed, Mar 29, 2017 at 09:23:57AM -0400, Luiz Capitulino wrote:
> 
> There are various reproducers actually. I started off with the simple
> loop above, then wrote the attach program and then wrote the one
> you're mentioning:
> 
>  http://people.redhat.com/~lcapitul/real-time/acct-bug.c
> 
> All of them reproduce the issue 100% of the time for me.

> #define _GNU_SOURCE
> #include 
> #include 
> #include 
> #include 
> #include 
> 
> static int move_to_cpu(int cpu)
> {
> cpu_set_t set;
> 
> CPU_ZERO();
> CPU_SET(cpu, );
> return sched_setaffinity(0, sizeof(set), );
> }
> 
> static void loop(void)
> {
> for (;;) ;
> }
> 
> static int fork_hog(int cpu)
> {
> int pid;
> 
> pid = (int) fork();
> if (pid == 0) {
> move_to_cpu(cpu);
> loop();
> exit(0);
> }
> 
> return pid;
> }
> 
> int main(int argc, char *argv[])
> {
> int i, pid, cpu, nr_procs;
> 
>   if (argc != 3) {
>   printf("usage: hog < nr-procs > < CPU >\n");
>   exit(1);
>   }
> 
>   cpu = atoi(argv[2]);
>   nr_procs = atoi(argv[1]);
> 
> for (i = 0; i < nr_procs; i++) {
> pid = fork_hog(cpu);
> fprintf(stderr, "created hog%d pid=%d\n", i, pid);
> }
> 
> fprintf(stderr, "pausing...\n");
> pause();
> 
> return 0;
> }

I just tried both of these and none seem to show incorrect cputime :-/
I'm wondering if that bug depends on some hardware.

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Wed, 2017-03-29 at 13:16 -0400, Luiz Capitulino wrote:
> On Tue, 28 Mar 2017 13:24:06 -0400
> Luiz Capitulino  wrote:
> 
> >  1. In my tracing I'm seeing that sometimes (always?) the
> > time interval between two timer interrupts is less than 1ms
> 
> I think that's the root cause.
> 
> In this trace, we see the following:
> 
>  1. On CPU15, we transition from user-space to kernel-space because
> of a timer interrupt (it's the tick)
> 
>  2. vtimer_delta() returns 0, because jiffies didn't change since the
> last accounting
> 
>  3. While CPU15 is executing in kernel-space, jiffies is updated
> by CPU0
> 
>  4. When going back to user-space, vtime_delta() returns non-zero
> and the whole time is accounted for system time (observe how
> the cputime parameter in account_system_time() is less than 1ms)

In other words, the tick on cpu0 is aligned
with the tick on the nohz_full cpus, and
jiffies is advanced while the nohz_full cpus
with an active tick happen to be in kernel
mode?

Frederic, can you think of any reason why
the tick on nohz_full CPUs would end up aligned
with the tick on cpu0, instead of running at some
random offset?

A random offset, or better yet a somewhat randomized
tick length to make sure that simultaneous ticks are
fairly rare and the vtime sampling does not end up
"in phase" with the jiffies incrementing, could make
the accounting work right again.

Of course, that assumes the above hypothesis is correct :)

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Wed, 2017-03-29 at 13:16 -0400, Luiz Capitulino wrote:
> On Tue, 28 Mar 2017 13:24:06 -0400
> Luiz Capitulino  wrote:
> 
> >  1. In my tracing I'm seeing that sometimes (always?) the
> > time interval between two timer interrupts is less than 1ms
> 
> I think that's the root cause.
> 
> In this trace, we see the following:
> 
>  1. On CPU15, we transition from user-space to kernel-space because
> of a timer interrupt (it's the tick)
> 
>  2. vtimer_delta() returns 0, because jiffies didn't change since the
> last accounting
> 
>  3. While CPU15 is executing in kernel-space, jiffies is updated
> by CPU0
> 
>  4. When going back to user-space, vtime_delta() returns non-zero
> and the whole time is accounted for system time (observe how
> the cputime parameter in account_system_time() is less than 1ms)

In other words, the tick on cpu0 is aligned
with the tick on the nohz_full cpus, and
jiffies is advanced while the nohz_full cpus
with an active tick happen to be in kernel
mode?

Frederic, can you think of any reason why
the tick on nohz_full CPUs would end up aligned
with the tick on cpu0, instead of running at some
random offset?

A random offset, or better yet a somewhat randomized
tick length to make sure that simultaneous ticks are
fairly rare and the vtime sampling does not end up
"in phase" with the jiffies incrementing, could make
the accounting work right again.

Of course, that assumes the above hypothesis is correct :)

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Wed, 29 Mar 2017 09:14:32 -0400
Rik van Riel  wrote:

> > I failed to reproduce with your config. I'm still getting 99%
> > userspace
> > cputime. So I'm wondering if the hogging style plays a role.
> > 
> > I run pure user loops:
> > 
> > int main(int argc, char **argv)
> > {
> > for (;;);
> > return 0
> > }
> > 
> > Does your user program perform syscalls or IOs of some sort?  
> 
> Luiz's program makes a syscall every millisecond,
> if started with the arguments he gave as his
> reproducer.

There are various reproducers actually. I started off with the simple
loop above, then wrote the attach program and then wrote the one
you're mentioning:

 http://people.redhat.com/~lcapitul/real-time/acct-bug.c

All of them reproduce the issue 100% of the time for me.
#define _GNU_SOURCE
#include 
#include 
#include 
#include 
#include 

static int move_to_cpu(int cpu)
{
cpu_set_t set;

CPU_ZERO();
CPU_SET(cpu, );
return sched_setaffinity(0, sizeof(set), );
}

static void loop(void)
{
for (;;) ;
}

static int fork_hog(int cpu)
{
int pid;

pid = (int) fork();
if (pid == 0) {
move_to_cpu(cpu);
loop();
exit(0);
}

return pid;
}

int main(int argc, char *argv[])
{
int i, pid, cpu, nr_procs;

		if (argc != 3) {
			printf("usage: hog < nr-procs > < CPU >\n");
			exit(1);
		}

		cpu = atoi(argv[2]);
		nr_procs = atoi(argv[1]);

for (i = 0; i < nr_procs; i++) {
pid = fork_hog(cpu);
fprintf(stderr, "created hog%d pid=%d\n", i, pid);
}

fprintf(stderr, "pausing...\n");
pause();

return 0;
}

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Wed, 29 Mar 2017 09:14:32 -0400
Rik van Riel  wrote:

> > I failed to reproduce with your config. I'm still getting 99%
> > userspace
> > cputime. So I'm wondering if the hogging style plays a role.
> > 
> > I run pure user loops:
> > 
> > int main(int argc, char **argv)
> > {
> > for (;;);
> > return 0
> > }
> > 
> > Does your user program perform syscalls or IOs of some sort?  
> 
> Luiz's program makes a syscall every millisecond,
> if started with the arguments he gave as his
> reproducer.

There are various reproducers actually. I started off with the simple
loop above, then wrote the attach program and then wrote the one
you're mentioning:

 http://people.redhat.com/~lcapitul/real-time/acct-bug.c

All of them reproduce the issue 100% of the time for me.
#define _GNU_SOURCE
#include 
#include 
#include 
#include 
#include 

static int move_to_cpu(int cpu)
{
cpu_set_t set;

CPU_ZERO();
CPU_SET(cpu, );
return sched_setaffinity(0, sizeof(set), );
}

static void loop(void)
{
for (;;) ;
}

static int fork_hog(int cpu)
{
int pid;

pid = (int) fork();
if (pid == 0) {
move_to_cpu(cpu);
loop();
exit(0);
}

return pid;
}

int main(int argc, char *argv[])
{
int i, pid, cpu, nr_procs;

		if (argc != 3) {
			printf("usage: hog < nr-procs > < CPU >\n");
			exit(1);
		}

		cpu = atoi(argv[2]);
		nr_procs = atoi(argv[1]);

for (i = 0; i < nr_procs; i++) {
pid = fork_hog(cpu);
fprintf(stderr, "created hog%d pid=%d\n", i, pid);
}

fprintf(stderr, "pausing...\n");
pause();

return 0;
}

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Wed, 2017-03-29 at 15:04 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 23, 2017 at 04:55:12PM -0400, Luiz Capitulino wrote:
> > 
> > When there are two or more tasks executing in user-space and
> > taking 100% of a nohz_full CPU, top reports 70% system time
> > and 30% user time utilization. Sometimes I'm even able to get
> > 100% system time and 0% user time.
> > 
> > This was reproduced with latest Linus tree (093b995), but I
> > don't believe it's a regression (at least not a recent one)
> > as I can reproduce it with older kernels. Also, I have
> > CONFIG_IRQ_TIME_ACCOUNTING=y and haven't tried to reproduce
> > without it yet.
> > 
> > Below you'll find the steps to reproduce and some initial
> > analysis.
> > 
> > Steps to reproduce
> > --
> > 
> > 1. Set up a CPU for nohz_full with isolcpus= nohz_full=
> > 
> > 2. Pin two tasks that hog the CPU 100% of the time to that CPU
> 
> I failed to reproduce with your config. I'm still getting 99%
> userspace
> cputime. So I'm wondering if the hogging style plays a role.
> 
> I run pure user loops:
> 
> int main(int argc, char **argv)
> {
> for (;;);
> return 0
> }
> 
> Does your user program perform syscalls or IOs of some sort?

Luiz's program makes a syscall every millisecond,
if started with the arguments he gave as his
reproducer.

Re: [BUG nohz]: wrong user and system time accounting

[Rik van Riel]

On Wed, 2017-03-29 at 15:04 +0200, Frederic Weisbecker wrote:
> On Thu, Mar 23, 2017 at 04:55:12PM -0400, Luiz Capitulino wrote:
> > 
> > When there are two or more tasks executing in user-space and
> > taking 100% of a nohz_full CPU, top reports 70% system time
> > and 30% user time utilization. Sometimes I'm even able to get
> > 100% system time and 0% user time.
> > 
> > This was reproduced with latest Linus tree (093b995), but I
> > don't believe it's a regression (at least not a recent one)
> > as I can reproduce it with older kernels. Also, I have
> > CONFIG_IRQ_TIME_ACCOUNTING=y and haven't tried to reproduce
> > without it yet.
> > 
> > Below you'll find the steps to reproduce and some initial
> > analysis.
> > 
> > Steps to reproduce
> > --
> > 
> > 1. Set up a CPU for nohz_full with isolcpus= nohz_full=
> > 
> > 2. Pin two tasks that hog the CPU 100% of the time to that CPU
> 
> I failed to reproduce with your config. I'm still getting 99%
> userspace
> cputime. So I'm wondering if the hogging style plays a role.
> 
> I run pure user loops:
> 
> int main(int argc, char **argv)
> {
> for (;;);
> return 0
> }
> 
> Does your user program perform syscalls or IOs of some sort?

Luiz's program makes a syscall every millisecond,
if started with the arguments he gave as his
reproducer.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 23, 2017 at 04:55:12PM -0400, Luiz Capitulino wrote:
> 
> When there are two or more tasks executing in user-space and
> taking 100% of a nohz_full CPU, top reports 70% system time
> and 30% user time utilization. Sometimes I'm even able to get
> 100% system time and 0% user time.
> 
> This was reproduced with latest Linus tree (093b995), but I
> don't believe it's a regression (at least not a recent one)
> as I can reproduce it with older kernels. Also, I have
> CONFIG_IRQ_TIME_ACCOUNTING=y and haven't tried to reproduce
> without it yet.
> 
> Below you'll find the steps to reproduce and some initial
> analysis.
> 
> Steps to reproduce
> --
> 
> 1. Set up a CPU for nohz_full with isolcpus= nohz_full=
> 
> 2. Pin two tasks that hog the CPU 100% of the time to that CPU

I failed to reproduce with your config. I'm still getting 99% userspace
cputime. So I'm wondering if the hogging style plays a role.

I run pure user loops:

int main(int argc, char **argv)
{
for (;;);
return 0
}

Does your user program perform syscalls or IOs of some sort?

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Thu, Mar 23, 2017 at 04:55:12PM -0400, Luiz Capitulino wrote:
> 
> When there are two or more tasks executing in user-space and
> taking 100% of a nohz_full CPU, top reports 70% system time
> and 30% user time utilization. Sometimes I'm even able to get
> 100% system time and 0% user time.
> 
> This was reproduced with latest Linus tree (093b995), but I
> don't believe it's a regression (at least not a recent one)
> as I can reproduce it with older kernels. Also, I have
> CONFIG_IRQ_TIME_ACCOUNTING=y and haven't tried to reproduce
> without it yet.
> 
> Below you'll find the steps to reproduce and some initial
> analysis.
> 
> Steps to reproduce
> --
> 
> 1. Set up a CPU for nohz_full with isolcpus= nohz_full=
> 
> 2. Pin two tasks that hog the CPU 100% of the time to that CPU

I failed to reproduce with your config. I'm still getting 99% userspace
cputime. So I'm wondering if the hogging style plays a role.

I run pure user loops:

int main(int argc, char **argv)
{
for (;;);
return 0
}

Does your user program perform syscalls or IOs of some sort?

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Wed, Mar 29, 2017 at 05:56:30PM +0800, Wanpeng Li wrote:
> 2017-03-29 5:26 GMT+08:00 Luiz Capitulino :
> > On Tue, 28 Mar 2017 17:01:52 -0400
> > Rik van Riel  wrote:
> >
> >> On Tue, 2017-03-28 at 16:14 -0400, Luiz Capitulino wrote:
> >> > On Tue, 28 Mar 2017 13:24:06 -0400
> >> > Luiz Capitulino  wrote:
> >> > > I'm starting to suspect that the nohz code may be programming
> >> > > the tick period to be shorter than 1ms when it re-activates
> >> > > the tick.
> >> >
> >> > And I think I was right, it looks like the nohz code is programming
> >> > the tick period incorrectly when restarting the tick. The patch below
> >> > fixes things for me, but I still have some homework todo and more
> >> > testing before posting a patch for inclusion. Could you guys test it?
> >>
> >> Your patch seems to work. I don't claim to understand why
> >> your patch makes a difference, but for this particular test
> >> case, on this particular setup, it seems to work...
> >
> > I don't fully understand why either yet. I was looking for places
> > where nohz might be programming the tick period incorrectly and
> 
> The bug is still present when I config CONTEXT_TRACKING_FORCE and
> nohz=off in the boot parameter.

Indeed I saw something similar a few days ago with:

!CONFIG_NO_HZ_FULL && CONFIG_VIRT_CPU_ACCOUNTING_GEN && 
CONTEXT_TRACKING_FORCE

And it disappeared with CONFIG_NO_HZ_FULL=y so I didn't care much because that 
setting
isn't used in production and in fact I intend to remove CONTEXT_TRACKING_FORCE. 
But
it could be the sign of something important.

It might be different than Luiz's bug because I can't reproduce his bug yet 
even with
his config.

Re: [BUG nohz]: wrong user and system time accounting

[Frederic Weisbecker]

On Wed, Mar 29, 2017 at 05:56:30PM +0800, Wanpeng Li wrote:
> 2017-03-29 5:26 GMT+08:00 Luiz Capitulino :
> > On Tue, 28 Mar 2017 17:01:52 -0400
> > Rik van Riel  wrote:
> >
> >> On Tue, 2017-03-28 at 16:14 -0400, Luiz Capitulino wrote:
> >> > On Tue, 28 Mar 2017 13:24:06 -0400
> >> > Luiz Capitulino  wrote:
> >> > > I'm starting to suspect that the nohz code may be programming
> >> > > the tick period to be shorter than 1ms when it re-activates
> >> > > the tick.
> >> >
> >> > And I think I was right, it looks like the nohz code is programming
> >> > the tick period incorrectly when restarting the tick. The patch below
> >> > fixes things for me, but I still have some homework todo and more
> >> > testing before posting a patch for inclusion. Could you guys test it?
> >>
> >> Your patch seems to work. I don't claim to understand why
> >> your patch makes a difference, but for this particular test
> >> case, on this particular setup, it seems to work...
> >
> > I don't fully understand why either yet. I was looking for places
> > where nohz might be programming the tick period incorrectly and
> 
> The bug is still present when I config CONTEXT_TRACKING_FORCE and
> nohz=off in the boot parameter.

Indeed I saw something similar a few days ago with:

!CONFIG_NO_HZ_FULL && CONFIG_VIRT_CPU_ACCOUNTING_GEN && 
CONTEXT_TRACKING_FORCE

And it disappeared with CONFIG_NO_HZ_FULL=y so I didn't care much because that 
setting
isn't used in production and in fact I intend to remove CONTEXT_TRACKING_FORCE. 
But
it could be the sign of something important.

It might be different than Luiz's bug because I can't reproduce his bug yet 
even with
his config.

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-29 5:26 GMT+08:00 Luiz Capitulino :
> On Tue, 28 Mar 2017 17:01:52 -0400
> Rik van Riel  wrote:
>
>> On Tue, 2017-03-28 at 16:14 -0400, Luiz Capitulino wrote:
>> > On Tue, 28 Mar 2017 13:24:06 -0400
>> > Luiz Capitulino  wrote:
>> > > I'm starting to suspect that the nohz code may be programming
>> > > the tick period to be shorter than 1ms when it re-activates
>> > > the tick.
>> >
>> > And I think I was right, it looks like the nohz code is programming
>> > the tick period incorrectly when restarting the tick. The patch below
>> > fixes things for me, but I still have some homework todo and more
>> > testing before posting a patch for inclusion. Could you guys test it?
>>
>> Your patch seems to work. I don't claim to understand why
>> your patch makes a difference, but for this particular test
>> case, on this particular setup, it seems to work...
>
> I don't fully understand why either yet. I was looking for places
> where nohz might be programming the tick period incorrectly and

The bug is still present when I config CONTEXT_TRACKING_FORCE and
nohz=off in the boot parameter.

Regards,
Wanpeng Li

> I found that there's a case in tick_nohz_stop_sched_tick() where
> tick_nohz_restart() is called only to reprogram the tick timer,
> not cancel the tick. In this case, ts->last_tick seems to be out
> of date. Fixing this fixed accounting for me.
>
>> > diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
>> > index 7fe53be..9abe979 100644
>> > --- a/kernel/time/tick-sched.c
>> > +++ b/kernel/time/tick-sched.c
>> > @@ -1152,6 +1152,7 @@ static enum hrtimer_restart
>> > tick_sched_timer(struct hrtimer *timer)
>> > struct pt_regs *regs = get_irq_regs();
>> > ktime_t now = ktime_get();
>> >
>> > +   ts->last_tick = now;
>> > tick_sched_do_timer(now);
>> >
>> > /*
>>
>

Re: [BUG nohz]: wrong user and system time accounting

[Wanpeng Li]

2017-03-29 5:26 GMT+08:00 Luiz Capitulino :
> On Tue, 28 Mar 2017 17:01:52 -0400
> Rik van Riel  wrote:
>
>> On Tue, 2017-03-28 at 16:14 -0400, Luiz Capitulino wrote:
>> > On Tue, 28 Mar 2017 13:24:06 -0400
>> > Luiz Capitulino  wrote:
>> > > I'm starting to suspect that the nohz code may be programming
>> > > the tick period to be shorter than 1ms when it re-activates
>> > > the tick.
>> >
>> > And I think I was right, it looks like the nohz code is programming
>> > the tick period incorrectly when restarting the tick. The patch below
>> > fixes things for me, but I still have some homework todo and more
>> > testing before posting a patch for inclusion. Could you guys test it?
>>
>> Your patch seems to work. I don't claim to understand why
>> your patch makes a difference, but for this particular test
>> case, on this particular setup, it seems to work...
>
> I don't fully understand why either yet. I was looking for places
> where nohz might be programming the tick period incorrectly and

The bug is still present when I config CONTEXT_TRACKING_FORCE and
nohz=off in the boot parameter.

Regards,
Wanpeng Li

> I found that there's a case in tick_nohz_stop_sched_tick() where
> tick_nohz_restart() is called only to reprogram the tick timer,
> not cancel the tick. In this case, ts->last_tick seems to be out
> of date. Fixing this fixed accounting for me.
>
>> > diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
>> > index 7fe53be..9abe979 100644
>> > --- a/kernel/time/tick-sched.c
>> > +++ b/kernel/time/tick-sched.c
>> > @@ -1152,6 +1152,7 @@ static enum hrtimer_restart
>> > tick_sched_timer(struct hrtimer *timer)
>> > struct pt_regs *regs = get_irq_regs();
>> > ktime_t now = ktime_get();
>> >
>> > +   ts->last_tick = now;
>> > tick_sched_do_timer(now);
>> >
>> > /*
>>
>

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Tue, 28 Mar 2017 17:24:11 -0400
Rik van Riel  wrote:

> On Tue, 2017-03-28 at 16:14 -0400, Luiz Capitulino wrote:
> 
> > And I think I was right, it looks like the nohz code is programming
> > the tick period incorrectly when restarting the tick. The patch below
> > fixes things for me, but I still have some homework todo and more
> > testing before posting a patch for inclusion. Could you guys test it?  
> 
> I spoke too soon.  After half an hour of runtime,
> things have gotten aligned to give me about 50/50
> user time and system time with your test case,
> again.

Hmmm, maybe it's incomplete. I still think that nohz might screwing
something up when re-activating the tick.

> 
> This is on an 8 VCPU virtual machine, with
> nohz_full=2-7, and the test case running on one
> of the nohz_full CPUs.
> 
> > diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> > index 7fe53be..9abe979 100644
> > --- a/kernel/time/tick-sched.c
> > +++ b/kernel/time/tick-sched.c
> > @@ -1152,6 +1152,7 @@ static enum hrtimer_restart
> > tick_sched_timer(struct hrtimer *timer)
> > struct pt_regs *regs = get_irq_regs();
> > ktime_t now = ktime_get();
> >  
> > +   ts->last_tick = now;
> > tick_sched_do_timer(now);
> >  
> > /*  
> 

Re: [BUG nohz]: wrong user and system time accounting

[Luiz Capitulino]

On Tue, 28 Mar 2017 17:24:11 -0400
Rik van Riel  wrote:

> On Tue, 2017-03-28 at 16:14 -0400, Luiz Capitulino wrote:
> 
> > And I think I was right, it looks like the nohz code is programming
> > the tick period incorrectly when restarting the tick. The patch below
> > fixes things for me, but I still have some homework todo and more
> > testing before posting a patch for inclusion. Could you guys test it?  
> 
> I spoke too soon.  After half an hour of runtime,
> things have gotten aligned to give me about 50/50
> user time and system time with your test case,
> again.

Hmmm, maybe it's incomplete. I still think that nohz might screwing
something up when re-activating the tick.

> 
> This is on an 8 VCPU virtual machine, with
> nohz_full=2-7, and the test case running on one
> of the nohz_full CPUs.
> 
> > diff --git a/kernel/time/tick-sched.c b/kernel/time/tick-sched.c
> > index 7fe53be..9abe979 100644
> > --- a/kernel/time/tick-sched.c
> > +++ b/kernel/time/tick-sched.c
> > @@ -1152,6 +1152,7 @@ static enum hrtimer_restart
> > tick_sched_timer(struct hrtimer *timer)
> > struct pt_regs *regs = get_irq_regs();
> > ktime_t now = ktime_get();
> >  
> > +   ts->last_tick = now;
> > tick_sched_do_timer(now);
> >  
> > /*  
>