Observing Softlockup's while running heavy IOs

Hi,

Problem statement:
Observing softlockups while running heavy IOs on 8 SSD drives
connected behind our LSI SAS 3004 HBA.

System configuration:
OS & kernel version: Fedora 23, v4.2.3-300.fc23.x86_64
NUMA : disabled,
CPUs : 24 logical cpus,
SCSI_MQ:  enabled
Driver : mpt3sas,
MSIx vectors: we have enabled only 2 MSIx vectors using driver module
parameter 'max_msix_vectors' set to 2,
IRQbalance version: v1.0.9
IRQbalance policy : 'subset'
rq_affinity : 2

mpt3sas IRQs info:
irq number =  219, smp_affinity = 000040     affinity_hint = 000fff
irq number =  220, smp_affinity = 001000     affinity_hint = fff000

issued IOs using fio tool with below parameters,
iodepth=128
direct=1
runtime=300
group_reporting
ioengine=libaio
cpus_allowed=6,7,8,9,10,11,18,19,20,21,22,23
time_based
[Ran-Read-4k-IOPs]
numjobs=24
rw=randread
bs=4k


My Analysis:
Observing a loop in the IO path, i.e only one CPU is busy with
processing the interrupts and other CPUs (in the affinity_hint mask)
are busy with sending the IOs (these CPUs are not yet all receiving

487 more lines

-----Original Message-----
From: <redacted> [mailto:linux-kernel-
owner@vger.kernel.org] On Behalf Of Sreekanth Reddy
Sent: Thursday, August 18, 2016 12:56 AM
Subject: Observing Softlockup's while running heavy IOs

Problem statement:
Observing softlockups while running heavy IOs on 8 SSD drives
connected behind our LSI SAS 3004 HBA.

...

Observing a loop in the IO path, i.e only one CPU is busy with
processing the interrupts and other CPUs (in the affinity_hint mask)
are busy with sending the IOs (these CPUs are not yet all receiving
any interrupts). For example, only CPU6 is busy with processing the
interrupts from IRQ 219 and remaining CPUs i.e CPU 7,8,9,10 & 11 are
just busy with pumping the IOs and they never processed any IO
interrupts from IRQ 219. So we are observing softlockups due to
existence this loop in the IO Path.

We may not observe these softlockups if irqbalancer might have
balanced the interrupts among the CPUs enabled in the particular
irq's
affinity_hint mask. so that all the CPUs are equaly busy with send
IOs
and processing the interrupts. I am not sure how irqbalancer balance
the load among the CPUs, but here I see only one CPU from irq's
affinity_hint mask is busy with interrupts and remaining CPUs won't
receive any interrupts from this IRQ.

Please help me with any suggestions/recomendations to slove/limit
these kind of softlockups. Also please let me known if I have missed
any setting in the irqbalance.

The CPUs need to be forced to self-throttle by processing interrupts for 
their own submissions, which reduces the time they can submit more IOs.

See https://lkml.org/lkml/2014/9/9/931 for discussion of this
problem when blk-mq was added.


---
Robert Elliott, HPE Persistent Memory

On 08/17/16 22:55, Sreekanth Reddy wrote:

Observing softlockups while running heavy IOs on 8 SSD drives
connected behind our LSI SAS 3004 HBA.

Hello Sreekanth,

This means that more than 23s was spent before the scheduler was 
invoked, probably due to a loop. Can you give the attached (untested) 
patch a try to see whether it is the loop in __blk_mq_run_hw_queue()?

Thanks,

Bart.

First of all thanks for Robert and Bart for reply.

Robert,
Thanks for the URL, I have gone though this URL.
Yes I am also observing that all the interrupts are routed to one CPU.
But still I observing softlockups (sometime hardlockups) even when I
set rq_affinity to 2.

Is their any way to route the interrupts the same CPUs which has
submitted the corresponding IOs?
or
Is their any way/option in the irqbalance/kernel which can route
interrupts to CPUs (enabled in affinity_hint) in round robin manner
after specific time period.


Bart,
I have tried with your path and here is logs,

[Aug19 13:48] __blk_mq_run_hw_queue() finished after 1 ms
[  +1.196454] __blk_mq_run_hw_queue() finished after 11 ms
[Aug19 13:49] __blk_mq_run_hw_queue() finished after 20 ms
[ +14.173018] __blk_mq_run_hw_queue() finished after 278 ms
[ +14.066448] __blk_mq_run_hw_queue() finished after 588 ms
[  +5.394698] __blk_mq_run_hw_queue() finished after 1360 ms
[Aug19 13:51] __blk_mq_run_hw_queue() finished after 1539 ms
[Aug19 13:54] __blk_mq_run_hw_queue() finished after 1762 ms
[Aug19 13:55] __blk_mq_run_hw_queue() finished after 2087 ms
[Aug19 13:57] __blk_mq_run_hw_queue() finished after 2915 ms
[Aug19 14:06] perf interrupt took too long (2509 > 2500), lowering
kernel.perf_event_max_sample_rate to 50000
[Aug19 14:10] __blk_mq_run_hw_queue() finished after 3266 ms
[Aug19 14:15] __blk_mq_run_hw_queue() finished after 3953 ms
[Aug19 14:22] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 22s!
[llvmpipe-9:3152]
[  +0.000439] __blk_mq_run_hw_queue() finished after 10058 ms
[  +0.007206] Modules linked in: mpt3sas(OE) xt_CHECKSUM
iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat
nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack
nf_conntrack tun bridge stp llc ebtable_filter ebtables

125 more lines

quoted

-----Original Message-----
From: <redacted> [mailto:linux-kernel-
owner@vger.kernel.org] On Behalf Of Sreekanth Reddy
Sent: Thursday, August 18, 2016 12:56 AM
Subject: Observing Softlockup's while running heavy IOs

Problem statement:
Observing softlockups while running heavy IOs on 8 SSD drives
connected behind our LSI SAS 3004 HBA.

...

quoted

Observing a loop in the IO path, i.e only one CPU is busy with
processing the interrupts and other CPUs (in the affinity_hint mask)
are busy with sending the IOs (these CPUs are not yet all receiving
any interrupts). For example, only CPU6 is busy with processing the
interrupts from IRQ 219 and remaining CPUs i.e CPU 7,8,9,10 & 11 are
just busy with pumping the IOs and they never processed any IO
interrupts from IRQ 219. So we are observing softlockups due to
existence this loop in the IO Path.

We may not observe these softlockups if irqbalancer might have
balanced the interrupts among the CPUs enabled in the particular
irq's
affinity_hint mask. so that all the CPUs are equaly busy with send
IOs
and processing the interrupts. I am not sure how irqbalancer balance
the load among the CPUs, but here I see only one CPU from irq's
affinity_hint mask is busy with interrupts and remaining CPUs won't
receive any interrupts from this IRQ.

Please help me with any suggestions/recomendations to slove/limit
these kind of softlockups. Also please let me known if I have missed
any setting in the irqbalance.

The CPUs need to be forced to self-throttle by processing interrupts for
their own submissions, which reduces the time they can submit more IOs.

9 more quoted lines

On 08/19/2016 04:44 AM, Sreekanth Reddy wrote:

[  +0.000439] __blk_mq_run_hw_queue() finished after 10058 ms
[ ... ]
[  +0.000005]  [<ffffffff810c392b>] ? finish_task_switch+0x6b/0x200
[  +0.000006]  [<ffffffff8176dabc>] __schedule+0x36c/0x950
[  +0.000002]  [<ffffffff8176e0d7>] schedule+0x37/0x80
[  +0.000006]  [<ffffffff81116a1c>] futex_wait_queue_me+0xbc/0x120
[  +0.000004]  [<ffffffff81116da9>] futex_wait+0x119/0x270
[  +0.000004]  [<ffffffff81116800>] ? futex_wake+0x90/0x180
[  +0.000003]  [<ffffffff81118d6b>] do_futex+0x12b/0xb00
[  +0.000005]  [<ffffffff810d348e>] ? set_next_entity+0x23e/0x440
[  +0.000007]  [<ffffffff810136f1>] ? __switch_to+0x261/0x4b0
[  +0.000004]  [<ffffffff811197c1>] SyS_futex+0x81/0x180
[  +0.000002]  [<ffffffff8176e0d7>] ? schedule+0x37/0x80
[  +0.000004]  [<ffffffff817721ae>] entry_SYSCALL_64_fastpath+0x12/0x71

Hello Sreekanth,

If a "soft lockup" is reported that often means that kernel code is iterating too long in a loop without giving up the CPU. Inserting a cond_resched() call in such loops usually resolves these soft lockup complaints. However, your latest e-mail shows that the soft lockup complaint was reported on other code than __blk_mq_run_hw_queue(). I'm afraid this means that the CPU on which the soft lockup was reported is hammered so hard with interrupts that hardly any time remains for the scheduler to run code on that CPU. You will have to follow Robert Elliott's advice and reduce the time that is spent per CPU in interrupt context.

Bart.

-----Original Message-----
From: Sreekanth Reddy [mailto:sreekanth.reddy@broadcom.com]
Sent: Friday, August 19, 2016 6:45 AM
To: Elliott, Robert (Persistent Memory) <redacted>
Subject: Re: Observing Softlockup's while running heavy IOs

...

Yes I am also observing that all the interrupts are routed to one
CPU.  But still I observing softlockups (sometime hardlockups)
even when I set rq_affinity to 2.

That'll ensure the block layer's completion handling is done there,
but not your driver's interrupt handler (which precedes the block
layer completion handling).

 

