Login occasionally redirects to the wrong path at random?

[nozpheratu]

I'm running into a strange bug that seems to appear seemingly at random. I have rack setup to pass requests on the '/authenticate' subdirectory to my Casino application:

map '/authenticate' do
  run Rails.application
end

I also inform rails that all routes need to include the '/authenticate' subpath:

Rails.application.config.relative_url_root = '/authenticate'

More often than not, everything works great with this setup. However, if I try repeatedly logging out and logging back in, on the very rare occasion CASino will try to redirect to login without the subpath after it makes a request to proxyValidate, as seen with my server logs:

127.0.0.1 - - [11/Dec/2015:14:05:20 -0600] "POST /authenticate/login HTTP/1.1" 303 - 0.1860
127.0.0.1 - - [11/Dec/2015:14:05:20 -0600] "GET /authenticate/proxyValidate?service=http%3A%2F%2Flocalhost%3A3000%2Fadmin_users%2Fservice&ticket=ST-14498643207475-muyPjLOST2JRU8NkPbEWgeMH5Qm7oMwAFSXytJS4 HTTP/1.1" 200 - 0.0139
**27.0.0.1 - - [11/Dec/2015:14:05:20 -0600] "GET /login?service=http%3A%2F%2Flocalhost%3A3000%2Fadmin_users%2Fservice HTTP/1.1" 404 - 0.0009**

And on the remote rails app service using ActiveAdmin:

Started GET "/admin_users/service?ticket=ST-14498643207475-muyPjLOST2JRU8NkPbEWgeMH5Qm7oMwAFSXytJS4" for 127.0.0.1 at 2015-12-11 14:05:20 -0600
Processing by CasSessionsController#service as HTML
  Parameters: {"ticket"=>"ST-14498643207475-muyPjLOST2JRU8NkPbEWgeMH5Qm7oMwAFSXytJS4"}
