cloudflare / workers-sdk

โ›…๏ธ Home to Wrangler, the CLI for Cloudflare Workersยฎ
https://developers.cloudflare.com/workers/
Apache License 2.0
2.71k stars 712 forks source link

๐Ÿ› BUG: Your worker called response.clone(), but did not read the body of both clones #3259

Open GeorgeTailor opened 1 year ago

GeorgeTailor commented 1 year ago

Which Cloudflare product(s) does this pertain to?

Wrangler

What version of Wrangler are you using?

3.0.0

What operating system are you using?

Windows

Describe the Bug

After upgrading to 3.0.0 new message started appearing in the console:

Your worker called response.clone(), but did not read the body of both clones. This is wasteful, as it forces the system to buffer the entire response body in memory, rather than streaming it through. This may cause your worker to be unexpectedly terminated for going over the memory limit. If you only meant to copy the response headers and metadata (e.g. in order to be able to modify them), use `new Response(response.body, response)` instead.  

However, it does not say which exactly part of code is to blame. I scanned my code and I do not call response.clone() directly anywhere, also, I have multiple levels of functions, making it hard to pin-point where the issue is and whether the issue is there at all.

KianNH commented 1 year ago

response.clone() isn't exactly what would have been called unfortunately - it appears for any .clone() on a Request or Response object where both bodies were not used.

GeorgeTailor commented 1 year ago

I do not have any clone() neither on Request nor on Response objects anywhere in my code. This must be something else

zwily commented 1 year ago

I do not have any clone() neither on Request nor on Response objects anywhere in my code. This must be something else

Are you using any frameworks? I'm using Remix, and see the same thing on any POST requests with bodies, and having a hard time tracking down where the clone is happening...

Also, it looks like this will happen when cloning any ReadableStream (without reading both sides), I believe, based on where it originates in workerd: https://github.com/cloudflare/workerd/blob/ed4c67df1b231270410a72cb0161c203e55b0bb6/src/workerd/api/streams/internal.c%2B%2B#L291-L298

GeorgeTailor commented 1 year ago

@zwily no, I do not use any frameworks. All I have is a _middleware.ts which calls next:

const response = await context.next();
// get username from headers
return new HTMLRewriter()
        .on("header", new UserElementHandler(username))
        .transform(response);

that's basically it

wydengyre commented 1 year ago

Getting this nuisance message with this minimal example:

export const onRequestPost: PagesFunction = async (context) => { };

Every POST results in the message appearing twice.

For what it's worth, adding some code that uses context.request makes the warning only appear a single time.

roman01la commented 1 year ago

Seeing the same warning when using D1 with Wrangler v3

houmark commented 1 year ago

Seeing the same warning when using D1 with Wrangler v3

Same...

manstfu commented 1 year ago

Seeing the same warning when using D1 with Wrangler v3

Same...

same, hop the train!

RichiCoder1 commented 1 year ago

Same. I can confirm that I'm not cloning anywhere, seems to reproduce with just adding a pages function. Seems like this might be a bug in the pages functions logic?

Edit: is it maybe the pages asset server? https://github.com/cloudflare/workers-sdk/blob/main/packages/pages-shared/asset-server/handler.ts#L340

shakibhasan09 commented 1 year ago

Hi, I'm getting the same warning, I'm using wrangler@3.0.1 os: Ubuntu 23.04

pmbanugo commented 1 year ago

any update on this @KianNH ?

pmbanugo commented 1 year ago

@RichiCoder1

Edit: is it maybe the pages asset server? https://github.com/cloudflare/workers-sdk/blob/main/packages/pages-shared/asset-server/handler.ts#L340

I think that might be the cause

EliBates commented 1 year ago

Having the same issue, using simple hono router, with v3 and D1 on MacOS.

shakibhasan09 commented 1 year ago

@EliBates you can upgrade the wrangler sdk to @3.1.0

zwily commented 1 year ago

@EliBates you can upgrade the wrangler sdk to @3.1.0

Was it addressed?

pmbanugo commented 1 year ago

@EliBates you can upgrade the wrangler sdk to @3.1.0

Nothing changed with regards to this in wrangler 3.1.0

bpleco commented 1 year ago

I'm on 3.1.0 and still the same issue in a bare bones project

bruceharrison1984 commented 1 year ago

I'm seeing this as well with 3.1.1 and pages functions. Not cloning the response anywhere. The following function runs after a couple layers of _middleware.ts.

export const onRequestPost = async ({ data }) => {

  if (!data.userProfile.id) throw new Error('UserProfile ID is null!');

  const apiKey = await data.db
    .insert(userApiKeys)
    .values({
      ownerId: data.userProfile.id,
    })
    .returning()
    .get();

  return new Response(JSON.stringify(apiKey), {
    headers: { 'Content-Type': 'application/json' },
    status: 200,
  });
};

