Ubuntu
irqbalance package

Bug #2038573
Comment #6

Comment 6 for bug 2038573

Revision history for this message

Mauricio Faria de Oliveira (mfo) wrote on 2023-10-06:

Verification done on jammy-proposed.

Environment:
---

There are 4x completion IRQs (network receive traffic / RX) plus 1x IRQ, for the Mellanox network VF.

  24: ... mlx5_comp0@pci:0b9d:00:02.0
  25: ... mlx5_comp1@pci:0b9d:00:02.0
  26: ... mlx5_comp2@pci:0b9d:00:02.0
  27: ... mlx5_comp3@pci:0b9d:00:02.0
  28: ... mlx5_async4@pci:0b9d:00:02.0

irqbalance is configured with `--debug` in /etc/default/irqbalance, and restarted.

$ journalctl -b -u irqbalance.service
...
Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 25 to database
Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 28 to database
Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 26 to database
Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 24 to database
Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 27 to database
...

With package from jammy-release:
----

The interrupts are initially balanced:

Oct 06 16:48:40 jammy irqbalance[1388]: CPU number 3 numa_node is 0 (load 0)
Oct 06 16:48:40 jammy irqbalance[1388]: Interrupt 27 node_num is 0 (ethernet/0:39)
Oct 06 16:48:40 jammy irqbalance[1388]: Interrupt 25 node_num is 0 (ethernet/0:3)
Oct 06 16:48:40 jammy irqbalance[1388]: CPU number 2 numa_node is 0 (load 0)
Oct 06 16:48:40 jammy irqbalance[1388]: Interrupt 26 node_num is 0 (ethernet/0:22)
...
Oct 06 16:48:40 jammy irqbalance[1388]: CPU number 1 numa_node is 0 (load 0)
Oct 06 16:48:40 jammy irqbalance[1388]: Interrupt 24 node_num is 0 (ethernet/0:13)
Oct 06 16:48:40 jammy irqbalance[1388]: CPU number 0 numa_node is 0 (load 0)
Oct 06 16:48:40 jammy irqbalance[1388]: Interrupt 28 node_num is 0 (ethernet/0:1)

Then VF is removed/re-added due to module remove/add of `mlx5_ib mlx5_core` modules.

Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 25 is removed from interrupts_db.
Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 28 is removed from interrupts_db.
Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 26 is removed from interrupts_db.
Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 24 is removed from interrupts_db.
Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 27 is removed from interrupts_db.
...
Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 24 to database
Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 24 finished.
Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 25 to database
Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 25 finished.
Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 26 to database
Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 26 finished.
Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 27 to database
Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 27 finished.
Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 28 to database
Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 28 finished.

Then all get into CPU2:

Oct 06 16:52:20 jammy irqbalance[1388]: CPU number 2 numa_node is 0 (load 3900000000)
Oct 06 16:52:20 jammy irqbalance[1388]: Interrupt 28 node_num is 0 (ethernet/0:3414)
Oct 06 16:52:20 jammy irqbalance[1388]: Interrupt 27 node_num is 0 (ethernet/0:29467)
Oct 06 16:52:20 jammy irqbalance[1388]: Interrupt 26 node_num is 0 (ethernet/0:92371)
Oct 06 16:52:20 jammy irqbalance[1388]: Interrupt 25 node_num is 0 (ethernet/0:84903)
Oct 06 16:52:20 jammy irqbalance[1388]: Interrupt 24 node_num is 0 (ethernet/0:67247)

No rebalancing until 17:05 (~13 minutes testing; irqbalance runs several times):

Oct 06 17:05:40 jammy irqbalance[1388]: CPU number 2 numa_node is 0 (load 2780000000)
Oct 06 17:05:40 jammy irqbalance[1388]: Interrupt 27 node_num is 0 (ethernet/806745040:148)
Oct 06 17:05:40 jammy irqbalance[1388]: Interrupt 26 node_num is 0 (ethernet/714078380:131)
Oct 06 17:05:40 jammy irqbalance[1388]: Interrupt 25 node_num is 0 (ethernet/659568580:121)
Oct 06 17:05:40 jammy irqbalance[1388]: Interrupt 28 node_num is 0 (ethernet/414274480:76)
Oct 06 17:05:40 jammy irqbalance[1388]: Interrupt 24 node_num is 0 (ethernet/185333320:34)

$ cat journalctl.log | sed -n '/16:52:20/,/17:05:40/p' | grep 'Selecting irq .* for rebalancing'
$

With package from jammy-proposed:
----

# dpkg -l |grep irqbalance
ii irqbalance 1.8.0-1ubuntu0.1 amd64 Daemon to balance interrupts for SMP systems

