Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Error during failsafe response: not opened for reading #5159

Closed
kaji-bikash opened this issue May 8, 2018 · 3 comments
Closed

Error during failsafe response: not opened for reading #5159

kaji-bikash opened this issue May 8, 2018 · 3 comments
Milestone
Invalid or Duplicate

Comments

@kaji-bikash
Copy link

kaji-bikash commented May 8, 2018 •
edited
Loading

Environment

:>jruby -v
jruby 9.1.16.0 (2.3.3) 2018-02-21 8f3f95a OpenJDK 64-Bit Server VM 24.95-b01 on 1.7.0_95-b00 +jit [linux-x86_64]

:>cat ~/.jruby_opts
#Following source will load ruby manager and other envs of shells like RAILS_ENV
export JRUBY_OPTS="--server -J-Xms2048m -J-Xmx2048m -J-XX:+UseConcMarkSweepGC -J-XX:-UseGCOverheadLimit -J-XX:+CMSClassUnloadingEnabled -J-XX:+HeapDumpOnOutOfMemoryError -J-XX:HeapDumpPath=/home/anon/debug/heap_dump"

:>uname -a
Linux app1 4.4.0-101-generic #124-Ubuntu SMP Fri Nov 10 18:29:59 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

:>lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 16.04.3 LTS
Release:	16.04
Codename:	xenial

We have Rails 5.0.2 framework with following gems activated.

Gemfile

source 'https://rubygems.org'
gem 'rails'
ruby '2.3.3', engine: :jruby, engine_version: '9.1.16.0' if RUBY_PLATFORM.eql?('java')

gem 'active_model_serializers'
gem 'activerecord'
gem 'json-schema'

# RabbitMQ adapter
gem 'hutch'

# monitoring
gem 'honeybadger'
gem 'newrelic_rpm', '~> 3.16', '>= 3.16.1.320'
gem 'puma'

gem 'gcm'
gem 'google_drive'
gem 'redis'
gem 'sidekiq-pro', '~> 3'
gem 'sidekiq-cron'

gem 'httparty'
# this gem is required to fix issue of CORS while performing request
gem 'rack-cors', require: 'rack/cors'

# rfc-compliant replacement for URI
gem 'addressable'

platform :jruby do
  gem 'jdbc-postgres'
  gem 'json'
  gem 'march_hare'

  if RUBY_PLATFORM.eql?('java')
    git_source(:github) { |repo_name| "https://github.com/#{repo_name}.git" }
    github 'jruby/activerecord-jdbc-adapter', branch: 'rails-5' do
      gem 'activerecord-jdbc-adapter'
      gem 'activerecord-jdbcpostgresql-adapter'
    end
  end
end

Current scenario

Nginx shows following in the logs

{
  "time": "2018-05-08T18:47:58+00:00",
  "remote_addr": "172.17.xx.yy",
  "remote_user": "-",
  "body_bytes_sent": "0",
  "request_time": "0.700",
  "status": "500",
  "request": "POST /api/v1/events HTTP/1.1",
  "request_method": "POST",
  "http_referrer": "-",
  "http_user_agent": "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186"
}

Corresponding to above 500 status, puma application server logs following

Error during failsafe response: not opened for reading
  org/jruby/ext/stringio/StringIO.java:822:in `read'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/request.rb:287:in `raw_post'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/parameters.rb:86:in `parse_formatted_parameters'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/request.rb:354:in `block in POST'
  org/jruby/RubyHash.java:1194:in `fetch'
  /home/anon/.gem/jruby/2.3.3/gems/rack-2.0.1/lib/rack/request.rb:57:in `fetch_header'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/request.rb:353:in `POST'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/parameters.rb:45:in `parameters'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/mime_negotiation.rb:63:in `block in formats'
  org/jruby/RubyHash.java:1194:in `fetch'
  /home/anon/.gem/jruby/2.3.3/gems/rack-2.0.1/lib/rack/request.rb:57:in `fetch_header'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/http/mime_negotiation.rb:61:in `formats'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/middleware/public_exceptions.rb:22:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/middleware/show_exceptions.rb:49:in `render_exception'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/middleware/show_exceptions.rb:34:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/railties-5.0.2/lib/rails/rack/logger.rb:36:in `call_app'
  /home/anon/.gem/jruby/2.3.3/gems/railties-5.0.2/lib/rails/rack/logger.rb:26:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/middleware/request_id.rb:24:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/app/releases/20180502083624/app/middleware/catch_json_parse_errors.rb:24:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/rack-2.0.1/lib/rack/runtime.rb:22:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/activesupport-5.0.2/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/middleware/executor.rb:12:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/rack-2.0.1/lib/rack/sendfile.rb:111:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/actionpack-5.0.2/lib/action_dispatch/middleware/ssl.rb:84:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/honeybadger-3.1.0/lib/honeybadger/rack/error_notifier.rb:34:in `block in call'
  /home/anon/.gem/jruby/2.3.3/gems/honeybadger-3.1.0/lib/honeybadger/agent.rb:321:in `with_rack_env'
  /home/anon/.gem/jruby/2.3.3/gems/honeybadger-3.1.0/lib/honeybadger/rack/error_notifier.rb:31:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/honeybadger-3.1.0/lib/honeybadger/rack/user_feedback.rb:31:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/honeybadger-3.1.0/lib/honeybadger/rack/user_informer.rb:21:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/rack-cors-0.4.1/lib/rack/cors.rb:81:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/railties-5.0.2/lib/rails/engine.rb:522:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/newrelic_rpm-3.18.1.330/lib/new_relic/agent/instrumentation/middleware_tracing.rb:96:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/puma-3.11.4-java/lib/puma/configuration.rb:225:in `call'
  /home/anon/.gem/jruby/2.3.3/gems/puma-3.11.4-java/lib/puma/server.rb:632:in `handle_request'
  /home/anon/.gem/jruby/2.3.3/gems/puma-3.11.4-java/lib/puma/server.rb:446:in `process_client'
  /home/anon/.gem/jruby/2.3.3/gems/puma-3.11.4-java/lib/puma/server.rb:306:in `block in run'
  /home/anon/.gem/jruby/2.3.3/gems/puma-3.11.4-java/lib/puma/thread_pool.rb:120:in `block in spawn_thread'

Is this a bug in JRuby?
@headius
Copy link
Member

headius commented May 14, 2018

Is this a bug in JRuby?

@kajisaap Probably! However I'm not sure exactly where to start looking for a solution. Could you try to test this against a master (development) build from http://ci.jruby.org and see if it still exists there?

@kaji-bikash
Copy link
Author

Thanks, @headius. I know it could be in our dependency library but the error went away after putting concurrency settings to 1 ie. defeating the purpose of JRuby. We want to have concurrency settings back though :)

So, it's definitely the concurrency-born issue but we are not able to pinpoint whether it's the runtime causing it or dependent libraries(which in our case could be any of the 15+ gems). Do you have any suggestions to find non-thread safe code or libraries?

@headius
Copy link
Member

headius commented Jul 18, 2020

Lots of libraries involved with no clear reproduction or pointer that JRuby is at fault.

We can help folks investigate concurrency bugs in libraries they're using on JRuby, but without some example there's nothing to do here. If you'd still like help, find us on our chats or file a bug with a specific reproduction.

@headius headius closed this as completed Jul 18, 2020
@headius headius added this to the Invalid or Duplicate milestone Jul 18, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
Invalid or Duplicate
Development

No branches or pull requests
2 participants
@headius @kaji-bikash