falcon: Unexpectedly and often getting Concurrent::IllegalOperationError

Here is the request log from Rails 7.0 and Postgres 14:

Started GET "/post/1?include=children" for 127.0.0.1 at 2022-03-18 22:50:53 +0100
Processing by PostsController#show as */*
  Parameters: {"id"=>"1"}
    1m    error: Falcon::Adapters::Rack [oid=0x57d0] [ec=0x57e4] [pid=39666] [2022-03-18 22:50:53 +0100]
               |   Concurrent::IllegalOperationError: Cannot release a read lock which is not held
               |   → /Users/emil/.rbenv/versions/3.1.1/lib/ruby/gems/3.1.0/gems/concurrent-ruby-1.1.9/lib/concurrent-ruby/concurrent/atomic/reentrant_read_write_lock.rb:244 in `release_read_lock'

Or alternatively:

 2.85s    error: Falcon::Adapters::Rack [oid=0x3070] [ec=0x3084] [pid=39709] [2022-03-18 22:54:43 +0100]
               |   NameError: uninitialized constant Rack::Mime
               |   
               |           content_type = ::Rack::Mime.mime_type(ext, nil)

They seem to appear when requests are coming in simultaneously from the same client.

Any thoughts?

Let me know if there’s anything else that I need to provide.

Thanks 🤝

About this issue

Original URL
State: closed
Created 2 years ago
Comments: 30 (22 by maintainers)

Most upvoted comments

@ioquatix, thank you for looking into this, and persistently working to fix it! 🤝

ekampp on Feb 18, 2023

Okay, apparently the correct way to fix this is here: https://github.com/rails/rails/pull/47347

Hopefully that’s sufficient, I’ll test it after it’s merged.

ioquatix on Feb 10, 2023

@ioquatix it looks like that might have fixed it for me! I haven’t been able to reproduce it since patching in your Rails change, and I was previously able to get it to break in under a minute of just refreshing my app.

I did run into a new issue though 😄 Looks like something may be off with ActiveSupport::CurrentAttributes + falcon. Ah ok no, sorry I’m writing this comment and researching at the same time. Looks like I should be configuring rails to use fiber isolation level when using Falcon, and I hadn’t seen that specified before now. I’m sure that’s my issue here.

# config/application.rb

# https://guides.rubyonrails.org/configuring.html#config-active-support-isolation-level
config.active_support.isolation_level = :fiber

Thanks so much for digging into this! 🙏

willcosgrove on Feb 5, 2023

Thanks for digging into this! I applied your monkey patch listed here https://github.com/ruby-concurrency/concurrent-ruby/issues/962#issuecomment-1281676806 and I got some new behavior.

I still get errors, but the server doesn’t hang. Before, when this would happen, the server would completely hang up, and not serve any other requests. This still errored, but the server would still serve subsequent requests. I refreshed several times, still with sporadic errors, and then it eventually settled into a steady state of no errors.

I recorded a screencast to try and capture the behavior. Pay no attention to the contents of my silly little demo app 😇 https://wco.sg/v6LpIc

You can see that it starts out loading with sporadic errors (which show up as images not loading, the images are served through the app from active storage). It eventually gets to a point where I cannot get it to error. Then I kill and restart the server and the behavior starts over.

willcosgrove on Oct 18, 2022

@ekampp I re-read your initial issue description, and it turns out there are two issues - the first one which was recently reproduced by @willcosgrove and the 2nd one which is a bug in Ruby autoload. The autoload bug is fixed by forcing Rails to load everything at boot. The 2nd issue is solved by Ruby 3.2 or config.eager_load=true (IIRC).

ioquatix on Oct 18, 2022

Thanks your report was really useful.

ioquatix on Oct 17, 2022

@ioquatix, it seems reasonable. Not sure what autoload it introduces because I will have to go through a lot of gems to detect that.

ekampp on Apr 15, 2022

I will take a look.

ioquatix on Mar 21, 2022