Make sure low level error response is sent to the client #3094

Vuta · 2023-03-12T16:52:28Z

Description

Currently, when Client I/O operations raise any exceptions, we build a fallback rack response (either by lowlevel_error_handler or by default puma's hard-coded response), but doesn't do anything with it. This commit ensures that this response is sent back to client.

To verify:

bundle exec puma -C test/config/lowlevel_error_handler.rb test/rackup/hello.ru
curl -i GET localhost:9292

HTTP/1.1 500 Internal Server Error
Content-Length: 24

something wrong happened

Your checklist for this pull request

I have reviewed the guidelines for contributing to this repository.
I have added (or updated) appropriate tests if this PR fixes a bug or adds a feature.
My pull request is 100 lines added/removed or less so that it can be easily reviewed.
If this PR doesn't need tests (docs change), I added [ci skip] to the title of the PR.
If this closes any issues, I have added "Closes #issue" to the PR description or my commit messages.
I have updated the documentation accordingly.
All new and existing tests passed, including Rubocop.

nateberkopec · 2023-03-15T06:07:37Z

test/test_response_header.rb

@@ -49,15 +49,15 @@ def test_integer_key
    server_run app: ->(env) { [200, { 1 => 'Boo'}, []] }
    data = send_http_and_read "GET / HTTP/1.0\r\n\r\n"

-    assert_match(/HTTP\/1.1 500 Internal Server Error/, data)
+    assert_match(/HTTP\/1.0 500 Internal Server Error/, data)


Previously it failed on some platforms (non MRI or windows I think). This is the full data

HTTP/1.0 500 Internal Server Error\r\nContent-Length: 659\r\n\r\nPuma caught this error: undefined method `downcase' for 1:Integer (NoMethodError)\n/Users/vutran/learning/puma/lib/puma/request.rb:610:in `block in str_headers'\n/Users/vutran/learning/puma/lib/puma/request.rb:607:in `each'\n/Users/vutran/learning/puma/lib/puma/request.rb:607:in `str_headers'\n/Users/vutran/learning/puma/lib/puma/request.rb:170:in `prepare_response'\n/Users/vutran/learning/puma/lib/puma/request.rb:131:in `handle_request'\n/Users/vutran/learning/puma/lib/puma/server.rb:431:in `process_client'\n/Users/vutran/learning/puma/lib/puma/server.rb:233:in `block in run'\n/Users/vutran/learning/puma/lib/puma/thread_pool.rb:147:in `block in spawn_thread'HTTP/1.1 500 Internal Server Error\r\n\r\n

I guess matching against "Puma caught this error: undefined method `downcase' for 1:Integer" would be better?

@nateberkopec I commented on the same thing with the previous attempt: https://github.com/puma/puma/pull/2731/files#diff-732bb402028f0495d2e1bbcdf2abd9deef82f19e1b5f45711e5e32d450656563

We should understand why this is changing, not just change it

This is the full data

Why does it say HTTP/1.1 500 Internal Server Error\r\n\r\n at the end?

What does it say in master?

Why does it say HTTP/1.1 500 Internal Server Error\r\n\r\n at the end?

That comes from the client.write_error(500). We can either

keep that line and change the regex to make the test pass

remove that line completely

I went with (1) because I wasn't sure if (2) has any other implications

lib/puma/server.rb

nateberkopec · 2023-03-16T00:56:05Z

Leaving unmerged to give other maintainers some time to look but LGTM

test/config/lowlevel_error_handler.rb

lib/puma/server.rb

MSP-Greg · 2023-03-16T02:06:05Z

I need to look at the code more, but is this optional? I'm not sure if everyone wants backtrace info sent to a client? Options for logging it, but not to the client, unless development mode? Sorry, busy with other things (reliable CI)...

Vuta · 2023-03-16T11:30:23Z

I need to look at the code more, but is this optional? I'm not sure if everyone wants backtrace info sent to a client? Options for logging it, but not to the client, unless development mode? Sorry, busy with other things (reliable CI)...

I think it's optional. If user sets the environment to something other than development and test, the general message An unhandled lowlevel error occurred. The application logs may have details. will be sent instead.

nateberkopec · 2023-03-29T06:24:24Z

Marking as waiting for review as @Vuta has responded to maintainer concerns but we don't have an approve yet.

MSP-Greg · 2023-06-17T17:59:49Z

I'll defer to others, but I'm not sure about any responses that might 'fingerprint' Puma's use to clients.

dentarg · 2023-06-19T18:13:45Z

I'll defer to others, but I'm not sure about any responses that might 'fingerprint' Puma's use to clients.

Fair point considering the recent Server header discussions.

It is set here

puma/lib/puma/server.rb

Line 544 in 6d3fd09

    
           [status, {}, ["An unhandled lowlevel error occurred. The application logs may have details.\n"]]

I guess it is meant to be helpful in cases where you haven't configured the low level handler and something unexpected happens in production... but I agree it is sharing unnecessary details to the end user.

Vuta · 2023-06-22T11:24:15Z

@dentarg thanks. I agree that end users don't need to know about "unhandled lowlevel error" or "application logs". So I removed them altogether.

dentarg · 2023-06-24T16:16:44Z

lib/puma/server.rb

@@ -541,10 +541,17 @@ def lowlevel_error(e, env, status=500)
        backtrace = e.backtrace.nil? ? '<no backtrace available>' : e.backtrace.join("\n")
        [status, {}, ["Puma caught this error: #{e.message} (#{e.class})\n#{backtrace}"]]
      else
-        [status, {}, ["An unhandled lowlevel error occurred. The application logs may have details.\n"]]
+        [status, {}, ["An error occurred\n"]]


I'm not sure this is that much better than the previous message, it is probably still somewhat unique to Puma.

I checked what pitchfork does in the 500 Internal Server Error case, and it doesn't respond with any body (RACK_ENV=development and RACK_ENV=production behaves the same).

$ curl -s -v http://127.0.0.1:8080/raise * Trying 127.0.0.1:8080... * Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0) > GET /raise HTTP/1.1 > Host: 127.0.0.1:8080 > User-Agent: curl/7.84.0 > Accept: */* > * Mark bundle as not supporting multiuse < HTTP/1.1 500 Internal Server Error * no chunk, no close, no size. Assume close to signal end < * Closing connection 0 $ curl -s -v http://127.0.0.1:8080/nil * Trying 127.0.0.1:8080... * Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0) > GET /nil HTTP/1.1 > Host: 127.0.0.1:8080 > User-Agent: curl/7.84.0 > Accept: */* > * Mark bundle as not supporting multiuse < HTTP/1.1 500 Internal Server Error * no chunk, no close, no size. Assume close to signal end < * Closing connection 0

…lient Currently, when Client I/O operations raise any exceptions, we build a fallback rack response (either by lowlevel_error_handler or by default puma's hard-coded response), but doesn't do anything with it. This commit ensures that this response is sent back to client.

nateberkopec · 2023-06-28T06:44:50Z

lib/puma/server.rb

      # Swallow, do not log
      return if [ConnectionError, EOFError].include?(e.class)

-      lowlevel_error(e, client.env)


Why does MiniSSL::SSLError get slightly different handling now? If I'm reading it right, this branch still has the "bug" of never responding to the client actually?

Adding lowlevel_error to MiniSSL::SSLError so that the handler code can be run, and we don't send anything back to client because there is nothing to send back right (the connection isn't established)? If I understand your previous comment correctly

Because of puma/puma#3094, Puma v6.4.0 now returns the status code sent from the low-level handler instead of Puma's recommended status code. Previously we hard-coded low-level errors to return a 500 error, but now we should adapt this to return the status code recommended by Puma. Relates to https://gitlab.com/gitlab-com/gl-infra/production/-/issues/16417 Changelog: fixed

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch 3 times, most recently from e83e5ad to a90b6b3 Compare March 12, 2023 17:38

Vuta changed the title ~~Closes #2341 - Make sure fallback Rack response are sent to the client~~ Closes #2341 - Make sure fallback Rack response is sent to the client Mar 12, 2023

Vuta mentioned this pull request Mar 12, 2023

Puma sends empty response bodies even when low-level handler is specified #2341

Closed

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch from a90b6b3 to 7c8fa70 Compare March 13, 2023 11:29

dentarg changed the title ~~Closes #2341 - Make sure fallback Rack response is sent to the client~~ Make sure low level error response is sent to the client Mar 13, 2023

nateberkopec added the feature label Mar 15, 2023

nateberkopec reviewed Mar 15, 2023

View reviewed changes

lib/puma/server.rb Outdated Show resolved Hide resolved

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch 2 times, most recently from ad437a7 to 70ce137 Compare March 15, 2023 11:24

nateberkopec approved these changes Mar 16, 2023

View reviewed changes

dentarg reviewed Mar 16, 2023

View reviewed changes

test/config/lowlevel_error_handler.rb Outdated Show resolved Hide resolved

dentarg reviewed Mar 16, 2023

View reviewed changes

lib/puma/server.rb Outdated Show resolved Hide resolved

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch from 70ce137 to 8a49366 Compare March 17, 2023 07:41

nateberkopec added the waiting-for-review Waiting on review from anyone label Mar 29, 2023

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch from 8a49366 to 864665a Compare May 22, 2023 05:29

Vuta requested a review from dentarg May 22, 2023 05:52

nateberkopec added waiting-for-changes Waiting on changes from the requestor and removed waiting-for-review Waiting on review from anyone labels May 25, 2023

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch from 864665a to 175334d Compare June 17, 2023 15:00

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch from 175334d to db7df2c Compare June 22, 2023 11:17

dentarg mentioned this pull request Jun 24, 2023

Issue 1548 (sinatra) Describe raise_errors better in README and configuration sinatra/sinatra.github.com#305

Open

dentarg reviewed Jun 24, 2023

View reviewed changes

Vuta force-pushed the make_sure_lowlevel_error_handler_are_returned branch from db7df2c to d56e8cb Compare June 24, 2023 18:40

Vuta requested a review from dentarg June 27, 2023 19:08

nateberkopec reviewed Jun 28, 2023

View reviewed changes

nateberkopec merged commit 99ae85b into puma:master Jul 23, 2023
64 checks passed

dentarg mentioned this pull request Nov 15, 2023

Reactor suddenly throws NoMethodError but can't find reason #3278

Closed

This was referenced Jan 8, 2024

Error responses written twice #3307

Closed

Fix response repeated status line when request is invalid or errors are raised #3308

Merged

dentarg mentioned this pull request Mar 15, 2024

Requests with a caret (< or >) in a query parameter raise a Puma::HttpParserError #3345

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Make sure low level error response is sent to the client #3094

Make sure low level error response is sent to the client #3094

Vuta commented Mar 12, 2023 •

edited by nateberkopec

nateberkopec Mar 15, 2023

Vuta Mar 15, 2023 •

edited

dentarg Mar 16, 2023

dentarg Mar 16, 2023

Vuta Mar 16, 2023

nateberkopec commented Mar 16, 2023

MSP-Greg commented Mar 16, 2023

Vuta commented Mar 16, 2023

nateberkopec commented Mar 29, 2023

MSP-Greg commented Jun 17, 2023

dentarg commented Jun 19, 2023

Vuta commented Jun 22, 2023

dentarg Jun 24, 2023

nateberkopec Jun 28, 2023

Vuta Jun 28, 2023 •

edited

Make sure low level error response is sent to the client #3094

Make sure low level error response is sent to the client #3094

Conversation

Vuta commented Mar 12, 2023 • edited by nateberkopec

Description

Your checklist for this pull request

nateberkopec Mar 15, 2023

Choose a reason for hiding this comment

Vuta Mar 15, 2023 • edited

Choose a reason for hiding this comment

dentarg Mar 16, 2023

Choose a reason for hiding this comment

dentarg Mar 16, 2023

Choose a reason for hiding this comment

Vuta Mar 16, 2023

Choose a reason for hiding this comment

nateberkopec commented Mar 16, 2023

MSP-Greg commented Mar 16, 2023

Vuta commented Mar 16, 2023

nateberkopec commented Mar 29, 2023

MSP-Greg commented Jun 17, 2023

dentarg commented Jun 19, 2023

Vuta commented Jun 22, 2023

dentarg Jun 24, 2023

Choose a reason for hiding this comment

nateberkopec Jun 28, 2023

Choose a reason for hiding this comment

Vuta Jun 28, 2023 • edited

Choose a reason for hiding this comment

Vuta commented Mar 12, 2023 •

edited by nateberkopec

Vuta Mar 15, 2023 •

edited

Vuta Jun 28, 2023 •

edited