Hey Guys-
I’ve been chasing down an issue for a while now where users lose their
session and their authlogic user_credential cookie inexplicably.
Apparently there have been some issues reported about Safari and
cookies (http://discussions.info.apple.com/thread.jspa?
messageID=12524941 and others).
I’m posting this to Ruby on Rails: Talk and authlogic google groups
because this does not seem to be a purely authlogic issue as I
witnessed both the session cookie and the authlogic user_credential
cookie disappearing from one request to the next without any
intervention by the app server. Also this may help others who
experience the same issue and hopefully save them hours of debugging.
After upgrading our site from restful authentication to authlogic (and
rails 2 to rails 3), some very reliable users reported that they
experienced issues where they were logged out of their session. The
old server (with restful_authentication) never produced the logouts.
Other users never experienced the issue.
Old Environment: apache, rails 2, ubuntu 10, memcached for sessions,
MySQL, restful authentication, passenger phusion
New Environment: apache, rails 3, ubuntu 10, memcached for sessions,
MySQL, authlogic, passenger phusion
We run both the old and new app on different ports in the same
domain. As a result the cookies for both sites are interleaved. The
old cookie uses a session cookie of _fluxx_session and the new one
uses _session_id.
We’ve been able to successfully reproduce this in Safari by simply
opening a browser window. Then, within a single session, visiting a
number of sites, opening many tabs and in general generating a lot of
session cookies. Simply put, if you use our application in a separate
browser and never visit other sites, the issue never appears. We were
also able to cause session and authlogic cookies to be deleted simply
by setting many session cookies via javascript:
for(i = 0; i < 60; i++){
$.cookie(‘foo’+i, i);
}
I modified the logformat for apache to print out cookies passed along
by the browser. I also wrote a small rack class to printout the
headers and status returned by the app to see if any cookies were
being set. Lastly, I added debug logging to authlogic to output
anytime cookies were deleted.
Here’s a sample of inexplicably losing cookies on our QA server:
24.130.172.154 - - [05/Nov/2010:00:21:51 +0000] “GET /realtime_updates?
last_id=43 HTTP/1.1” 304 - “/dashboard/” “Mozilla/5.0 (Macintosh; U;
Intel Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
user_credentials=f4876ccdeb5248513a9e13a34d6b04af9e1f482fbbef5871a57c2a7fc4e91892a17b8d2384d232dd3079dbd6da43e7c2881589c51c4aae63a01bcda2a46165cc
%3A%3A13329; _session_id=7db2887348b4ebd30861585f3471f13b;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
24.130.172.154 - - [05/Nov/2010:00:22:21 +0000] “GET /realtime_updates?
last_id=43 HTTP/1.1” 304 - “/dashboard/” “Mozilla/5.0 (Macintosh; U;
Intel Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
_session_id=7db2887348b4ebd30861585f3471f13b;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
24.130.172.154 - - [05/Nov/2010:00:22:51 +0000] “GET /realtime_updates?
last_id=43 HTTP/1.1” 304 - “/dashboard/” “Mozilla/5.0 (Macintosh; U;
Intel Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
_session_id=7db2887348b4ebd30861585f3471f13b;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
24.130.172.154 - - [05/Nov/2010:00:23:22 +0000] “GET /realtime_updates?
last_id=43 HTTP/1.1” 304 - “/dashboard/” “Mozilla/5.0 (Macintosh; U;
Intel Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
_session_id=7db2887348b4ebd30861585f3471f13b;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
24.130.172.154 - - [05/Nov/2010:00:23:52 +0000] “GET /realtime_updates?
last_id=43 HTTP/1.1” 304 - “/dashboard/” “Mozilla/5.0 (Macintosh; U;
Intel Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
_session_id=7db2887348b4ebd30861585f3471f13b;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
24.130.172.154 - - [05/Nov/2010:00:24:22 +0000] “GET /realtime_updates?
last_id=43 HTTP/1.1” 302 121 “/dashboard/” “Mozilla/5.0 (Macintosh; U;
Intel Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
24.130.172.154 - - [05/Nov/2010:00:24:22 +0000] “GET /user_sessions/
new HTTP/1.1” 200 1036 “/dashboard/” “Mozilla/5.0 (Macintosh; U; Intel
Mac OS X 10_6_4; en-us) AppleWebKit/533.18.1 (KHTML, like Gecko)
Version/5.0.2 Safari/533.18.5”
“_session_id=c2a9b2ddaa1c0cb9a4c2465c2f6be87c;
_fluxx_session=e8d8f02b0d114b591441f20f8b92e29f;
__utma=105904087.2047678217.1287014277.1287014277.1287377061.2;
__qca=P0-399113251-1287181376898;
__utmz=105904087.1287014277.1.1.utmcsr=(direct)|utmccn=(direct)|
utmcmd=(none)”
Authlogic stores your credentials in your session store, and also
stores a cookie user_credentials which contains the user_id. As long
as one of them remains the user will be authenticated.
- After the first request at 00:21:51 we lose the user_credentials
request - Then at 00:24:22 the _session_id vanishes
- Notice that the _session_id changes on the last request; we lose the
session ID and that’s why the user is redirected to /user_sessions/
new.
Also notice that throughout the old application’s _fluxx_session
remains undisturbed. No idea why it would selectively drop some
cookies but not others within the same domain but that’s
consistent…
Ring any bells folks? Any suggestions?
Thanks much,
Eric