Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Getting ERR_STREAM_WRITE_AFTER_END after #4139 #4151

Closed
5 tasks done
tmcw opened this issue Nov 11, 2021 · 27 comments · Fixed by #4516
Closed
5 tasks done

Getting ERR_STREAM_WRITE_AFTER_END after #4139 #4151

tmcw opened this issue Nov 11, 2021 · 27 comments · Fixed by #4516

Comments

@tmcw
Copy link

tmcw commented Nov 11, 2021

Package + Version

  • @sentry/next-js

Version:

6.14.3

Description

Hi! I'm using Sentry with a Blitzjs stack, which is a mildly abstracted version of Next.js. Generally, the Next.js sentry module works very well, but after 6.14.3, I experienced crashes on any request in prod:

Nov 11 04:11:01 PM  Error [ERR_STREAM_WRITE_AFTER_END] [ERR_STREAM_WRITE_AFTER_END]: write after end
Nov 11 04:11:01 PM      at writeAfterEnd (_http_outgoing.js:694:15)
Nov 11 04:11:01 PM      at write_ (_http_outgoing.js:706:5)
Nov 11 04:11:01 PM      at ServerResponse.write (_http_outgoing.js:687:15)
Nov 11 04:11:01 PM      at ServerResponse.write (/opt/render/project/src/node_modules/next/dist/compiled/compression/index.js:1:4006)
Nov 11 04:11:01 PM      at Request.ondata (internal/streams/readable.js:745:22)
Nov 11 04:11:01 PM      at Request.emit (events.js:376:20)
Nov 11 04:11:01 PM      at Request.emit (domain.js:532:15)
Nov 11 04:11:01 PM      at addChunk (internal/streams/readable.js:309:12)
Nov 11 04:11:01 PM      at readableAddChunk (internal/streams/readable.js:284:9)
Nov 11 04:11:01 PM      at Request.Readable.push (internal/streams/readable.js:223:10)

This is noted in the PR itself, and appears to not affect Next.js in some configurations, but clearly affects my relatively vanilla setup of Blitz running on Render (and the bug also appears locally). I'll try to figure out if this is purely a Blitz-level occurrence or something that manifests in Render on serverful non-Lambda environments as well. I've set up the externalResolver option as suggested to avoid the error message that this PR attempts to fix systematically.

@AbhiPrasad
Copy link
Member

Hey, thank you for reporting. This might be Blitz configuring the request in a special way, since we are reaching in pretty heavily into the internals to access request data. To confirm that the issue is caused by #4139, could you check if 6.14.1 works as expected?

A reproduction of some kind would be a huge help for us to get a head start on debugging - but no worries if you can't share it, we can take a look.

@lobsterkatie ping to get your thoughts here as well.

@tmcw
Copy link
Author

tmcw commented Nov 16, 2021

Yep, I'm trying to get a reduced example for you to look at. I've swapped through the versions of @sentry/nextjs and confirm that versions <= 6.14.1 work as expected and all versions > 6.14.1 trigger a hard crash.

@tmcw
Copy link
Author

tmcw commented Nov 16, 2021

Okay, I've figured out the cause. One of my API routes had this code in it:

res.json(pullResponse);
res.end();

Which is redundant, because res.json ends the request, but was not a problem - you can call .end on a HttpResponse multiple times with no ill effects. The changes in 6.14.3 changes this from a redundancy to a hard crash, because the .json method ends the request, then the overridden end method flips the finished flag back to false, Node tries to end the request again, and chaos ensues.

That said: I can just yank the second line from ^ that example, and it works fine. So this is more of a bug that turns non-ideal code from symptomless to very symptomful, depending on how you think about the guarantees around res.end(). Fwiw, I'd consider it still a bug because it changes the behavior of a core node api.

@AbhiPrasad
Copy link
Member

We should aim to either address this, or document as a limitation.

Thanks for investigating @tmcw!

@bunea
Copy link

bunea commented Nov 26, 2021

I just want to add that I got this error as well on an api endpoints that pipes a file response. Basically I just request a file from a url and pipe that response to the NextApiResponse. I guess this might happen because sentry ends the response before it's finished streaming and then .pipe complains that it has already ended.

@yousefcisco
Copy link

yousefcisco commented Jan 5, 2022

We're getting the same error with a next.js API route that adds authentication headers and proxies the request to a third party api endpoint. We were able to resolve the issue by removing withSentry from that API route (which is concerning). It only occurs on next.js version >12.0.5 but works fine in v12.0.4. Offending code below

import { withSentry } from '@sentry/nextjs';
import httpProxy from 'http-proxy';
import { NextApiRequest, NextApiResponse } from 'next';

/**
 * @see https://www.npmjs.com/package/http-proxy
 */
