Seeing this error in our app. Hard to reproduce. We handle more traffic than an average site. Fix looks simple.

TypeError: Cannot read property 'length' of undefined
    at Timeout._onTimeout (/media/ephemeral0/fc-2017-app/release-build-583/node_modules/express-graceful-exit/lib/graceful-exit.js:121:38)
    at ontimeout (timers.js:475:11)
    at tryOnTimeout (timers.js:310:5)
    at Timer.listOnTimeout (timers.js:270:5)

As specify in doc, socketio is a Configuration option.
But is missing in

Any chance that exports.gracefulExitHandler could take a callback?
The default behaviour (if callback not supplied) could be to call process.exit when the server closes, but it would be handy to callback to the user for the user to perform any further orderly shutdown tasks.

Summary

https://github.com/huntharo/express-graceful-exit-test has a test application that shows that express-graceful-exit will, depending on the number of open sockets at the time of shutdown, either sever a socket and exit immediately after receiving a request OR (worse) sever the socket but run any received requests on all sockets except for the last one open. This second scenario could likely result in transactions committed to databases that the caller is not directly informed about and that might have been retried as a result of the connection being closed (this may then cause the retry to fail if the already running transaction is still open).

There does not appear to be any reading of the HTTP 1.1 spec that would support the current behavior and it does not appear that the proposed fix can make things worse as the current behavior is unpredictable as to whether any individual request will run or be dropped during the shutdown process. The fix makes it 100% predictable that all requests will be started during shutdown, but if they take longer than the suicideTimeout then they may be terminated before finishing.

Thanks

Hat tip to #9 for having the right fix for a different problem description (closed without merging... I think they determined their originally reported problem was actually working correctly).

Reproduced from express-graceful-exit-test repo

https://github.com/huntharo/express-graceful-exit-test

Overview

This application demonstrates an issue with express-graceful-exit which connections are abruptly terminated after receiving a request on an existing connection during the graceful exit period. This abrupt termination looks the same as the application crashing and will generally be handled by HTTP-level load balancers as something that they should generate a 5xx-level error for (or close their incoming corresponding connection).

This application is also used to test that the fix for the issue works correctly.

HTTP 1.1 Connection Headers

Connection close in a response header signals to the caller that the connection will have been closed after the response bytes have been sent, meaning that the connection can no longer be used to send additional requests. This is similar to the way that HTTP 1.0 worked by default.

https://www.w3.org/Protocols/rfc2616/rfc2616-sec14.html#sec14.10

HTTP/1.1 defines the "close" connection option for the sender to signal that the connection will be closed after completion of the response. For example,

  Connection: close