This error only seems to be thrown on a POST request, GET requests seem unaffected.

It also appears this message is generated at each level of _middleware that your request passes through. Simply reading the request body at each layer will squelch one instance of the message.

Something as simple as the following is enough:

const noopBody = request.json();

I was able to remove most of the recurrent message, but not all by using this method. Definitely seems like something is off here.

joaoguidev commented 1 year ago

Im having the same problem here since Remix 18.1 and can confirm that this problem persists on Remix 2.0. Any update?

VicSmithVercel commented 1 year ago

I am having the same issue: Using the following npm packages. @cfworker/cosmos and uuid

Do any of you having the issue have these in node_modules?

eugene-haas commented 1 year ago

I am having the same problem. Updating from wrangler 3.3.0 to 3.4.0 has the same issue. The usage code is below. _middleware.js

const user = async ({ request, next, env }) => {
const url = new URL(request.url);
const cookie = request.headers.get('cookie');
return next();
};

export const onRequest = [user];

It is doubtful whether it can be applied to actual service in this state.

Has anyone solved it?

shakibhasan09 commented 1 year ago

Nobody fixed that yet?

alexmacarthur commented 1 year ago

I'm having the same issue, no matter if I clone or .tee() the body.

KrisBraun commented 1 year ago

I'm getting five copies of this error on every call to a resource-only Remix action:

export const action = async () => { return new Response("Not implemented", { status: 501 }); };

Your worker created multiple branches of a single stream (for instance, by calling response.clone() or request.clone()) but did not read the body of both branches. This is wasteful, as it forces the system to buffer the entire stream of data in memory, rather than streaming it through. This may cause your worker to be unexpectedly terminated for going over the memory limit. If you only meant to copy the request or response headers and metadata (e.g. in order to be able to modify them), use the appropriate constructors instead (for instance, new Response(response.body, response), new Request(request), etc).

Edit: Found this Remix issue.

danboyle8637 commented 1 year ago

I'm using Astro though that should not matter when the request gets into the functions context.

Using the property bodyUsed I confirmed I have only read my request body one time. But I still get this warning about creating multiple streams.

It has to be a Pages functions bug of some sort.

I will probably test creating a Worker separate from Pages and use bindings to forward the request to the Worker and see what happens.

I'll report back but it will have to be later today or tomorrow.

klaemo commented 1 year ago

We just tried wrangler 3.7.0 and can still observe this warning.

@GregBrimble @JacobMGEvans do you need anything from the community in order to be able to tackle this?

OnurGvnc commented 1 year ago

I think the lines below might be causing the problem, but I'm not sure.

https://github.com/cloudflare/workers-sdk/blob/a986f19f2d7989639524f9fd73761ea69aef4f6b/packages/wrangler/templates/pages-template-plugin.ts#L149

https://github.com/cloudflare/workers-sdk/blob/a986f19f2d7989639524f9fd73761ea69aef4f6b/packages/wrangler/templates/pages-template-worker.ts#L140

kingmesal commented 1 year ago

I'm on 3.8.0 and seeing this as well....

stukennedy commented 1 year ago

this is driving me nuts, trying to debug code in dev on wrangler is literally impossible with this junk filling up your console. Come on Cloudflare, this needs addressing ASAP ... it's been like this for months.

bompus commented 1 year ago

This is super frustrating. I'm on 3.9.0 and still seeing when using fetch + POST and returning the response within a pages function.

Phoenixmatrix commented 1 year ago

Adding my voice to this one. I understand its some internal logging, but it throws folks in the team in for a loop since the tool will spam this warning virtually every request even with sample code that doesn't clone anything (probably because its happening internally?).

I relied on piping the output to 2>/dev/null, but then real errors in my functions get swallowed. It's an unfortunate situation :(

aroman commented 1 year ago

really hard to understand why this has not been addressed. is the warning message just wrong? I am not .clone()ing anywhere. Not using remix, just an onRequestPost in a Pages function.

kingmesal commented 1 year ago

Utilization of function findings causes this to show up.

So, just using a provided feature can trigger this warning... which makes it no so much a warning. This warning is clearly coming from deeper in the stack and it should NOT be showing up.

What do we have to do to get rid of this? It hides everything every user cares to see.

CarmenPopoviciu commented 1 year ago

Hi folks, Carmen from Pages here. So very sorry about the delay on our side ๐Ÿ™ . I totes understand your frustration. I'll be taking this over and will look into what's going on. I'll update my findings here and let you know when I have a fix.

Pls hold on just a little while longer <3

CarmenPopoviciu commented 1 year ago

Hi there ๐Ÿ‘‹ . A few updates from me, to keep everyone in the loop:

There are reasons why we want to perform that request cloning on the Pages side, mainly so that each Pages Function handler can get a clean copy of the request. Removing that code would be a breaking change, so it requires a bit more thought on our side.