const proxy: httpProxy = httpProxy.createProxy();

async function handler(
  req: NextApiRequest,
  res: NextApiResponse,
): Promise<void> {
  if (req.method !== 'POST') {
    return res.status(405).send('405: Method not allowed');
  }

  let authorization: string;

  if (req.headers.authorization) {
    authorization = req.headers.authorization;
  } else {
    const authorization = await getServerSideUserSessionAccessToken({
      req,
      res,
    });
  }

  return new Promise((resolve, reject) => {
    req.url = req.url?.replace(
      pathRegex,
      `/graphql`,
    );

    proxy
      .once('proxyRes', resolve)
      .once('error', reject)
      .web(req, res, {
        target: 'https://third-party.com',
        headers: {
          authorization,
          cookie: '',
        },
        changeOrigin: true,
      });
  });
}

export const config = {
  api: {
    bodyParser: false,
    externalResolver: true,
  },
};

export default withSentry(handler);

@joggienl
Copy link

Stumbled on this today.

Found this interesting monologue in the sentry source:

// Temporarily mark the response as finished, as a hack to get nextjs to not complain that we're coming back

I have some cases where I call .end() after .json().. removing the .end() "fixes" the issue. But just like @bunea I also pipe a file through NextApiResponse. Not sure how to tackle this yet, removing withSentry seems to be the quickfix but is not what I would like to do 🤔

@joggienl
Copy link

The file I was trying to pass via a pipe to the NextApiResponse was a PDF rendered with @react-pdf/renderer.

I was using the renderToStream method. I was able to tackle this specific situation by using the renderToString method, and now this works fine (without having to remove withSentry).

@moshie
Copy link

moshie commented Jan 31, 2022

I just want to add that I got this error as well on an api endpoints that pipes a file response. Basically I just request a file from a url and pipe that response to the NextApiResponse. I guess this might happen because sentry ends the response before it's finished streaming and then .pipe complains that it has already ended.

You're a real life saver we had a Nextjs api handler which piped down a pdf file wrapped in withSentry this was crashing our server and was a real head scratcher thanks to your comment we solved it just wanted to say thanks!

@tmcw
Copy link
Author

tmcw commented Jan 31, 2022

Is the Sentry team looking for a contributed PR, or working on a fix? This bug has rather major impact - it hard-crashes apps with an internal and hard to track down exception in Node.js internals - and has been in the wild for a few months now. My application at least is pinning Sentry indefinitely because I'd rather have less accurate traces than hard crashes in production.

@patroza
Copy link

patroza commented Feb 2, 2022

Next 12.0.10 or close to, appears to demand newer sentry/nextjs version, or nothing works at all.
I'm dropping sentry/nextjs and will use a custom capture for now.

@smeubank
Copy link
Member

smeubank commented Feb 2, 2022

hi @tmcw

we are always happy if someone can help out with a contribution! I can understand this is an issue for quite some folks in this thread and possibly elsewhere we will try to escalate it internally. If that is to help with reviewing a PR for the fix we could that as well.

@lobsterkatie
Copy link
Member

Hey, all. Sorry this has been dangling. I think at this point the lesser of two evils is to back out the original change, rather than try to find a hack to fix the hack, or try to find a different solution to the original problem, given that it seems non-trivial and I'm not sure we have the resources to address it right now. I'll try to get that done in the next few days.

After that, if someone wants to take a stab at fixing the original problem (next expects .end() to be sync but our wrapper makes it async), as Steven says, contributions welcome! 🙂

lobsterkatie added a commit that referenced this issue Feb 8, 2022
…ue (#4516)

In #4139, a change was introduced in order to suppress a false positive warning thrown by nextjs, by setting `res.finished` to `true` just long enough for nextjs to check it and decide no warning was needed. In simple cases, it worked just fine, but in some set-ups the "just long enough for nextjs to check it and calm down" turned out to also be "just long enough for other things to check it and get mad."

This backs out that change, as it seems it's doing more harm than good. In order to address the original problem (documented in [1] and [2]), a new warning is added, explaining that the false positive is just that. Not as elegant as suppressing the message altogether, but it should tide us over until such time as we're able to try again with a different approach.

Fixes #4151.

[1] #3852
[2] #4007
lobsterkatie added a commit that referenced this issue Mar 11, 2022
…4706)

In the nextjs SDK, when we wrap users' API routes, we also wrap the response's `end` method, in order to keep the lambda running the route handler alive long enough to send events to Sentry. As a consequence, however, Next thinks a response hasn't been sent at all, because `end` hasn't been called within the timeframe that it expects, so it throws a warning in dev. 

