From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754728AbdC1IOh (ORCPT ); Tue, 28 Mar 2017 04:14:37 -0400 Received: from mx1.redhat.com ([209.132.183.28]:45064 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754568AbdC1IOg (ORCPT ); Tue, 28 Mar 2017 04:14:36 -0400 DMARC-Filter: OpenDMARC Filter v1.3.2 mx1.redhat.com CA3BF437F77 Authentication-Results: ext-mx05.extmail.prod.ext.phx2.redhat.com; dmarc=none (p=none dis=none) header.from=redhat.com Authentication-Results: ext-mx05.extmail.prod.ext.phx2.redhat.com; spf=pass smtp.mailfrom=brouer@redhat.com DKIM-Filter: OpenDKIM Filter v2.11.0 mx1.redhat.com CA3BF437F77 Date: Tue, 28 Mar 2017 10:14:03 +0200 From: Jesper Dangaard Brouer To: Frederic Weisbecker , linux-kernel@vger.kernel.org Cc: brouer@redhat.com, "netdev@vger.kernel.org" , linux-mm , Mel Gorman , Tariq Toukan , Tariq Toukan , Peter Zijlstra , Rik van Riel , Thomas Gleixner , Ingo Molnar Subject: Bisected softirq accounting issue in v4.11-rc1~170^2~28 Message-ID: <20170328101403.34a82fbf@redhat.com> MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.29]); Tue, 28 Mar 2017 08:14:11 +0000 (UTC) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org (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 -- Best regards, Jesper Dangaard Brouer MSc.CS, Principal Kernel Engineer at Red Hat LinkedIn: http://www.linkedin.com/in/brouer From mboxrd@z Thu Jan 1 00:00:00 1970 From: Jesper Dangaard Brouer Subject: Bisected softirq accounting issue in v4.11-rc1~170^2~28 Date: Tue, 28 Mar 2017 10:14:03 +0200 Message-ID: <20170328101403.34a82fbf@redhat.com> Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Cc: brouer@redhat.com, "netdev@vger.kernel.org" , linux-mm , Mel Gorman , Tariq Toukan , Tariq Toukan , Peter Zijlstra , Rik van Riel , Thomas Gleixner , Ingo Molnar To: Frederic Weisbecker , linux-kernel@vger.kernel.org Return-path: Sender: owner-linux-mm@kvack.org List-Id: netdev.vger.kernel.org (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 -- Best regards, Jesper Dangaard Brouer MSc.CS, Principal Kernel Engineer at Red Hat LinkedIn: http://www.linkedin.com/in/brouer -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to majordomo@kvack.org. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: email@kvack.org