# systemctl restart irqbalance.service

...
Oct 06 17:12:42 jammy systemd[1]: Stopped irqbalance daemon.
Oct 06 17:12:42 jammy systemd[1]: Started irqbalance daemon.
...
Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 25 to database
Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 28 to database
Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 26 to database
Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 24 to database
Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 27 to database

The interrupts are initially balanced:

Oct 06 17:13:12 jammy irqbalance[6183]: CPU number 3 numa_node is 0 (load 0)
Oct 06 17:13:12 jammy irqbalance[6183]: Interrupt 27 node_num is 0 (ethernet/0:17)
Oct 06 17:13:12 jammy irqbalance[6183]: Interrupt 25 node_num is 0 (ethernet/0:13)
Oct 06 17:13:12 jammy irqbalance[6183]: CPU number 2 numa_node is 0 (load 0)
Oct 06 17:13:12 jammy irqbalance[6183]: Interrupt 26 node_num is 0 (ethernet/0:20)
...
Oct 06 17:13:12 jammy irqbalance[6183]: CPU number 1 numa_node is 0 (load 0)
Oct 06 17:13:12 jammy irqbalance[6183]: Interrupt 24 node_num is 0 (ethernet/0:6)
Oct 06 17:13:12 jammy irqbalance[6183]: CPU number 0 numa_node is 0 (load 0)
Oct 06 17:13:12 jammy irqbalance[6183]: Interrupt 28 node_num is 0 (ethernet/0:1)

Then VF is removed/re-added due to module remove/add of `mlx5_ib mlx5_core` modules.

Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 25 is removed from interrupts_db.
Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 28 is removed from interrupts_db.
Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 26 is removed from interrupts_db.
Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 24 is removed from interrupts_db.
Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 27 is removed from interrupts_db.
...
Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 24 to database
Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 24 finished.
Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 25 to database
Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 25 finished.
Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 26 to database
Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 26 finished.
Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 27 to database
Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 27 finished.
Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 28 to database
Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 28 finished.

Then all get into CPU3:

Oct 06 17:15:52 jammy irqbalance[6183]: CPU number 3 numa_node is 0 (load 5810000000)
Oct 06 17:15:52 jammy irqbalance[6183]: Interrupt 28 node_num is 0 (ethernet/0:433)
Oct 06 17:15:52 jammy irqbalance[6183]: Interrupt 27 node_num is 0 (ethernet/0:2896)
Oct 06 17:15:52 jammy irqbalance[6183]: Interrupt 26 node_num is 0 (ethernet/0:3418)
Oct 06 17:15:52 jammy irqbalance[6183]: Interrupt 25 node_num is 0 (ethernet/0:3901)
Oct 06 17:15:52 jammy irqbalance[6183]: Interrupt 24 node_num is 0 (ethernet/0:134)

But now are frequently balanced until the end of the test (~30 minutes):

Oct 06 17:43:32 jammy irqbalance[6183]: -----------------------------------------------------------------------------

$ cat journalctl.log | sed -n '/17:12:42/,/17:43:32/p' | grep 'Selecting irq 2[45678].* for rebalancing'
Oct 06 17:14:32 jammy irqbalance[6183]: Selecting irq 27 for rebalancing
Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 26 for rebalancing
Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 27 for rebalancing
Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 25 for rebalancing
Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 24 for rebalancing
Oct 06 17:19:22 jammy irqbalance[6183]: Selecting irq 26 for rebalancing
Oct 06 17:19:22 jammy irqbalance[6183]: Selecting irq 24 for rebalancing
...
Oct 06 17:42:52 jammy irqbalance[6183]: Selecting irq 28 for rebalancing

i.e., the condition is now working, and the function does not return before rebalancing.

76 static void move_candidate_irqs(struct irq_info *info, void *data)
...
100 if ((lb_info->min_load + info->load) < delta_load + (lb_info->adjustment_load - info->load)) {
...
106 } else
107 return;
108
109 log(TO_CONSOLE, LOG_INFO, "Selecting irq %d for rebalancing\n", info->irq);

Verification done on jammy-proposed.

Environment:
---

There are 4x completion IRQs (network receive traffic / RX) plus 1x IRQ, for the Mellanox network VF.

24: ... mlx5_comp0@pci:0b9d:00:02.0
	 25: ... mlx5_comp1@pci:0b9d:00:02.0
	 26: ... mlx5_comp2@pci:0b9d:00:02.0
	 27: ... mlx5_comp3@pci:0b9d:00:02.0
	 28: ... mlx5_async4@pci:0b9d:00:02.0