A previous attempt[1] to fix this problem backfired[2], and had to be reverted[3], so as a compromise option for the moment, we log a warning about the Next warning, so at least people know it's nothing to worry about. Some people are finding this behavior spammy[4], though, so this PR adds an env variable check which allows a user to suppress our meta-warning, and also improves the warning itself so that people know the option is there.

[1] #4139
[2] #4151
[3] #4516
[4] #3852 (comment)
@statico
Copy link

statico commented Oct 8, 2022

FYI, this is still an issue for us, and appeared to start after we upgraded from "@sentry/nextjs": "^7.14.0" to "^7.14.1".

We're using the latest Sentry & Next.js:

    "@sentry/nextjs": "^7.14.1",
    ...
    "next": "^12.3.1",

And our handlers are wrapped like this:

  return async (req: NextApiRequest, res: NextApiResponse) => {
    process.env.SENTRY_IGNORE_API_RESOLUTION_ERROR = "1"
    // @ts-ignore
    await withSentry(innerHandler)(req, res)
    await res.end()
  }

We're running on Vercel and our logs are full of errors like this (reformatted for readability):

500 www.xxxxxxxxxx.com/xxxxx
2022-10-07T14:33:39.283Z		ERROR	Uncaught Exception 	
{
  "errorType": "Error",
  "errorMessage": "write after end",
  "code": "ERR_STREAM_WRITE_AFTER_END",
  "domainEmitter": ...
  "domainThrown": false,
  "stack": [
    "Error [ERR_STREAM_WRITE_AFTER_END]: write after end",
    "    at new NodeError (internal/errors.js:322:7)",
    "    at writeAfterEnd (_http_outgoing.js:694:15)",
    "    at ServerResponse.end (_http_outgoing.js:815:7)",
    "    at ServerResponse.apiRes.end (/var/task/node_modules/next/dist/server/api-utils/node.js:346:25)",
    "    at ServerResponse.sentryWrappedEnd [as end] (/var/task/node_modules/@sentry/nextjs/cjs/config/wrappers/utils/responseEnd.js:29:22)",
    "    at processTicksAndRejections (internal/process/task_queues.js:95:5)"
  ]
Unknown application error occurred

Since this is flooding our logs I've removed withSentry() and our logs are now clean.

@emberist
Copy link

emberist commented Oct 9, 2022

for me too, this is making the dev environment crashing.

The issue appears also removing the withSentry wrapper in the APIs handlers

@jessehansen
Copy link

This is happening to us as well - can we get this reopened? Or should we submit a new issue?

@AbhiPrasad
Copy link
Member

@jessehansen could you open a new issue with your nextjs, node, and webpack versions, as well as your next config, sentry config and information about your deploy set up?

@uwatm8
Copy link

uwatm8 commented Nov 6, 2022

This is still a problem, brought down our prod

There's no .end() in our codebase

next: "12.2.3",
node: v18.11.0
"@sentry/nextjs": "^7.17.4",

next.config.js:

const { withSentryConfig } = require("@sentry/nextjs");

const sentryWebpackPluginOptions = {
  silent: true, 
};


const nextConfig = {
  reactStrictMode: false,
  swcMinify: true,

  sentry: {
    hideSourceMaps: true,
  },
};

module.exports = withSentryConfig(nextConfig, sentryWebpackPluginOptions);

@tmcw
Copy link
Author

tmcw commented Nov 10, 2022

This error keeps cropping up for me too on new versions. It's pretty frustrating: digging through the Sentry code, there's still a bunch of code overriding the meaning of res.end which is just dangerous. I, and I think many others, would prefer slightly less precise error reports to hard crashes in production.

@statico
Copy link

statico commented Nov 10, 2022

@AbhiPrasad Please consider reopening this issue per your earlier comment:

We should aim to either address this, or document as a limitation.

@vladanpaunovic
Copy link
Contributor

Reopening this issue as there is still work to be done here.

@timfish
Copy link
Collaborator

timfish commented Nov 11, 2022

This comment suggests that this might be caused by apollo-server auto instrumentation, although this might be only one source of the issue.

Does anyone have a minimal reproduction of this since I can't reproduce it with a basic nextjs app.

@AbhiPrasad
Copy link
Member

Also, please let us know if you are running on Vercel or not - that will help a lot with debugging!

@statico
Copy link

statico commented Nov 11, 2022

Yes, running on Vercel. Not using Apollo Server.

@uwatm8
Copy link

uwatm8 commented Nov 11, 2022

We're running in a DigitalOcean droplet, not Vercel

@adarnon
Copy link

adarnon commented Nov 11, 2022

We're running in Google Cloud Run, have a docker container running a custom Node express server with Next on top

@timfish
Copy link
Collaborator

timfish commented Dec 4, 2022

I'm going to close this as a duplicate of #6099 since this issue has been closed once before when it was first fixed and these two issues appear to be identical.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.