[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20161005155959.GH10625@jcartwri.amer.corp.natinst.com>
Date: Wed, 5 Oct 2016 10:59:59 -0500
From: Julia Cartwright <julia@...com>
To: "Koehrer Mathias (ETAS/ESW5)" <mathias.koehrer@...s.com>,
Jeff Kirsher <jeffrey.t.kirsher@...el.com>
Cc: Sebastian Andrzej Siewior <sebastian.siewior@...utronix.de>,
"linux-rt-users@...r.kernel.org" <linux-rt-users@...r.kernel.org>,
intel-wired-lan@...ts.osuosl.org, netdev@...r.kernel.org
Subject: Re: Kernel 4.6.7-rt13: Intel Ethernet driver igb causes huge
latencies in cyclictest
On Wed, Oct 05, 2016 at 07:02:21AM +0000, Koehrer Mathias (ETAS/ESW5) wrote:
> Hi Julia,
>
> > > In the meanwhile I have detected another finding which might be relevant:
> > >
> > > With the 3.18 kernel the igb driver comes with two interrupts per
> > > NIC (e.g. eth2 and eth2-TxRx0) with the 4.6. kernel the igb driver
> > > comes with 9 (!) interrupts per NIC: eth2, and eth2-TxRx-0,
> > > eth2-TxRx-1, ... , eth2-TxRx-7.
> > >
> > > As I have used initially the same kernel configuration from 3.18 also
> > > for the 4.6. kernel I wonder where this comes from and if there is any
> > > kernel option I may use to disable these many interrupts and to reduce
> > > it to 2 again.
> >
> > If it's all of these interrupts that are firing and being handled at the same time, that
> > can account for the latencies you were seeing. As I suggested before, having a
> > trace with the sched_wakeup event enabled can help confirm that it's these
> > interrupts causing problems.
> >
> > If it is true, then the question is: why is the device triggering all of these interrupts all
> > at once? Is that expected? These are questions for netdev folks, I think.
> >
> > Julia
>
> OK - I ran again the cyclictest. This time I used the -C option:
> # cyclictest -a -i 100 -m -n -p 80 -t 1 -b 21 -C
>
> And the last output lines of the trace are:
> cyclicte-5887 0d...2.. 1504647266us!: sched_switch: prev_comm=cyclictest prev_pid=5887 prev_prio=19 prev_state=S ==> next_comm=kworker/0:0 next_pid=5 next_prio=120
> kworker/-5 0dN.h2.. 1504647372us : sched_wakeup: comm=cyclictest pid=5887 prio=19 target_cpu=000
> kworker/-5 0dN.h3.. 1504647374us : sched_wakeup: comm=irq/54-eth2-TxR pid=5883 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647375us : sched_wakeup: comm=irq/53-eth2-TxR pid=5882 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647377us : sched_wakeup: comm=irq/52-eth2-TxR pid=5881 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647378us : sched_wakeup: comm=irq/51-eth2-TxR pid=5880 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647380us : sched_wakeup: comm=irq/50-eth2-TxR pid=5879 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647381us : sched_wakeup: comm=irq/49-eth2-TxR pid=5878 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647382us : sched_wakeup: comm=irq/48-eth2-TxR pid=5877 prio=49 target_cpu=000
> kworker/-5 0dN.h3.. 1504647383us : sched_wakeup: comm=irq/47-eth2-TxR pid=5876 prio=49 target_cpu=000
> kworker/-5 0d...2.. 1504647384us : sched_switch: prev_comm=kworker/0:0 prev_pid=5 prev_prio=120 prev_state=R+ ==> next_comm=cyclictest next_pid=5887 next_prio=19
> cyclicte-5887 0.....11 1504647389us : tracing_mark_write: hit latency threshold (28 > 21)
>
> The attached trace-extract.gz shows some more lines.
> It actually looks to me as if the the many irq threads from igb are causing the issue.
Yes, I think so.
Although, to be clear, it isn't the fact that there exists 8 threads,
it's that the device is firing all 8 interrupts at the same time. The
time spent in hardirq context just waking up all 8 of those threads (and
the cyclictest wakeup) is enough to cause your regression.
netdev/igb folks-
Under what conditions should it be expected that the i350 trigger all of
the TxRx interrupts simultaneously? Any ideas here?
See the start of this thread here:
http://lkml.kernel.org/r/d648628329bc446fa63b5e19d4d3fb56@FE-MBX1012.de.bosch.com
Julia
Powered by blists - more mailing lists