WEBrick handler breaks POST request

[voxik]

I think that #8 breaks Rack application doing POST request using WEBrick. I have filled already some issues which captures the genesis:

typhoeus/ethon#243
sinatra/sinatra#2112

And finally I am here, because I am now looking into em-http-request and there are again failing POST related test cases:

 1) EventMachine::HttpRequest should perform successful POST
     Failure/Error: http.response.should match(/data/)
     
       expected "" to match /data/
       Diff:
       @@ -1 +1 @@
       -/data/
       +""
       
     # ./spec/client_spec.rb:186:in 'block (4 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/client_spec.rb:180:in 'block (2 levels) in <top (required)>'

  2) EventMachine::HttpRequest should escape body on POST
     Failure/Error: http.response.should == "stuff=string%26string"
     
       expected: "stuff=string%26string"
            got: "" (using ==)
     # ./spec/client_spec.rb:212:in 'block (4 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/client_spec.rb:206:in 'block (2 levels) in <top (required)>'

  3) EventMachine::HttpRequest should perform successful POST with Ruby Hash/Array as params
     Failure/Error: http.response.should match(/key1=1&key2\[0\]=2&key2\[1\]=3/)
     
       expected "" to match /key1=1&key2\[0\]=2&key2\[1\]=3/
       Diff:
       @@ -1 +1 @@
       -/key1=1&key2\[0\]=2&key2\[1\]=3/
       +""
       
     # ./spec/client_spec.rb:226:in 'block (4 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/client_spec.rb:219:in 'block (2 levels) in <top (required)>'

  4) EventMachine::HttpRequest should stream a file off disk
     Failure/Error: http.response.should match('google')
       expected "" to match "google"
     # ./spec/client_spec.rb:800:in 'block (4 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/client_spec.rb:795:in 'block (2 levels) in <top (required)>'

  5) EventMachine::HttpRequest streams POST request from disk via Pathname
     Failure/Error: http.response.should match('google')
       expected "" to match "google"
     # ./spec/client_spec.rb:811:in 'block (4 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/client_spec.rb:807:in 'block (2 levels) in <top (required)>'

  6) EventMachine::HttpRequest streams POST request from IO object
     Failure/Error: http.response.should match('google')
       expected "" to match "google"
     # ./spec/client_spec.rb:822:in 'block (4 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/client_spec.rb:818:in 'block (2 levels) in <top (required)>'

  7) EventMachine::HttpRequest request should execute request middleware before dispatching request
     Failure/Error: req.response.should match(/data modified/)
     
       expected "" to match /data modified/
       Diff:
       @@ -1 +1 @@
       -/data modified/
       +""
       
     # ./spec/middleware_spec.rb:110:in 'block (5 levels) in <top (required)>'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/middleware_spec.rb:103:in 'block (3 levels) in <top (required)>'

  8) EventMachine::HttpRequest jsonify should use middleware to JSON encode and JSON decode the body
     Failure/Error: resp.response = MultiJson.load(resp.response)
     
     MultiJson::ParseError:
       JSON::ParserError
     # /usr/share/gems/gems/multi_json-1.15.0/lib/multi_json/adapter.rb:20:in 'MultiJson::Adapter.load'
     # /usr/share/gems/gems/multi_json-1.15.0/lib/multi_json.rb:122:in 'MultiJson#load'
     # ./spec/middleware_spec.rb:124:in 'JSONify#response'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:151:in 'EventMachine::Deferrable#set_deferred_status'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/em/deferrable.rb:191:in 'EventMachine::Deferrable#succeed'
     # ./lib/em-http/client.rb:113:in 'EventMachine::HttpClient#unbind'
     # ./lib/em-http/client.rb:71:in 'EventMachine::HttpClient#on_request_complete'
     # ./lib/em-http/http_connection.rb:205:in 'block in EventMachine::HttpConnection#post_init'
     # ./lib/em-http/http_connection.rb:220:in 'HTTP::Parser#<<'
     # ./lib/em-http/http_connection.rb:220:in 'EventMachine::HttpConnection#receive_data'
     # ./lib/em-http/http_connection.rb:26:in 'EventMachine::HttpStubConnection#receive_data'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run_machine'
     # /usr/share/gems/gems/eventmachine-1.2.7/lib/eventmachine.rb:195:in 'EventMachine.run'
     # ./spec/middleware_spec.rb:129:in 'block (3 levels) in <top (required)>'
     # ------------------
     # --- Caused by: ---
     # JSON::ParserError:
     #   JSON::ParserError
     #   /usr/share/gems/gems/multi_json-1.15.0/lib/multi_json/adapter.rb:20:in 'MultiJson::Adapter.load'