Is their any way to route the interrupts the same CPUs which has
submitted the corresponding IOs?
or
Is their any way/option in the irqbalance/kernel which can route
interrupts to CPUs (enabled in affinity_hint) in round robin manner
after specific time period.

Ensure your driver creates one MSIX interrupt per CPU core, uses
that interrupt for all submissions from that core, and reports
that it would like that interrupt to be serviced by that core
in /proc/irq/nnn/affinity_hint.  

Even with hyperthreading, this needs to be based on the logical
CPU cores, not just the physical core or the physical socket.
You can swamp a logical CPU core as easily as a physical CPU core.

Then, provide an irqbalance policy script that honors the
affinity_hint for your driver, or turn off irqbalance and
manually set /proc/irq/nnn/smp_affinity to match the
affinity_hint.  

Some versions of irqbalance honor the hints; some purposely
don't and need to be overridden with a policy script.


---
Robert Elliott, HPE Persistent Memory

-----Original Message-----
From: Elliott, Robert (Persistent Memory) [mailto:<redacted>]
Sent: Saturday, August 20, 2016 2:58 AM
To: Sreekanth Reddy
Cc: <redacted>; <redacted>;
irqbalance@lists.infradead.org; Kashyap Desai; Sathya Prakash Veerichetty;
Chaitra Basappa; Suganath Prabu Subramani
Subject: RE: Observing Softlockup's while running heavy IOs

