Bug 1026389 - Duplicated login events
Duplicated login events
Status: CLOSED ERRATA
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: ovirt-engine (Show other bugs)
3.2.0
All Linux
medium Severity medium
: ---
: 3.4.0
Assigned To: Ravi Nori
Martin Pavlik
infra
: Reopened
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-11-04 09:35 EST by Julio Entrena Perez
Modified: 2016-02-10 14:25 EST (History)
19 users (show)

See Also:
Fixed In Version: ovirt-3.4.0-alpha1
Doc Type: Bug Fix
Doc Text:
Previously, logging in to the Administration Portal of the Red Hat Enterprise Virtualization Manager resulted in two login events being reported in the Events tab. This was caused by the logic used to authenticate the internal 'admin' user, whereby the first event was triggered by the Administration Portal, and the second event was triggered by the plug-in infrastructure. Now, an audit interval has been created for the login action so that only one login event is reported in the Events tab.
Story Points: ---
Clone Of:
Environment:
Last Closed: 2014-06-09 11:00:39 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Infra
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Duplicated login events (22.46 KB, image/png)
2013-11-14 10:17 EST, Julio Entrena Perez
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 531193 None None None Never
oVirt gerrit 22939 None None None Never

  None (edit)
Description Julio Entrena Perez 2013-11-04 09:35:48 EST
> Description of problem:
When logging in to webadmin portal duplicated login events are created.

> Version-Release number of selected component (if applicable):
rhevm-backend-3.2.4-0.44.el6ev

> How reproducible:
Always.

> Steps to Reproduce:
1. Log in to webadmin portal using admin@internal user.
2. Observe the events list at the botton of the page.

> Actual results:
Two login events show up:

2013-Nov-04, 13:51 User admin@internal logged in.
2013-Nov-04, 13:51 User admin@internal logged in.

> Expected results:
One login event only:

2013-Nov-04, 13:51 User admin@internal logged in.

> Additional info:

https://<rhevm>/api/events shows both login events:

<event href="/api/events/29323" id="29323">
  <description>User admin@internal logged in.</description>
  <code>30</code>
  <severity>normal</severity>
  <time>2013-11-04T13:51:45.952Z</time>
  <user href="/api/users/fdfc627c-d875-11e0-90f0-83df133b58cc" id="fdfc627c-d875-11e0-90f0-83df133b58cc"/>
  <origin>oVirt</origin>
  <custom_id>-1</custom_id>
  <flood_rate>30</flood_rate>
</event>
<event href="/api/events/29322" id="29322">
  <description>User admin@internal logged in.</description>
  <code>30</code><severity>normal</severity>
  <time>2013-11-04T13:51:45.885Z</time>
  <user href="/api/users/fdfc627c-d875-11e0-90f0-83df133b58cc" id="fdfc627c-d875-11e0-90f0-83df133b58cc"/>
  <origin>oVirt</origin>
  <custom_id>-1</custom_id>
  <flood_rate>30</flood_rate>
</event>

engine.log shows the following entries:

2013-11-04 13:51:45,867 INFO  [org.ovirt.engine.core.bll.LoginAdminUserCommand] (ajp-/127.0.0.1:8702-12) Running command: LoginAdminUserCommand internal: false.
2013-11-04 13:51:45,885 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-12) Unable to get value of property: glusterVolume for class org.ovirt.engine.core.bll.LoginAdminUserCommand
2013-11-04 13:51:45,885 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-12) Unable to get value of property: vds for class org.ovirt.engine.core.bll.LoginAdminUserCommand
2013-11-04 13:51:45,940 INFO  [org.ovirt.engine.core.bll.LoginUserCommand] (ajp-/127.0.0.1:8702-9) Running command: LoginUserCommand internal: false.
2013-11-04 13:51:45,952 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-9) Unable to get value of property: glusterVolume for class org.ovirt.engine.core.bll.LoginUserCommand
2013-11-04 13:51:45,952 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-9) Unable to get value of property: vds for class org.ovirt.engine.core.bll.LoginUserCommand
2013-11-04 13:51:45,968 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ApplicationMode) with null version, using default general for version
2013-11-04 13:51:45,969 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (ProductRPMVersion) with null version, using default general for version
2013-11-04 13:51:45,969 WARN  [org.ovirt.engine.core.bll.GetConfigurationValueQuery] (ajp-/127.0.0.1:8702-9) calling GetConfigurationValueQuery (VdcVersion) with null version, using default general for version