[voxik]

Interesting, I have changed the em-http-request to use Rack::Handler.default and therefore I was able to run the test suite against Puma and it fails similarly. That is surprising 🤔

[voxik]

I don't think anymore this is just WEBrick. Admittedly, I am still not clear what is going on and I am not HTTP expert, but this is my debug session:

$ RACKUP_HANDLER=webrick env -u NOTIFY_SOCKET rdbg -c -- rspec spec/ethon/easy/http/custom_spec.rb:125 -f d -b
[4, 13] in /usr/bin/rspec
     4| #
     5| # The application 'rspec-core' is installed as part of a gem, and
     6| # this file is here to facilitate running it.
     7| #
     8| 
=>   9| require 'rubygems'
    10| 
    11| Gem.use_gemdeps
    12| 
    13| version = ">= 0.a"
=>#0    <main> at /usr/bin/rspec:9
(rdbg) b /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532    # break command
#0  BP - Line (pending)  /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532
(rdbg) c    # continue command
Run options: include {locations: {"./spec/ethon/easy/http/custom_spec.rb" => [125]}}
[527, 536] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   527|     def parse_host_request_line(host)
   528|       host.scan(HOST_PATTERN)[0]
   529|     end
   530| 
   531|     def read_body(socket, block)
=> 532|       return unless socket
   533|       if tc = self['transfer-encoding']
   534|         if self['content-length']
   535|           raise HTTPStatus::BadRequest, "request with both transfer-encoding and content-length, possible request smuggling"
   536|         end
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 9, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fdb54670 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fdb54670 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 3 frames (use `bt' command for all frames)

Stop by #0  BP - Line  /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532 (call)
(rdbg) c    # continue command

Ethon::Easy::Http::Custom
  #setup
    when body
      when not multipart
        when requesting
D, [2025-06-27T16:22:26.938702 #56] DEBUG -- : Rack::Protection::HostAuthorization @all_permitted_hosts=["localhost", ".localhost", ".test", #<IPAddr: IPv4:0.0.0.0/0.0.0.0>, #<IPAddr: IPv6:0000:0000:0000:0000:0000:0000:0000:0000/0000:0000:0000:0000:0000:0000:0000:0000>] @permitted_hosts=["localhost", "localhost", "test"] @domain_hosts=[/\A(?-mix:[a-z0-9\-.]+)localhost\z/i, /\A(?-mix:[a-z0-9\-.]+)test\z/i] @ip_hosts=[#<IPAddr: IPv4:0.0.0.0/0.0.0.0>, #<IPAddr: IPv6:0000:0000:0000:0000:0000:0000:0000:0000/0000:0000:0000:0000:0000:0000:0000:0000>] origin_host="localhost" forwarded_host=nil
[527, 536] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   527|     def parse_host_request_line(host)
   528|       host.scan(HOST_PATTERN)[0]
   529|     end
   530| 
   531|     def read_body(socket, block)
=> 532|       return unless socket
   533|       if tc = self['transfer-encoding']
   534|         if self['content-length']
   535|           raise HTTPStatus::BadRequest, "request with both transfer-encoding and content-length, possible request smuggling"
   536|         end
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)

Stop by #0  BP - Line  /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532 (call)
(rdbg) bt    # backtrace command
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:532
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  #2    block in Rackup::Handler::WEBrick::Input#initialize at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb:67
(rdbg) pp self    # command
#<WEBrick::HTTPRequest:0x00007f93fdbcca80
 @accept=["*/*"],
 @accept_charset=[],
 @accept_encoding=[],
 @accept_language=[],
 @addr=["AF_INET6", 3001, "::1", "::1"],
 @attributes={},
 @body="",
 @buffer_size=65536,
 @config=
  {BindAddress: "localhost",
   Port: 3001,
   MaxClients: 100,
   ServerType: nil,
   Logger: #<Rack::NullLogger:0x00007f93fc5f2ef8 @app=#<TESTSERVER app_file="/builddir/build/BUILD/rubygem-ethon-0.15.0-build/ethon-0.15.0/usr/share/gems/gems/ethon-0.15.0/spec/support/server.rb">>,
   ServerSoftware: "WEBrick/1.9.0 (Ruby/3.4.2/2025-02-15)",
   TempDir: "/tmp",
   DoNotListen: false,
   StartCallback: nil,
   StopCallback: nil,
   AcceptCallback: nil,
   DoNotReverseLookup: true,
   ShutdownSocketWithoutClose: false,
   RequestTimeout: 30,
   HTTPVersion: #<WEBrick::HTTPVersion:0x00007f93fd8cb728 @major=1, @minor=1>,
   AccessLog: [],
   MimeTypes:
    {"ai" => "application/postscript",
     "asc" => "text/plain",
     "avi" => "video/x-msvideo",
     "avif" => "image/avif",
     "bin" => "application/octet-stream",
     "bmp" => "image/bmp",
     "class" => "application/octet-stream",
     "cer" => "application/pkix-cert",
     "crl" => "application/pkix-crl",
     "crt" => "application/x-x509-ca-cert",
     "css" => "text/css",
     "dms" => "application/octet-stream",
     "doc" => "application/msword",
     "dvi" => "application/x-dvi",
     "eps" => "application/postscript",
     "etx" => "text/x-setext",
     "exe" => "application/octet-stream",
     "gif" => "image/gif",
     "htm" => "text/html",
     "html" => "text/html",
     "ico" => "image/x-icon",
     "jpe" => "image/jpeg",
     "jpeg" => "image/jpeg",
     "jpg" => "image/jpeg",
     "js" => "application/javascript",
     "json" => "application/json",
     "lha" => "application/octet-stream",
     "lzh" => "application/octet-stream",
     "mjs" => "application/javascript",
     "mov" => "video/quicktime",
     "mp4" => "video/mp4",
     "mpe" => "video/mpeg",
     "mpeg" => "video/mpeg",
     "mpg" => "video/mpeg",
     "otf" => "font/otf",
     "pbm" => "image/x-portable-bitmap",
     "pdf" => "application/pdf",
     "pgm" => "image/x-portable-graymap",
     "png" => "image/png",
     "pnm" => "image/x-portable-anymap",
     "ppm" => "image/x-portable-pixmap",
     "ppt" => "application/vnd.ms-powerpoint",
     "ps" => "application/postscript",
     "qt" => "video/quicktime",
     "ras" => "image/x-cmu-raster",
     "rb" => "text/plain",
     "rd" => "text/plain",
     "rtf" => "application/rtf",
     "sgm" => "text/sgml",
     "sgml" => "text/sgml",
     "svg" => "image/svg+xml",
     "tif" => "image/tiff",
     "tiff" => "image/tiff",
     "ttc" => "font/collection",
     "ttf" => "font/ttf",
     "txt" => "text/plain",
     "wasm" => "application/wasm",
     "webm" => "video/webm",
     "webmanifest" => "application/manifest+json",
     "webp" => "image/webp",
     "woff" => "font/woff",
     "woff2" => "font/woff2",
     "xbm" => "image/x-xbitmap",
     "xhtml" => "text/html",
     "xls" => "application/vnd.ms-excel",
     "xml" => "text/xml",
     "xpm" => "image/x-xpixmap",
     "xwd" => "image/x-xwindowdump",
     "zip" => "application/zip"},
   DirectoryIndex: ["index.html", "index.htm", "index.cgi", "index.rhtml"],
   DocumentRoot: nil,
   DocumentRootOptions: {FancyIndexing: true},
   RequestCallback: nil,
   ServerAlias: nil,
   InputBufferSize: 65536,
   OutputBufferSize: 65536,
   ProxyAuthProc: nil,
   ProxyContentHandler: nil,
   ProxyVia: true,
   ProxyTimeout: true,
   ProxyURI: nil,
   CGIInterpreter: nil,
   CGIPathEnv: nil,
   Escape8bitURI: false,
   ServerName: "23708227a3c24bf38dab6141d4bded39"},
 @cookies=[],
 @form_data=nil,
 @forwarded_for=nil,
 @forwarded_host=nil,
 @forwarded_port=nil,
 @forwarded_proto=nil,
 @forwarded_server=nil,
 @header={"host" => ["localhost:3001"], "accept" => ["*/*"], "content-length" => ["11"], "content-type" => ["application/x-www-form-urlencoded"]},
 @host="localhost",
 @http_version=#<WEBrick::HTTPVersion:0x00007f93fd9b55d0 @major=1, @minor=1>,
 @keep_alive=true,
 @logger=#<Rack::NullLogger:0x00007f93fc5f2ef8 @app=#<TESTSERVER app_file="/builddir/build/BUILD/rubygem-ethon-0.15.0-build/ethon-0.15.0/usr/share/gems/gems/ethon-0.15.0/spec/support/server.rb">>,
 @path="/",
 @path_info="/",
 @peeraddr=["AF_INET6", 47774, "::1", "::1"],
 @port=3001,
 @query=nil,
 @query_string=nil,
 @raw_header=["Host: localhost:3001\r\n", "Accept: */*\r\n", "Content-Length: 11\r\n", "Content-Type: application/x-www-form-urlencoded\r\n"],
 @remaining_size=nil,
 @request_bytes=122,
 @request_line="PURGE / HTTP/1.1\r\n",
 @request_method="PURGE",
 @request_time=2025-06-27 16:22:26.937638932 +0200,
 @request_uri=#<URI::HTTP http://localhost:3001/>,
 @script_name="",
 @socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>,
 @unparsed_uri="/",
 @user=nil>
(rdbg) n    # next command
[528, 537] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   528|       host.scan(HOST_PATTERN)[0]
   529|     end
   530| 
   531|     def read_body(socket, block)
   532|       return unless socket
=> 533|       if tc = self['transfer-encoding']
   534|         if self['content-length']
   535|           raise HTTPStatus::BadRequest, "request with both transfer-encoding and content-length, possible request smuggling"
   536|         end
   537| 
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:533
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[537, 546] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   537| 
   538|         case tc
   539|         when /\Achunked\z/io then read_chunked(socket, block)
   540|         else raise HTTPStatus::NotImplemented, "Transfer-Encoding: #{tc}."
   541|         end
=> 542|       elsif self['content-length'] || @remaining_size
   543|         @remaining_size ||= self['content-length'].to_i
   544|         while @remaining_size > 0
   545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:542
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[538, 547] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   538|         case tc
   539|         when /\Achunked\z/io then read_chunked(socket, block)
   540|         else raise HTTPStatus::NotImplemented, "Transfer-Encoding: #{tc}."
   541|         end
   542|       elsif self['content-length'] || @remaining_size
=> 543|         @remaining_size ||= self['content-length'].to_i
   544|         while @remaining_size > 0
   545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
   547|           @remaining_size -= buf.bytesize
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:543
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) p self['content-length']    # command
=> "11"
(rdbg) p @remaining_size    # command
=> nil
(rdbg) n    # next command
[539, 548] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   539|         when /\Achunked\z/io then read_chunked(socket, block)
   540|         else raise HTTPStatus::NotImplemented, "Transfer-Encoding: #{tc}."
   541|         end
   542|       elsif self['content-length'] || @remaining_size
   543|         @remaining_size ||= self['content-length'].to_i
=> 544|         while @remaining_size > 0
   545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
   547|           @remaining_size -= buf.bytesize
   548|           block.call(buf)
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:544
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[540, 549] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   540|         else raise HTTPStatus::NotImplemented, "Transfer-Encoding: #{tc}."
   541|         end
   542|       elsif self['content-length'] || @remaining_size
   543|         @remaining_size ||= self['content-length'].to_i
   544|         while @remaining_size > 0
=> 545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
   547|           @remaining_size -= buf.bytesize
   548|           block.call(buf)
   549|         end
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:545
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[541, 550] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   541|         end
   542|       elsif self['content-length'] || @remaining_size
   543|         @remaining_size ||= self['content-length'].to_i
   544|         while @remaining_size > 0
   545|           sz = [@buffer_size, @remaining_size].min
=> 546|           break unless buf = read_data(socket, sz)
   547|           @remaining_size -= buf.bytesize
   548|           block.call(buf)
   549|         end
   550|         if @remaining_size > 0 && @socket.eof?
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:546
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[542, 551] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   542|       elsif self['content-length'] || @remaining_size
   543|         @remaining_size ||= self['content-length'].to_i
   544|         while @remaining_size > 0
   545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
=> 547|           @remaining_size -= buf.bytesize
   548|           block.call(buf)
   549|         end
   550|         if @remaining_size > 0 && @socket.eof?
   551|           raise HTTPStatus::BadRequest, "invalid body size."
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:547
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) p buf    # command
=> "a=1%26b%3D2"
(rdbg) n    # next command
[543, 552] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   543|         @remaining_size ||= self['content-length'].to_i
   544|         while @remaining_size > 0
   545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
   547|           @remaining_size -= buf.bytesize
=> 548|           block.call(buf)
   549|         end
   550|         if @remaining_size > 0 && @socket.eof?
   551|           raise HTTPStatus::BadRequest, "invalid body size."
   552|         end
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:548
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) s    # step command
[63, 72] in /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb
    63|         def initialize(request)
    64|           @request = request
    65| 
    66|           @reader = Fiber.new do
    67|             @request.body do |chunk|
=>  68|               Fiber.yield(chunk)
    69|             end
    70| 
    71|             Fiber.yield(nil)
    72| 
=>#0    block {|chunk="a=1%26b%3D2"|} in Rackup::Handler::WEBrick::Input#initialize (2 levels) at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb:68
  #1    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:548
  # and 2 frames (use `bt' command for all frames)
(rdbg) s    # step command
[83, 92] in /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb
    83|         private
    84| 
    85|         # Read one chunk from the request body.
    86|         def read_next
    87|           @reader&.resume
=>  88|         end
    89|       end
    90| 
    91|       def service(req, res)
    92|         env = req.meta_vars
=>#0    Rackup::Handler::WEBrick::Input#read_next at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb:88 #=> "a=1%26b%3D2"
  #1    Rackup::Stream::Reader#read(length=nil, buffer="") at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/stream.rb:65
  # and 20 frames (use `bt' command for all frames)
(rdbg) 
[61, 70] in /usr/share/gems/gems/rackup-2.2.1/lib/rackup/stream.rb
    61|           else
    62|             return buffer
    63|           end
    64|         else
    65|           while chunk = read_next
=>  66|             buffer << chunk
    67|           end
    68| 
    69|           return buffer
    70|         end
=>#0    Rackup::Stream::Reader#read(length=nil, buffer="") at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/stream.rb:66
  #1    Rack::Request::Helpers#POST at /usr/share/gems/gems/rack-3.1.8/lib/rack/request.rb:531
  # and 19 frames (use `bt' command for all frames)
(rdbg) p chunk    # command
=> "a=1%26b%3D2"
(rdbg) p buffer    # command
=> ""
(rdbg) n    # next command
[64, 73] in /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb
    64|           @request = request
    65| 
    66|           @reader = Fiber.new do
    67|             @request.body do |chunk|
    68|               Fiber.yield(chunk)
=>  69|             end
    70| 
    71|             Fiber.yield(nil)
    72| 
    73|             # End of stream:
=>#0    block {|chunk="a=1%26b%3D2"|} in Rackup::Handler::WEBrick::Input#initialize (2 levels) at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb:69 #=> nil
  #1    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:548
  # and 2 frames (use `bt' command for all frames)
(rdbg) s    # step command
[545, 554] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   545|           sz = [@buffer_size, @remaining_size].min
   546|           break unless buf = read_data(socket, sz)
   547|           @remaining_size -= buf.bytesize
   548|           block.call(buf)
   549|         end
=> 550|         if @remaining_size > 0 && @socket.eof?
   551|           raise HTTPStatus::BadRequest, "invalid body size."
   552|         end
   553|       elsif BODY_CONTAINABLE_METHODS.member?(@request_method)
   554|         raise HTTPStatus::LengthRequired
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:550
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) p buf    # command
=> "a=1%26b%3D2"
(rdbg) p @body    # command
=> ""
(rdbg) n    # next command
[551, 560] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   551|           raise HTTPStatus::BadRequest, "invalid body size."
   552|         end
   553|       elsif BODY_CONTAINABLE_METHODS.member?(@request_method)
   554|         raise HTTPStatus::LengthRequired
   555|       end
