workerd throws "Can't read from request stream after response has been sent" after responding to request with unconsumed body

[dpeek]

This might be a duplicate of #918 but opening as a seperate issue for visibility (and incase the other issue is indeed related to DurableObjects only).

We were experiencing consistent failures of certain tests in our API test suite (using ustable_dev and vite). After investigation, it seems the failures were actually caused by a workerd exception from the test before each failing test. This only became clear after running the tests in sequence and turning on debug level logging for unstable_dev.

It looks like workerd throws this exception (originating here) any time a request body is not consumed and a response is sent. So, in our case, I was checking authz first in handlers and throwing on fail, and then parsing request body. Parsing the body first fixed the failures.

However, clients passing request bodies where one isn't expected should in theory cause the same exception in production. I guess this is fine because Cloudflare just spins up another worker and gets on with it's life, but this seems like it should be avoided.

[kentonv]

You should only be seeing this exception if you actually try to use the Request object after the response has been fully sent. If you don't touch the object, no error should be seen. I tried writing a simple worker that doesn't read the request body, then sent it a POST request with a body. As expected, I did not observe this error being logged. When I added a waitUntil() that waits until after the response is done, and then tries to read the request body, I got the error.

Can you please provide self-contained sample code which reproduces the error, where you believe the error is spurious?

[dpeek]

Hi Kenton, here's a minimal reproduction:

package.json

{
  "dependencies": {
    "vitest": "^1.3.1",
    "wrangler": "^3.29.0"
  }
}

index.js

export default {
  async fetch() {
    return new Response("ok");
  },
};

index.test.js

import { expect, test } from "vitest";
import { unstable_dev } from "wrangler";

const dev = await unstable_dev("./index.js");

test("this always passes", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

test("these will randomly fail", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

test("these will randomly fail", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

test("these will randomly fail", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

test("these will randomly fail", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

test("these will randomly fail", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

test("these will randomly fail", async () => {
  const res = await dev.fetch("/", { method: "POST", body: "body" });
  expect(res.status).toBe(200);
});

Then run the tests sequentially:

vitest run --pool forks --poolOptions.forks.singleFork

[kentonv]

Oh, I wonder if the error is actually coming from the proxy that workers-sdk sets up during testing, which also runs on workerd? So it's not actually your worker complaining, it's the test infrastructure.

@mrbbot is that possible?

[kentonv]

(If that's the case, then this is not a workerd bug, it's a bug in the workers-sdk proxy.)

[mrbbot]

is that possible?

@kentonv Potentially. The proxy workers-sdk sets up during testing passes all requests through a singleton Durable Object which could result in #918 for what appeared to be non-Durable Object requests. Though in that case, the requests returned 200 responses, just with a spurious error message. @dpeek, in your reproduction, were the expect(res.status).toBe(200); assertions failing, or were you just seeing unexpected error messages?

[dpeek]

@mrbbot the assertion fails with res.status 500, and the response body is "Error: Network connection lost"

Turning on debug logging from unstable_dev, I can see two different errors being logged:

✘ [ERROR] Error in ProxyController: Error inside ProxyWorker

   {
    name: 'Error',
    message: 'Network connection lost.',
    stack: 'Error: Network connection lost.'
  }

✘ [ERROR] workerd/io/worker.c++:1761: info: uncaught exception; source = Uncaught (async); exception = TypeError: Can't read from request stream after response has been sent.

[mrbbot]

Ah ok. Given the Can't read from request stream after response has been sent. is uncaught, I suspect you are hitting #918 through the proxy Durable Object. The Error: Network connection lost. errors you're seeing are likely the result of a different problem (cloudflare/workers-sdk#5095 or cloudflare/workers-sdk#4562 maybe). Would you be able to try out [email protected] and see if that solves your issue?

[dpeek]

Hi @mrbbot I just tested the repro against 3.30.1 and can confirm the issue is resolved. Thanks for your help!

[AbakirH]

This issue still exists, and I do not see a solution. I still have this issue in [email protected]

[dpeek]

@AbakirH it's fixed for that test-case, at least. Since it looks like the issue was in wrangler (Proxy Durable Object) maybe you could open a new issue in that repo with a reproduction?

[amiranvarov]

This issue still persists.