Rails app hangs: Completed 401 Unauthorized in x ms

Question

After updating a Rails app from RestfulAuthentication and Rails 2.3 to Devise and Rails 5.0, we are getting strange "401 Unauthorized" errors, and the rails application hangs at the first request:

Completed 401 Unauthorized in x ms

where x is a very high number. The error occurs only if the server is started the first time (after a long period of inactivity). The application just hangs and refuses to start, and if we interrupt the server the 401 Unauthorized errors appear. It does not seem to matter if we use Webrick, Puma, Thin or Unicorn. The ApplicationController looks like

class ApplicationController < ActionController::Base
  protect_from_forgery with: :exception
  before_action :set_http_headers
  alias login_required authenticate_user!
  ...

(the alias was added to guarantee a smooth transition to Devise). The database.yml config file looks like

development:
  adapter: mysql2
  encoding: utf8
  database: db_name
  pool: 5
  timeout: 5000
  username: db_user
  passwort:

Once the application is running the errors disappear, but if we restart the computer after a few hours or in the next day, the error appears again.

Occasionally there are also Timeout errors like

ActiveRecord::ConnectionTimeoutError: could not obtain a connection from the pool within 5.000 seconds (waited 5.003 seconds); all pooled connections were in use

or

No live threads left. Deadlock? (fatal)

The related Devise issues (here and here) are not helpful, and none of the related questions provided a solution, neither ActiveRecord::Base.clear_active_connections! helps, as proposed here nor Session.delete_all (the session is stored in ActiveRecord). Help! Any ideas?

This will be very hard to troubleshoot without having access to the app. Did you really upgrade from 2.3 to 5.0? In one go? Then expect lots of other issues :) Or did you upgrade in increments? Then between which versions did this actually occur? — Thilo, Sep 06 '16 at 09:24
Well actually we created a new Rails 5 app which is connected to the old MySQL database, and modified it a bit according to the official recommendations https://github.com/plataformatec/devise/wiki/How-To:-Migrate-from-restful_authentication-to-Devise — 0x4a6f4672, Sep 06 '16 at 09:41
The problem is likely in your code, which you haven't included in the question. We need to see that to be able to diagnose the issue. Before the *Completed 401 Unauthorized in x ms* line in your log, there should be another line that indicates which controller and action is handling the request - post the code for that controller. If it's happening on *every* request, post the application controller. — ArtOfCode, Sep 06 '16 at 11:54
I have added the first lines of the application controller. Somehow the logs say nothing, because the application just hangs :-( Only if the application is interrupted by Ctrl-C in the terminal an error message appears, and the stack trace only points to the web server itself :-( — 0x4a6f4672, Sep 06 '16 at 12:44
Add your `database.yml` and possibly your `my.cnf` files - I suspects this is just a configuration error somewhere. — Thilo, Sep 06 '16 at 23:08
Unfortunately it is also hard to troubleshoot if you **have** access to the app. The problem is still happening and it is very annoying :-( — 0x4a6f4672, Sep 28 '16 at 11:18

score 4 · Answer 1 · answered Dec 22 '16 at 22:50

4

I agree this was a particularly nasty bug. For me, what ultimately fixed it was changing:

config.eager_load = false

to

config.eager_load = true

in config/environments/development.rb

answered Dec 22 '16 at 22:50

apod

578
5
16

Thanks! I have indeed `config.cache_classes = false` and `config.eager_load = false` in the config. Let me check if it finally solves this really nasty bug. What would be the use of `eager_load = false` if it makes the application unusable? – 0x4a6f4672 Dec 23 '16 at 11:15
I haven't gotten too deep into the Devise repo, but my guess would be this bug is related to Devise not having access to some module it needs when it first attempts to authenticate. So while having eager_load turned off may be fine for a vanilla Rails app, it seems like it creates trouble when combined with Devise. Clearly a bug somewhere, but not sure where exactly. – apod Dec 23 '16 at 17:08
No unfortunately it didn't help :-( I hate this problem :-( – 0x4a6f4672 Jan 17 '17 at 12:33

score 0 · Answer 2 · edited May 23 '17 at 12:02

I do not know how many hours this problem has cost me, it is really annoying. In the last 8 years I have not met a bug which took me so long to figure out. It only occurred in the development environment. The Gemfile says

group :development do
  # Spring speeds up development by keeping your application running in the background.
  # Read more: https://github.com/rails/spring
  gem 'spring'
end

The Gemfile.lock says bundler has installed the version 1.7.2 of spring. Some people suggest to stop spring if a rails command hangs. I commented out the spring gem in the Gemfile, uninstalled the gem with gem uninstall spring and updated the RVM ruby version manager which I still use and the problem that rails hangs at first start seems to be less frequent (but it is not completely gone)

  # gem 'spring'

So it seems to be partly a spring problem, maybe related to this issue. Quite paradox, a gem which is supposed to speed the application up slows it down until it hangs :-(

Rails app hangs: Completed 401 Unauthorized in x ms

2 Answers2