=> 556|       return @body
   557|     end
   558| 
   559|     def read_chunk_size(socket)
   560|       line = read_line(socket)
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:556
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[551, 560] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   551|           raise HTTPStatus::BadRequest, "invalid body size."
   552|         end
   553|       elsif BODY_CONTAINABLE_METHODS.member?(@request_method)
   554|         raise HTTPStatus::LengthRequired
   555|       end
=> 556|       return @body
   557|     end
   558| 
   559|     def read_chunk_size(socket)
   560|       line = read_line(socket)
=>#0    WEBrick::HTTPRequest#read_body(socket=#<TCPSocket:fd 11, AF_INET6, ::1, 3001>, block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:556 #=> ""
  #1    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:257
  # and 1 frames (use `bt' command for all frames)
(rdbg) 
[253, 262] in /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb
   253|     # Returns the request body.
   254| 
   255|     def body(&block) # :yields: body_chunk
   256|       block ||= Proc.new{|chunk| @body << chunk }
   257|       read_body(@socket, block)
=> 258|       @body.empty? ? nil : @body
   259|     end
   260| 
   261|     ##
   262|     # Prepares the HTTPRequest object for use as the
=>#0    WEBrick::HTTPRequest#body(block=#<Proc:0x00007f93fc683f48 /usr/share/gems...) at /usr/share/gems/gems/webrick-1.9.0/lib/webrick/httprequest.rb:258
  #1    block in Rackup::Handler::WEBrick::Input#initialize at /usr/share/gems/gems/rackup-2.2.1/lib/rackup/handler/webrick.rb:67

