Re: [RFC 1/2] softirq: Defer net rx/tx processing to ksoftirqd context
From: Dmitry Safonov
Date: Wed Jan 10 2018 - 16:20:47 EST
On Tue, 2018-01-09 at 17:03 +0100, Frederic Weisbecker wrote:
> 2018-01-09 14:36 UTC+01:00, Dmitry Safonov <dima@xxxxxxxxxx>:
> > Warning: Not merge-ready
> >
> > I. Current workflow of ksoftirqd.
> > Softirqs are processed in the context of ksoftirqd iff they are
> > being raised very frequently. How it works:
> > do_softirq() and invoke_softirq() deffer pending softirq iff
> > ksoftirqd is in runqueue. Ksoftirqd is scheduled mostly in the
> > end of processed softirqs if 2ms were not enough to process all
> > pending softirqs.
> >
> > Here is pseudo-picture of the workflow (for simplicity on UMP):
> > ------------- ------------------ ------------------
> > | ksoftirqd | | User's process | | Softirqs |
> > ------------- ------------------ ------------------
> > Not scheduled Running
> > |
> > o------------------------o
> > |
> > __do_softirq()
> > |
> > 2ms & softirq
> > pending?
> > Schedule ksoftirqd
> > |
> > Scheduled o------------------------o
> > |
> > o--------------------o
> > |
> > Running Scheduled
> > |
> > o--------------------o
> > |
> > Not scheduled Running
> >
> > Timegraph for the workflow,
> > dash (-) means ksoftirqd not scheduled;
> > equal(=) ksoftirqd is scheduled, a softirq may still be
> > pending
> >
> > Pending softirqs
> > | | | | | | | | |
> > v v v v | | | | v
> > Processing o-----o | | | | o--o
> > softirqs | | | | | | | |
> > | | | | | | | |
> > | | | | | | | |
> > Userspace o-o o=========o | | | | o----o o---------o
> > <-2ms-> | | | | | |
> > | v v v v |
> > Ksoftirqd o----------o
> >
> > II. Corner-conditions.
> > During testing of commit [1] on some non-mainstream driver,
> > I've found that due to platform specifics, the IRQ is being
> > raised too late (after softirq has been processed).
>
> I'm a bit confused about that part. I would expect the softirq to be
> raised by the IRQ.
The rx-softirq is raised by napi_schedule(), which is called on
receiving an interrupt from device, yes.
> So I guess in this scenario the softirq is raised by something else
> and you expect the upcoming IRQ to handle the softirq, right? (sorry
> I'm not used to networking code).
So, the softirq is served by after upcomming IRQ. But in the end of the
softirq there is no yet-pending softirq. And just after irq_exit(),
there emerges another pending softirq.
ITOW, here is what I see on the trace:
python-8597 [001] d... 16635.495480: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495498: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495503: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495533: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495542: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495567: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495576: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495601: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495615: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495627: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495637: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495668: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495684: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495703: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495710: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495723: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495736: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495755: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495769: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495788: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495804: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495822: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495834: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495857: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495868: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495891: rcu_irq_exit <-irq_exit
python-8597 [001] d.s1 16635.495907: rcu_irq_exit <-irq_exit
python-8597 [001] d..1 16635.495908: __do_softirq <-
do_softirq_own_stack
python-8597 [001] d... 16635.495939: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495959: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.495973: __do_softirq <-irq_exit
python-8597 [001] d... 16635.495988: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496002: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496014: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496027: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496044: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496059: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496088: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496102: __do_softirq <-irq_exit
python-8597 [001] d.s. 16635.496108: rcu_irq_exit <-irq_exit
python-8597 [001] dN.. 16635.496131: rcu_irq_exit <-irq_exit
ksoftirqd/1-14 [001] d... 16635.496132: __do_softirq <-
run_ksoftirqd
ksoftirqd/1-14 [001] d.s1 16635.496145: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496171: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496191: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496204: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496218: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496231: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496250: rcu_irq_exit <-irq_exit
python-8597 [001] d... 16635.496263: __do_softirq <-irq_exit
python-8597 [001] d... 16635.496283: rcu_irq_exit <-irq_exit
Ksoftirqd here is very rarely scheduled, the python process here is
receiver, and looks CPU-starving:
%Cpu1 : 0.6 us, 9.5 sy, 0.0 ni, 0.0 id, 0.0 wa, 35.3 hi, 54.6
si, 0.0 st
[..]
PID USER PR NI VIRT RES SHR S %CPU
%MEM TIME+ COMMAND
8597 root 20 0 7664 5736 3924 R 10 0.0 4:00.69 python
That's what I tried to picture there with diagrams.
(the source of __do_softirq() also show how ksoftirq got scheduled)
--
Thanks,
Dmitry