Repository navigation
Stop the HTTP/2 handler with a valid GenServer stop tuple on rescued … - #742
Merged
Merged
Conversation
…errors
The `handle_call` and `handle_info` clauses in `Bandit.HTTP2.Handler` rescue anything the connection raises and go through `rescue_error_handle_info/4`, which sends the GOAWAY, logs the error and then returns `{:stop, :normal}`. That isn't a return value GenServer accepts from those callbacks. A stop has to be `{:stop, reason, new_state}`, so GenServer treats the two element tuple as a bad return and the process exits with `{:bad_return_value, {:stop, :normal}}` instead of stopping cleanly. Any GenServer that returns it from `handle_info/2` shows what that looks like:
```
[error] GenServer #PID<0.100.0> terminating
** (stop) bad return value: {:stop, :normal}
Last message: :go
State: {:socket, %{connection: ...}}
```
For the real handler that `State:` line is the whole connection: every stream, both HPACK tables, the settings, the pending sends. The client isn't affected, it already got its GOAWAY from `do_rescue_error/4`, but a connection that was closed on purpose ends up as a crash report at error level, and Thousand Island's `terminate/2` takes the `{:bad_return_value, _}` path too, which marks the connection's telemetry stop event with `error: {:bad_return_value, ...}` rather than ending it as a local close.
This path doesn't fire often (a `ConnectionError` raised while handling a stream's send, or a bug somewhere in that code), which is probably why it has sat there. The one clause that calls `close_connection/4` directly, for the `:close_connection` message, already returns a proper three element tuple.
The fix is to return `{:stop, {:shutdown, :local_closed}, {socket, state}}`. That's the reason Thousand Island itself stops with when `handle_data/3` returns `{:close, state}`, so the handler ends the same way it does for every other local close: `handle_close/2` runs, the socket is closed, no crash report, no `error` in the stop event.
There was no unit test file for the HTTP/2 handler, so I added a small one that calls `handle_info/2` and `handle_call/3` with a `nil` connection (which makes the `Connection` calls raise, standing in for the errors these clauses rescue) and asserts the stop tuple and the error log. Both fail on `main`, where the match sees `{:stop, :normal}`. Suite, format, credo and dialyzer are clean.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
(Claude helped with test cases)
Small one. When the HTTP/2 connection process hits an error while handling a message from one of its streams, the handler already does everything you'd want: it rescues the error, sends the client a GOAWAY, and logs what happened. The only thing off is the return value at the end,
{:stop, :normal}. GenServer callbacks stop with a three element tuple,{:stop, reason, new_state}, so it reads the two element version as a bad return value and the process exits with{:bad_return_value, {:stop, :normal}}rather than stopping cleanly.This is what any GenServer logs in that situation:
The reason I think it's worth fixing, even though the client is unaffected (it already has its GOAWAY), comes down to what that log line carries and where it goes. For this handler the
State:is the whole connection: every open stream, both HPACK tables, the settings, the queue of pending sends. So a connection Bandit closed on purpose, after dealing with a client's protocol error, is recorded as an error level crash report with a sizeable state dump, which is easy to misread as a server fault when reading production logs. Thousand Island'sterminate/2also sees the{:bad_return_value, _}reason and takes its error path, so the connection's stop telemetry event getserror: {:bad_return_value, ...}, and anyone graphing or alerting on connection errors counts a routine close as a failure.Seven rescue clauses across
handle_callandhandle_infoshare this helper, covering a stream's send, its headers, window updates, RST_STREAM, consumed-message accounting and stream exits, so anyConnectionErrorraised while processing one of those ends up here. It's a rare path, which is probably why it hasn't come up before. The clause that handles the:close_connectionmessage already stops with a proper three element tuple, so this just brings the rescue path in line with it.The change is to return
{:stop, {:shutdown, :local_closed}, {socket, state}}. That is the same reason Thousand Island uses when a handler returns{:close, state}fromhandle_data/3, so the connection ends the way every other local close does:handle_close/2runs, the socket is closed, no crash report, noerrorkey in the stop event. I did consider{:stop, :normal, {socket, state}}, which GenServer would also accept, but Thousand Island routes:normalthrough its error clause and tags the telemetry witherror: :normal, so matching the local close reason seemed the cleaner fit. Happy to switch if you'd prefer otherwise.There wasn't a unit test file for the HTTP/2 handler yet, so I added a small one. It calls
handle_info/2andhandle_call/3with anilconnection, which makes theConnectionfunctions raise and stands in for the errors these clauses rescue in practice, then asserts the stop tuple and that the error was logged. Both tests fail onmainwith the match seeing{:stop, :normal}. Suite, format, credo and dialyzer are clean.