This shows that at some point, the expected "a=1%26b%3D2" sting is read from the socket. But it is not stored into the @body. Only RACK_REQUEST_FORM_VARS and RACK_REQUEST_FORM_HASH are populated.

[voxik]

Finally, I was able to pass the Ethon test suite using Rack::RewindableInput::Middleware:

$ git diff
diff --git a/spec/support/server.rb b/spec/support/server.rb
index ab8ffd3..a8e3072 100644
--- a/spec/support/server.rb
+++ b/spec/support/server.rb
@@ -5,6 +5,8 @@ require 'zlib'
 require 'sinatra/base'
 
 TESTSERVER = Sinatra.new do
+  use Rack::RewindableInput::Middleware
+
   set :logging, nil
 
   fail_count = 0
@@ -94,7 +96,7 @@ TESTSERVER = Sinatra.new do
   end
 
   post '/**' do
-    request.env.merge!(:body => request.body.read).to_json
+    request.env.merge!(:body => request.body.tap {|b| b.rewind }.read).to_json
   end
 
   delete '/**' do
@@ -110,6 +112,6 @@ TESTSERVER = Sinatra.new do
   end
 
   route 'PURGE', '/**' do
-    request.env.merge!(:body => request.body.read).to_json
+    request.env.merge!(:body => request.body.tap {|b| b.rewind }.read).to_json
   end
 end

