Bugzilla (bugzilla.redhat.com) will be under maintenance for infrastructure upgrades and will not be available on July 31st between 12:30 AM - 05:30 AM UTC. We appreciate your understanding and patience. You can follow status.redhat.com for details.
Bug 1417661 - trying to log in with user admin after timeout on different user will get the UI stuck on login + error on wrong credentials will show in log
Summary: trying to log in with user admin after timeout on different user will get the...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: UI - OPS
Version: 5.7.0
Hardware: x86_64
OS: Linux
high
medium
Target Milestone: GA
: 5.8.0
Assignee: Martin Hradil
QA Contact: Einat Pacifici
URL:
Whiteboard: rbac
Depends On:
Blocks: 1427172
TreeView+ depends on / blocked
 
Reported: 2017-01-30 15:13 UTC by Dafna Ron
Modified: 2018-06-05 11:14 UTC (History)
6 users (show)

Fixed In Version: 5.8.0.2
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1427172 (view as bug list)
Environment:
Last Closed: 2017-06-12 17:13:41 UTC
Category: Bug
Cloudforms Team: CFME Core
Target Upstream Version:


Attachments (Terms of Use)
screenshot (215.56 KB, image/png)
2017-01-30 15:13 UTC, Dafna Ron
no flags Details
cfme logs from pod (7.78 MB, application/x-gzip)
2017-01-31 11:08 UTC, Dafna Ron
no flags Details

Description Dafna Ron 2017-01-30 15:13:40 UTC
Created attachment 1245911 [details]
screenshot

Description of problem:

I was logged in with a user I created to cfme. after about an hour I went back to the cfme and got re-directed to the login screen. 
I tried to log in with the admin user (not the user I was logged in with before) and the UI login page seems to get stuck (see screenshot). 
you can keep on pressing the login button and you would get an authentication error. 
we have to reload the page completely and try to login again for a successful login

Version-Release number of selected component (if applicable):

cfme-5.7.1.0-2.el7cf.x86_64

Please note - this was done on a podfied cfme (don't think it's related but mentioning in case it is) 


How reproducible:

randomly (happened a few times)

Steps to Reproduce:
1. create a user with permission role for compute -> containers and log in
2. let the session time out and get re-directed to the main page for login
3. try to login with admin user

Actual results:

we are not logged in. 
both user and password are greyed out but the login button is available 
when pressing the login button and grepping logs we get an error message in the production log for wrong credentials. 

Expected results:

we should be able to login with a different user after a timeout. 

Additional info:

This was tested on a podfied cfme but I don't think it's related to the fact it's a pod. 

sh-4.2# tail -f * |grep -i error
tail: error reading ‘apache’: Is a directory
tail: apache: cannot follow end of this type of file; giving up on this name


