Reduce raised IPIs

[krizhanovsky]

Currently each task put into a work queue for a different CPU raises IPI to wake up ksoftirqd on the CPU. It seems IPIs are relatively expensive (?) and there is sense to raise IPI only if ksoftirqd on the designated CPU is inactive. It seems we can just wakeup appropriate ksoftirqd just like wakeup_softirqd() does it.

Also consider integration with Flow Director - probably we can get some benefits from it in our intra-CPU communication at all. However, the main point for the intra-CPU transport is that we have to communicate via pair of sockets, client and server, and the pairs aren't stable. (Are they?)

[krizhanovsky]

Benchnark from http://natsys-lab.blogspot.ru/2018/03/http-requests-proxying.html for Tempesta FW and 3-byte index.html gives perf top as

     8.99%  [kernel]       [k] call_function_single_interrupt
     2.25%  [kernel]       [k] __default_send_IPI_dest_field
     1.74%  [kernel]       [k] queued_spin_lock_slowpath
     1.40%  [kernel]       [k] _raw_spin_lock_irqsave
     1.33%  [kernel]       [k] skb_release_data
     1.22%  [kernel]       [k] __inet_lookup_established
     1.03%  [kernel]       [k] tcp_ack
     1.01%  [kernel]       [k] syscall_return_via_sysret
     0.78%  [kernel]       [k] tcp_transmit_skb
     0.75%  [kernel]       [k] _raw_spin_lock
     0.72%  [kernel]       [k] native_apic_mem_write

I didn't do any deep analysis so far, but it seems IPIs hurt performance.

[krizhanovsky]

It has sense to start from introducing an IPI counter in perfstat to analyze how many IPIs do we have now and after the fix. Also it's necessary to clearly understand how expensive IPI is, especially in contest of sofirq pipelining. E.g. it has sense to write a simple ping-pong benchmark comparing IPIs with CMXCHG instruction.

[aleksostapenko]

I've got alike results for IPI processing on my virtual machine; perf record/report output:

+    10.37%      [k] call_function_single_interrupt     [kernel.vmlinux]
+    2.64%       [k] update_stack_state                 [kernel.vmlinux]
+    1.62%       [k] unwind_next_frame.part.5           [kernel.vmlinux]
+    1.60%       [k] tfw_http_parse_resp                [tempesta_fw]
+    1.55%       [k] memcmp                             [kernel.vmlinux]
+    1.39%       [k] tcp_ack                            [kernel.vmlinux]
+    1.34%       [k] check_memory_region                [kernel.vmlinux]
+    1.25%       [k] skb_release_data                   [kernel.vmlinux]
+    1.20%       [k] __module_address                   [kernel.vmlinux]
+    1.17%       [k] memset_erms                        [kernel.vmlinux]
+    1.04%       [k] __inet_lookup_established          [kernel.vmlinux]
+    0.83%       [k] tcp_transmit_skb                   [kernel.vmlinux]
+    0.82%       [k] __skb_fragment                     [tempesta_fw]
+    0.80%       [k] tcp_write_xmit                     [kernel.vmlinux]

for benchmark from http://natsys-lab.blogspot.ru/2018/03/http-requests-proxying.html.

About 10% of time we spend in IPI processing, so the possible reason is in excessive
generation of IPI. Also it is worth to mention, that RPS was enabled during test, so the
part of IPI had been generated in order to distribute packets among SoftIRQs of different
CPUs in context of Packet Steering functionality.

Almost 80% of IPI generation (x2apic_send_IPI() function) is produced from irq_work_queue_on() (Tempesta FW) and net_rps_send_ipi() (RPS functionality) interfaces:

-    0.11%  [k] x2apic_send_IPI  [kernel.vmlinux]
   - x2apic_send_IPI
      - 79.55% native_send_call_func_single_ipi
         + 71.45% irq_work_queue_on
         - 28.55% generic_exec_single
              smp_call_function_single_async
            + net_rps_send_ipi