But I still consider this weird. Previously, no rewind was needed. It was possible to read the body (at least once). Why this should change?

[ioquatix]

Rack 3 input bodies are not rewindable.

[voxik]

Rack 3 input bodies are not rewindable.

Yes, but they should be readable at least once IMHO, which they are not.

[ioquatix]

Okay, let me take a quick peek and see if I can figure out what's going on.

[voxik]

BTW I believe the culprit for WEBrick is somewhere here:

https://github.com/ruby/webrick/blob/4a03fe85eae0107b713a29839b9fee9837754e21/lib/webrick/httprequest.rb#L255-L259

Specifically at the line 258, the @body should not be empty, but it is. To me it is like some weird interaction with the Fiber.

[jackorp]

I had a look also due to the em-http-request.

I found the data is there, but available as query params for some reason, on specific values of the Content-Type header.
Both on situations with no content-type header and also with the header's value 'application/x-www-form-urlencoded', the body is not in body, I assume something might read from it along the way at some unknown junction.

Instead body is parsed out in params, and any subsequent reads to body return empty string.

I have been testing & capturing traffic running em-http-request's spec suite with this one test: https://github.com/igrigorik/em-http-request/blob/v1.1.7/spec/client_spec.rb#L178

and with this PR applied: igrigorik/em-http-request#370

