Deno: Server hangs on close

[zhmushan]

following code works at v0.27 but hangs at v0.28

import { test, runIfMain } from "https://deno.land/[email protected]/testing/mod.ts";
import { assertEquals } from "https://deno.land/[email protected]/testing/asserts.ts";
import { serve, Server } from "https://deno.land/[email protected]/http/server.ts";

const encoder = new TextEncoder();
let s: Server = undefined;

async function createServer() {
  s = serve(":8080");
  for await (const req of s) {
    req.respond({ body: encoder.encode(req.url) });
  }
}

test(async function foo() {
  createServer();

  const res = await fetch("http://127.0.0.1:8080/hello");
  assertEquals(await res.text(), "/hello");
  s.close();
});

runIfMain(import.meta);

[95th]

Seems like a TcpStream is not getting closed.

If you do:

test(async function foo() {
  createServer();

  const res = await fetch("http://127.0.0.1:8080/hello");
  assertEquals(await res.text(), "/hello");
  s.close();
  console.table(Deno.resources());
});

you can see below in 0.27.0:

┌─────────┬──────────┐
│ (index) │  Values  │
├─────────┼──────────┤
│    0    │ "stdin"  │
│    1    │ "stdout" │
│    2    │ "stderr" │
└─────────┴──────────┘

but in 0.28.0:

┌─────────┬─────────────┐
│ (index) │   Values    │
├─────────┼─────────────┤
│    0    │   "stdin"   │
│    1    │  "stdout"   │
│    2    │  "stderr"   │
│    4    │ "tcpStream" │
└─────────┴─────────────┘

[95th]

Isolate seems to have one pending op at the end and doesn't get woken up.

[kevinkassimo]

This tcpStream, while is a problem, is not the cause of hanging... I actually managed to have the resource closed, but Deno still hangs... More investigation needed...

[kevinkassimo]

More investigation shows that it is a Conn.read on a closed resource hangs instead of error/EOF. This should be a Rust side problem instead of with our http server changes. (might relate to Tokio 0.2 upgrade)

[nayeemrmn]

Possibly related: #3160.

[kevinkassimo]

This might have been a fetch only problem: using Deno.dial and manually closing the connection does not suffer this. Basically, I suspect that connection is not properly closed by fetch after res.text() (even though it is gone from the resource table)

Actually, maybe related to https://github.com/seanmonstar/reqwest/issues/746

[95th]

We can try with tokio upgrade to 0.2.8 as mentioned in https://github.com/seanmonstar/reqwest/issues/746#issuecomment-571972378

[bartlomieju]

FYI: I tested described problem with tokio 0.2.9 and it still persists. Tried [email protected] as well as [email protected].

It needs further investigation

[bartlomieju]

Update: did some investigation, the problem is in this bit:

for await (const req of s) {
    req.respond({ body: encoder.encode(req.url) });
  }

Async iterator is never notified that server is closing and thus never closes the tcp connection, hence "tcpStream" visible in resource table. @kevinkassimo could you take a look at it?

[nayeemrmn]

My repro:

import { serve } from "./std/http/server.ts";

const server = serve(":8080");

// Iterate requests asynchronously.
(async () => {
  for await (const request of server) {
    console.log("Request received.");
    await request.respond({ body: new TextEncoder().encode("Hi!") });
    console.log("Responded.");
  }
  console.log(`Done iterating requests!`);
})();

// Send a request.
console.log("Sending request.");
const res = await fetch("http://127.0.0.1:8080/hello");
await res.text(); // Consuming the body so the resource closes.
console.log("Response received!");

// Close the server.
server.close();
console.log("Server closed!")
setTimeout(() => console.log(Deno.resources()), 500);

If a connection closes while the server is reading it, the read hangs.

I get this deno v0.29.0 and std on master:

Sending request.
Request received.
Responded.
Response received!
Server closed!
{ 0: "stdin", 1: "stdout", 2: "stderr", 4: "tcpStream" }

and it hangs there.

I applied this patch (https://github.com/nayeemrmn/deno/commit/ce8ebf6d7b986a072656a32a48b735d219ae15b6) to short-circuit the read on server close -- and got this:

Sending request.
Request received.
Responded.
Response received!
Server closed!
Done iterating requests!
{ 0: "stdin", 1: "stdout", 2: "stderr" }

Great, correct output... except it still hangs for some reason! 🤷‍♂️

[kevinkassimo]

@bartlomieju I'll look deeper into this tomorrow

@nayeemrmn The latter is the exact problem I was describing in https://github.com/denoland/deno/issues/3593#issuecomment-570949318

[bartlomieju]

@bartlomieju I'll look deeper into this tomorrow

@nayeemrmn The latter is the exact problem I was describing in #3593 (comment)

Cool, I think #3656 and #3657 are related - there's a good chance that process is hanging because of shared HTTP client, but I have not experienced it (MacOS). What OS are you testing on?

EDIT: @nayeemrmn I don't think you patch fully alleviates the problem - it should call conn.close() on all connections that server opened to that point. nvm, it does close, I can see there's still one pending op - that might be the problem.

EDIT2: Yeah, so pending op is read. I'll dig into into deeper later 👍 should be straight-forward fix.

EDIT3: Just call Deno.shutdown() before closing the connection to let read future know that it should drop :+1:

Deno.shutdown(conn.rid, 0);
Deno.shutdown(conn.rid, 1);
conn.close();

[nayeemrmn]

Just call Deno.shutdown() before closing the connection to let read future know that it should drop 👍

Ah! I knew it was because the read wasn't actually aborted, I didn't know Deno.shutdown() existed! That should go inside the conn.close() implementation.

[bartlomieju]

Fixed in #3657