quoted

-----Original Message-----
From: Sreekanth Reddy [mailto:sreekanth.reddy@broadcom.com]
Sent: Friday, August 19, 2016 6:45 AM
To: Elliott, Robert (Persistent Memory) <redacted>
Subject: Re: Observing Softlockup's while running heavy IOs

...

quoted

Yes I am also observing that all the interrupts are routed to one CPU.
But still I observing softlockups (sometime hardlockups) even when I
set rq_affinity to 2.

How about below scenario ?  For simplicity. HBA with single MSI-x vector.
(Whenever HBA supports less MSI-x and logical CPUs are more on system, we
can see chance of these issue frequently..)

Assume we have 32 logical CPU  (4 socket, each with 8 logical CPU). CPU-0 is
not participating in IO.
Remaining CPU range from 1 to 31 is submitting IO. In such a scenario
rq_affinity=2 and irqbalance supporting *exact* smp_affinity_hint will not
help.

We may see soft/hard lockup on CPU-0.. Are we going to resolve such issue or
it is very rare to happen on field  ?

That'll ensure the block layer's completion handling is done there, but
not your
driver's interrupt handler (which precedes the block layer completion
handling).

quoted

Is their any way to route the interrupts the same CPUs which has
submitted the corresponding IOs?
or
Is their any way/option in the irqbalance/kernel which can route
interrupts to CPUs (enabled in affinity_hint) in round robin manner
after specific time period.