Rack::Request is formed here: https://github.com/igrigorik/em-http-request/blob/v1.1.7/spec/stallion.rb#L60
at this point, request.body.read will produce the correct body (JFTR, if read for debug purposes, at this place will always return empty string later on)

Body is expected to be read for the first time in this place: https://github.com/igrigorik/em-http-request/blob/v1.1.7/spec/stallion.rb#L116

but when we reach that place, the string is already empty, and params is populated.

This is observed with both Puma and WEBrick.

But as mentioned, this does not happen with every Content-Type request header. If we provide text/plain, both of the mentioned webservers exhibit the same behavior in terms of state of the #body, #params when we try to respond in the stallion's block.

I am not sure yet and mainly curious as to why with no Content-Type, params are being populated. Currently I assume, since body is not rewindable, that some parsing somewhere for params destroys body and it is no longer usable.

Few examples with Puma, there is no functional difference to webrick in terms of body processing that can be observed for the test suite:

No header

Client Request:

POST / HTTP/1.1
Connection: close
Host: 127.0.0.1:8090
User-Agent: EventMachine HttpClient
Accept-Encoding: gzip, compressed
Content-Length: 4

data

Server Response:

HTTP/1.1 200 OK
Connection: close
Content-Length: 0

#params are { "data" => nil}

