Merge branch 'bugfix/iperf_performance_v4.4' into 'release/v4.4'

Bugfix/iperf performance (v4.4)

See merge request espressif/esp-idf!17600

components/esp_eth/src/esp_eth_mac_esp.c

@@ -226,7 +226,7 @@ static esp_err_t emac_esp32_transmit(esp_eth_mac_t *mac, uint8_t *buf, uint32_t
     esp_err_t ret = ESP_OK;
     emac_esp32_t *emac = __containerof(mac, emac_esp32_t, parent);
     uint32_t sent_len = emac_hal_transmit_frame(&emac->hal, buf, length);
-    ESP_GOTO_ON_FALSE(sent_len == length, ESP_ERR_INVALID_SIZE, err, TAG, "insufficient TX buffer size");
+    ESP_GOTO_ON_FALSE(sent_len == length, ESP_ERR_NO_MEM, err, TAG, "insufficient TX buffer size");
     return ESP_OK;
 err:
     return ret;

components/lwip/port/esp32/netif/ethernetif.c

@@ -134,11 +134,12 @@ static err_t ethernet_low_level_output(struct netif *netif, struct pbuf *p)
         pbuf_free(q);
     }
     /* Check error */
-    if (unlikely(ret != ESP_OK)) {
+    if (likely(ret == ESP_OK)) {
-        return ERR_ABRT;
-    } else {
         return ERR_OK;
+    } else if (ret == ESP_ERR_NO_MEM) {
+        return ERR_MEM;
     }
+    return ERR_IF;
 }
 
 /**

examples/common_components/iperf/include/iperf.h

@@ -33,6 +33,7 @@ extern "C" {
 #define IPERF_DEFAULT_PORT 5001
 #define IPERF_DEFAULT_INTERVAL 3
 #define IPERF_DEFAULT_TIME 30
+#define IPERF_DEFAULT_NO_BW_LIMIT -1
 
 #define IPERF_TRAFFIC_TASK_NAME "iperf_traffic"
 #define IPERF_TRAFFIC_TASK_PRIORITY 4
@@ -67,6 +68,7 @@ typedef struct {
     uint32_t interval;
     uint32_t time;
     uint16_t len_send_buf;
+    int32_t bw_lim;
 } iperf_cfg_t;
 
 esp_err_t iperf_start(iperf_cfg_t *cfg);

examples/common_components/iperf/iperf.c

@@ -14,6 +14,8 @@
 #include "freertos/task.h"
 #include "esp_check.h"
 #include "esp_log.h"
+#include "esp_rom_sys.h"
+#include "esp_timer.h"
 #include "iperf.h"
 
 typedef struct {
@@ -147,25 +149,40 @@ static void socket_recv(int recv_socket, struct sockaddr_storage listen_addr, ui
     }
 }
 
-static void socket_send(int send_socket, struct sockaddr_storage dest_addr, uint8_t type)
+static void socket_send(int send_socket, struct sockaddr_storage dest_addr, uint8_t type, int bw_lim)
 {
-    bool retry = false;
     uint8_t *buffer;
-    uint8_t delay = 0;
     int actual_send = 0;
     int want_send = 0;
+    int period_us = -1;
+    int delay_us = 0;
+    int64_t prev_time = 0;
+    int64_t send_time = 0;
     int err = 0;
 
     buffer = s_iperf_ctrl.buffer;
     want_send = s_iperf_ctrl.buffer_len;
     iperf_start_report();
 
-    while (!s_iperf_ctrl.finish) {
+    if (bw_lim > 0) {
-        if (type == IPERF_TRANS_TYPE_UDP) {
+        period_us = want_send * 8 / bw_lim;
-            if (false == retry) {
-                delay = 1;
     }
-            retry = false;
+
+    while (!s_iperf_ctrl.finish) {
+        if (period_us > 0) {
+            send_time = esp_timer_get_time();
+            if (actual_send > 0){
+                // Last packet "send" was successful, check how much off the previous loop duration was to the ideal send period. Result will adjust the
+                // next send delay.
+                delay_us += period_us + (int32_t)(prev_time - send_time);
+            } else {
+                // Last packet "send" was not successful. Ideally we should try to catch up the whole previous loop duration (e.g. prev_time - send_time).
+                // However, that's not possible since the most probable reason why the send was unsuccessful is the HW was not able to process the packet.
+                // Hence, we cannot queue more packets with shorter (or no) delay to catch up since we are already at the performance edge. The best we
+                // can do is to reset the send delay (which is probably big negative number) and start all over again.
+                delay_us = 0;
+            }
+            prev_time = send_time;
         }
         if (s_iperf_ctrl.cfg.type == IPERF_IP_TYPE_IPV6) {
             actual_send = sendto(send_socket, buffer, want_send, 0, (struct sockaddr *)&dest_addr, sizeof(struct sockaddr_in6));
@@ -175,17 +192,9 @@ static void socket_send(int send_socket, struct sockaddr_storage dest_addr, uint
         if (actual_send != want_send) {
             if (type == IPERF_TRANS_TYPE_UDP) {
                 err = iperf_get_socket_error_code(send_socket);
-                if (err == ENOMEM) {
+                // ENOMEM is expected under heavy load => do not print it
-                    vTaskDelay(delay);
+                if (err != ENOMEM) {
-                    if (delay < IPERF_MAX_DELAY) {
+                    iperf_show_socket_error_reason("udp client send", send_socket);
-                        delay <<= 1;
-                    }
-                    retry = true;
-                    continue;
-                } else {
-                    if (s_iperf_ctrl.cfg.type == IPERF_IP_TYPE_IPV4) {
-                        ESP_LOGE(TAG, "udp client send abort: err=%d", err);
-                    }
                 }
             }
             if (type == IPERF_TRANS_TYPE_TCP) {
@@ -196,6 +205,10 @@ static void socket_send(int send_socket, struct sockaddr_storage dest_addr, uint
         } else {
             s_iperf_ctrl.actual_len += actual_send;
         }
+        // The send delay may be negative, it indicates we are trying to catch up and hence to not delay the loop at all.
+        if (delay_us > 0) {
+            esp_rom_delay_us(delay_us);
+        }
     }
 }
 
@@ -316,7 +329,7 @@ static esp_err_t iperf_run_tcp_client(void)
         memcpy(&dest_addr, &dest_addr4, sizeof(dest_addr4));
     }
 
-    socket_send(client_socket, dest_addr, IPERF_TRANS_TYPE_TCP);
+    socket_send(client_socket, dest_addr, IPERF_TRANS_TYPE_TCP, s_iperf_ctrl.cfg.bw_lim);
 exit:
     if (client_socket != -1) {
         shutdown(client_socket, 0);
@@ -423,7 +436,7 @@ static esp_err_t iperf_run_udp_client(void)
         memcpy(&dest_addr, &dest_addr4, sizeof(dest_addr4));
     }
 
-    socket_send(client_socket, dest_addr, IPERF_TRANS_TYPE_UDP);
+    socket_send(client_socket, dest_addr, IPERF_TRANS_TYPE_UDP, s_iperf_ctrl.cfg.bw_lim);
 exit:
     if (client_socket != -1) {
         shutdown(client_socket, 0);

examples/ethernet/iperf/README.md

@@ -149,7 +149,7 @@ I (2534456) iperf: want recv=16384
 ## Suggestions of getting higher bandwidth
 
 1. Higher MCU working frequency will get higher bandwidth.
-2. Put frequency invoked function into IRAM via macro `IRAM_ATTR` in code.
+2. Put frequently invoked functions into IRAM via macro `IRAM_ATTR` in code. Note that the lwIP IRAM optimization is already enabled by default.
 3. Priority of iperf task may also have effect.
 
 ## Troubleshooting

examples/ethernet/iperf/iperf_test.py

@@ -24,6 +24,8 @@ except ImportError:
     # Only used for type annotations
     pass
 
+NO_BANDWIDTH_LIMIT = -1  # iperf send bandwith is not limited
+
 
 class IperfTestUtilityEth(IperfUtility.IperfTestUtility):
     """ iperf test implementation """
@@ -46,7 +48,7 @@ class IperfTestUtilityEth(IperfUtility.IperfTestUtility):
         self.dut.write('ethernet start')
         time.sleep(10)
         self.dut.write('ethernet info')
-        dut_ip = self.dut.expect(re.compile(r'ETHIP: ([\d.]+)'))[0]
+        dut_ip = self.dut.expect(re.compile(r'ETHIP: (\d+[.]\d+[.]\d+[.]\d+)'))[0]
         rssi = 0
         return dut_ip, rssi
 
@@ -78,7 +80,10 @@ def test_ethernet_throughput_basic(env, _):  # type: (Any, Any) -> None
 
     # 3. run test for TCP Tx, Rx and UDP Tx, Rx
 
-    test_utility.run_all_cases(0)
+    test_utility.run_test('tcp', 'tx', 0, NO_BANDWIDTH_LIMIT)
+    test_utility.run_test('tcp', 'rx', 0, NO_BANDWIDTH_LIMIT)
+    test_utility.run_test('udp', 'tx', 0, 80)
+    test_utility.run_test('udp', 'rx', 0, NO_BANDWIDTH_LIMIT)
 
     # 4. log performance and compare with pass standard
     performance_items = []

examples/ethernet/iperf/main/cmd_ethernet.c

@@ -70,6 +70,7 @@ static struct {
     struct arg_int *length;
     struct arg_int *interval;
     struct arg_int *time;
+    struct arg_int *bw_limit;
     struct arg_lit *abort;
     struct arg_end *end;
 } iperf_args;
@@ -167,6 +168,16 @@ static int eth_cmd_iperf(int argc, char **argv)
         }
     }
 
+    /* iperf -b */
+    if (iperf_args.bw_limit->count == 0) {
+        cfg.bw_lim = IPERF_DEFAULT_NO_BW_LIMIT;
+    } else {
+        cfg.bw_lim = iperf_args.bw_limit->ival[0];
+        if (cfg.bw_lim <= 0) {
+            cfg.bw_lim = IPERF_DEFAULT_NO_BW_LIMIT;
+        }
+    }
+
     printf("mode=%s-%s sip=%d.%d.%d.%d:%d, dip=%d.%d.%d.%d:%d, interval=%d, time=%d\r\n",
            cfg.flag & IPERF_FLAG_TCP ? "tcp" : "udp",
            cfg.flag & IPERF_FLAG_SERVER ? "server" : "client",
@@ -345,6 +356,7 @@ void register_ethernet(void)
     iperf_args.interval = arg_int0("i", "interval", "<interval>",
                                    "seconds between periodic bandwidth reports");
     iperf_args.time = arg_int0("t", "time", "<time>", "time in seconds to transmit for (default 10 secs)");
+    iperf_args.bw_limit = arg_int0("b", "bandwidth", "<bandwidth>", "bandwidth to send at in Mbits/sec");
     iperf_args.abort = arg_lit0("a", "abort", "abort running iperf");
     iperf_args.end = arg_end(1);
     const esp_console_cmd_t iperf_cmd = {

examples/ethernet/iperf/sdkconfig.defaults

@@ -19,4 +19,7 @@ CONFIG_ESPTOOLPY_FLASHSIZE_4MB=y
 CONFIG_ESP_INT_WDT=n
 CONFIG_ESP_TASK_WDT=n
 
+# Enable lwIP IRAM optimization
+CONFIG_LWIP_IRAM_OPTIMIZATION=y
+
 CONFIG_ESP_NETIF_TCPIP_ADAPTER_COMPATIBLE_LAYER=n

examples/wifi/iperf/iperf_test.py

@@ -35,6 +35,7 @@ from tiny_test_fw import DUT, TinyFW, Utility
 # configurations
 RETRY_COUNT_FOR_BEST_PERFORMANCE = 2
 ATTEN_VALUE_LIST = range(0, 60, 2)
+NO_BANDWIDTH_LIMIT = -1  # iperf send bandwith is not limited
 
 CONFIG_NAME_PATTERN = re.compile(r'sdkconfig\.ci\.(.+)')
 
@@ -173,7 +174,7 @@ def test_wifi_throughput_with_different_configs(env, extra_data):
                                                      pc_iperf_log_file, test_result[config_name])
 
         for _ in range(RETRY_COUNT_FOR_BEST_PERFORMANCE):
-            test_utility.run_all_cases(0)
+            test_utility.run_all_cases(0, NO_BANDWIDTH_LIMIT)
 
         for result_type in test_result[config_name]:
             summary = str(test_result[config_name][result_type])
@@ -234,7 +235,7 @@ def test_wifi_throughput_vs_rssi(env, extra_data):
         for atten_val in ATTEN_VALUE_LIST:
             assert Attenuator.set_att(att_port, atten_val) is True
             try:
-                test_utility.run_all_cases(atten_val)
+                test_utility.run_all_cases(atten_val, NO_BANDWIDTH_LIMIT)
             except AssertionError:
                 break
 
@@ -280,7 +281,7 @@ def test_wifi_throughput_basic(env, extra_data):
 
     # 3. run test for TCP Tx, Rx and UDP Tx, Rx
     for _ in range(RETRY_COUNT_FOR_BEST_PERFORMANCE):
-        test_utility.run_all_cases(0)
+        test_utility.run_all_cases(0, NO_BANDWIDTH_LIMIT)
 
     # 4. log performance and compare with pass standard
     performance_items = []
@@ -335,7 +336,7 @@ def test_softap_throughput_vs_rssi(env, extra_data):
     for atten_val in ATTEN_VALUE_LIST:
         assert Attenuator.set_att(att_port, atten_val) is True
         try:
-            test_utility.run_all_cases(atten_val)
+            test_utility.run_all_cases(atten_val, NO_BANDWIDTH_LIMIT)
         except AssertionError:
             break
 

examples/wifi/iperf/main/cmd_wifi.c

@@ -30,6 +30,7 @@ typedef struct {
     struct arg_int *length;
     struct arg_int *interval;
     struct arg_int *time;
+    struct arg_int *bw_limit;
     struct arg_lit *abort;
     struct arg_end *end;
 } wifi_iperf_t;
@@ -402,6 +403,17 @@ static int wifi_cmd_iperf(int argc, char **argv)
         }
     }
 
