[PATCH v3 0/1] Added cond_resched() to crdump collection

[PATCH v3 0/1] Added cond_resched() to crdump collection

[Mohamed Khalfella]

Changes in v3:
- Added Fixes: 8b9d8baae1de ("net/mlx5: Add Crdump support").
- Updated the commit message to mention why cond_resched() every 128
  registers read.
- Simplified the check that calls cond_resched().

v1: https://lore.kernel.org/all/20240819214259.38259-1-mkhalfella@purestorage.com/
v2: https://lore.kernel.org/all/20240829213856.77619-1-mkhalfella@purestorage.com/

Mohamed Khalfella (1):
  net/mlx5: Added cond_resched() to crdump collection

 drivers/net/ethernet/mellanox/mlx5/core/lib/pci_vsc.c | 10 ++++++++++
 1 file changed, 10 insertions(+)

-- 
2.45.2

[PATCH v3 1/1] net/mlx5: Added cond_resched() to crdump collection

[Mohamed Khalfella]

Collecting crdump involves reading vsc registers from pci config space
of mlx device, which can take long time to complete. This might result
in starving other threads waiting to run on the cpu.

Numbers I got from testing ConnectX-5 Ex MCX516A-CDAT in the lab:

- mlx5_vsc_gw_read_block_fast() was called with length = 1310716.
- mlx5_vsc_gw_read_fast() reads 4 bytes at a time. It was not used to
  read the entire 1310716 bytes. It was called 53813 times because
  there are jumps in read_addr.
- On average mlx5_vsc_gw_read_fast() took 35284.4ns.
- In total mlx5_vsc_wait_on_flag() called vsc_read() 54707 times.
  The average time for each call was 17548.3ns. In some instances
  vsc_read() was called more than one time when the flag was not set.
  As expected the thread released the cpu after 16 iterations in
  mlx5_vsc_wait_on_flag().
- Total time to read crdump was 35284.4ns * 53813 ~= 1.898s.

It was seen in the field that crdump can take more than 5 seconds to
complete. During that time mlx5_vsc_wait_on_flag() did not release the
cpu because it did not complete 16 iterations. It is believed that pci
config reads were slow. Adding cond_resched() every 128 register read
improves the situation. In the common case the, crdump takes ~1.8989s,
the thread yields the cpu every ~4.51ms. If crdump takes ~5s, the thread
yields the cpu every ~18.0ms.

Fixes: 8b9d8baae1de ("net/mlx5: Add Crdump support")
Reviewed-by: Yuanyuan Zhong <yzhong@purestorage.com>
Signed-off-by: Mohamed Khalfella <mkhalfella@purestorage.com>
---
 drivers/net/ethernet/mellanox/mlx5/core/lib/pci_vsc.c | 10 ++++++++++
 1 file changed, 10 insertions(+)

diff --git a/drivers/net/ethernet/mellanox/mlx5/core/lib/pci_vsc.c b/drivers/net/ethernet/mellanox/mlx5/core/lib/pci_vsc.c
index 6b774e0c2766..c14f9529c25f 100644
--- a/drivers/net/ethernet/mellanox/mlx5/core/lib/pci_vsc.c
+++ b/drivers/net/ethernet/mellanox/mlx5/core/lib/pci_vsc.c
@@ -24,6 +24,11 @@
 	pci_write_config_dword((dev)->pdev, (dev)->vsc_addr + (offset), (val))
 #define VSC_MAX_RETRIES 2048
 
+/* Reading VSC registers can take relatively long time.
+ * Yield the cpu every 128 registers read.
+ */
+#define VSC_GW_READ_BLOCK_COUNT 128
+
 enum {
 	VSC_CTRL_OFFSET = 0x4,
 	VSC_COUNTER_OFFSET = 0x8,
@@ -269,6 +274,7 @@ int mlx5_vsc_gw_read_block_fast(struct mlx5_core_dev *dev, u32 *data,
 {
 	unsigned int next_read_addr = 0;
 	unsigned int read_addr = 0;
+	unsigned int count = 0;
 
 	while (read_addr < length) {
 		if (mlx5_vsc_gw_read_fast(dev, read_addr, &next_read_addr,
@@ -276,6 +282,10 @@ int mlx5_vsc_gw_read_block_fast(struct mlx5_core_dev *dev, u32 *data,
 			return read_addr;
 
 		read_addr = next_read_addr;
+		if (++count == VSC_GW_READ_BLOCK_COUNT) {
+			cond_resched();
+			count = 0;
+		}
 	}
 	return length;
 }
-- 
2.45.2

Re: [PATCH v3 1/1] net/mlx5: Added cond_resched() to crdump collection

[Moshe Shemesh]

On 9/5/2024 7:02 AM, Mohamed Khalfella wrote:
> Collecting crdump involves reading vsc registers from pci config space
> of mlx device, which can take long time to complete. This might result
> in starving other threads waiting to run on the cpu.
> 
> Numbers I got from testing ConnectX-5 Ex MCX516A-CDAT in the lab:
> 
> - mlx5_vsc_gw_read_block_fast() was called with length = 1310716.
> - mlx5_vsc_gw_read_fast() reads 4 bytes at a time. It was not used to
>    read the entire 1310716 bytes. It was called 53813 times because
>    there are jumps in read_addr.
> - On average mlx5_vsc_gw_read_fast() took 35284.4ns.
> - In total mlx5_vsc_wait_on_flag() called vsc_read() 54707 times.
>    The average time for each call was 17548.3ns. In some instances
>    vsc_read() was called more than one time when the flag was not set.
>    As expected the thread released the cpu after 16 iterations in
>    mlx5_vsc_wait_on_flag().
> - Total time to read crdump was 35284.4ns * 53813 ~= 1.898s.
> 
> It was seen in the field that crdump can take more than 5 seconds to
> complete. During that time mlx5_vsc_wait_on_flag() did not release the
> cpu because it did not complete 16 iterations. It is believed that pci
> config reads were slow. Adding cond_resched() every 128 register read
> improves the situation. In the common case the, crdump takes ~1.8989s,
> the thread yields the cpu every ~4.51ms. If crdump takes ~5s, the thread
> yields the cpu every ~18.0ms.
> 
> Fixes: 8b9d8baae1de ("net/mlx5: Add Crdump support")
> Reviewed-by: Yuanyuan Zhong<yzhong@purestorage.com>
> Signed-off-by: Mohamed Khalfella<mkhalfella@purestorage.com>
> ---

Reviewed-by: Moshe Shemesh <moshe@nvidia.com>