in either the request or the response header fields indicates that the connection SHOULD NOT be considered `persistent' (section 8.1) after the current request/response is complete.

Problem Cases

• Single Connection Open @ Shutdown
  • One connection is open to the application
  • Shutdown of the application is initiated
  • Request received on the single connection
  • Observed:
    • Application immediately closes the connection
    • express-graceful-exit sees there are no more connections
    • process.exit() is called and the request effectively does not run
• Multiple Connections Open @ Shutdown
  • Two connections are open to the application
    • Both with ~60 seconds remaining before closed for idle
  • Shutdown of the application is initiated
  • Request received on the first connection
  • Second connection is left idle (the caller will close it in 60 seconds or express-graceful-exit will force-close it in around 60 seconds)
  • Observed:
    • Application receives and runs the request
    • Application closed the connection upon which it would send a response
    • Summary: Request runs but has no where to send a response to
      • Imagine a purchase transaction that does not check for exceptions on writing the response back to the caller: the transaction would remain committed in the database, the item was purchased, but the request looked as if it failed

Environment Setup

• Confirm Node version
  • node --version - 10.x is confirmed to work with this application
• Checkout express-graceful-exit
  • cd ..
  • git clone [email protected]:emostar/express-graceful-exit.git
  • cd express-graceful-exit
  • npm install
• Install application Node modules
  • cd express-graceful-exit-test
  • npm install
• Link application to local express-graceful-exit
  • cd express-graceful-exit-test
  • npm link ../express-graceful-exit

Send Test Request

• Use Telnet
  • Telnet is used as the state of the socket is very easy to determine
  • Telnet does not exit immediately after sending an HTTP request, such as curl would do by default
• Start the app
  • Note: Do not use npm run start to start the app as this changes signal handling behavior
  • cd express-graceful-exit-test
  • node index.js
• Send test request
  • Note: Use another terminal
  • telnet localhost 3000
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe:
    • Application will print trace indicating that the request was received
    • Telnet will show nothing new for 10 seconds
    • Telnet will print the response
    • Application will indicate that a response was sent
    • After ~65 seconds telnet will indicate that the connection was closed

Reproduce the Problem - Single Connection Case

• Checkout a version with the problem
  • cd express-graceful-exit
  • git checkout 6eba1de
• Start the app
  • Note: Do not use npm run start to start the app as this changes signal handling behavior
  • cd express-graceful-exit-test
  • node index.js
  • Copy the PID
• Send initial request - Leave connection open
  • Note: Use another terminal
  • telnet localhost 3000
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe:
    • The connection should remain open after the request is sent
• Send SIGTERM or SIGINT to application
  • Either option works fine for this test
  • kill -SIGTERM [PID]
  • Press [Ctrl-C] in the window running node
  • Observe:
    • Application will print that SIGINT or SIGTERM was received
    • Application will continue running for up to 60 seconds
• Send second request on initial connection
  • Note: Use the terminal that has telnet already connected from above
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe:
    • Application will not print trace that a request was received
    • Telnet will immediately report that the connection was closed
    • Application and telnet will both immediately exit
  • Expected:
    • Application should have printed that a request was received
    • Application should have run the request (waited 10 seconds)
    • Application should have returned a response
    • Telnet should receive a response with a Connection: close header value
    • Telnet should report that the connection was closed
    • Application and telnet should exit

Reproduce the Problem - Multiple Connection Case

• Checkout a version with the problem
  • cd express-graceful-exit
  • git checkout 6eba1de
• Start the app
  • Note: Do not use npm run start to start the app as this changes signal handling behavior
  • cd express-graceful-exit-test
  • node index.js
  • Copy the PID
• Send initial request on first connection - Leave connection open
  • Note: Use another terminal
  • telnet localhost 3000
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe:
    • The connection should remain open after the request is sent
• Open second connection
  • Note: Use another terminal
  • telnet localhost 3000
  • Note: There is no need to send a request, this serves as another idle connection that prevents immediate shutdown of the app when the first connection receives a request
• Send SIGTERM or SIGINT to application
  • Either option works fine for this test
  • kill -SIGTERM [PID]
  • Press [Ctrl-C] in the window running node
  • Observe:
    • Application will print that SIGINT or SIGTERM was received
    • Application will continue running for up to 60 seconds
• Send second request on first connection
  • Note: Use the terminal that has telnet already connected from above
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe:
    • Application will print trace that a request was received
      • Note: this differs from the single connection test
    • Telnet will immediately report that the connection was closed
    • Telnet will immediately exit
      • It is unable to recieve any response as the connection has closed
    • Application will print trace after 10 seconds indicating that the request finished and that it thinks it is sending a response
      • Note: this differs from the single connection test in that the request has actually run but cannot communicate with the caller
  • Expected:
    • Application should have printed that a request was received
    • Application should have run the request (waited 10 seconds)
    • Application should have returned a response
    • Telnet should receive a response with a Connection: close header value
    • Telnet should report that the connection was closed
    • Application and telnet should exit

Fix the Problem

• Locate the problem line
  • cd express-graceful-exit
  • Open lib/graceful-exit.js
  • Find the line req.connection.setTimeout(1);
• Comment out the original line
• Replace the line with res.set('Connection', 'close');

Test the Fix

• Start the app
  • Note: Do not use npm run start to start the app as this changes signal handling behavior
  • cd express-graceful-exit-test
  • node index.js
  • Copy the PID
• Send initial request - Leave connection open
  • Note: Use another terminal
  • telnet localhost 3000
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe: the connection should remain open after the request is sent
• Send SIGTERM or SIGINT to application
  • Either option works fine for this test
  • kill -SIGTERM [PID]
  • Press [Ctrl-C] in the window running node
  • Observe:
    • Application will print that SIGINT or SIGTERM was received
    • Application will continue running for up to 60 seconds
• Send second request on initial connection
  • Note: Use the terminal that has telnet already connected from above
  • Type: GET /sleep HTTP/1.1, press [enter] twice
  • Observe:
    • Application prints trace that a request was received
    • Application runs the request (waits 10 seconds)
    • Application prints trace that it returned a response
    • Telnet receives a response with a Connection: close header value
    • Telnet reports that the connection was closed
    • Application and telnet should exit
• Repeat the test with two connections
  • Observe that the response is correctly received in this case as well

Conclusion

The express-graceful-exit library does a lot of the heavy lifting to setup to be able to gracefully close all connections. However, setting the timeout on the connection to 1 ms after a request is received causes both the ability to run and finish requests without being able to tell the caller that they succeeded or failed and the dropping of received requests without running them.

Gracefully handling shutdown requires processing any last incoming requests and sending their responses, or responding to them, without running them, with an HTTP-level status code indicating that they can be retried (there is, unfortunately, no such code with 429 and 503 and Retry-After response header being the closest matches).

It is a very minor change to express-graceful-exit to allow it to correctly handle both scenarios reproduced above.

I understand wanting to set exitProcess to false to handle shutdown in a custom manner. However, I was surprised to find that doing so also disables the suicide shutdown. I would consider those two things to be separate, as in "I'll handle closing everything myself, but I would still like shutdown to happen after 2 minutes if clean up is not done by then."

It's simple enough to implement a custom suicide routine, but obviously it would be nicer if this package handled it automatically.

Is suicide shutdown being tied to exitProcess intentional, or an oversight?

Can you get 0.4.2 published to npm please. 😸

• fixes undefined socket array error
  • #10
  • 8400a23

It is not up there

• https://yarnpkg.com/en/package/express-graceful-exit
• https://www.npmjs.com/package/express-graceful-exit

The current NPM package does not contain index.d.ts, it will be great if you publish a new version :-)

I'm opening this mostly to start a discussion and kick around some ideas. I've noticed that when the express server is shutting down and getting requests the handleFinalRequests function is logging the headers which could include sensitive information like an API token.

We are providing our own bunyan logger instance method (either info or error method).

A couple of ideas on how we could deal with this:

• The gracefulExitHandler function could take a new option which is a callback function to scrub header values for logging which by default would just return the headers object back untouched (or a copy of it really so it's not modified by reference, that's probably better to not cause issues with downstream middleware).
• We could probably work around this if the headers are passed as an object to the logger method like how bunyan's log method API works but that is probably not generic enough, i.e. we shouldn't restrict the solution to assuming everyone's logger method is from bunyan. But with that idea the passed in logger function could check if that object contains a header property and scrub is as necessary before passing it on to the underlying logger (bunyan in our case).
• As a fully out-of-tree workaround, our logger function passed in could check the log message for known header keys that we need to scrub and find/replace the values as appropriate. Then there would be no changes to express-graceful-exit. If this is how everyone else is already dealing with this issue, I'm OK with that as the answer.