| Message ID | CANRm+Cwb3uAiZdufqDsyzQ1GZYh3nUr2uTyg1Hb2oVoxJZKMvg@mail.gmail.com |
|---|---|
| State | RFC, archived |
| Delegated to: | David Miller |
| Headers | show |
On Tue, 28 Mar 2017 18:34:52 +0800 Wanpeng Li <kernellwp@gmail.com> wrote: > 2017-03-28 16:14 GMT+08:00 Jesper Dangaard Brouer <brouer@redhat.com>: > > > > (While evaluating some changes to the page allocator) I ran into an > > issue with ksoftirqd getting too much CPU sched time. > > > > I bisected the problem to > > a499a5a14dbd ("sched/cputime: Increment kcpustat directly on irqtime account") > > > > a499a5a14dbd1d0315a96fc62a8798059325e9e6 is the first bad commit > > commit a499a5a14dbd1d0315a96fc62a8798059325e9e6 > > Author: Frederic Weisbecker <fweisbec@gmail.com> > > Date: Tue Jan 31 04:09:32 2017 +0100 > > > > sched/cputime: Increment kcpustat directly on irqtime account > > > > The irqtime is accounted is nsecs and stored in > > cpu_irq_time.hardirq_time and cpu_irq_time.softirq_time. Once the > > accumulated amount reaches a new jiffy, this one gets accounted to the > > kcpustat. > > > > This was necessary when kcpustat was stored in cputime_t, which could at > > worst have jiffies granularity. But now kcpustat is stored in nsecs > > so this whole discretization game with temporary irqtime storage has > > become unnecessary. > > > > We can now directly account the irqtime to the kcpustat. > > > > Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com> > > Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org> > > Cc: Fenghua Yu <fenghua.yu@intel.com> > > Cc: Heiko Carstens <heiko.carstens@de.ibm.com> > > Cc: Linus Torvalds <torvalds@linux-foundation.org> > > Cc: Martin Schwidefsky <schwidefsky@de.ibm.com> > > Cc: Michael Ellerman <mpe@ellerman.id.au> > > Cc: Paul Mackerras <paulus@samba.org> > > Cc: Peter Zijlstra <peterz@infradead.org> > > Cc: Rik van Riel <riel@redhat.com> > > Cc: Stanislaw Gruszka <sgruszka@redhat.com> > > Cc: Thomas Gleixner <tglx@linutronix.de> > > Cc: Tony Luck <tony.luck@intel.com> > > Cc: Wanpeng Li <wanpeng.li@hotmail.com> > > Link: http://lkml.kernel.org/r/1485832191-26889-17-git-send-email-fweisbec@gmail.com > > Signed-off-by: Ingo Molnar <mingo@kernel.org> > > > > The reproducer is running a userspace udp_sink[1] program, and taskset > > pinning the process to the same CPU as softirq RX is running on, and > > starting a UDP flood with pktgen (tool part of kernel tree: > > samples/pktgen/pktgen_sample03_burst_single_flow.sh). > > > > [1] udp_sink > > https://github.com/netoptimizer/network-testing/blob/master/src/udp_sink.c > > > > The expected results (after commit 4cd13c21b207 ("softirq: Let > > ksoftirqd do its job")) is that the scheduler split the CPU time 50/50 > > between udp_sink and ksoftirqd. > > > > After this commit, the udp_sink program does not get any sched CPU > > time, and no packets are delivered to userspace. (All packets are > > dropped by softirq due to a full socket queue, nstat UdpRcvbufErrors). > > > > A related symptom is that ksoftirqd no longer get accounted in top. > > > > $ grep CONFIG_IRQ_TIME_ACCOUNTING .config > > CONFIG_IRQ_TIME_ACCOUNTING=y > > > > Full .config uploaded here[2]: > > [2] http://people.netfilter.org/hawk/kconfig/config02-bisect-softirq-a499a5a14dbd > > void irqtime_account_irq(struct task_struct *curr) > { > struct irqtime *irqtime = this_cpu_ptr(&cpu_irqtime); > u64 *cpustat = kcpustat_this_cpu->cpustat; > s64 delta; > int cpu; > > if (!sched_clock_irqtime) > return; > > cpu = smp_processor_id(); > delta = sched_clock_cpu(cpu) - irqtime->irq_start_time; > > sched_clock_cpu(cpu) should be converted from cputime to ns. However, > cputime_to_nsecs() API is removed by > https://lkml.org/lkml/2017/1/22/230 for generic usage, so could you > try the below patch just for testing? Sure... it didn't solve the problem :-( > diff --git a/include/linux/sched/cputime.h b/include/linux/sched/cputime.h > index 4c5b973..166efba 100644 > --- a/include/linux/sched/cputime.h > +++ b/include/linux/sched/cputime.h > @@ -7,14 +7,14 @@ > * cputime accounting APIs: > */ > > -#ifdef CONFIG_VIRT_CPU_ACCOUNTING_NATIVE > -#include <asm/cputime.h> > +#define cputime_div(__ct, divisor) div_u64((__force u64)__ct, divisor) > +#define cputime_to_usecs(__ct) \ > + cputime_div(__ct, NSEC_PER_USEC) > > #ifndef cputime_to_nsecs > # define cputime_to_nsecs(__ct) \ > (cputime_to_usecs(__ct) * NSEC_PER_USEC) > #endif > -#endif /* CONFIG_VIRT_CPU_ACCOUNTING_NATIVE */ > > #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN > extern void task_cputime(struct task_struct *t, > diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c > index f3778e2b..68064d1 100644 > --- a/kernel/sched/cputime.c > +++ b/kernel/sched/cputime.c > @@ -49,7 +49,7 @@ void irqtime_account_irq(struct task_struct *curr) > return; > > cpu = smp_processor_id(); > - delta = sched_clock_cpu(cpu) - irqtime->irq_start_time; > + delta = cputime_to_nsecs(sched_clock_cpu(cpu)) - irqtime->irq_start_time; > irqtime->irq_start_time += delta; > > u64_stats_update_begin(&irqtime->sync);
On Tue, Mar 28, 2017 at 06:34:52PM +0800, Wanpeng Li wrote: > > sched_clock_cpu(cpu) should be converted from cputime to ns. Uhm, no. sched_clock_cpu() returns u64 in ns.
On Tue, Mar 28, 2017 at 02:26:42PM +0200, Peter Zijlstra wrote: > On Tue, Mar 28, 2017 at 06:34:52PM +0800, Wanpeng Li wrote: > > > > sched_clock_cpu(cpu) should be converted from cputime to ns. > > Uhm, no. sched_clock_cpu() returns u64 in ns. Yes, and most of the cputime_t have been converted to u64 so there should be no such conversion issue between u64 and cputime_t anymore. Perhaps my commit has another side effect on softirq time accounting, I'll see if I can reproduce.
On Tue, 28 Mar 2017 15:06:04 +0200 Frederic Weisbecker <fweisbec@gmail.com> wrote: > On Tue, Mar 28, 2017 at 02:26:42PM +0200, Peter Zijlstra wrote: > > On Tue, Mar 28, 2017 at 06:34:52PM +0800, Wanpeng Li wrote: > > > > > > sched_clock_cpu(cpu) should be converted from cputime to ns. > > > > Uhm, no. sched_clock_cpu() returns u64 in ns. > > Yes, and most of the cputime_t have been converted to u64 so there > should be no such conversion issue between u64 and cputime_t anymore. > > Perhaps my commit has another side effect on softirq time accounting, > I'll see if I can reproduce. (Disclaimer without knowing anything about the scheduler code) my theory is that irqtime_account_irq() does not get invoked often enough, as in my pktgen "overload" use-case keeps softirq always running. And your change moved updating cpustat[CPUTIME_SOFTIRQ] here. Before it got updated by account_other_time() which gets invoked from irqtime_account_process_tick().
diff --git a/include/linux/sched/cputime.h b/include/linux/sched/cputime.h index 4c5b973..166efba 100644 --- a/include/linux/sched/cputime.h +++ b/include/linux/sched/cputime.h @@ -7,14 +7,14 @@ * cputime accounting APIs: */ -#ifdef CONFIG_VIRT_CPU_ACCOUNTING_NATIVE -#include <asm/cputime.h> +#define cputime_div(__ct, divisor) div_u64((__force u64)__ct, divisor) +#define cputime_to_usecs(__ct) \ + cputime_div(__ct, NSEC_PER_USEC) #ifndef cputime_to_nsecs # define cputime_to_nsecs(__ct) \ (cputime_to_usecs(__ct) * NSEC_PER_USEC) #endif -#endif /* CONFIG_VIRT_CPU_ACCOUNTING_NATIVE */ #ifdef CONFIG_VIRT_CPU_ACCOUNTING_GEN extern void task_cputime(struct task_struct *t, diff --git a/kernel/sched/cputime.c b/kernel/sched/cputime.c index f3778e2b..68064d1 100644 --- a/kernel/sched/cputime.c +++ b/kernel/sched/cputime.c @@ -49,7 +49,7 @@ void irqtime_account_irq(struct task_struct *curr) return; cpu = smp_processor_id(); - delta = sched_clock_cpu(cpu) - irqtime->irq_start_time; + delta = cputime_to_nsecs(sched_clock_cpu(cpu)) - irqtime->irq_start_time; irqtime->irq_start_time += delta; u64_stats_update_begin(&irqtime->sync);