search

heartcombo / devise

Flexible authentication solution for Rails with Warden.
http://blog.plataformatec.com.br/tag/devise/
MIT License
23.83k stars 5.54k forks source link

Devise sessions inadvertently destroyed in production mode #2817

Closed herman5 closed 10 years ago

herman5 commented 10 years ago

After successfully logging in to my rails application in production mode, I will attempt to click on one of the filter buttons at the top of the table: 'All Servers', 'In Progress', or 'Remediation.' After pressing one of these buttons, the session will be destroyed and redirect the user back to the login page; however, this does not occur in the development environment. In the dev environment, when the user presses one of the filter buttons, the proper scope is applied and no redirection occurs.

After comparing the production logs to the development logs, the error appears to manifest in Devise::SessionsController#new

I have the application hosted on Heroku, so the effects can be seen.

URL: http://testdomain.dcmdashboard.com

email: moderator@example.com

password: password

After logging in and pressing a filter button (GET "/?order=id_desc&page=1&scope=in_progress") in the dev environment:

Started POST "/users/sign_in" for 127.0.0.1 at 2013-12-29 19:40:15 -0600
Processing by Devise::SessionsController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"UmLj+rzYzRWPr/Y7G5q2Y+/6KptI6X1EzoE7xJCjCIQ=", "user"=>{"email"=>"moderator@example.com", "password"=>"[FILTERED]", "remember_me"=>"0"}, "commit"=>"Sign in"}
  Tenant Load (1.4ms)  SELECT "tenants".* FROM "tenants" WHERE "tenants"."subdomain" = 'testdomain' LIMIT 1
  User Load (1.7ms)  SELECT "users".* FROM "users" WHERE "users"."email" = 'moderator@example.com' LIMIT 1
   (1.6ms)  BEGIN
   (2.5ms)  UPDATE "users" SET "last_sign_in_at" = '2013-12-30 00:14:55.058879', "current_sign_in_at" = '2013-12-30 01:40:15.445913', "sign_in_count" = 3, "updated_at" = '2013-12-30 01:40:15.450781' WHERE "users"."id" = 3
   (1.6ms)  COMMIT
Redirected to http://testdomain.warthog.dev/admin
Completed 302 Found in 131ms (ActiveRecord: 1.0ms)

