[edge-http]: Server doesn't seem to free handler after `[FIN, ACK]` from client.

[AnthonyGrondin]

Using edge-net with esp-wifi and embassy-net, I'm noticing the following behaviour; When I make a curl request, without any closing headers, (Connection: Close), my client (curl) sends a [FIN, ACK] at the end of an HTTP request, which is acknowledged by an ACK from my esp32 but then the handler isn't freed and only is freed when the timeout is reached.

Here's a Wireshark log of a connection using curl, without any closing headers in the HTTP request:

• Client: 192.168.11.50
• Esp32: 192.168.11.1
  

The issue is that the handler, which hasn't been liberated, isn't re-used if I immediately send another request with the same client, as it can be observed in the following logs:

INFO - [0] GET / HTTP/1.1
INFO - 200 OK: /
INFO - [1] GET / HTTP/1.1
INFO - 200 OK: /
INFO - Handler task 0: Closing connection due to inactivity
INFO - Handler task 1: Closing connection due to inactivity

Excerpts of my Cargo.toml:

esp-hal = { version = "0.23.1", features = ["unstable"] }
esp-wifi = { version = "0.12.0", features = ["wifi", "serde"] }
embassy-net = { version = "0.6.0", features = [
  "tcp",
  "udp",
  "dhcpv4",
  "dhcpv4-hostname",
  "dns",
  "medium-ethernet",
] }
smoltcp = { version = "0.12.0", default-features = false, features = [
  "multicast",
  "proto-ipv4",
  "socket-tcp",
  "socket-icmp",
  "socket-udp",
  "medium-ethernet",
  "proto-dhcpv4",
  "socket-raw",
  "socket-dhcpv4",
  "dns-max-server-count-2",
] }
edge-nal-embassy = "0.5.0"
edge-http = "0.5.0"

My server:

async fn http_server(
    stack: &'static edge_nal_embassy::Tcp<'static, 2, 4096, 4096>,
) -> Result<(), edge_http::io::Error<TcpError>> {
    let addr = "0.0.0.0:80";

    let acceptor = stack.bind(addr.parse().unwrap()).await.unwrap();

    let mut server = Server::<2, 4096, 16>::new();
    server
        .run(
            Some(15 * 1000),
            acceptor,
            Handler,
        )
        .await
}

[ivmarkov]

@AnthonyGrondin That might be this: embassy-rs/embassy#3141

We are still on embassy-net 0.6, and I suspect this only made it for 0.7?

[ivmarkov]

And more importantly this: embassy-rs/embassy#3135

[ivmarkov]

Actually these are for ReadReady, but I wonder if our Readable is affected as well?

[AnthonyGrondin]

So I can confirm that updating to the latest version still has the same issue

embassy-net@0.6.0 => embassy-net@0.7.0
edge-http@0.5.0 => edge-http@0.6.0
edge-nal-embassy@0.5.0 => edge-nal-embassy0.6.0
esp-wifi@0.14.0

• Client: 192.168.32.135
• Esp32s3: 192.168.32.153

(Yes, DHCP luck gave me 135 and 153 making it hard to read)

As you can see in the packet trace below, I do a:

curl http://192.168.32.153 http://192.168.32.153 http://192.168.32.153

to test the keep-alive functionality. I get all my connections on the same handler without issue:

Point your browser to https://192.168.32.153/
INFO (2824) - Creating 2 handler tasks, memory: 3256B
DEBUG (2826) - Handler task 0: Waiting for connection
DEBUG (2832) - Handler task 1: Waiting for connection
DEBUG (5694) - Handler task 0: Got connection request
DEBUG (5695) - Handler task 0: Waiting for a new request
DEBUG (5696) - Unknown body type in a request. Assuming Content-Length=0.
[0] Got new connection
DEBUG (5724) - Handler task 0: Request complete
DEBUG (5725) - Handler task 0: Waiting for a new request
DEBUG (5726) - Unknown body type in a request. Assuming Content-Length=0.
[0] Got new connection
DEBUG (5754) - Handler task 0: Request complete
DEBUG (5755) - Handler task 0: Waiting for a new request
DEBUG (5756) - Unknown body type in a request. Assuming Content-Length=0.
[0] Got new connection
DEBUG (5785) - Handler task 0: Request complete
DEBUG (5785) - Handler task 0: Waiting for a new request
INFO (20785) - Handler task 0: Closing connection due to inactivity
DEBUG (20804) - Handler task 0: Waiting for connection

edge-http server:

server.run(
    Some(15 * 1000),
    edge_nal::WithTimeout::new(15_000, &acceptor),
    HttpHandler,
)
.await

P.S. I've noticed that after upgrading to 0.6.0 it doesn't log when the connection closes
EDIT: I didn't notice the new log and defmt features

[ivmarkov]

Yes guilty as charged as I still haven't looked into this. In theory, if your curl client sends a "FIN", then at our end - as we are waiting to read the next bytes from the socket, the Read::read or Readable::readable (we are surely waiting in one of those) should return an error, and then this should immediately break the timeout, unroll everything and force us to close the socket and free the connection at the end of the connection handler.

But for some reason Read::read and/or Readable::readable don't do that. Without spending time to test and debug (first - on STD, then - on embassy) I can't say much more.

[Luni-4]

@ivmarkov

Is there any update on this one?

[ivmarkov]

Nope. PRs appreciated!

[ivmarkov]

@copilot please analyze for a potential bug causing this.