Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755027AbdC1Ke5 (ORCPT ); Tue, 28 Mar 2017 06:34:57 -0400 Received: from mail-wr0-f194.google.com ([209.85.128.194]:34385 "EHLO mail-wr0-f194.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754432AbdC1Kez (ORCPT ); Tue, 28 Mar 2017 06:34:55 -0400 MIME-Version: 1.0 In-Reply-To: <20170328101403.34a82fbf@redhat.com> References: <20170328101403.34a82fbf@redhat.com> From: Wanpeng Li Date: Tue, 28 Mar 2017 18:34:52 +0800 Message-ID: Subject: Re: Bisected softirq accounting issue in v4.11-rc1~170^2~28 To: Jesper Dangaard Brouer Cc: Frederic Weisbecker , "linux-kernel@vger.kernel.org" , "netdev@vger.kernel.org" , linux-mm , Mel Gorman , Tariq Toukan , Tariq Toukan , Peter Zijlstra , Rik van Riel , Thomas Gleixner , Ingo Molnar Content-Type: text/plain; charset=UTF-8 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4746 Lines: 124 2017-03-28 16:14 GMT+08:00 Jesper Dangaard Brouer : > > (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 > 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 > Cc: Benjamin Herrenschmidt > Cc: Fenghua Yu > Cc: Heiko Carstens > Cc: Linus Torvalds > Cc: Martin Schwidefsky > Cc: Michael Ellerman > Cc: Paul Mackerras > Cc: Peter Zijlstra > Cc: Rik van Riel > Cc: Stanislaw Gruszka > Cc: Thomas Gleixner > Cc: Tony Luck > Cc: Wanpeng Li > Link: http://lkml.kernel.org/r/1485832191-26889-17-git-send-email-fweisbec@gmail.com > Signed-off-by: Ingo Molnar > > 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? 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 +#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); Regards, Wanpeng Li