static.test.js fails with node >= v11.4.x

[misterdjules]

• Used appropriate template for the issue type
• Searched both open and closed issues for duplicates of this issue
• Title adequately and concisely reflects the feature or the bug

Bug Report

Restify Version

7.3.0

Node.js Version

>= v11.4.0

Expected behaviour

static.test.js should pass.

Actual behaviour

$ nvm use 11.4.0
Now using node v11.4.0 (npm v6.4.1)
$ ./node_modules/.bin/mocha test/plugins/static.test.js 


  static resource plugin
    ✓ static serves static files
    ✓ static serves static files in nested folders
    ✓ static serves static files in with a root regex
    ✓ static serves static files with a root, !greedy, regex
    ✓ static serves default file
    ✓ restify-GH-379 static serves file with parentheses in path
    ✓ restify-GH-719 serve a specific static file
    ✓ static serves static file with appendRequestPath = false
    ✓ static serves default file with appendRequestPath = false
    ✓ restify serve a specific static file with appendRequestPath = false
    ✓ static responds 404 for missing file
    ✓ GH-1382 static responds 404 for missing file with percent-codes
    ✓ static does not leak the file stream and next() is properly called when the client disconnects before receiving a reply
    1) static does not open a file stream and next() is properly called when the client disconnects immediately after sending a request
    ✓ static responds 404 for missing file
    ✓ GH-1382 static responds 404 for missing file with percent-codes


  15 passing (134ms)
  1 failing

  1) static resource plugin static does not open a file stream and next() is properly called when the client disconnects immediately after sending a request:
     Uncaught TypeError: Cannot read property 'name' of undefined
      at Server.<anonymous> (test/plugins/static.test.js:367:37)
      at Server.EventEmitter.emit (domain.js:441:20)
      at Server._finishReqResCycle (lib/server.js:1259:14)
      at ServerResponse.onResClose (lib/server.js:1207:14)
      at ServerResponse.EventEmitter.emit (domain.js:441:20)
      at Socket.onServerResponseClose (_http_server.js:169:44)
      at Socket.EventEmitter.emit (domain.js:441:20)
      at TCP._handle.close (net.js:613:12)



$ 

Repro case

See above.

Cause

A change in Node.js' core causes the response's close event to be emitted at a different time. That change has landed in node versions 11.4.0 and 11.5.0, and I assume it will be present in all later versions of node.

At this point, I don't think that Node.js change should be considered to be a bug, and instead I think we should treat the fact that Restify is relying on that specific timing to be the actual problem.

Basically, before that change, the sequence of events is the following when running that test:

1. The request's 'aborted' event is handled, and res.err is set to RequestCloseError
2. The response's 'close' event is handled, and the request/response cycle is "finished" by passing the previously saved RequestCloseError to it, which is again assigned to res.err.
3. The Server.prototype._afterRoute method is called, which sets res._handlersFinished = true and effectively marks the request/response lifecycle as complete as far as the 'after' event is concerned.
4. _afterRoute in turns calls _finishReqResCycle with an undefined error parameter, but since we had saved the original error (RequestCloseError) on res.err, the 'after' event is emitted with that original error as parameter.

After that Node.js change, the sequence of events is:

1. The request's 'aborted' event is handled, and res.err is set to RequestCloseError
2. The Server.prototype._afterRoute method is called (note that the response's 'close' event is not handled yet), which sets res._handlersFinished = true.
3. _afterRoute in turns calls _finishReqResCycle with an undefined error parameter. Since the response's 'close' event has not been processed yet, the req/res lifecycle is not considered to be finished and restify overrides the previously set res.err property with the value undefined.
4. The response's 'close' event is handled, and the request/response cycle is "finished" by passing the previously set undefined value to it.
5. At this point the 'after' event is emitted with an err parameter of undefined instead of passing the original RequestCloseError error.

Are you willing and able to fix this?

Yes.

[misterdjules]

Fixed with #1732.