Started GET "/admin" for 127.0.0.1 at 2013-12-29 19:40:15 -0600
Processing by Admin::ServersController#index as HTML
  Tenant Load (1.7ms)  SELECT "tenants".* FROM "tenants" WHERE "tenants"."subdomain" = 'testdomain' LIMIT 1
  User Load (32.2ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 3 LIMIT 1
   (2.8ms)  SELECT COUNT(*) FROM "servers" WHERE ('t')
   (2.5ms)  SELECT COUNT(*) FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA')
   (4.0ms)  SELECT COUNT(*) FROM "servers" WHERE (build_stage = '7 - Build Team Remediation' OR build_stage = '13 - SecOps Remediation')
   (2.4ms)  SELECT COUNT(count_column) FROM (SELECT 1 AS count_column FROM "servers" LIMIT 30 OFFSET 0) subquery_for_count
  CACHE (0.0ms)  SELECT COUNT(count_column) FROM (SELECT 1 AS count_column FROM "servers" LIMIT 30 OFFSET 0) subquery_for_count
   (2.6ms)  SELECT COUNT(*) FROM "servers"
  CACHE (0.0ms)  SELECT COUNT(count_column) FROM (SELECT 1 AS count_column FROM "servers" LIMIT 30 OFFSET 0) subquery_for_count
  Server Load (2.6ms)  SELECT "servers".* FROM "servers" ORDER BY "servers"."id" desc LIMIT 30 OFFSET 0
  Rendered /Users/Dylan/.rvm/gems/ruby-1.9.3-p392/bundler/gems/active_admin-ec9996406df5/app/views/active_admin/resource/index.html.arb (354.6ms)
Completed 200 OK in 403ms (Views: 342.4ms | ActiveRecord: 54.0ms)

Started GET "/assets/jquery.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:15 -0600

Started GET "/assets/jquery_ujs.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:15 -0600
Served asset /jquery.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/lib/namespace.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:15 -0600
Served asset /jquery_ujs.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.checkbox-toggler.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:15 -0600
Served asset /active_admin/components/jquery.aa.checkbox-toggler.js - 304 Not Modified (0ms)
Served asset /active_admin/lib/namespace.js - 304 Not Modified (0ms)

Started GET "/assets/jquery-ui.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:15 -0600

Started GET "/assets/active_admin/components/jquery.aa.dropdown-menu.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:15 -0600
Served asset /jquery-ui.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.table-checkbox-toggler.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin/components/jquery.aa.dropdown-menu.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.popover.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin/components/jquery.aa.table-checkbox-toggler.js - 304 Not Modified (4ms)

Started GET "/assets/active_admin/pages/batch_actions.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin/components/jquery.aa.popover.js - 304 Not Modified (5ms)

Started GET "/assets/active_admin/pages/application.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin/pages/batch_actions.js - 304 Not Modified (4ms)
Served asset /active_admin/pages/application.js - 304 Not Modified (3ms)

Started GET "/assets/active_admin/application.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin/application.js - 304 Not Modified (9ms)

Started GET "/assets/active_admin/base.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin/base.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:16 -0600
Served asset /active_admin.js - 304 Not Modified (0ms)

Started GET "/?order=id_desc&page=1&scope=in_progress" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
  User Load (1.2ms)  SELECT "users".* FROM "users" WHERE "users"."id" = 3 LIMIT 1
Processing by Admin::ServersController#index as HTML
  Parameters: {"order"=>"id_desc", "page"=>"1", "scope"=>"in_progress"}
  Tenant Load (2.4ms)  SELECT "tenants".* FROM "tenants" WHERE "tenants"."subdomain" = 'testdomain' LIMIT 1
   (2.6ms)  SELECT COUNT(*) FROM "servers" WHERE ('t')
   (4.3ms)  SELECT COUNT(*) FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA')
   (2.8ms)  SELECT COUNT(*) FROM "servers" WHERE (build_stage = '7 - Build Team Remediation' OR build_stage = '13 - SecOps Remediation')
   (2.3ms)  SELECT COUNT(count_column) FROM (SELECT 1 AS count_column FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA') LIMIT 30 OFFSET 0) subquery_for_count
  CACHE (0.0ms)  SELECT COUNT(count_column) FROM (SELECT 1 AS count_column FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA') LIMIT 30 OFFSET 0) subquery_for_count
  CACHE (0.0ms)  SELECT COUNT(*) FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA')
  CACHE (0.0ms)  SELECT COUNT(count_column) FROM (SELECT 1 AS count_column FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA') LIMIT 30 OFFSET 0) subquery_for_count
  Server Load (2.6ms)  SELECT "servers".* FROM "servers" WHERE (build_stage = '2 - In Progress' OR build_stage = '4 - Build Team QA') ORDER BY "servers"."id" desc LIMIT 30 OFFSET 0
  Rendered /Users/Dylan/.rvm/gems/ruby-1.9.3-p392/bundler/gems/active_admin-ec9996406df5/app/views/active_admin/resource/index.html.arb (359.3ms)
Completed 200 OK in 373ms (Views: 349.4ms | ActiveRecord: 19.5ms)

Started GET "/assets/jquery.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600

Started GET "/assets/jquery-ui.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /jquery-ui.js - 304 Not Modified (0ms)

Started GET "/assets/jquery_ujs.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /jquery_ujs.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.checkbox-toggler.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/components/jquery.aa.checkbox-toggler.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.popover.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/components/jquery.aa.popover.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/pages/application.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/pages/application.js - 304 Not Modified (0ms)
Served asset /jquery.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/application.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600

Started GET "/assets/active_admin/lib/namespace.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/application.js - 304 Not Modified (0ms)
Served asset /active_admin/lib/namespace.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.dropdown-menu.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/components/jquery.aa.dropdown-menu.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/components/jquery.aa.table-checkbox-toggler.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/components/jquery.aa.table-checkbox-toggler.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/pages/batch_actions.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/pages/batch_actions.js - 304 Not Modified (0ms)

Started GET "/assets/active_admin/base.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin/base.js - 304 Not Modified (12ms)

Started GET "/assets/active_admin.js?body=1" for 127.0.0.1 at 2013-12-29 19:40:26 -0600
Served asset /active_admin.js - 304 Not Modified (0ms)

After logging in and pressing the filter button (GET "/?order=id_desc&page=1&scope=in_progress") in the production environment:

Started POST "/users/sign_in" for 127.0.0.1 at 2013-12-29 19:47:10 -0600
Processing by Devise::SessionsController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"UmLj+rzYzRWPr/Y7G5q2Y+/6KptI6X1EzoE7xJCjCIQ=", "user"=>{"email"=>"moderator@example.com", "password"=>"[FILTERED]", "remember_me"=>"0"}, "commit"=>"Sign in"}
Redirected to http://testdomain.warthog.dev/admin
Completed 302 Found in 116ms (ActiveRecord: 1.8ms)
Started GET "/admin" for 127.0.0.1 at 2013-12-29 19:47:11 -0600
Processing by Admin::ServersController#index as HTML
  Rendered /Users/Dylan/.rvm/gems/ruby-1.9.3-p392/bundler/gems/active_admin-ec9996406df5/app/views/active_admin/resource/index.html.arb (115.1ms)
Completed 200 OK in 126ms (Views: 97.7ms | ActiveRecord: 24.6ms)
Started GET "/?order=id_desc&page=1&scope=in_progress" for 127.0.0.1 at 2013-12-29 19:47:23 -0600
Processing by Devise::SessionsController#new as HTML
  Parameters: {"order"=>"id_desc", "page"=>"1", "scope"=>"in_progress"}
  Rendered devise/shared/_links.haml (0.3ms)
  Rendered devise/sessions/new.html.haml within layouts/application (3.2ms)
Completed 200 OK in 14ms (Views: 7.2ms | ActiveRecord: 4.4ms)
josevalim commented 10 years ago

Thanks but there isn't much we can do without taking a look at the application. Can you provide a sample application that reproduces the error? :)

herman5 commented 10 years ago

Absolutely! As stated above I have the application hosted on Heroku :-)

URL: http://testdomain.dcmdashboard.com

email: moderator@example.com

password: password

josevalim commented 10 years ago

I checked that application linked but I couldn't find anything from external. We need to check the source, debug, access the logs. That's why we need a sample application that reproduces the error.

herman5 commented 10 years ago

Sorry for the misunderstanding. I've made the repository public and it can be found at https://github.com/herman5/warthog

seanlinsley commented 10 years ago

@herman5 opened a duplicate ticket for Active Admin: https://github.com/gregbell/active_admin/issues/2839

I'd suggest closing this ticket, as it's much more likely to be AA's problem.