midori-rb / midori.rb

Lightweight, Flexible and Fast Ruby Web Framework
MIT License
870 stars 57 forks source link

IOError when respond with large body #155

Closed li-thy-um closed 6 years ago

li-thy-um commented 6 years ago

This will cause the server process abort.

I, [2018-02-28T08:09:48.730775 #1]  INFO -- : Midori 0.5.2 is now running on 0.0.0.0:3000
I, [2018-02-28T08:09:50.043817 #1]  INFO -- : 172.25.0.1 - - "GET /documents HTTP/1.0" 200 OK 0.034884
I, [2018-02-28T08:09:50.360293 #1]  INFO -- : 172.25.0.1 - - "GET /origin_websites HTTP/1.0" 200 OK 0.286312
I, [2018-02-28T08:09:50.437701 #1]  INFO -- : 172.25.0.1 - - "GET /output_columns HTTP/1.0" 200 OK 0.076205
I, [2018-02-28T08:09:51.133797 #1]  INFO -- : 172.25.0.1 - - "GET /compose_organizations HTTP/1.0" 200 OK 0.693688
/app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:62:in `fileno': closed stream (IOError)
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:62:in `deregister'
    from /app/vendor/bundle/ruby/2.5.0/gems/midori.rb-0.5.2/lib/midori/connection.rb:63:in `close_connection'
    from /app/vendor/bundle/ruby/2.5.0/gems/midori.rb-0.5.2/lib/midori/connection.rb:33:in `block in listen'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:75:in `block in run_once'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:74:in `select'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:74:in `run_once'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:101:in `start'
    from /app/vendor/bundle/ruby/2.5.0/gems/midori.rb-0.5.2/lib/midori/runner.rb:44:in `start'
    from /app/midori.rb:6:in `<main>'
dsh0416 commented 6 years ago

Bug confirmed. Can you provide any sample code?

li-thy-um commented 6 years ago

It's hard to provide sample code, but I'm trying.

I removed the Nginx reverse proxy in between, and did the test again. It will response the data successfully, but the server will shutdown.

get '/multi_aggs' do
   # here it will do elasticsearch aggregation search
   MultiAggs::Index.new(request.query_params, user).to_json
end

RestClient::Request.execute(method: :get, url: url,
      timeout: 5,
      headers: {params: params, Authorization: @auth_token})
I, [2018-03-01T04:48:23.105229 #1]  INFO -- : Midori 0.5.2 is now running on 0.0.0.0:3000
287465 # This is the response body's size of request bellow
I, [2018-03-01T04:48:38.949328 #1]  INFO -- : 172.25.0.1 - - "GET /multi_aggs HTTP/1.1" 200 OK 0.971632
320426
I, [2018-03-01T04:48:47.213653 #1]  INFO -- : 172.25.0.1 - - "GET /multi_aggs HTTP/1.1" 200 OK 1.264781
361135
I, [2018-03-01T04:48:56.695555 #1]  INFO -- : 172.25.0.1 - - "GET /multi_aggs HTTP/1.1" 200 OK 1.449826
286526
I, [2018-03-01T04:49:06.100274 #1]  INFO -- : 172.25.0.1 - - "GET /multi_aggs HTTP/1.1" 200 OK 1.100490
180645
I, [2018-03-01T04:49:11.421074 #1]  INFO -- : 172.25.0.1 - - "GET /multi_aggs HTTP/1.1" 200 OK 0.465922
/app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:62:in `fileno': closed stream (IOError)
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:62:in `deregister'
    from /app/vendor/bundle/ruby/2.5.0/gems/midori.rb-0.5.2/lib/midori/connection.rb:63:in `close_connection'
    from /app/vendor/bundle/ruby/2.5.0/gems/midori.rb-0.5.2/lib/midori/connection.rb:33:in `block in listen'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:75:in `block in run_once'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:74:in `select'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:74:in `run_once'
    from /app/vendor/bundle/ruby/2.5.0/gems/murasaki-0.2.0/lib/murasaki/event_loop.rb:101:in `start'
    from /app/vendor/bundle/ruby/2.5.0/gems/midori.rb-0.5.2/lib/midori/runner.rb:44:in `start'
    from /app/midori.rb:6:in `<main>'
li-thy-um commented 6 years ago

Gems:

gem 'activesupport'
gem 'tzinfo-data'
gem 'midori.rb'
gem 'elasticsearch'
gem 'monadic'
gem 'jbuilder'
gem 'nokogiri'
gem 'redis'
dsh0416 commented 6 years ago

This seems to be the problem that midori accidentally closed the stream multiple times. A patch would be applied soon.

luikore commented 6 years ago

Any update on this bug?

dsh0416 commented 6 years ago

@luikore There has been a temp fix merged, which has already fixed this problem. But it may take some time to rewrite the part with the fd number to fix the problem more elegantly.

dsh0416 commented 6 years ago

Fixed in the v0.5.4 with the update of murasaki.

Thank you guys so much for reporting and tracking this issue. Sorry for the late fix.