Do not swallow calls to res.end()

[martinslota]

Background

In our application we tend to rely on res.end() calls to perform cleanup. Specifically, we intercept those calls, similarly to how the same is done in the compression middleware, and take custom actions before calling the original res.end function.

Recently we found out that depending on middleware order, our cleanup code either gets called reliably or it does not. Additional investigation revealed that it is the compression middleware that sometimes "swallows" calls to res.end, which is to say that even though a route handler calls res.end, the middleware never calls the original res.end function. In particular, this happens when the client cuts the connection before consuming the compressed response because the following happens:

1. Since the connection is cut, bytes cannot continue to be written into the response, and the compressed stream gets paused.
2. Once the route handler calls res.end, the compression middleware does not call the original res.end function and instead calls stream.end.
3. Since the data in the stream is not entirely consumed, the end event does not get emitted and the handler attached to it never calls the original res.end function.

We considered using the finish or prefinish events instead of wrapping res.end calls, but these do not get emitted either, likely because OutgoingMessage.end never gets called either.

Change

1. Adds tests covering a few scenarios under which the original res.end function does not get called with the code on master
2. Uses on-finished to detect client disconnect and call the original res.end function - though this is only done if the replacement res.end wrapper had already been called, or if it is currently being called
3. Due to the added call sites for the original res.end function, the changed code also ensures that we never call the function more than once

Overall, the change should ensure that res.end calls do not get swallowed by the compression middleware.

Acknowledgement

Lots of the ideation around this change as well as the test code originate from @papandreou - many thanks for all the help! 🙇

[martinslota]

This addition takes care of situations where a route handler calls res.end() after the response is considered "finished". This is often due to the client having moved on before the response is ready for them.

[martinslota]

This addition takes care of situations where a response becomes "finished" soon after res.end() gets called by a route handler. Without this code, if the events occur close enough to one another, the stream may (at least in principle) get stuck in a "paused" state, never emitting the end event that would normally invoke the original res.end function.

[martinslota]

Waiting for the condition to assert could be extracted into a generic helper, and it could also poll a couple of times if that is desired. I left this code in its naked form for now, and it is also duplicated in the other added test cases. I'm happy to improve this further as needed.

[bjohansebas]

Can we do this without on-finished? Ideally, this would go into the v2 branch, so support for older Node versions doesn’t matter—we’ll support Node 18+. Sorry for the delay.

[martinslota]

Can we do this without on-finished? Ideally, this would go into the v2 branch, so support for older Node versions doesn’t matter—we’ll support Node 18+.

I suppose we can.

Is there an alternative way to detect client disconnect that you can recommend?

I will look into putting this on top of the v2 branch.

Sorry for the delay.

No worries. 👍

[bjohansebas]

Is there an alternative way to detect client disconnect that you can recommend?

maybe stream.finished could help you, and request.writableFinished

[martinslota]

I believe that the essential condition here is !this.socket.writable but checking this.writableFinished seems reasonable as well.

[bjohansebas]

Just that last change

[Copilot]

Copilot reviewed 2 out of 2 changed files in this pull request and generated no comments.

[martinslota]

Unfortunately, the changes here seem to lead to an issue with sometimes calling res.write() after res.end(), resulting in a rare uncaught exception:

uncaughtException: write after end
Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at write_ (node:_http_outgoing:907:11)
    at ServerResponse.write (node:_http_outgoing:860:15)
    at Gzip.onStreamData (/app/node_modules/compression/index.js:219:20)
    at Gzip.emit (node:events:519:28)
    at addChunk (node:internal/streams/readable:559:12)
    at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)
    at Readable.push (node:internal/streams/readable:390:5)
    at Zlib.processCallback (node:zlib:526:32)
    at Zlib.callbackTrampoline (node:internal/async_hooks:130:17)

[martinslota]

I'll attempt to deploy this alternative patch on our end.

We only got 2 of those uncaught exceptions over the last month, so only time will tell whether the alternative fix helps resolve them.

[bjohansebas]

Unfortunately, the changes here seem to lead to an issue with sometimes calling res.write() after res.end(), resulting in a rare uncaught exception:

Could you add a test for that case, please?

[martinslota]

Could you add a test for that case, please?

Getting the actual uncaught error is not something I was able to reproduce on my laptop so far. All I really know is that it originates from this line of code (Node version 20.18.0) - and it is not exactly clear to me how it bubbles up as being uncaught.

When I experiment with things locally and attach a callback to write() calls, I do see the ERR_STREAM_WRITE_AFTER_END error being passed to it after the response is finished. I just had no luck provoking the uncaught error.

I added a specific test around ERR_STREAM_WRITE_AFTER_END in fd1500b. That fails reliably on the original fix in 7ff0e90.

Then I generalised the test a bit further in 175a50d - but that has then the implication of not even attempting to write into the response after it appears to be finished, and all the stream does is ignore all the compressed data. Not sure whether this is the way to go but I'm happy to revert this part or adjust things in another way.

[Copilot]

Copilot reviewed 2 out of 2 changed files in this pull request and generated no comments.

Comments suppressed due to low confidence (2)

index.js:318

• Consider verifying that res.socket exists before accessing its properties to prevent potential runtime errors in environments where res.socket may be undefined.

return res.writableFinished || !res.socket.writable

test/compression.js:973

• [nitpick] The use of fixed setTimeout delays could lead to intermittent test failures on slower machines; consider using event-driven triggers or increasing the timeout duration for more reliable synchronization.

setTimeout(function () {

[bjohansebas]

I still don't quite understand at what point this becomes necessary, given that finished runs after ('error', 'end', 'finish', and 'close') have already been emitted. Why should we call stream.resume()?

[bjohansebas]

Okay, after doing more research, I think resume() is necessary — but it's already being called in the data event, so doing it again would be redundant.

I'm going to leave this here in case anyone has comments about it

[martinslota]

For completeness: There is no test that fails if this piece of code gets removed.

I kept it in place in case the sequence of events goes something like this:

1. At first, response socket is all well and good but the connection is slow, causing its buffer to fill up. This leads to calling stream.pause(), which is all completely fine.
2. Before the response buffer gets drained, the socket connection dies. As a result, the drain event on the response does not get emitted.
3. The stream remains paused and never emits the end event, and the original res.end() never gets called.

I can attempt to write a test that captures this scenario but it might end up being somewhat artificial (i.e. relying on mocking res.write() so it returns false without the response appearing as finished). What do you think?

[bjohansebas]

it's better to add a comment explaining why it's necessary

[martinslota]

Added a tentative comment in 11f8f24.

[bjohansebas]

Thanks for this great work

[bjohansebas]

i've gone back to using on-finished in order to use isFinished, since it's easier to make changes there and just update the dependency here. I've also added several debug messages.