+    /* iperf -b */
+    if (iperf_args.bw_limit->count == 0) {
+        cfg.bw_lim = IPERF_DEFAULT_NO_BW_LIMIT;
+    } else {
+        cfg.bw_lim = iperf_args.bw_limit->ival[0];
+        if (cfg.bw_lim <= 0) {
+            cfg.bw_lim = IPERF_DEFAULT_NO_BW_LIMIT;
+        }
+    }
+
+
     ESP_LOGI(TAG, "mode=%s-%s sip=%d.%d.%d.%d:%d, dip=%d.%d.%d.%d:%d, interval=%d, time=%d",
              cfg.flag & IPERF_FLAG_TCP ? "tcp" : "udp",
              cfg.flag & IPERF_FLAG_SERVER ? "server" : "client",
@@ -476,6 +488,7 @@ void register_wifi(void)
     iperf_args.length = arg_int0("l", "len", "<length>", "Set read/write buffer size");
     iperf_args.interval = arg_int0("i", "interval", "<interval>", "seconds between periodic bandwidth reports");
     iperf_args.time = arg_int0("t", "time", "<time>", "time in seconds to transmit for (default 10 secs)");
+    iperf_args.bw_limit = arg_int0("b", "bandwidth", "<bandwidth>", "bandwidth to send at in Mbits/sec");
     iperf_args.abort = arg_lit0("a", "abort", "abort running iperf");
     iperf_args.end = arg_end(1);
     const esp_console_cmd_t iperf_cmd = {

tools/ci/python_packages/idf_iperf_test_util/IperfUtility.py

@@ -286,7 +286,7 @@ class IperfTestUtility(object):
     def _save_test_result(self, test_case, raw_data, att, rssi, heap_size):  # type: (str, str, int, int, int) -> Any
         return self.test_result[test_case].add_result(raw_data, self.ap_ssid, att, rssi, heap_size)
 
-    def _test_once(self, proto, direction):   # type: (Any, str, str) -> Tuple[str, int, int]
+    def _test_once(self, proto, direction, bw_limit):   # type: (Any, str, str, int) -> Tuple[str, int, int]
         """ do measure once for one type """
         # connect and scan to get RSSI
         dut_ip, rssi = self.setup()
@@ -301,11 +301,17 @@ class IperfTestUtility(object):
                     process = subprocess.Popen(['iperf', '-s', '-B', self.pc_nic_ip,
                                                 '-t', str(TEST_TIME), '-i', '1', '-f', 'm'],
                                                stdout=f, stderr=f)
+                    if bw_limit > 0:
+                        self.dut.write('iperf -c {} -i 1 -t {} -b {}'.format(self.pc_nic_ip, TEST_TIME, bw_limit))
+                    else:
                         self.dut.write('iperf -c {} -i 1 -t {}'.format(self.pc_nic_ip, TEST_TIME))
                 else:
                     process = subprocess.Popen(['iperf', '-s', '-u', '-B', self.pc_nic_ip,
                                                 '-t', str(TEST_TIME), '-i', '1', '-f', 'm'],
                                                stdout=f, stderr=f)
+                    if bw_limit > 0:
+                        self.dut.write('iperf -c {} -u -i 1 -t {} -b {}'.format(self.pc_nic_ip, TEST_TIME, bw_limit))
+                    else:
                         self.dut.write('iperf -c {} -u -i 1 -t {}'.format(self.pc_nic_ip, TEST_TIME))
 
                 for _ in range(TEST_TIMEOUT):
@@ -327,9 +333,12 @@ class IperfTestUtility(object):
                     except DUT.ExpectTimeout:
                         # compatible with old iperf example binary
                         Utility.console_log('create iperf tcp server fail')
+                    if bw_limit > 0:
+                        process = subprocess.Popen(['iperf', '-c', dut_ip, '-b', str(bw_limit) + 'm',
+                                                    '-t', str(TEST_TIME), '-f', 'm'], stdout=f, stderr=f)
+                    else:
                         process = subprocess.Popen(['iperf', '-c', dut_ip,
-                                                '-t', str(TEST_TIME), '-f', 'm'],
+                                                    '-t', str(TEST_TIME), '-f', 'm'], stdout=f, stderr=f)
-                                               stdout=f, stderr=f)
                     for _ in range(TEST_TIMEOUT):
                         if process.poll() is not None:
                             break