Ensure your driver creates one MSIX interrupt per CPU core, uses that
interrupt
for all submissions from that core, and reports that it would like that
interrupt to
be serviced by that core in /proc/irq/nnn/affinity_hint.

Even with hyperthreading, this needs to be based on the logical CPU cores,
not
just the physical core or the physical socket.
You can swamp a logical CPU core as easily as a physical CPU core.

Then, provide an irqbalance policy script that honors the affinity_hint
for your
driver, or turn off irqbalance and manually set /proc/irq/nnn/smp_affinity
to
match the affinity_hint.

Some versions of irqbalance honor the hints; some purposely don't and need
to
be overridden with a policy script.


---
Robert Elliott, HPE Persistent Memory

On Fri, Aug 19, 2016 at 9:26 PM, Bart Van Assche
[off-list ref] wrote:

On 08/19/2016 04:44 AM, Sreekanth Reddy wrote:

quoted

[  +0.000439] __blk_mq_run_hw_queue() finished after 10058 ms
[ ... ]
[  +0.000005]  [<ffffffff810c392b>] ? finish_task_switch+0x6b/0x200
[  +0.000006]  [<ffffffff8176dabc>] __schedule+0x36c/0x950
[  +0.000002]  [<ffffffff8176e0d7>] schedule+0x37/0x80
[  +0.000006]  [<ffffffff81116a1c>] futex_wait_queue_me+0xbc/0x120
[  +0.000004]  [<ffffffff81116da9>] futex_wait+0x119/0x270
[  +0.000004]  [<ffffffff81116800>] ? futex_wake+0x90/0x180
[  +0.000003]  [<ffffffff81118d6b>] do_futex+0x12b/0xb00
[  +0.000005]  [<ffffffff810d348e>] ? set_next_entity+0x23e/0x440
[  +0.000007]  [<ffffffff810136f1>] ? __switch_to+0x261/0x4b0
[  +0.000004]  [<ffffffff811197c1>] SyS_futex+0x81/0x180
[  +0.000002]  [<ffffffff8176e0d7>] ? schedule+0x37/0x80
[  +0.000004]  [<ffffffff817721ae>] entry_SYSCALL_64_fastpath+0x12/0x71

Hello Sreekanth,

If a "soft lockup" is reported that often means that kernel code is
iterating too long in a loop without giving up the CPU. Inserting a
cond_resched() call in such loops usually resolves these soft lockup
complaints. However, your latest e-mail shows that the soft lockup complaint
was reported on other code than __blk_mq_run_hw_queue(). I'm afraid this
means that the CPU on which the soft lockup was reported is hammered so hard
with interrupts that hardly any time remains for the scheduler to run code
on that CPU. You will have to follow Robert Elliott's advice and reduce the
time that is spent per CPU in interrupt context.

Sorry for delay in response as I was on Vacation.

Bart,

I reduced the ISR workload by one third in-order to reduce the time
that is spent per CPU in interrupt context, even then I am observing
softlockups.

As I mentioned before only same single CPU in the set of CPUs(enabled
in affinity_hint) is busy with handling the interrupts from
corresponding IRQx. I have done below experiment in driver to limit
these softlockups/hardlockups. But I am not sure whether it is
reasonable to do this in driver,

