Created attachment 1295704 [details] engine log Description of problem: Event log and engine spammed with 'User admin@internal-authz logged in/out' info messages. The event log ui and engine log are spammed with info event messages about user admin logged in and out every 20 to 50 minutes. The events are followed as 3 messages about user admin logged in then 3 messages as user admin logged out. The messages appears when no user admin was logged in the session. Something triggers those messages info events, not sure what. Version-Release number of selected component (if applicable): 4.1.4-0.2.el7 How reproducible: 100% on 4.1.4-0.2.el7 Steps to Reproduce: 1. Just log in the webadmin and check the log event ui or check for engine log
Created attachment 1295705 [details] screenshot
I see this behaviour on the latest master as well - 4.2.0-0.0.master.20170709165327.gitfd2334b.el7.centos
Thinking about it, those rhv-m engines are running in CFME(5.8.1) as 'Infrastructure Providers', so maybe it now make sense from where all of those log in and out messages event are coming, the question is this is expected? Is something like that is expected - Jul 10, 2017, 8:23:09 AM User admin@internal-authz logged out. Jul 10, 2017, 8:23:09 AM User admin@internal-authz logged out. Jul 10, 2017, 8:23:08 AM User admin@internal-authz logged out. Jul 10, 2017, 8:05:52 AM User admin@internal-authz logged out. Jul 10, 2017, 8:05:52 AM User admin@internal-authz logged out. Jul 10, 2017, 8:05:52 AM User admin@internal-authz logged out.
As part of the provider work we do login/logout. We do use the same session for some cases, but not for all of them. Juan - I guess that is expected, but please take a look and let me know whether I'm wrong.
(In reply to Oved Ourfali from comment #4) > As part of the provider work we do login/logout. > We do use the same session for some cases, but not for all of them. > > Juan - I guess that is expected, but please take a look and let me know > whether I'm wrong. I guess as well, but i don't think that the same event should be printed 3 times for log in and 3 times for log out(it's confusing).
It is not the same event printed three times, but three different events. The reason is probably the CFME provider is logging in multiple times instead of reusing the authentication session. Michael, can you please check the /var/log/httpd/ssl_access_log file corresponding to the time of those events? It should reflect the API activity, and will help us determine if those events are really triggered by CFME.
Created attachment 1295727 [details] /var/log/httpd/ssl_access_log
(In reply to Michael Burman from comment #5) > (In reply to Oved Ourfali from comment #4) > > As part of the provider work we do login/logout. > > We do use the same session for some cases, but not for all of them. > > > > Juan - I guess that is expected, but please take a look and let me know > > whether I'm wrong. > > I guess as well, but i don't think that the same event should be printed 3 > times for log in and 3 times for log out(it's confusing). AFAIK we don't print the same message 3 times, so most probably it's 3 different sessions for the same user. We show client IP or database session id inside Sessions tab in webadmin, so we could probably add more info about each logged-out session (maybe some unique session ID which could be visible in both webadmin and logs). Ravi, what do you think?
Looking at the logs I see that all the API access come from the same IP address, and the requests match what CFME does. A normal installation of CFME creates three different workers to handle the integration with RHV: * One worker that performs the inventory refresh. * One worker that catches events. * One worker that collects metrics. In the CFME architecture each of these workers is a separate Ruby process. The 'ovirt' Ruby gem that we currently use to talk to RHV stores in a global variable the authentication session id, and renews it when it expires in the RHV side. Processes don't share global variables. This means that each of the three workers will need to log-in to renew the session id when the session expires in the RHV side. That explains the three consecutive long-in events that you see. So these events are normal, and not a regression, in my opinion. If we want to avoid them we can devise a mechanism to share the session between the workers that need it. This could be achieved in the CFME side storing the session id in the database, or in memcached, instead of using global variables. Alternatively we could consider a mechanism for the RHV administrator to mute events based on certain rules, for example to ignore the login/logout events coming from the CFME IP address. (Note that when using version 4 of the API instead of version 3 the same will apply, but to the SSO token instead of to the session id.)
Personally I don't think it's an issue for CFME to use 3 sessions per engine, so the only issue is that having 3 same logging messages is confusing. So let's add some differentiation to the logging message so admin will know that those were 3 different sessions. Based on above removing regression keyword and targeting to 4.2 as it should be an easy fix
Verified in ovirt-engine-webadmin-portal-4.2.0-0.0.master.20171029154613.git19686f3.el7.centos.noarch ovirt-engine-4.2.0-0.0.master.20171029154613.git19686f3.el7.centos.noarch As per comment 11, the login/logout messages now contain the client IP and session ID: User admin@internal-authz connecting from '<IP>' using session '<SESSION_ID>' logged in. User admin@internal-authz connected from '<IP>' using session '<SESSION_ID>' logged out. See attached screenshot for more details.
Created attachment 1345524 [details] screen: enhanced login/logout event messages
This bugzilla is included in oVirt 4.2.0 release, published on Dec 20th 2017. Since the problem described in this bug report should be resolved in oVirt 4.2.0 release, published on Dec 20th 2017, it has been closed with a resolution of CURRENT RELEASE. If the solution does not work for you, please open a new bug report.