How is it that we are still in this readStream method after that long?

I'm not sure,

Have you seen cases of this and maybe could point me in a direction to look for some bad request I am sending in?

The only cases I've heard of is that the request was incomplete.

Can you provide information on how to reproduce the issue? That's probably the only way I would be able to help figure it out, if I could reproduce it.

I was thinking it was related to this question: #112 but we are logging it in our error handler, just not seeing it until the request has been around for 120 seconds.

Your error above shows that "expected: 85" and "received: 0" which means that there must be Content-Length: 85 header on the request and either you have code in your app that is reading the request before this module or the client never sent a single byte to the server.

@dougwilson thanks for the quick reply. Ok so look for something that is reading before this middleware. This could be possible because we only invoke this on api calls.

Currently this module requires setting req._body = true when something reads the request so this module knows just to skip reading the request body, since otherwise it's hard to tell if it has been read or not. I have been testing an alternative method to detect this on the 2.x branch, but had some issues, so it hasn't been promoted into a release yet, so usually that is the main cause for a stalled request inside this middleware, which can be worked-around by setting req._body = true anywhere in your app you're reading the request body so this middleware knows it can't read it any longer.

Maybe I need to post this in the raw-body npm package github issues, but I am going through this module.

Talking here is fine since I happen to be maintaining both, so no reason to create an extra issue :)

I am looking through all our middleware at the moment that gets called before this one. I do not see that any are reading the body, just looking at header values.

Could this happen if the client sent headers but has not yet sent the body, or somehow the body is lost?

I know a response can work like that, but do not know if a request can work like that. I guess if this is possible I will need to look through our infrastructure to see why the body portion could be lost.

Could this happen if the client sent headers but has not yet sent the body, or somehow the body is lost?

Yea, if the client sends the Content-Length: 85 header but no body, then this would happen.

I know a response can work like that, but do not know if a request can work like that.

It can, which if of course an invalid request, but it can still happen if something is emitting an invalid request.

I guess if this is possible I will need to look through our infrastructure to see why the body portion could be lost.

A good place to start is just do a packet capture right at the Node.js server. This is a quick way to tell you if the issue is inside Node.js code somewhere or outside the code.

What do you recommend for packet capture in the node server? Sorry for my ignorance.

I always use https://www.wireshark.org/ personally. It works on all platforms.

That puts me in a bad spot, running on azure web apps, which will not allow me to put this in front of my nodejs server. We are testing a performance environment that matches our production environment. Will see if I can get this to happen locally.

EDIT: Azure has logging for this I can turn on :(.

Update: We were able to track down that if traffic is not sent through our application firewall we do not see the issue of headers but no body.

After we removed the application firewall from the flow on our performance tests, we were able to get back up to our known limit.

Is this an error case we might be able to bubble up in the error message in the body-parser? Seems like it might be not an easy thing, since a user could also abandon the request causing the abandon to be called not just the expressjs hitting request timeout. If you believe this is something you would be interested in I can open a pull request against body-raw for.

Awesome that you found your issue! What was the wording of the error you're thinking of? I don't think there is any way to actually determine anything from within these modules / Node.js other than that a timeout occurred while trying to wait for the body to arrive. What do other web servers say under these conditions?

Given the abandoned error I would not want to mess with that one. However thinking about this is there a way we can set a wait for body timeout on that stream? If we can set that then we can do a specific error on did not receive full body within timeout. Writing this while thinking about t on my phone when I get back to my computer I will take a look of this already exists.

It does not exist outside of the socket timeout from Node.js you can set. I have an open issue about adding this, but it is more complicated than I think you realize. Apache and nginx are good examples of how to implement it correctly, so we want to add the same method for calculating this that those servers use.

awesome! I agree I am just looking at this through the lens of my current issue. Thank you tons for your insights on this. It has really helped us track down this issue and keep some things in mind for future. I will keep an eye for any changes.

any news???

It's on my backlog of things to do, but I have not made it to this task still. Anyone is welcome to make a pull request with an implementation since the source code is open. I can bet that would end up la ding much sooner than just waiting for me to get to it 👍

@cross311 I have the same issue as you. It's very rare, so most requests succeed, but some hang until being aborted. At that point, I can see expected bytes > 0 but received bytes == 0. Can you give any details on what application firewall you needed to turn off, or any other details about this issue that aren't in this thread?

Just sharing here how we overcame the same issue (no timeout when client sends Content-Length header with size higher than actual payload size).

I kind of expected such feature to be a part of bodyParser, but didn't find any.

I've created 2 middlewares - one to put before bodyParser (that sets the timeout) and one after (that removes the timeout when bodyParser was executed successfully):

app.use(bodyParserTimeout())
app.use(express.json())
app.use(clearBodyParserTimeout())

And implementation is (very simple timeout/clearTimeout, no magic):

/**
 * Should be called BEFORE bodyParser
 */
export function bodyParserTimeout (cfg: BodyParserTimeoutCfg = {}): RequestHandler {
  const { timeoutSeconds, httpStatusCode, httpStatus } = {
    timeoutSeconds: 10,
    httpStatusCode: 400,
    httpStatus: 'Timeout reading request input',
    ...cfg,
  }

  const timeout = timeoutSeconds * 1000

  return (req: RequestWithTimeout, res, next) => {
    req._bodyParserTimeout = setTimeout(() => {
      if (res.headersSent) return

      respondWithError(
        req,
        res,
        new HttpError(httpStatus, {
          code,
          httpStatusCode,
          userFriendly: true,
        }),
      )
    }, timeout)

    next()
  }
}

/**
 * Should be called AFTER bodyParser
 */
export function clearBodyParserTimeout (): RequestHandler {
  return (req: RequestWithTimeout, res, next) => {
    if (req._bodyParserTimeout) clearTimeout(req._bodyParserTimeout)
    next()
  }
}

I have had this issue for a while where specific api calls in my application would hang for two minutes . I've spend the morning finding out what is happening and it appears to be this issue reported here. Its not entirely consistent - although I can effectively make it so by clean loading everything (ie starting the server from scratch and then reloading the client) and then it occurs about 80% of the time. Using node 12.16.1 and using nodes built in http2 server.

This snippet of code is where the problem is (in an enormous and non-public application). Since it is related to logon - a few things have happened with get requests, but this is the first attempt at a POST request and therefore the first time that bodyParser.json() has been called (its used elsewhere in the middleware chain once the client has logged on.

      const parser = bodyParser.json();
      debug('set up /logon route');
//      router.route('/logon').all(bodyParser.json()).post((req,res) => {
      const logonRouter = router.route('/logon');
      logonRouter.all((req,res,next) => {
        try {
          debug('about to parse body');
          parser(req,res,(err) => {
            if (err) {
              debug('had logon body error');
            } else {
              debug('logon parsed body ok');
            }
            next();
          });
        } catch(e) {
          debug('error in body parser ', e);
        }
      }).post((req, res) => {
        debug('logon request');

I see the debug statement "about to parse body", but the callback is never called.

I am not sure how important the "first time bodyParser.json()" has been called is. Elsewhere in my application I have an api which is called once a minute once the user has logged on and that is also sometimes hanging. However I cannot at yet reproduce it at will, and it does involve a quite long running database query every so often, which might be the reason its timing out.