irqbalance is configured with `--debug` in /etc/default/irqbalance, and restarted.

$ journalctl -b -u irqbalance.service
	...
	Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 25 to database
	Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 28 to database
	Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 26 to database
	Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 24 to database
	Oct 06 16:48:40 jammy irqbalance[1388]: Adding IRQ 27 to database
	...

With package from jammy-release:
----

The interrupts are initially balanced:

Oct 06 16:48:40 jammy irqbalance[1388]:                 CPU number 3  numa_node is 0 (load 0)
	Oct 06 16:48:40 jammy irqbalance[1388]:                   Interrupt 27 node_num is 0 (ethernet/0:39)
	Oct 06 16:48:40 jammy irqbalance[1388]:                   Interrupt 25 node_num is 0 (ethernet/0:3)
	Oct 06 16:48:40 jammy irqbalance[1388]:                 CPU number 2  numa_node is 0 (load 0)
	Oct 06 16:48:40 jammy irqbalance[1388]:                   Interrupt 26 node_num is 0 (ethernet/0:22)
	...
	Oct 06 16:48:40 jammy irqbalance[1388]:                 CPU number 1  numa_node is 0 (load 0)
	Oct 06 16:48:40 jammy irqbalance[1388]:                   Interrupt 24 node_num is 0 (ethernet/0:13)
	Oct 06 16:48:40 jammy irqbalance[1388]:                 CPU number 0  numa_node is 0 (load 0)
	Oct 06 16:48:40 jammy irqbalance[1388]:                   Interrupt 28 node_num is 0 (ethernet/0:1)

Then VF is removed/re-added due to module remove/add of `mlx5_ib mlx5_core` modules.

Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 25 is removed from interrupts_db.
	Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 28 is removed from interrupts_db.
	Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 26 is removed from interrupts_db.
	Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 24 is removed from interrupts_db.
	Oct 06 16:51:40 jammy irqbalance[1388]: IRQ 27 is removed from interrupts_db.
	...
	Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 24 to database
	Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 24 finished.
	Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 25 to database
	Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 25 finished.
	Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 26 to database
	Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 26 finished.
	Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 27 to database
	Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 27 finished.
	Oct 06 16:52:20 jammy irqbalance[1388]: Adding IRQ 28 to database
	Oct 06 16:52:20 jammy irqbalance[1388]: Hotplug dev irq: 28 finished.

Then all get into CPU2:

Oct 06 16:52:20 jammy irqbalance[1388]:                 CPU number 2  numa_node is 0 (load 3900000000)
	Oct 06 16:52:20 jammy irqbalance[1388]:                   Interrupt 28 node_num is 0 (ethernet/0:3414)
	Oct 06 16:52:20 jammy irqbalance[1388]:                   Interrupt 27 node_num is 0 (ethernet/0:29467)
	Oct 06 16:52:20 jammy irqbalance[1388]:                   Interrupt 26 node_num is 0 (ethernet/0:92371)
	Oct 06 16:52:20 jammy irqbalance[1388]:                   Interrupt 25 node_num is 0 (ethernet/0:84903)
	Oct 06 16:52:20 jammy irqbalance[1388]:                   Interrupt 24 node_num is 0 (ethernet/0:67247)

No rebalancing until 17:05 (~13 minutes testing; irqbalance runs several times):

Oct 06 17:05:40 jammy irqbalance[1388]:                 CPU number 2  numa_node is 0 (load 2780000000)
	Oct 06 17:05:40 jammy irqbalance[1388]:                   Interrupt 27 node_num is 0 (ethernet/806745040:148)
	Oct 06 17:05:40 jammy irqbalance[1388]:                   Interrupt 26 node_num is 0 (ethernet/714078380:131)
	Oct 06 17:05:40 jammy irqbalance[1388]:                   Interrupt 25 node_num is 0 (ethernet/659568580:121)
	Oct 06 17:05:40 jammy irqbalance[1388]:                   Interrupt 28 node_num is 0 (ethernet/414274480:76)
	Oct 06 17:05:40 jammy irqbalance[1388]:                   Interrupt 24 node_num is 0 (ethernet/185333320:34)

$ cat journalctl.log | sed -n '/16:52:20/,/17:05:40/p' | grep 'Selecting irq .* for rebalancing'
	$

With package from jammy-proposed:
----

# dpkg -l |grep irqbalance
	ii  irqbalance                             1.8.0-1ubuntu0.1                        amd64        Daemon to balance interrupts for SMP systems

# systemctl restart irqbalance.service