D, [2015-12-11T14:05:20.764793 #19427] DEBUG -- : [httplog] Connecting: localtoast:3001
D, [2015-12-11T14:05:20.765043 #19427] DEBUG -- : [httplog] Sending: GET http://localtoast:3001/authenticate/proxyValidate?service=http%3A%2F%2Flocalhost%3A3000%2Fadmin_users%2Fservice&ticket=ST-14498643207475-muyPjLOST2JRU8NkPbEWgeMH5Qm7oMwAFSXytJS4
D, [2015-12-11T14:05:20.765093 #19427] DEBUG -- : [httplog] Data: 
D, [2015-12-11T14:05:20.779228 #19427] DEBUG -- : [httplog] Status: 200
D, [2015-12-11T14:05:20.779301 #19427] DEBUG -- : [httplog] Benchmark: 0.014076887999181054 seconds
D, [2015-12-11T14:05:20.779352 #19427] DEBUG -- : [httplog] Response:
<cas:serviceResponse xmlns:cas="http://www.yale.edu/tp/cas">
  <cas:authenticationSuccess>
    <cas:user>[email protected]</cas:user>
  </cas:authenticationSuccess>
</cas:serviceResponse>
Using conditions {email => [email protected]} to find the User
  AdminUser Load (0.4ms)  SELECT  "admin_users".* FROM "admin_users"  WHERE "admin_users"."email" = '[email protected]'  ORDER BY "admin_users"."id" ASC LIMIT 1
   (0.1ms)  BEGIN
   (0.1ms)  COMMIT
   (0.1ms)  BEGIN
  SQL (0.2ms)  UPDATE "admin_users" SET "current_sign_in_at" = $1, "sign_in_count" = $2, "updated_at" = $3 WHERE "admin_users"."id" = 2  [["current_sign_in_at", "2015-12-11 20:05:20.786058"], ["sign_in_count", 2], ["updated_at", "2015-12-11 20:05:20.786633"]]
   (10.7ms)  COMMIT
Redirected to http://localhost:3000/admin
Completed 302 Found in 35ms (ActiveRecord: 11.5ms)

I can't for the life of me figure out where that redirect to /login is coming from. Again, I see this completely at random after logging in and logging out consecutive times. http://localhost:3000/admin is the path where the browser should have been redirected to, but that seems to get overridden by CASino's redirect to http://localtoast:3001/login (and no, "localtoast" is not a typo 😄).

[nozpheratu]

Perhaps even stranger, sometimes I don't even see the redirect to /login in the logs. It just happens....

[nozpheratu]

It seems the rubygems version is out of date. The latest version on master seems to resolve this issue for me!

[bakku]

I am experiencing the same issue. Following @nozpheratu solution I set in my Gemfile:

gem 'casino', git: 'https://github.com/rbCAS/CASino.git'

also I set:

gem 'casino-ldap_authenticator', git: 'https://github.com/rbCAS/casino-ldap_authenticator.git'
gem 'casino-activerecord_authenticator', git: 'https://github.com/rbCAS/casino-activerecord_authenticator.git'

just to be safe.

Still my requests are as follows:

I want to visit a site in my application which requires me to log in. This log in redirects me to the CASino Application:

Started GET "/login?service=http%3A%2F%2Fexample.com%3A3003%2Fusers%2Fservice" for 127.0.0.1 at 2015-12-14 13:15:15 +0100

Now I enter my credentials and submit:

Started POST "/login" for 127.0.0.1 at 2015-12-14 13:15:17 +0100
Started GET "/proxyValidate?service=http%3A%2F%2Fexample.com%3A3003%2Fusers%2Fservice&ticket=ST-14500953173713-IlAub2jS0iVCjwiPV0uIXx4jSdwpxMMNkecpE0Us" for 127.0.0.1 at 2015-12-14 13:15:17 +0100
Started GET "/login?service=http%3A%2F%2Fexample.com%3A3003%2Fusers%2Fservice" for 127.0.0.1 at 2015-12-14 13:15:17 +0100

Because of the /login request at the end I won't get redirected to the previous path in my other application which was restricted and started the whole sign in process. I get redirected to the root path.

For me this happens probably ~60-70 % of the time.

Anybody knows a solution for this?

[nozpheratu]

@bakku Yeah, that definietly sounds like the issue I was running into.

I'm not entirely sure how bundler determines whether or not a gem is up-to-date, but I believe both the rubygems version of CASino and the Github version both resolve to v4.0.2 (despite 5 months of development between now & the last version bump!). You might have to manually run bundle update casino to pull in the version that worked for me. After updating I've yet to see that /login request crop up.

I believe you'll also need to re-run the rake task as well as rake db:migrate. The most up-to-date version includes some new migrations - though you probably already know that as you would have run into an undefined method exception otherwise if you're indeed using the latest version.

[bakku]

@nozpheratu Thank you for your response. I tried out setting gem 'casino' in the Gemfile and running bundle update casino but still the problem appears. I migrated the database aswell

In the past I made two observations (I don't know of how much value they are):

• I inspected the request objects in the CASino::SessionsController#new action. While the first request has the HTTP_REFERRER set to the application where I wanted to log in, the second request to /login has HTTP_REFERRER set to the CASino App. As far as I know the HTTP_REFERRER determines from where a user got redirected?!
• When I disable JavaScript in the browser I did not run into the problem yet

[bakku]

@pencil I found the piece of code causing this problem. I looked up the commit history and saw that you commited this script initially (eventhough it was in 2012)

In CASino the file app/assets/javascripts/casino/sessions.js triggers the request to /login in the following line:

win.location = url;

I don't really know when and why this line gets executed but I think the "random" effect of this problem has to do with the setTimeout(checkCookieExists, 1000);. Maybe because my application needs a longer time to load (pictures, files, etc) the problem occurs here more often than on a simple application.

How can this be fixed?

[pencil]

How can this be fixed?

Currently don't have the time to look into this but you should check app/assets/javascripts/casino/application.js.erb since it looks like whatever win.CASino.url('login') returns is not correct in your case.

[bakku]

@pencil I don't really think that this is the problem, since there can hardly be an error in this piece of code, only if the root_path of CASino would be wrong in my application.

win.CASino.url('login') returns /login like it should do.

I rather think that the problem lies in sessions.js.

If a user has two browsers with the CASino Application open and he logs in, in one window then it works how it should and the second window will log in aswell.

The problem is the following:

The user gets redirected to /login. He types in his details and tries to log in. If the timing is not on our side now, CASino will try to login twice, since the cookie might exist while the script can still be executed which is the case for me.

Moreover CASino sends a logout POST request to the applications telling them that a new user logged in.

So at the moment in my application the user gets logged in twice in a very short and unnoticable time. But one (of all if there are more) sideeffect is that the saved url on the other application gets lost and the user is just redirected to the root path (if root path is the default url which a user gets redirected to after logging in as in devise).

The two ways I tried out to try to keep sessions.js and make it work 100 % of the time, failed:

• setting the timeout higher will lower the probability of this case but it will always be a timing condition if it will be a double log in or a single log in
• removing url += '?service=' + encodeURIComponent(service); will prevent the CASino application from effecting the service application, but when the double login will take effect then we will end up in the CASino "after login path" since the script will make a request to /login

Maybe there are other possibilies but as long as there are not, in my view the benefit of having this functionality is not worth the double login it can produce.

Until there is no other solution I will fork this project and take out sessions.js.

How should we procede?

[ebarra]

I also have this problem. How did you solve it? If I remove sessions.js it stills redirects to the wrong url sometimes.

[bakku]

Deleting sessions.js was enough in my case.

If this does not work in your case then first try out if it works 100% of the time with Javascript disabled in the browser.

Note that you might have to try it MANY times. Since the problem in the JavaScript was a timing problem.

[nozpheratu]

@ebarra are you using the absolute latest sorce code? See my comment abovem

[ebarra]

I am trying with the latest source code (but I have a problem that I have opened in another issue).
As soon as I solve it I will answer here.
Thank you very much

[ebarra]

Hello:
This is still happening although I have the latests source code (updated the Gemfile with
gem 'casino', git: 'https://github.com/rbCAS/CASino.git'
gem 'casino-ldap_authenticator', git: 'https://github.com/rbCAS/casino-ldap_authenticator.git'
gem 'casino-activerecord_authenticator', git: 'https://github.com/rbCAS/casino-activerecord_authenticator.git')

And also deleted sessions.js file

Any other idea?
Thank you very much

[bakku]

You can test by using my fork at https://github.com/bakku/CASino instead of the official CASino version to try out if you have the same problem as me or if it is something else.

[ebarra]

I changed to your fork and it still happens.
So it is another thing, I will investigate further

[bakku]

try to disable javascript in the browser. if it still occurs then the problem lies elsewhere

[ebarra]

Without javascript the error disappears. I have logged-in and out like 30 times and all of them worked.
I think the problem comes with the assets precompiling that is failing in production and I have precompiled assets that include an old sessions.js
I will investigate and answer as soon as I validate my approach

[ebarra]

Hello:
It was that. My assets were not being precompiled, a permission problem in public.
Now it works like a charm.
Thank you very much @bakku and all the team for this great software

[bakku]

This thread has already 18 comments and three people reported the same issue.
Maybe a rbCAS member might get involved in this issue?

[pencil]

Can somebody please post steps to reproduce, expected result, and actual result?

[bakku]

• Two rails servers. One using Devise CAS authenticatable (I don't know if you also can use something else) and one is the CASino App
• Now when trying to log in in the Devise CAS authenticatable application you get redirected to the CASino App
• Expected Result: After logging in I get redirected back to the url I came from
• Occasional Actual Result: I get redirected to the root path of the other application

In my application where the redirect was slow it happened ~70% of the time.
When I used two clean versions of both servers it happened maybe ~5% of the time since the redirect was fast.

I already posted detailed description of what I tracked as the problem above and how I solved it.

[lchanouha]

I also encoutered this bug too.
The page where the real login happened shoud never call checkCookieExists otherwhise you can be redirected twice, not letting the service provider handle de service ticket.

[lchanouha]

#162 I propose an new corrected session.js (instead of deleting it). Hope it will work for you

[bakku]

Should theoretically work. I hope your pull request will get merged so I can change to the official version again

[lchanouha]

My code is a little buggy.

we need to move
document.getElementById('login-form').addEventListener("submit", function(){
clearTimeout(timeoutAutoLogin);
});"

inside (after checkCookieExists();)
if(doc.getElementById('login-form')) {

}
to avoid JS erreurs on non-login pages.

For one week now, i don't have redirect problems anymore.

L.

[nozpheratu]

So I find myself running into this issue again almost a year later. It's definitely something in the sessions.js file as others have said. @lchanouha modifications seems to work for me.