Merge branch 'fix/http_server_async_requests_on_same_socket_blocks' into 'master'

Fix async requests on same socket blocking server

Closes IDFGH-16057 and IDF-13859

See merge request espressif/esp-idf!41724

Author: hrushikesh430

components/esp_http_server/src/esp_httpd_priv.h

@@ -37,6 +37,19 @@ extern "C" {
 /* Formats a log string to prepend context function name */
 #define LOG_FMT(x)      "%s: " x, __func__
 
+/**
+ * @brief Control message data structure for internal use. Sent to control socket.
+ */
+struct httpd_ctrl_data {
+    enum httpd_ctrl_msg {
+        HTTPD_CTRL_SHUTDOWN,
+        HTTPD_CTRL_WORK,
+        HTTPD_CTRL_MAX,
+    } hc_msg;
+    httpd_work_fn_t hc_work;
+    void *hc_work_arg;
+};
+
 /**
  * @brief Thread related data for internal use
  */

components/esp_http_server/src/httpd_main.c

@@ -134,15 +134,6 @@ static esp_err_t httpd_accept_conn(struct httpd_data *hd, int listen_fd)
     return ESP_FAIL;
 }
 
-struct httpd_ctrl_data {
-    enum httpd_ctrl_msg {
-        HTTPD_CTRL_SHUTDOWN,
-        HTTPD_CTRL_WORK,
-    } hc_msg;
-    httpd_work_fn_t hc_work;
-    void *hc_work_arg;
-};
-
 esp_err_t httpd_queue_work(httpd_handle_t handle, httpd_work_fn_t work, void *arg)
 {
     if (handle == NULL || work == NULL) {

components/esp_http_server/src/httpd_txrx.c

@@ -12,6 +12,7 @@
 #include <esp_http_server.h>
 #include "esp_httpd_priv.h"
 #include <netinet/tcp.h>
+#include "ctrl_sock.h"
 
 static const char *TAG = "httpd_txrx";
 
@@ -699,6 +700,11 @@ esp_err_t httpd_req_async_handler_complete(httpd_req_t *r)
         return ESP_ERR_INVALID_ARG;
     }
 
+    // Get server handle and control socket info before freeing the request
+    struct httpd_data *hd = (struct httpd_data *) r->handle;
+    int msg_fd = hd->msg_fd;
+    int port = hd->config.ctrl_port;
+
     struct httpd_req_aux *ra = r->aux;
     ra->sd->for_async_req = false;
     free(ra->scratch);
@@ -709,6 +715,18 @@ esp_err_t httpd_req_async_handler_complete(httpd_req_t *r)
     free(r->aux);
     free(r);
 
+    // Send a dummy control message(httpd_ctrl_data) to unblock the main HTTP server task from the select() call.
+    // Since the current connection FD was marked as inactive for async requests, the main task
+    // will now re-add this FD to its select() descriptor list. This ensures that subsequent requests
+    // on the same FD are processed correctly
+    struct httpd_ctrl_data msg = {.hc_msg = HTTPD_CTRL_MAX};
+    int ret = cs_send_to_ctrl_sock(msg_fd, port, &msg, sizeof(msg));
+    if (ret < 0) {
+        ESP_LOGW(TAG, LOG_FMT("failed to send socket notification"));
+        return ESP_FAIL;
+    }
+
+    ESP_LOGD(TAG, LOG_FMT("socket notification sent"));
     return ESP_OK;
 }
 

examples/protocols/http_server/async_handlers/pytest_http_server_async.py

@@ -16,14 +16,14 @@ def test_http_server_async_handler_multiple_long_requests(dut: Dut) -> None:
     # Get binary file
     binary_file = os.path.join(dut.app.binary_path, 'simple.bin')
     bin_size = os.path.getsize(binary_file)
