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

From	Luiz Capitulino <lcapitulino@redhat.com>
Newsgroups	linux.kernel
Subject	Re: [BUG nohz]: wrong user and system time accounting
Date	2017-04-03 21:10 +0200
Message-ID	<tsfwv-2wG-49@gated-at.bofh.it> (permalink)
References	(6 earlier) <tqPNL-3S3-5@gated-at.bofh.it> <trb1T-QL-3@gated-at.bofh.it> <tre9r-2KJ-3@gated-at.bofh.it> <trhK1-5pA-1@gated-at.bofh.it> <tsc5B-cE-45@gated-at.bofh.it>
Organization	Red Hat

Show all headers | View raw

On Mon, 3 Apr 2017 17:23:17 +0200
Frederic Weisbecker <fweisbec@gmail.com> 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=0xffffc900039fbe58 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=1000000 (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.

Thread

Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-03-27 19:40 +0200
  Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-28 09:30 +0200
  Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-03-28 23:10 +0200
    Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-03-28 23:30 +0200
      Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-29 12:00 +0200
        Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-29 15:00 +0200
  Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-03-28 23:30 +0200
    Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-03-28 23:40 +0200
  Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-03-29 22:20 +0200
    Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-30 01:00 +0200
      Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-03-30 15:00 +0200
    Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-30 04:00 +0200
      Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-30 14:50 +0200
        Re: [BUG nohz]: wrong user and system time accounting Mike Galbraith <efault@gmx.de> - 2017-03-30 15:20 +0200
    Re: [BUG nohz]: wrong user and system time accounting Mike Galbraith <efault@gmx.de> - 2017-03-30 06:30 +0200
      Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-30 08:50 +0200
        Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-30 14:00 +0200
          Re: [BUG nohz]: wrong user and system time accounting Mike Galbraith <efault@gmx.de> - 2017-03-30 14:40 +0200
        Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-30 15:40 +0200
          Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-30 16:10 +0200
            Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-30 16:30 +0200
              Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-03-30 23:30 +0200
                Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-03-31 22:10 +0200
                Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-04-01 01:30 +0200
                Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-04-01 05:20 +0200
                Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-04-03 17:30 +0200
                Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-04-03 21:10 +0200
                Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-04-04 20:10 +0200
                Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-04-05 16:30 +0200
      Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-30 15:00 +0200
        Re: [BUG nohz]: wrong user and system time accounting Rik van Riel <riel@redhat.com> - 2017-03-30 15:10 +0200
          Re: [BUG nohz]: wrong user and system time accounting Mike Galbraith <efault@gmx.de> - 2017-03-30 15:40 +0200
            Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-04-03 16:50 +0200
              Re: [BUG nohz]: wrong user and system time accounting Mike Galbraith <efault@gmx.de> - 2017-04-04 09:40 +0200
          Re: [BUG nohz]: wrong user and system time accounting Frederic Weisbecker <fweisbec@gmail.com> - 2017-03-30 15:50 +0200
  Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-30 00:50 +0200
    Re: [BUG nohz]: wrong user and system time accounting Luiz Capitulino <lcapitulino@redhat.com> - 2017-03-30 04:20 +0200
      Re: [BUG nohz]: wrong user and system time accounting Wanpeng Li <kernellwp@gmail.com> - 2017-03-30 14:30 +0200

csiph-web