[----] F, [2017-01-30T14:39:56.548995 #1862:19b11fc] FATAL -- : Error caught: [ActionController::InvalidAuthenticityToken] ActionController::InvalidAuthenticityToken
[----] F, [2017-01-30T14:40:00.356234 #1862:19af7d0] FATAL -- : Error caught: [ActionController::InvalidAuthenticityToken] ActionController::InvalidAuthenticityToken
^C



/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/request_forgery_protection.rb:195:in `handle_unverified_request'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/request_forgery_protection.rb:223:in `handle_unverified_request'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/request_forgery_protection.rb:218:in `verify_authenticity_token'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:382:in `block in make_lambda'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:150:in `block (2 levels) in halting_and_conditional'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/callbacks.rb:12:in `block (2 levels) in <module:Callbacks>'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:151:in `block in halting_and_conditional'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:454:in `block in call'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:454:in `each'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:454:in `call'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:101:in `__run_callbacks__'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:750:in `_run_process_action_callbacks'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:90:in `run_callbacks'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/notifications.rb:164:in `block in instrument'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/notifications.rb:164:in `instrument'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal/params_wrapper.rb:248:in `process_action'
/opt/rh/cfme-gemset/gems/activerecord-5.0.0.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/abstract_controller/base.rb:126:in `process'
/opt/rh/cfme-gemset/gems/actionview-5.0.0.1/lib/action_view/rendering.rb:30:in `process'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal.rb:190:in `dispatch'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_controller/metal.rb:262:in `dispatch'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/routing/route_set.rb:32:in `serve'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/journey/router.rb:39:in `block in serve'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/journey/router.rb:26:in `each'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/journey/router.rb:26:in `serve'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/routing/route_set.rb:725:in `call'
/opt/rh/cfme-gemset/gems/secure_headers-3.0.3/lib/secure_headers/middleware.rb:10:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/etag.rb:25:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/conditional_get.rb:38:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/head.rb:12:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/session/abstract/id.rb:222:in `context'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/session/abstract/id.rb:216:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:97:in `__run_callbacks__'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/callbacks.rb:90:in `run_callbacks'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/callbacks.rb:36:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/opt/rh/cfme-gemset/gems/railties-5.0.0.1/lib/rails/rack/logger.rb:36:in `call_app'
/opt/rh/cfme-gemset/gems/railties-5.0.0.1/lib/rails/rack/logger.rb:26:in `call'
/opt/rh/cfme-gemset/gems/request_store-1.3.2/lib/request_store/middleware.rb:9:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/request_id.rb:24:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/method_override.rb:22:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/runtime.rb:22:in `call'
/opt/rh/cfme-gemset/gems/activesupport-5.0.0.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
/opt/rh/cfme-gemset/gems/actionpack-5.0.0.1/lib/action_dispatch/middleware/executor.rb:12:in `call'
/opt/rh/cfme-gemset/gems/rack-2.0.1/lib/rack/sendfile.rb:111:in `call'
/opt/rh/cfme-gemset/gems/railties-5.0.0.1/lib/rails/engine.rb:522:in `call'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/configuration.rb:224:in `call'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:561:in `handle_request'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:406:in `process_client'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/server.rb:271:in `block in run'
/opt/rh/rh-ruby23/root/usr/share/gems/gems/puma-3.3.0/lib/puma/thread_pool.rb:111:in `block in spawn_thread'
[----] I, [2017-01-30T14:39:56.549811 #1862:19b11fc]  INFO -- :   Rendered layouts/_exception_contents.html.haml (0.1ms)
[----] I, [2017-01-30T14:39:56.550244 #1862:19b11fc]  INFO -- : Completed 200 OK in 2ms (Views: 0.9ms | ActiveRecord: 0.0ms)
[----] I, [2017-01-30T14:39:59.764846 #1875:19a3e58]  INFO -- : Started DELETE "/api/auth" for 127.0.0.1 at 2017-01-30 14:39:59 +0000
[----] I, [2017-01-30T14:39:59.766581 #1875:19a3e58]  INFO -- : Processing by Api::AuthController#destroy as JSON
[----] I, [2017-01-30T14:39:59.775363 #1875:199c874]  INFO -- : Started GET "/api/auth?requester_type=ui" for 127.0.0.1 at 2017-01-30 14:39:59 +0000
[----] I, [2017-01-30T14:39:59.780167 #1875:199c874]  INFO -- : Processing by Api::AuthController#show as JSON
[----] I, [2017-01-30T14:39:59.780272 #1875:199c874]  INFO -- :   Parameters: {"requester_type"=>"ui"}
[----] I, [2017-01-30T14:39:59.875674 #1875:19a3e58]  INFO -- : Completed 204 No Content in 109ms (ActiveRecord: 0.0ms)
[----] I, [2017-01-30T14:39:59.966945 #1875:199c874]  INFO -- : Completed 200 OK in 187ms (Views: 0.2ms | ActiveRecord: 0.0ms)
[----] I, [2017-01-30T14:40:00.125264 #1875:199e138]  INFO -- : Started GET "/api/auth?requester_type=ws" for 127.0.0.1 at 2017-01-30 14:40:00 +0000
[----] I, [2017-01-30T14:40:00.128136 #1875:199e138]  INFO -- : Processing by Api::AuthController#show as JSON
[----] I, [2017-01-30T14:40:00.128605 #1875:199e138]  INFO -- :   Parameters: {"requester_type"=>"ws"}
[----] I, [2017-01-30T14:40:00.147380 #1875:199e138]  INFO -- : Completed 200 OK in 19ms (Views: 0.3ms | ActiveRecord: 0.0ms)
[----] I, [2017-01-30T14:40:00.315976 #1862:19ac92c]  INFO -- : Started GET "/" for 127.0.0.1 at 2017-01-30 14:40:00 +0000
[----] I, [2017-01-30T14:40:00.317443 #1862:19ac92c]  INFO -- : Processing by DashboardController#login as HTML
[----] I, [2017-01-30T14:40:00.318935 #1862:19b0734]  INFO -- : Started GET "/" for 127.0.0.1 at 2017-01-30 14:40:00 +0000
[----] I, [2017-01-30T14:40:00.320645 #1862:19b0734]  INFO -- : Processing by DashboardController#login as HTML
[----] I, [2017-01-30T14:40:00.341831 #1862:19ac92c]  INFO -- :   Rendering dashboard/login.html.haml within layouts/login
[----] I, [2017-01-30T14:40:00.344980 #1862:19af7d0]  INFO -- : Started POST "/dashboard/authenticate?button=login" for 127.0.0.1 at 2017-01-30 14:40:00 +0000
[----] I, [2017-01-30T14:40:00.348110 #1862:19af7d0]  INFO -- : Processing by DashboardController#authenticate as JS
[----] I, [2017-01-30T14:40:00.348334 #1862:19af7d0]  INFO -- :   Parameters: {"user_name"=>"admin", "user_password"=>"[FILTERED]", "browser_name"=>"Firefox", "browser_version"=>"38", "browser_os"=>"Linux", "user_TZO"=>"0", "button"=>"login"}
[----] I, [2017-01-30T14:40:00.352007 #1862:19ac92c]  INFO -- :   Rendered layouts/_spinner.html.haml (9.0ms)
[----] I, [2017-01-30T14:40:00.352470 #1862:19ac92c]  INFO -- :   Rendered layouts/_flash_msg.html.haml (0.1ms)
[----] I, [2017-01-30T14:40:00.353074 #1862:19ac92c]  INFO -- :   Rendered dashboard/_login_more.html.haml (0.1ms)
[----] W, [2017-01-30T14:40:00.355938 #1862:19af7d0]  WARN -- : Can't verify CSRF token authenticity.
[----] F, [2017-01-30T14:40:00.356234 #1862:19af7d0] FATAL -- : Error caught: [ActionController::InvalidAuthenticityToken] ActionController::InvalidAuthenticityToken

Comment 2 Dafna Ron 2017-01-31 11:08:57 UTC
Created attachment 1246177 [details]
cfme logs from pod

I reproduced again and have logs - attached.

Comment 3 Martin Hradil 2017-02-24 14:36:45 UTC
I believe this god fixed by https://github.com/ManageIQ/manageiq-ui-classic/pull/451 - removing the CSRF token check on the login screen.

Comment 6 Dafna Ron 2017-04-03 14:38:47 UTC
verified on cfme-gemset-5.7.2.0-1.el7cf.x86_64

Comment 7 Dafna Ron 2017-04-03 14:39:22 UTC
sorry, wrong, bug 
verified on cfme-5.8.0.8-alpha1.1.el7cf.x86_64


Note You need to log in before you can comment on or make changes to this bug.