Devise Filter chain halted as :require_no_authentication rendered or redirected

I have an app with Rails 3.2.20 and Devise 2.1.2 (Yes I know it's old) and there are random occasions where a user will trigger a URL i.e. site.com/calls and I will receive an error in the production.log such as: Filter chain halted as :require_no_authentication rendered or redirected and it will then redirect to the proper path.

I've done some research on Stack and all of the answers people have given have nothing to do with my current scenario.

Was wondering if anyone has received this error using Rails and Devise, and if it's something non-volatile that I can ignore, or if it's something I should look into.

It should be noted that I cannot reproduce this in development or staging environments. It only happens in my production app instance.

Do you have a method called require_no_authentication in your app anywhere?

No sir, I think it's a Devise built-in method. Devise Rdoc

But the question is why is it randomly getting called? It doesn't happen very often, maybe a couple times a day in production. And I can't reproduce it in development, lord knows I've tried. It seems non-volatile, but I'm not entirely sure.

The example here shows it being used in a before_filter but I'm guessing you aren't calling it anywhere in your app? Are there other Devise related gems that might be adding it in for you?

No, I'm not calling it anywhere in my app. The only thing I can think of that might be triggering it is my after_sign_in_path method in application_controller.rb but I'm not sure why it's being triggered. I'm having a hard time parsing through logs to see when the behavior pops up and why.

 before_filter :authenticate_user!    
    def after_sign_in_path_for(resource)
      case resource.role
        when "client"
        clients_path
        when "dispatch"
        home_index_path
        when "medic"
        mdt_path
        when "supervisor"
        supervisors_path
        when "admin"
        home_index_path
        when "disabled"
        destroy_user_session_path
      else
        super
      end
    end

Maybe you're redirect a user to a devise URL that is only for users that are signed out, hence the before_filter. If you have the log of the request that triggers the Filter and the one after it, I'd be curious to see them.

Here's the nginx log:

75.148.203.249 - - [17/Nov/2014:07:00:53 -0600] "GET /calls?_=1416229226292 HTTP/1.1" 200 24883 "https://cad.hcems.com/calls" "Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; WOW64; Trident/5.0)"
75.148.203.249 - - [17/Nov/2014:07:00:55 -0600] "GET /users/sign_in HTTP/1.1" 302 109 "https://cad.hcems.com/units" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
75.148.203.249 - - [17/Nov/2014:07:00:55 -0600] "GET /home/index HTTP/1.1" 200 15441 "https://cad.hcems.com/units" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"

Here's the production log output:

Started GET "/users/sign_in" for 75.148.203.249 at 2014-11-17 07:00:55 -0600
Processing by MySessionsController#new as HTML
Redirected to https://cad.hcems.com/home/index
Filter chain halted as :require_no_authentication rendered or redirected
Completed 302 Found in 2.3ms (ActiveRecord: 0.6ms)
Started GET "/home/index" for 75.148.203.249 at 2014-11-17 07:00:55 -0600
Processing by HomeController#index as HTML
  Rendered home/index.html.erb within layouts/application (260.0ms)
Completed 200 OK in 311.1ms (Views: 66.1ms | ActiveRecord: 237.4ms)

Okay, so as I thought, for some reason you're sending an already signed in user to the sign_in view. Somewhere you're sending them to that view, but they're already signed in and Devise knows that so it sends them on. It's a before_filter inside the Devise::SessionsController in the gem. Naturally if the user is already signed in, they don't need to be able to sign in again.

Steps to reproduce are probably:

1. Sign in
2. Visit /users/sign_in
3. You will get redirected

The only thing I can think of is that the employee may have been signed in as another user who just left their shift, then they possibly closed the browser window, and tried to log back in (ergo the hit to the MySessionsController#new, when Devise realized the user never logged out perhaps it gave this :require_no_authentication directive because there was already a session established.

This is really weird and doesn't seem to be impacting users.

Good call, Chris.

I was able to manually reproduce the error by

1.) Signing in
2.) Visiting /users/sign_in
3.) Boom I got redirected to the root url home_index_path
4.) The :require_no_authentication error occurred in development log

Now the 1M question is. How to figure out where I'm sending them to that view? I have no earthly clue on where to start looking. Any advice? :)

The only thing that jumps out at me is in routes.rb

  devise_scope :user do
    get "/login" => "devise/sessions#new"
    delete "/logout" => "devise/sessions#destroy"
  end

If by chance they are hitting /login and already logged in this behavior would exhibit itself.

Then there's another theory I've come up with by looking at the log:

Started GET "/users/sign_in" for 75.148.203.249 at 2014-11-17 07:00:55 -0600
Processing by MySessionsController#new as HTML
Redirected to https://cad.hcems.com/home/index
Filter chain halted as :require_no_authentication rendered or redirected
Completed 302 Found in 2.3ms (ActiveRecord: 0.6ms)
Started GET "/home/index" for 75.148.203.249 at 2014-11-17 07:00:55 -0600
Processing by HomeController#index as HTML
  Rendered home/index.html.erb within layouts/application (260.0ms)
Completed 200 OK in 311.1ms (Views: 66.1ms | ActiveRecord: 237.4ms)

User closes browser without logging out
User opens bookmark for application which defaults to the users/sign_in url
Devise detects that they are already logged in
:require_no_authentication is triggered

Without actually seeing this happen in person, it's really hard to nail down.

Would you mind looking at a couple things for me if you have time? Or telling me how I can search through my codebase to see if I'm mistakenly redirecting them?

You'll probably want to check the request just before the redirect to see what they were accessing when they got redirected. Feel free to post more of the log.

I'll have to dig through the logs and see if I can track it down. So far the problem with tracking this issue down is parsing the logs I'm looking for requests by IP address, but there's usually more than one user logged in behind an IP address (NAT/Router) so it's hard to tell from the Nginx logs what the request was before the behavior happened. Since we do have multiple users using the same browser/etc the Nginx log is not very helpful in tracking this down.

The only thing I can think of is they closed the browser while still being logged in, reopened a new browser, and started typing the url and the browser history auto-completed it to https://cad.hcems.com/users/sign_in. Then it triggered a :require_no_authentication in Devise.

Do you see a clearer method on how to track this down besides what I've mentioned?

This is an interesting problem to solve.

That's possible for why it is happening. I know I've done that before.

You may be able to rejig your logs to print out the user ID in them (if available) so you can associate the requests together.

That's a good idea, I'll have to look into that. For now I think it's an EUE issue by hitting the sign_in URL. Or at least that's all I can see from the logs. Again this doesn't happen very often so it's really tough to track down. And since it doesn't throw an exception or present an error to the user, they don't really notice anything and just go about their business. Frustrating to say the least knowing there "may" me a bug somewhere that you can't track down easily. I have AirBrake installed in production and it doesn't catch it, but of course it's not an exception so it's not going to give me any 411 on it. Sigh.