Alternatively, we could try to "turn off" these annoying warnings, but there is no way to my knowledge we could do that selectively. That means that were we to turn them off, we would turn them off for everything, including for .clone() instances that originate in user code.

I don't have an answer yet as to why we're seeing these logs for POST & co but not for GET requests. As far as my debugging goes, all these requests follow the same code path, so I am not yet sure where the difference is. Perhaps something further down the stack?...not sure, but I'll keep investigating.

Not a fix just yet as I was hoping, but hopefully this provides a little bit more context for everyone. I will follow-up with updates as soon as I have them

<3

zwily commented 1 year ago

@CarmenPopoviciu My guess is after cloning the request, you want to call request.body.cancel() on the original request to signal that you're not interested in that readable stream anymore. When you clone the request, it clones the stream, which is what is triggering the error. (I'd test this myself but I'm not sure how to wire everything up in development...)

Also, GETs don't typically have bodies which would explain why there is not a body stream being cloned.

CarmenPopoviciu commented 1 year ago

you are correct @zwily, request.body.cancel() does fix the logs issue! I'd need to test a little bit more to make sure there are no unintended side-effects, but it'd be awesome if this is all it took :)

CarmenPopoviciu commented 1 year ago

this issue seems to have been fixed in wrangler version 3.15.0. Is anyone still experiencing issues?

CarmenPopoviciu commented 1 year ago

Closing as this behaviour was fixed as of wrangler version 3.15.0. If you still experience issues, please feel free to re-open

ivotkv commented 11 months ago

Hi @CarmenPopoviciu, I am running wrangler 3.18.0 and I am still having this issue. I have implemented code similar to this example:

https://developers.cloudflare.com/workers/examples/cache-post-request/

Specifically this line is causing the warnings:

const body = await request.clone().text();

However, removing the .clone() causes a TypeError: Body has already been used. error, so clearly there is no body left unread and the warning is a false positive.

Let me know if you need more information!

tj-noor commented 10 months ago

Ran into a similar issue with Remix & Cloudflare Pages (wrangler@3.22.3) where your proposed fix works. If we can reopen this issue and you need anything, I'll be available to assist.

โœ˜ [ERROR] Your worker created multiple branches of a single stream (for instance, by calling response.clone() or request.clone()) but did not read the body of both branches. This is wasteful, as it forces the system to buffer the entire stream of data in memory, rather than streaming it through. This may cause your worker to be unexpectedly terminated for going over the memory limit. If you only meant to copy the request or response headers and metadata (e.g. in order to be able to modify them), use the appropriate constructors instead (for instance, new Response(response.body, response), new Request(request), etc).

Remix has a pre-existing open issue @ https://github.com/remix-run/remix/issues/7032

wrangler 3.22.3
@remix-run/dev 2.4.1
@remix-run/cloudflare-pages 2.4.1
@remix-run/cloudflare 2.4.1
@remix-run/css-bundle 2.4.1 
@remix-run/react 2.4.1
saidelimam commented 10 months ago

Looks like this error reappeared in version 3.22.3 I got the stream error message multiple times on a code than never calls response/request.clone()

cryptiddddd commented 10 months ago

same as @saidelimam, i'm on 3.22.4, at no point do i call response/request.clone(). i've been searching around for a while assuming this is my own error, but the only interaction i have with the request object is collecting the form data.

figured i should leave a comment to validate that the issue is still happening, or to maybe discover my own mistake.

heathdutton commented 10 months ago

Can confirm, same issue in wrangler 3.22.3 / 3.22.4 Using functions with react-app and proxy locally. Does not matter what the function is I'm calling.

davidysoards commented 9 months ago

If I roll back to 3.22.1 I don't see this error, but anything >=3.22.2 I'm getting it on every request to any Pages Function.

davidysoards commented 9 months ago

Can this issue still be re-opened or do we need to create a new issue? @CarmenPopoviciu

WebShapedBiz commented 9 months ago

I can confirm it's still happening with Wrangler v3.23.0 and the "Hello world" example from the Pages Functions docs.

ozanmakes commented 9 months ago

I can confirm the downgrading wrangler to 3.22.1 gets rid of the error. The change in https://github.com/cloudflare/workers-sdk/pull/4185 does silence the error as well, but my app does not work anymore. I really hope this error can be fixed in wrangler-side, it's making local dev with CF Pages very cumbersome.

aroman commented 9 months ago

@lrapoport-cf looks like this is a regression

per your comment here, you mentioned we should feel free to add the 'regression' label when appropriate ourselves, however, non-CF employees don't seem to have those permissions (probably a wise decision). so, tagging you here for visibility/so the tag can get added

lrapoport-cf commented 9 months ago

@aroman thanks for the ping :) i've added the regression label and re-opened the issue, and a fix is being worked on in https://github.com/cloudflare/workers-sdk/pull/4861 ๐Ÿ‘