application/x-www-form-urlencoded

Request

POST / HTTP/1.1
Content-Type: application/x-www-form-urlencoded
Connection: close
Host: 127.0.0.1:8090
User-Agent: EventMachine HttpClient
Accept-Encoding: gzip, compressed
Content-Length: 4

data

Response

HTTP/1.1 200 OK
Connection: close
Content-Length: 0

#params are { "data" => nil}

text/plain

Request

POST / HTTP/1.1
Content-Type: text/plain
Connection: close
Host: 127.0.0.1:8090
User-Agent: EventMachine HttpClient
Accept-Encoding: gzip, compressed
Content-Length: 4

data

Response

HTTP/1.1 200 OK
Connection: close
Content-Length: 4

data

#params are {}

[jackorp]

Looks like when interacting with Rack::Request, https://github.com/rack/rack/blob/8116397b447e6dc8117c8409cc083bf5b0e2f8fb/lib/rack/request.rb#L475 Content-Type should be specified to anything but a form to be safe from this, or other request handling avenues could be considered. @voxik not sure if I'd consider this rackup's bug anymore.

[voxik]

@jackorp nice. Thanks for helping to move this forward 👏

In other words, this is where the behavior change is documented and from there on can get to this 2.2 code reference with explicit rewind call.

Nevertheless, I still find this change surprising in the context of the tickets I am coming from. Non of the affected libraries actually cared about rewind explicitly. Rack let the body to always be read at least once. This is not the case anymore.

At minimum, this hint is hardly helpful in this context:

Use Rack::RewindableInput::Middleware to make the body rewindable, and call .rewind explicitly to match this behavior.

Maybe it should elaborate that body is not expected to be accessed in this case, because the form from the body was already consumed? 🤷

[voxik]

not sure if I'd consider this rackup's bug anymore.

Actually, should I understand your remark that this should be moved to Rack?