From b852d505f97f8075d598af9ba545764c82e46a9f Mon Sep 17 00:00:00 2001 From: Takahiro Itazuri Date: Wed, 9 Jul 2025 12:52:21 +0000 Subject: [PATCH 1/2] test: Print log of iperf server running in guest We occasionally see failures of `test_rx_rate_limiting` with the following error: ``` iperf3: error - unable to connect to server - server may have stopped running or use a different port, firewall issue, etc.: Connection refused ``` However, we didn't have any diagnostic info about what happened inside a guest. Signed-off-by: Takahiro Itazuri --- .../performance/test_rate_limiter.py | 25 +++++++++++-------- 1 file changed, 15 insertions(+), 10 deletions(-) diff --git a/tests/integration_tests/performance/test_rate_limiter.py b/tests/integration_tests/performance/test_rate_limiter.py index 025f92d4d79..12055d8af96 100644 --- a/tests/integration_tests/performance/test_rate_limiter.py +++ b/tests/integration_tests/performance/test_rate_limiter.py @@ -9,6 +9,9 @@ # The iperf version to run this tests with IPERF_BINARY = "iperf3" +# iperf server side log path inside guest +GUEST_IPERF_SERVER_LOG = "/tmp/iperf-server.log" + # Interval used by iperf to get maximum bandwidth IPERF_TRANSMIT_TIME = 4 @@ -127,7 +130,7 @@ def test_rx_rate_limiting_cpu_load(uvm_plain): threshold=20, ) with cpu_load_monitor: - _run_iperf_on_host(iperf_cmd) + _run_iperf_on_host(iperf_cmd, test_microvm) def _check_tx_rate_limiting(test_microvm): @@ -219,8 +222,7 @@ def _check_rx_rate_limiting(test_microvm): BURST_SIZE, IPERF_TCP_WINDOW, ) - iperf_out = _run_iperf_on_host(iperf_cmd) - print(iperf_out) + iperf_out = _run_iperf_on_host(iperf_cmd, test_microvm) _, burst_kbps = _process_iperf_output(iperf_out) print("RX burst_kbps: {}".format(burst_kbps)) # Test that the burst bandwidth is at least as two times the rate limit. @@ -357,9 +359,7 @@ def _get_rx_bandwidth_with_duration(test_microvm, guest_ip, duration): duration, IPERF_TCP_WINDOW, ) - iperf_out = _run_iperf_on_host(iperf_cmd) - print(iperf_out) - + iperf_out = _run_iperf_on_host(iperf_cmd, test_microvm) _, observed_kbps = _process_iperf_output(iperf_out) print("RX observed_kbps: {}".format(observed_kbps)) return observed_kbps @@ -383,7 +383,7 @@ def _patch_iface_bw(test_microvm, iface_id, rx_or_tx, new_bucket_size, new_refil def _start_iperf_server_on_guest(test_microvm): """Start iperf in server mode through an SSH connection.""" - iperf_cmd = "{} -sD -f KBytes\n".format(IPERF_BINARY) + iperf_cmd = f"{IPERF_BINARY} -sD -f KBytes --logfile {GUEST_IPERF_SERVER_LOG}" test_microvm.ssh.run(iperf_cmd) # Wait for the iperf daemon to start. @@ -411,10 +411,15 @@ def _start_iperf_server_on_host(netns_cmd_prefix): time.sleep(1) -def _run_iperf_on_host(iperf_cmd): +def _run_iperf_on_host(iperf_cmd, test_microvm): """Execute a client related iperf command locally.""" - code, stdout, stderr = utils.check_output(iperf_cmd) - assert code == 0, f"stdout: {stdout}\nstderr: {stderr}" + rc, stdout, stderr = utils.run_cmd(iperf_cmd) + assert rc == 0, "stdout:\n{}\nstderr:\n{}\niperf server log:\n{}\n".format( + stdout, + stderr, + test_microvm.ssh.check_output(f"cat {GUEST_IPERF_SERVER_LOG}").stdout, + ) + print(f"iperf log:\n{stdout}") return stdout From 55f4e95ee68862542b8a2392c62f4c615bd659cd Mon Sep 17 00:00:00 2001 From: Takahiro Itazuri Date: Wed, 9 Jul 2025 13:05:37 +0000 Subject: [PATCH 2/2] test: Print the same formatted message before running iperf The integration tests for rate limiter run iperf command multiple times for different configurations. Printing the same formatted message before every iperf run improves readability. Signed-off-by: Takahiro Itazuri --- .../integration_tests/performance/test_rate_limiter.py | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/tests/integration_tests/performance/test_rate_limiter.py b/tests/integration_tests/performance/test_rate_limiter.py index 12055d8af96..e050a20c55d 100644 --- a/tests/integration_tests/performance/test_rate_limiter.py +++ b/tests/integration_tests/performance/test_rate_limiter.py @@ -144,7 +144,7 @@ def _check_tx_rate_limiting(test_microvm): # First step: get the transfer rate when no rate limiting is enabled. # We are receiving the result in KBytes from iperf. - print("Run guest TX iperf with no rate-limit") + print("Run guest TX iperf for no rate limiting") rate_no_limit_kbps = _get_tx_bandwidth_with_duration( test_microvm, eth0.host_ip, IPERF_TRANSMIT_TIME ) @@ -160,11 +160,12 @@ def _check_tx_rate_limiting(test_microvm): assert _get_percentage_difference(rate_no_limit_kbps, expected_kbps) > 100 # Second step: check bandwidth when rate limiting is on. + print("Run guest TX iperf for rate limiting without burst") _check_tx_bandwidth(test_microvm, eth1.host_ip, expected_kbps) # Third step: get the number of bytes when rate limiting is on and there is # an initial burst size from where to consume. - print("Run guest TX iperf with exact burst size") + print("Run guest TX iperf for rate limiting with burst") # Use iperf to obtain the bandwidth when there is burst to consume from, # send exactly BURST_SIZE packets. iperf_cmd = "{} -c {} -n {} -f KBytes -w {} -N".format( @@ -192,7 +193,7 @@ def _check_rx_rate_limiting(test_microvm): # First step: get the transfer rate when no rate limiting is enabled. # We are receiving the result in KBytes from iperf. - print("Run guest RX iperf with no rate-limit") + print("Run guest RX iperf with no rate limiting") rate_no_limit_kbps = _get_rx_bandwidth_with_duration( test_microvm, eth0.guest_ip, IPERF_TRANSMIT_TIME ) @@ -208,11 +209,12 @@ def _check_rx_rate_limiting(test_microvm): assert _get_percentage_difference(rate_no_limit_kbps, expected_kbps) > 100 # Second step: check bandwidth when rate limiting is on. + print("Run guest RX iperf for rate limiting without burst") _check_rx_bandwidth(test_microvm, eth1.guest_ip, expected_kbps) # Third step: get the number of bytes when rate limiting is on and there is # an initial burst size from where to consume. - print("Run guest RX iperf with exact burst size") + print("Run guest RX iperf for rate limiting with burst") # Use iperf to obtain the bandwidth when there is burst to consume from, # send exactly BURST_SIZE packets. iperf_cmd = "{} {} -c {} -n {} -f KBytes -w {} -N".format(