-    logging.info('http_server_bin_size : {}KB'.format(bin_size // 1024))
+    logging.info(f'http_server_bin_size : {bin_size // 1024}KB')
     logging.info('Waiting to connect with Ethernet')
 
     # Parse IP address of Ethernet
     got_ip = dut.expect(r'IPv4 address: (\d+\.\d+\.\d+\.\d+)[^\d]', timeout=30)[1].decode()
     got_port = 80  # Assuming the server is running on port 80
-    logging.info('Got IP   : {}'.format(got_ip))
-    logging.info('Connecting to server at {}:{}'.format(got_ip, got_port))
+    logging.info(f'Got IP   : {got_ip}')
+    logging.info(f'Connecting to server at {got_ip}:{got_port}')
 
     # Create two HTTP connections for long requests
     conn_long1 = http.client.HTTPConnection(got_ip, got_port, timeout=30)
@@ -51,8 +51,8 @@ def test_http_server_async_handler_multiple_long_requests(dut: Dut) -> None:
     response_long1 = conn_long1.getresponse()
     response_long2 = conn_long2.getresponse()
 
-    logging.info('Response status for first long URI: {}'.format(response_long1.status))
-    logging.info('Response status for second long URI: {}'.format(response_long2.status))
+    logging.info(f'Response status for first long URI: {response_long1.status}')
+    logging.info(f'Response status for second long URI: {response_long2.status}')
 
     assert response_long1.status == 200, 'Failed to access first long URI'
     assert response_long2.status == 200, 'Failed to access second long URI'
@@ -67,38 +67,109 @@ def test_http_server_async_handler(dut: Dut) -> None:
     # Get binary file
     binary_file = os.path.join(dut.app.binary_path, 'simple.bin')
     bin_size = os.path.getsize(binary_file)
-    logging.info('http_server_bin_size : {}KB'.format(bin_size // 1024))
+    logging.info(f'http_server_bin_size : {bin_size // 1024}KB')
     logging.info('Waiting to connect with Ethernet')
 
     # Parse IP address of Ethernet
     got_ip = dut.expect(r'IPv4 address: (\d+\.\d+\.\d+\.\d+)[^\d]', timeout=30)[1].decode()
     got_port = 80  # Assuming the server is running on port 80
-    logging.info('Got IP   : {}'.format(got_ip))
-    logging.info('Connecting to server at {}:{}'.format(got_ip, got_port))
+    logging.info(f'Got IP   : {got_ip}')
+    logging.info(f'Connecting to server at {got_ip}:{got_port}')
 
     # Create HTTP connection
     conn_long = http.client.HTTPConnection(got_ip, got_port, timeout=15)
 
     # Test long URI
     long_uri = '/long'
-    logging.info('Sending request to long URI: {}'.format(long_uri))
+    logging.info(f'Sending request to long URI: {long_uri}')
     conn_long.request('GET', long_uri)
     dut.expect('uri: /long', timeout=30)
     response_long = conn_long.getresponse()
-    logging.info('Response status for long URI: {}'.format(response_long.status))
+    logging.info(f'Response status for long URI: {response_long.status}')
     assert response_long.status == 200, 'Failed to access long URI'
 
     # Test quick URI
     for i in range(3):
         conn_quick = http.client.HTTPConnection(got_ip, got_port, timeout=15)
         quick_uri = '/quick'
-        logging.info('Sending request to quick URI: {}'.format(quick_uri))
+        logging.info(f'Sending request to quick URI: {quick_uri}')
         conn_quick.request('GET', quick_uri)
         time.sleep(1)  # Adding a delay of 1 second before getting the response
         response_quick = conn_quick.getresponse()
         dut.expect('uri: /quick', timeout=30)
-        logging.info('Response status for quick URI: {}'.format(response_quick.status))
+        logging.info(f'Response status for quick URI: {response_quick.status}')
         assert response_quick.status == 200, 'Failed to access quick URI'
         conn_quick.close()
 
     conn_long.close()
+
+
+@pytest.mark.ethernet
+@idf_parametrize('target', ['esp32'], indirect=['target'])
+def test_http_server_async_handler_same_session_sequential(dut: Dut) -> None:
+    """
+    Test that verifies async completion fix:
+    1. Send /long request (async, 60 seconds)
+    2. Wait for completion
+    3. Send another request on same session
+    4. Verify second request works (doesn't get stuck)
+    """
+    # Get binary file
+    binary_file = os.path.join(dut.app.binary_path, 'simple.bin')
+    bin_size = os.path.getsize(binary_file)
+    logging.info(f'http_server_bin_size : {bin_size // 1024}KB')
+    logging.info('Waiting to connect with Ethernet')
+
+    # Parse IP address of Ethernet
+    got_ip = dut.expect(r'IPv4 address: (\d+\.\d+\.\d+\.\d+)[^\d]', timeout=30)[1].decode()
+    got_port = 80  # Assuming the server is running on port 80
+    logging.info(f'Got IP   : {got_ip}')
+    logging.info(f'Connecting to server at {got_ip}:{got_port}')
+
+    # Create HTTP connection for same session testing
+    conn = http.client.HTTPConnection(got_ip, got_port, timeout=70)  # Longer timeout for async
+
+    # Test 1: Send /long request (async, 60 seconds)
+    logging.info('=== Test 1: Sending /long request (async) ===')
+    conn.request('GET', '/long?test=sequential1')
+
+    # Verify request is received and processed
+    dut.expect('uri: /long', timeout=30)
+    dut.expect('Found query string => test=sequential1', timeout=30)
+
+    # Wait for async completion (60 seconds + buffer)
+    logging.info('Waiting for async /long request to complete (60 seconds)...')
+    start_time = time.time()
+
+    # Get response (this will block until async handler completes)
+    response_long = conn.getresponse()
+    completion_time = time.time() - start_time
+
+    logging.info(f'Response status for /long: {response_long.status}')
+    logging.info(f'Async request completed in {completion_time:.2f} seconds')
+    assert response_long.status == 200, 'Failed to access /long URI'
+
+    # Verify we got the full response (should contain 60 ticks)
+    response_data = response_long.read().decode()
+    assert 'req: 1' in response_data, 'Expected request count in response'
+    assert '59' in response_data, 'Expected final tick (59) in response'
+
+    # Test 3: Send another /long request on same session
+    logging.info('=== Test 2: Sending another /long request on same session ===')
+    conn.request('GET', '/long?test=sequential3')
+
+    # Verify third request is processed
+    dut.expect('uri: /long', timeout=30)
+    dut.expect('Found query string => test=sequential3', timeout=30)
+
+    # Get response for third request
+    response_long2 = conn.getresponse()
+    logging.info(f'Response status for second /long: {response_long2.status}')
+    assert response_long2.status == 200, 'Failed to access second /long URI on same session'
+
+    # Verify we got the full response
+    response_data2 = response_long2.read().decode()
+    assert 'req: 2' in response_data2, 'Expected request count 2 in response'
+
+    conn.close()
+    logging.info('=== Test completed successfully: Same session sequential requests work ===')