Experiment:
If the CPUx is continuously busy with handling the remote CPUs
(enabled in the corresponding IRQ's affinity_hint) IO works by 1/4th
of the HBA queue depth in the same ISR context then enable a flag
called 'change_smp_affinity' for this IRQ. Also created a thread with
will poll for this flag for every IRQ's (enabled by driver) for every
second. If this thread see that this flag is enabled for any IRQ then
it will write next CPU number from the CPUs enabled in the IRQ's
affinity_hint to the IRQ's smp_affinity procfs attribute using
'call_usermodehelper()' API.

This to make sure that interrupts are not processed by same single CPU
all the time and to make the other CPUs to handle the interrupts if
the current CPU is continuously busy with handling the other CPUs IO
interrupts.

For example consider a system which has 8 logical CPUs and one MSIx
vector enabled (called IRQ 120) in driver, HBA queue depth as 8K.
then IRQ's procfs attributes will be
IRQ# 120, affinity_hint=0xff, smp_affinity=0x00

After starting heavy IOs, we will observe that only CPU0 will be busy
with handling the interrupts. This experiment driver will change the
smp_affinity to next CPU number i.e. 0x01 (using cmd 'echo 0x01 >
/proc/irq/120/smp_affinity', driver issue's this cmd using

9 more lines

Bart.

On 09/01/2016 03:31 AM, Sreekanth Reddy wrote:

I reduced the ISR workload by one third in-order to reduce the time
that is spent per CPU in interrupt context, even then I am observing
softlockups.

As I mentioned before only same single CPU in the set of CPUs(enabled
in affinity_hint) is busy with handling the interrupts from
corresponding IRQx. I have done below experiment in driver to limit
these softlockups/hardlockups. But I am not sure whether it is
reasonable to do this in driver,

Experiment:
If the CPUx is continuously busy with handling the remote CPUs
(enabled in the corresponding IRQ's affinity_hint) IO works by 1/4th
of the HBA queue depth in the same ISR context then enable a flag
called 'change_smp_affinity' for this IRQ. Also created a thread with
will poll for this flag for every IRQ's (enabled by driver) for every
second. If this thread see that this flag is enabled for any IRQ then
it will write next CPU number from the CPUs enabled in the IRQ's
affinity_hint to the IRQ's smp_affinity procfs attribute using
'call_usermodehelper()' API.

This to make sure that interrupts are not processed by same single CPU
all the time and to make the other CPUs to handle the interrupts if
the current CPU is continuously busy with handling the other CPUs IO
interrupts.

For example consider a system which has 8 logical CPUs and one MSIx
vector enabled (called IRQ 120) in driver, HBA queue depth as 8K.
then IRQ's procfs attributes will be
IRQ# 120, affinity_hint=0xff, smp_affinity=0x00

After starting heavy IOs, we will observe that only CPU0 will be busy
with handling the interrupts. This experiment driver will change the
smp_affinity to next CPU number i.e. 0x01 (using cmd 'echo 0x01 >
/proc/irq/120/smp_affinity', driver issue's this cmd using
call_usermodehelper() API) if it observes that CPU0 is continuously
processing more than 2K of IOs replies of other CPUs i.e from CPU1 to
CPU7.

Whether doing this kind of stuff in driver is ok?

Hello Sreekanth,

To me this sounds like something that should be implemented in the I/O chipset on the motherboard. If you have a look at the Intel Software Developer Manuals then you will see that logical destination mode supports round-robin interrupt delivery. However, the Linux kernel selects physical destination mode on systems with more than eight logical CPUs (see also arch/x86/kernel/apic/apic_flat_64.c).

I'm not sure the maintainers of the interrupt subsystem would welcome code that emulates round-robin interrupt delivery. So your best option is probably to minimize the amount of work that is done in interrupt context and to move as much work as possible out of interrupt context in such a way that it can be spread over multiple CPU cores, e.g. by using queue_work_on().

Bart.