Both of these functions generate CALL_FUNCTION_SINGLE_VECTOR IPI, processed in
call_function_single_interrupt() handler (which is in top of perf output). We can compare
relative contribution to IPI generation volume from Tempesta FW, and from RPS functionality
(the overhead percentage is relative, not absolute, in the following perf output):

-   88.91%  [k] irq_work_queue_on  [kernel.vmlinux]
   - irq_work_queue_on
      + 90.26% ss_wq_push
      + 9.74% ss_send
-   11.09%  [k] net_rps_send_ipi   [kernel.vmlinux]
   - net_rps_send_ipi
      + 52.11% net_rx_action
      + 31.96% __do_softirq
      + 15.92% process_backlog

So, it seems that RPS processing does not make a significant contribution into IPI generation volume.

Other interesting perf outputs:
CPU balance
(hard IRQ of NIC is bound to CPU0)

  Overhead  CPU
+   26.49%  003
+   26.10%  001
+   24.75%  000
+   22.67%  002

Overhead percentage is relative in next two outputs.
Balance of ksoftirqd:

  Overhead  Command
+   74.39%  ksoftirqd/0
+    9.19%  ksoftirqd/2
+    8.32%  ksoftirqd/3
+    8.09%  ksoftirqd/1

Balance of SoftIRQ processing (via sampling of __do_softirq()):

  Overhead  CPU
-   31.62%  001
   - __do_softirq
      + 60.86% irq_exit
      + 17.60% do_softirq_own_stack
      + 9.93% run_ksoftirqd
      + 7.31% smp_call_function_single_interrupt
      + 4.30% __GI___setsockopt
-   27.26%  002
   - __do_softirq
      + 65.60% irq_exit
      + 17.18% do_softirq_own_stack
      + 9.20% run_ksoftirqd
      + 3.62% smp_call_function_single_interrupt
      + 3.19% smpboot_thread_fn
      + 1.21% __GI___setsockopt
-   26.54%  003
   - __do_softirq
      + 54.90% irq_exit
      + 24.70% do_softirq_own_stack
      + 11.77% run_ksoftirqd
      + 7.61% smp_call_function_single_interrupt
      + 1.02% __GI___setsockopt
-   14.57%  000
   - __do_softirq
      + 67.11% run_ksoftirqd
      + 21.14% irq_exit
      + 6.95% do_softirq_own_stack
      + 4.81% smpboot_thread_fn

It seems that CPU0 tends to process SoftIRQs in context of ksoftirqd (run_ksoftirqd() function),
while other CPUs spend more time processing SoftIRQs in context of IRQ (irq_exit() function in
sampling).

The counts of IPIs with vector CALL_FUNCTION_SINGLE_VECTOR for specified above benchmark test
(with 31K RPS) are:

• generated: 1366K;
• handled: 1347K;

(collected via perf stat for irq_vectors:* static tracepoints and dynamic kprobe tracepoint for x2apic_send_IPI() function with filter CALL_FUNCTION_SINGLE_VECTOR for vector variable).

[aleksostapenko]

Control benchmarks on VM after the fix gave the following results:
perf record/report:

4.65%  [k] call_function_single_interrupt
3.07%  [k] update_stack_state
2.03%  [k] pvclock_clocksource_read
1.92%  [k] unwind_next_frame.part.5
1.90%  [k] memcmp
1.75%  [k] tfw_http_parse_resp
1.56%  [k] check_memory_region
1.52%  [k] tcp_ack
1.52%  [k] __skb_fragment
1.26%  [k] __module_address
1.23%  [k] skb_release_data
1.09%  [k] __inet_lookup_established
1.04%  [k] memset_erms
0.90%  [k] tcp_transmit_skb
0.85%  [k] syscall_return_via_sysret
0.84%  [k] __raw_callee_save___pv_queued_spin_unlock
0.80%  [k] e1000_xmit_frame

i.e. time of IPI handler decreased in 2 times, but remains on the top.

The counts of IPIs with vector CALL_FUNCTION_SINGLE_VECTOR are:

• generated: 783K;
• handled: 764K;

Detailed picture for above counts (via perf stat):

