Bug 1026389

Summary: Duplicated login events
Product: Red Hat Enterprise Virtualization Manager Reporter: Julio Entrena Perez <jentrena>
Component: ovirt-engineAssignee: Ravi Nori <rnori>
Status: CLOSED ERRATA QA Contact: Martin Pavlik <mpavlik>
Severity: medium Docs Contact:
Priority: medium    
Version: 3.2.0CC: aberezin, acathrow, adahms, akotov, bazulay, emesika, flo_bugzilla, iheim, jentrena, lpeer, mpavlik, pablo.iranzo, pep, pstehlik, Rhev-m-bugs, rnori, vszocs, yeylon
Target Milestone: ---Keywords: Reopened
Target Release: 3.4.0   
Hardware: All   
OS: Linux   
Whiteboard: infra
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 15:00:39 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Duplicated login events none

Description Julio Entrena Perez 2013-11-04 14:35:48 UTC
> 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 11:01:21 UTC
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 13:37:53 UTC
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 17:27:02 UTC
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-14 01:33:27 UTC
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 15:10:18 UTC
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 15:17:15 UTC
(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 15:17:40 UTC
Created attachment 824001 [details]
Duplicated login events

Comment 13 Ravi Nori 2013-11-14 16:01:45 UTC
Hi Julio, are you able to reproduce this with the latest build?

Comment 14 Julio Entrena Perez 2013-11-14 16:06:14 UTC
(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 16:15:06 UTC
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 10:04:45 UTC
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 08:43:12 UTC
ovirt 3.4.0 alpha has been released

Comment 22 Martin Pavlik 2014-02-07 08:07:09 UTC
works with  oVirt Engine Version: 3.4.0-0.5.beta1.el6

Comment 37 errata-xmlrpc 2014-06-09 15:00:39 UTC
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