...
	Oct 06 17:12:42 jammy systemd[1]: Stopped irqbalance daemon.
	Oct 06 17:12:42 jammy systemd[1]: Started irqbalance daemon.
	...
	Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 25 to database
	Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 28 to database
	Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 26 to database
	Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 24 to database
	Oct 06 17:13:12 jammy irqbalance[6183]: Adding IRQ 27 to database

The interrupts are initially balanced:

Oct 06 17:13:12 jammy irqbalance[6183]:                 CPU number 3  numa_node is 0 (load 0)
	Oct 06 17:13:12 jammy irqbalance[6183]:                   Interrupt 27 node_num is 0 (ethernet/0:17)
	Oct 06 17:13:12 jammy irqbalance[6183]:                   Interrupt 25 node_num is 0 (ethernet/0:13)
	Oct 06 17:13:12 jammy irqbalance[6183]:                 CPU number 2  numa_node is 0 (load 0)
	Oct 06 17:13:12 jammy irqbalance[6183]:                   Interrupt 26 node_num is 0 (ethernet/0:20)
	...
	Oct 06 17:13:12 jammy irqbalance[6183]:                 CPU number 1  numa_node is 0 (load 0)
	Oct 06 17:13:12 jammy irqbalance[6183]:                   Interrupt 24 node_num is 0 (ethernet/0:6)
	Oct 06 17:13:12 jammy irqbalance[6183]:                 CPU number 0  numa_node is 0 (load 0)
	Oct 06 17:13:12 jammy irqbalance[6183]:                   Interrupt 28 node_num is 0 (ethernet/0:1)

Then VF is removed/re-added due to module remove/add of `mlx5_ib mlx5_core` modules.

Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 25 is removed from interrupts_db.
	Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 28 is removed from interrupts_db.
	Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 26 is removed from interrupts_db.
	Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 24 is removed from interrupts_db.
	Oct 06 17:15:12 jammy irqbalance[6183]: IRQ 27 is removed from interrupts_db.
	...
	Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 24 to database
	Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 24 finished.
	Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 25 to database
	Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 25 finished.
	Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 26 to database
	Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 26 finished.
	Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 27 to database
	Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 27 finished.
	Oct 06 17:15:52 jammy irqbalance[6183]: Adding IRQ 28 to database
	Oct 06 17:15:52 jammy irqbalance[6183]: Hotplug dev irq: 28 finished.

Then all get into CPU3:

Oct 06 17:15:52 jammy irqbalance[6183]:                 CPU number 3  numa_node is 0 (load 5810000000)
	Oct 06 17:15:52 jammy irqbalance[6183]:                   Interrupt 28 node_num is 0 (ethernet/0:433)
	Oct 06 17:15:52 jammy irqbalance[6183]:                   Interrupt 27 node_num is 0 (ethernet/0:2896)
	Oct 06 17:15:52 jammy irqbalance[6183]:                   Interrupt 26 node_num is 0 (ethernet/0:3418)
	Oct 06 17:15:52 jammy irqbalance[6183]:                   Interrupt 25 node_num is 0 (ethernet/0:3901)
	Oct 06 17:15:52 jammy irqbalance[6183]:                   Interrupt 24 node_num is 0 (ethernet/0:134)

But now are frequently balanced until the end of the test (~30 minutes):

Oct 06 17:43:32 jammy irqbalance[6183]: -----------------------------------------------------------------------------

$ cat journalctl.log | sed -n '/17:12:42/,/17:43:32/p' | grep 'Selecting irq 2[45678].* for rebalancing'
	Oct 06 17:14:32 jammy irqbalance[6183]: Selecting irq 27 for rebalancing
	Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 26 for rebalancing
	Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 27 for rebalancing
	Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 25 for rebalancing
	Oct 06 17:15:52 jammy irqbalance[6183]: Selecting irq 24 for rebalancing
	Oct 06 17:19:22 jammy irqbalance[6183]: Selecting irq 26 for rebalancing
	Oct 06 17:19:22 jammy irqbalance[6183]: Selecting irq 24 for rebalancing
	...
	Oct 06 17:42:52 jammy irqbalance[6183]: Selecting irq 28 for rebalancing

i.e., the condition is now working, and the function does not return before rebalancing.

76 static void move_candidate_irqs(struct irq_info *info, void *data)
	...
	100         if ((lb_info->min_load + info->load) < delta_load + (lb_info->adjustment_load - info->load)) {
	...
	106         } else
	107                 return;
	108
	109         log(TO_CONSOLE, LOG_INFO, "Selecting irq %d for rebalancing\n", info->irq);

Ubuntuirqbalance package

Comment 6 for bug 2038573

Ubuntu
irqbalance package