. . .
764103      irq_vectors:call_function_single_entry
764103      irq_vectors:call_function_single_exit
. . .
782685      probe:x2apic_send_IPI
. . .
481285      probe:irq_work_queue_on
301322      probe:net_rps_send_ipi```

i.e. the count of IPI handler call_function_single_entry calls decreased in 1.8 time, and the same order - for IPI generation - x2apic_send_IPI, which consists of two components:

1. net_rps_send_ipi - IPI generated by Packet Steering functionality - as expected, it has not changed almost;
2. irq_work_queue_on - our IPIs, generated by Tempesta FW (via irq_work); the count decreased in 2.4 times.

RPS: 34K.

[aleksostapenko]

Results of the same benchmark test - on bare metal server.
Before patch 5577d2a:
perf top:

2.42%  [tempesta_fw]        [k] tfw_http_parse_resp
1.81%  [kernel]             [k] skb_release_data
1.26%  [kernel]             [k] tcp_ack
1.23%  [mlx4_en]            [k] mlx4_en_process_rx_cq
1.18%  [kernel]             [k] _raw_spin_lock
1.14%  [tempesta_fw]        [k] tfw_http_parse_req
1.11%  [kernel]             [k] __inet_lookup_established
. . .
0.17%  [kernel]             [k] call_function_single_interrupt

perf stat with traceponts:

17141378      irq_vectors:call_function_single_entry
. . . 
11729040      probe:irq_work_queue_on
 5469709      probe:net_rps_send_ipi

After patch 5577d2a:
perf top:

2.53%  [tempesta_fw]       [k] tfw_http_parse_resp
1.76%  [kernel]            [k] skb_release_data
1.30%  [mlx4_en]           [k] mlx4_en_process_rx_cq
1.28%  [kernel]            [k] tcp_ack
1.25%  [kernel]            [k] _raw_spin_lock
1.12%  [kernel]            [k] __inet_lookup_established
1.12%  [kernel]            [.] syscall_return_via_sysret
.  .  .
0.15%  [kernel]            [k] call_function_single_interrupt

perf stat with tracepoints:

13477653      irq_vectors:call_function_single_entry
. . .
 7371283      probe:irq_work_queue_on
 6162090      probe:net_rps_send_ipi

In both cases the result with 230K - 240K RPS was observed.
It seems that on bare metal server there is no problem with too much time spent in call_function_single_interrupt handler.

[aleksostapenko]

More tests on the same benchmark had been made after fix, on VM and bare metal servers - to analyze the picture in comparison of separate CPUs. For tests - dynamic probes had been set in following places of Tempesta FW code:
*ss_ipi (entry),
*ss_tx_action (entry),
*ss_tx_action_1 (here

tempesta/tempesta_fw/sock.c

Line 1382 in c39e8d7

raise_softirq(NET_TX_SOFTIRQ);

to count exits - when the message(s) are remained in worq_queue and we regenerate SoftIRQ while IPI stay disbled),
*tfw_wq_pop_ticket (here

tempesta/tempesta_fw/work_queue.c

Line 171 in c39e8d7

memcpy(buf, &q->array[tail & QMASK], WQ_ITEM_SZ);

to count times when work_queue is not empty and we get next message from it).

In general, it is clear, that under load (after fix), the more time we leave IPI disabled (i.e. the more time we spend in cycles of SoftIRQ regeneration on target CPU) - the less count of IPI we'll get.
The results of tests on VM, collected by Perf, are the following:
General:

310K probe:tfw_wq_pop_ticket
 10K  probe:ss_tx_action_1
 54K  probe:ss_tx_action
 45K  probe:ss_ipi

I.e. it can be seen, that the number of exits from ss_tx_action with disabled IPI is less than 20% (10K/54K) in total number of ss_tx_action calls; in remaining 80% cases IPI has been enabled, since work_queue was empty.

probe:ss_tx_action:

Overhead       Samples  CPU  Symbol            Shared Object
 26.25%         14191  003  [k] ss_tx_action  [tempesta_fw]  
 25.70%         13892  001  [k] ss_tx_action  [tempesta_fw]
 24.33%         13150  000  [k] ss_tx_action  [tempesta_fw]
 23.72%         12821  002  [k] ss_tx_action  [tempesta_fw]

probe:ss_tx_action_1

Overhead       Samples  CPU  Symbol          Shared Object
54.73%          5770  000  [k] ss_tx_action  [tempesta_fw]
17.23%          1816  003  [k] ss_tx_action  [tempesta_fw]
15.07%          1589  001  [k] ss_tx_action  [tempesta_fw]
12.97%          1367  002  [k] ss_tx_action  [tempesta_fw]

The ss_tx_action и ss_tx_action_1 tracing for separate CPUs shows that the situation is not identical for different CPUs (constantly): on CPU0, this figure is 44%, while on others only 10-13%.

probe:ss_ipi:

Overhead       Samples  CPU  Symbol    Shared Object
29.09%         13175  001  [k] ss_ipi  [tempesta_fw]
28.77%         13028  003  [k] ss_ipi  [tempesta_fw]
27.09%         12269  002  [k] ss_ipi  [tempesta_fw]
15.06%          6819  000  [k] ss_ipi  [tempesta_fw]

As a result, the ss_ipi tracing for separate CPUs also shows the count of processed IPI (i.e received IPI - thus, generated on other CPUs for CPU0) 2 times less on CPU0 than on other CPUs.
Such behavior of CPU0 is explained by its higher workload: the RX IRQ is assigned to it (since RSS is absence); also, enabled RPS forces CPU0 to spend time distributing incoming packets to other CPUs - this is confirmed by samples of RPS subsystem calls (not shown here).

probe:tfw_wq_pop_ticket:

Overhead       Samples  CPU  Symbol               Shared Object
40.98%        127195  000  [k] tfw_wq_pop_ticket  [tempesta_fw]
21.34%         66229  003  [k] tfw_wq_pop_ticket  [tempesta_fw]
20.04%         62205  001  [k] tfw_wq_pop_ticket  [tempesta_fw]
17.64%         54738  002  [k] tfw_wq_pop_ticket  [tempesta_fw]

The tfw_wq_pop_ticket tracing for separate CPUs allows to get rough estimate of the average work_queue size for each CPU as the ratio of ss_tx_action calls count to the number of accesses to non-empty queue in tfw_wq_pop_ticket: for CPU0 it is equal 10 (127195 / 13150), while for other CPUs it is equal 4–5.

The picture is almost the same on bare metal server, except the work load is more evenly distributed between CPUs (RSS enabled on with 8 queues per 8 CPUs on incoming Mellanox NIC, and RPS is disabled): on average, for each CPU, the estimated queue size is 2–3.

Thus, the above tests showed a low work_queue load: 2–5 messages retrieved from queue on each ss_tx_action call, and IPI enabling in 80% calls to ss_tx_action. And in this context, the situation with CPU0 on VM is especially interesting: due to the additional load from the IRQ, it has less time to service its work_queue and it offloads queue slower: its average queue size is 10 and IPI is enabled only in 50% of ss_tx_action calls; and, as a result, - decreased in 2–3 times count of IPI, generated for CPU0, and therefore, the similar decrease in the load of call_function_single_interrupt:

Overhead     Samples  CPU                   Symbol                          Shared Object
 1.54%          5159  002  [k] call_function_single_interrupt              [kernel.vmlinux]
 1.44%          4945  003  [k] call_function_single_interrupt              [kernel.vmlinux]
 1.41%          4826  001  [k] call_function_single_interrupt              [kernel.vmlinux]
. . .
 0.38%          1455  000  [k] call_function_single_interrupt              [kernel.vmlinux]

such distribution of IPI handler workload have separate CPUs from general workload (depicted above):

4.65%         [k] call_function_single_interrupt

So, it seems that the cause of the remaining count of IPI is that the queue is underloaded. In order to further reduce IPIs, it is possible to hypothetically make the minimum required number of iterations in ss_tx_action, or in NET_TX_SOFTIRQ regenerations, but these will be idle iterations, they will not do useful work (due to an empty queues), consuming the CPUs resource.