Matching the exact timestamp from https://<rhevm>/api/events to the entries in engine log:

  <time>2013-11-04T13:51:45.952Z</time>
  <time>2013-11-04T13:51:45.885Z</time>

would match those from engine.log:

2013-11-04 13:51:45,885 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-12) Unable to get value of property: glusterVolume for class org.ovirt.engine.core.bll.LoginAdminUserCommand
2013-11-04 13:51:45,885 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-12) Unable to get value of property: vds for class 

2013-11-04 13:51:45,952 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-9) Unable to get value of property: glusterVolume for class org.ovirt.engine.core.bll.LoginUserCommand
2013-11-04 13:51:45,952 WARN  [org.ovirt.engine.core.compat.backendcompat.PropertyInfo] (ajp-/127.0.0.1:8702-9) Unable to get value of property: vds for class org.ovirt.engine.core.bll.LoginUserCommand

???
Comment 3 Eli Mesika 2013-11-06 06:01:21 EST
Seems not critical for 3.3.z 
Andrew , can you please recheck and remove the 3.3.z flag if you agree...
Comment 6 Eli Mesika 2013-11-12 08:37:53 EST
This occurs only on the 1st time after app restarts and only from UI 
From API , there is no duplication 
It seems that UI calls backend.login twice (checked with the debugger)
Comment 8 Ravi Nori 2013-11-13 12:27:02 EST
Please refer to BZ 906046

The first event is from Webadmin and the second is from Plugin Infra structure.

Works as intended
Comment 9 Itamar Heim 2013-11-13 20:33:27 EST
Ravi - why it is "intended" to have two login events? can you elaborate on the flow causing this?

thanks,
   Itamar
Comment 10 Ravi Nori 2013-11-14 10:10:18 EST
We are seeing two login events because Webadmin and the plugin infrastructure try to authenticate with backend using the credentials provided at webadmin portal. 

This only occurs on first user login from the webadmin after a server restart.



Here is the complete explanation from the bug 906046 where the issue of multiple login events was fixed

Previously the web browser sent HTTP Authorization headers for all requests to a given origin after the header has already been set for the initial request. This meant the user interface plugin infrastructure acquired a REST API session using web administration portal user credentials including domain and password information, and the session was kept alive until the user signed out of the administration portal.

To work around this issue, all user interface plugins now receive a single shared session ID based on the web administration portal user login credentials. This session times out after six hours, and the administration portal will not attempt to keep this session alive using periodic heartbeat requests. 

The plugin is in charge of keeping its session alive, and if no plugin interacts with the REST API session via the provided ID for more than six hours, the session will time out.
Comment 11 Julio Entrena Perez 2013-11-14 10:17:15 EST
(In reply to Ravi Nori from comment #10)
> This only occurs on first user login from the webadmin after a server
> restart.
Happens in my RHEV environment at every login.

1. Login to webadmin portal: duplicated login events.
2. Logout.
3. Login to webadmin portal again: same outcome, duplicated login events.
Comment 12 Julio Entrena Perez 2013-11-14 10:17:40 EST
Created attachment 824001 [details]
Duplicated login events
Comment 13 Ravi Nori 2013-11-14 11:01:45 EST
Hi Julio, are you able to reproduce this with the latest build?
Comment 14 Julio Entrena Perez 2013-11-14 11:06:14 EST
(In reply to Ravi Nori from comment #13)
> Hi Julio, are you able to reproduce this with the latest build?

Running 3.2.4-0.44.el6ev , is that the latest one?
Comment 16 Ravi Nori 2013-11-14 11:15:06 EST
is23 is the lastest 3.3 

3.3.0-0.33.beta1.el6ev

You can get it from

http://bob.eng.lab.tlv.redhat.com/builds/is23/

Since this is targeted for 3.4 I think we should try reproducing against the latest build we can get.

I reported my findings from current master in #10
Comment 19 Arthur Berezin 2013-12-26 05:04:45 EST
In most common use case UI plugin would use same set of permissions, hence most RHEV setups that would use UI Plugins would get duplicate messages - undesirable state, even that that's the way we implement UI plugins.

Engine should recognise authentication of same user via UI plugin and register only single login event.
Comment 21 Sandro Bonazzola 2014-01-14 03:43:12 EST
ovirt 3.4.0 alpha has been released
Comment 22 Martin Pavlik 2014-02-07 03:07:09 EST
works with  oVirt Engine Version: 3.4.0-0.5.beta1.el6
Comment 37 errata-xmlrpc 2014-06-09 11:00:39 EDT
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHSA-2014-0506.html

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