@@ -344,6 +353,16 @@ class IperfTestUtility(object):
                     except DUT.ExpectTimeout:
                         # compatible with old iperf example binary
                         Utility.console_log('create iperf udp server fail')
+                    if bw_limit > 0:
+                        process = subprocess.Popen(['iperf', '-c', dut_ip, '-u', '-b', str(bw_limit) + 'm',
+                                                    '-t', str(TEST_TIME), '-f', 'm'], stdout=f, stderr=f)
+                        for _ in range(TEST_TIMEOUT):
+                            if process.poll() is not None:
+                                break
+                            time.sleep(1)
+                        else:
+                            process.terminate()
+                    else:
                         for bandwidth in range(50, 101, 5):
                             process = subprocess.Popen(['iperf', '-c', dut_ip, '-u', '-b', str(bandwidth) + 'm',
                                                         '-t', str(TEST_TIME / 11), '-f', 'm'], stdout=f, stderr=f)
@@ -371,7 +390,7 @@ class IperfTestUtility(object):
         # return server raw data (for parsing test results) and RSSI
         return server_raw_data, rssi, heap_size
 
-    def run_test(self, proto, direction, atten_val):   # type: (str, str, int) -> None
+    def run_test(self, proto, direction, atten_val, bw_limit):   # type: (str, str, int, int) -> None
         """
         run test for one type, with specified atten_value and save the test result
 
@@ -382,7 +401,7 @@ class IperfTestUtility(object):
         rssi = FAILED_TO_SCAN_RSSI
         heap_size = INVALID_HEAP_SIZE
         try:
-            server_raw_data, rssi, heap_size = self._test_once(proto, direction)
+            server_raw_data, rssi, heap_size = self._test_once(proto, direction, bw_limit)
             throughput = self._save_test_result('{}_{}'.format(proto, direction),
                                                 server_raw_data, atten_val,
                                                 rssi, heap_size)
@@ -396,16 +415,16 @@ class IperfTestUtility(object):
             self.fail_to_scan += 1
             Utility.console_log('Fail to scan AP.')
 
-    def run_all_cases(self, atten_val):   # type: (int) -> None
+    def run_all_cases(self, atten_val, bw_limit):   # type: (int, int) -> None
         """
         run test for all types (udp_tx, udp_rx, tcp_tx, tcp_rx).
 
         :param atten_val: attenuate value
         """
-        self.run_test('tcp', 'tx', atten_val)
+        self.run_test('tcp', 'tx', atten_val, bw_limit)
-        self.run_test('tcp', 'rx', atten_val)
+        self.run_test('tcp', 'rx', atten_val, bw_limit)
-        self.run_test('udp', 'tx', atten_val)
+        self.run_test('udp', 'tx', atten_val, bw_limit)
-        self.run_test('udp', 'rx', atten_val)
+        self.run_test('udp', 'rx', atten_val, bw_limit)
         if self.fail_to_scan > 10:
             Utility.console_log(
                 'Fail to scan AP for more than 10 times. Lowest RSSI scanned is {}'.format(self.lowest_rssi_scanned))