Bug 1271252

Summary: virt-who is sending every 15 minutes instead of configured every hour
Product: Red Hat Enterprise Linux 7 Reporter: Peter Vreman <peter.vreman>
Component: virt-whoAssignee: Radek Novacek <rnovacek>
Status: CLOSED ERRATA QA Contact: Eko <hsun>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.2CC: andrewrpalmer, bkearney, dgupte, greartes, hsun, kcleveng, mlinden, ovasik, parmstro, rnovacek, sgao, shihliu
Target Milestone: rcKeywords: Reopened
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: virt-who-0.17-1.el7 Doc Type: No Doc Update
Doc Text:
undefined
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-04 05:06:21 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1122832    

Description Peter Vreman 2015-10-13 13:38:06 UTC
Description of problem:
I have configured virt-who to send the host mapping every hour:

$ sudo grep 'VIRTWHO_' /etc/sysconfig/virt-who
VIRTWHO_BACKGROUND=1
VIRTWHO_DEBUG=1
VIRTWHO_INTERVAL=3600

Instead of every hour (3600 seconds) it sends it every 15 minutes (900 seconds). In the rhsm.log it can even been seen that it has found the correct value of 3600. But somehow it does not use it:

Another strange is that it sends the information twice.

$ grep -E '2015-10-13 1[1-4].*(Starting|Sending)' /var/log/rhsm/rhsm.log
2015-10-13 11:42:59,383 [DEBUG]  @virtwho.py:152 - Starting infinite loop with 3600 seconds interval
2015-10-13 11:43:11,935 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 11:43:27,225 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 11:58:12,122 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 11:58:34,409 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:13:12,456 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:13:27,199 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:28:12,843 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:28:27,452 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:43:13,166 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:43:16,252 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:58:13,494 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 12:58:26,358 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 13:13:13,836 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 13:13:27,101 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 13:28:14,216 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2015-10-13 13:28:27,394 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {


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


How reproducible:


Steps to Reproduce:
1. Configure virt-who interval of 3600
2. Check rhsm.log
3.

Actual results:
Virt-who sends every 15 minutes

Expected results:
Virt-who sends every 1 hour as configured


Additional info:

Comment 1 Peter Vreman 2015-10-13 13:50:00 UTC
The sending of the information twice was a configuration mistake. Both the new style /etc/virt-who.d and the legacy environment variables were defined.
After removing the legacy environment variables it is now send only once

Comment 2 Bryan Kearney 2015-10-13 17:43:41 UTC
Based on Comemnt 1, closing this out.

Comment 3 Peter Vreman 2015-10-14 07:05:54 UTC
Re-opening the comment 1 was only about second remark of the duplicate sending. 

The interval being 15minutes instead of 60minutes is still the issue, even with only 1 ESX server defined:

# grep hypervisors_update /var/log/foreman/production.log
2015-10-14 03:42:00 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 03:57:01 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 04:12:01 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 04:27:01 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 04:42:02 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 04:57:02 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 05:12:02 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 05:27:02 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 05:42:03 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 05:57:03 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 06:12:03 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 06:27:04 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 06:42:04 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON
2015-10-14 06:57:04 [I] Processing by Katello::Api::Rhsm::CandlepinProxiesController#hypervisors_update as JSON

Comment 4 Bryan Kearney 2015-10-15 19:30:39 UTC
Moving to the virt-who component.

Comment 7 Radek Novacek 2016-04-21 11:28:53 UTC
Upstream virt-who (that will get to 7.3 by rebase) is now sending host/guest association to candlepin only when it changes. The interval now only determines how often should virt-who look for changes in hypervisors.

There is also a rate-limit that will throttle reports going to candlepin which should also reduce the load.

Comment 8 Radek Novacek 2016-05-17 13:03:20 UTC
Fixed in virt-who-0.17-1.el7.

Comment 10 Peter Vreman 2016-05-18 07:54:51 UTC
We are using RHEL6.8. How about RHEL6 virt-who?

Comment 11 Radek Novacek 2016-05-19 06:37:36 UTC
Peter, this should be already fixed in RHEL-6.8. The fix there is the same as in RHEL-7:

Upstream virt-who is now sending host/guest association to candlepin only when it changes. The interval now only determines how often should virt-who look for changes in hypervisors.

There is also a rate-limit that will throttle reports going to candlepin which should also reduce the load.

Comment 12 Peter Vreman 2016-05-19 07:33:58 UTC
Confirmed it is fixed in RHEL6.8. Below is my log of sending of the hosts-to-guests, after the upgrade to RHEl6.8 there was only 3 times an update being send instead of every 15 minutes:

2016-05-17 11:21:53,501 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 11:36:53,875 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 11:51:54,262 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 12:06:54,647 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 12:11:14,571 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 12:26:14,903 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 12:41:15,234 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 12:56:15,546 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 13:11:15,914 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 13:25:43,886 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 13:28:19,524 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 13:33:46,036 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 13:48:19,905 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 13:56:06,391 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {
2016-05-17 14:11:06,700 [INFO]  @subscriptionmanager.py:146 - Sending update in hosts-to-guests mapping: {

<<< Upgrade to RHEL6.8 >>>>>
$ sudo grep virt-who /var/log/yum.log
May 17 14:14:27 Updated: virt-who-0.16-8.el6.noarch

2016-05-17 14:15:50,043 [INFO]  @subscriptionmanager.py:185 - Sending update in hosts-to-guests mapping for config "li-vcenterd01.hilti.com": 4 hypervisors and 117 guests found
2016-05-18 09:49:02,682 [INFO]  @subscriptionmanager.py:185 - Sending update in hosts-to-guests mapping for config "li-vcenterd01.hilti.com": 4 hypervisors and 117 guests found
2016-05-18 10:00:42,509 [INFO]  @subscriptionmanager.py:185 - Sending update in hosts-to-guests mapping for config "li-vcenterd01.hilti.com": 4 hypervisors and 117 guests found

Comment 16 Radek Novacek 2016-06-02 14:06:08 UTC
That should work if they don't need updates in the meantime. I'm not aware of any other workaround.

Comment 17 Liushihui 2016-06-06 07:58:36 UTC
Verified it on virt-who-0.17-2.el7.noarch since virt-who can refresh host/guest association as configure interval(every 1 hour). Therefore, verify it.

Verified version:
virt-who-0.17-2.el7.noarch
subscription-manager-1.17.6-1.el7.x86_64
python-rhsm-1.17.2-1.el7.x86_64

Verified process:
1. register system to satellite6.2
2. Configure virt-who run at esx mode and refresh interval is 3600s
[root@dell-per920-02 ~]# cat /etc/sysconfig/virt-who  | grep -v ^# | grep -v ^$
VIRTWHO_DEBUG=1
VIRTWHO_INTERVAL=3600

[root@dell-per920-02 ~]# cat /etc/virt-who.d/virt 
[test-esx1]
type=esx
server=10.73.2.95
username=Administrator
password=Welcome1!
owner=ACME_Corporation
env=Library
3. Restart virt-who service and check virt-who's log after 1h.
2016-06-02 01:55:20,184 [virtwho.test-esx1 DEBUG] Esx-1(86984):MainThread @virt.py:enqueue:357 - Report for config "test-esx1" gathered, putting to queue for sending
2016-06-02 01:55:20,204 [virtwho.main DEBUG] MainProcess(86977):MainThread @subscriptionmanager.py:_connect:123 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2016-06-02 01:55:22,013 [virtwho.main DEBUG] MainProcess(86977):MainThread @subscriptionmanager.py:hypervisorCheckIn:171 - Checking if server has capability 'hypervisor_async'
2016-06-02 01:55:23,817 [virtwho.main DEBUG] MainProcess(86977):MainThread @subscriptionmanager.py:hypervisorCheckIn:183 - Server does not have 'hypervisors_async' capability
2016-06-02 01:55:23,818 [virtwho.main INFO] MainProcess(86977):MainThread @subscriptionmanager.py:hypervisorCheckIn:194 - Sending update in hosts-to-guests mapping for config "test-esx1": 2 hypervisors and 1 guests found
2016-06-02 01:55:23,818 [virtwho.main DEBUG] MainProcess(86977):MainThread @subscriptionmanager.py:hypervisorCheckIn:195 - Host-to-guest mapping: {
    "3e504d56-3982-037b-f3e6-669289892fa1": [
        {
            "guestId": "4206405a-4133-bd0c-f8a5-9c7bc1355837", 
            "state": 1, 
            "attributes": {
                "active": 1, 
                "virtWhoType": "esx"
            }
        }
    ], 
    "60554d56-20cb-f25e-7ab9-33e7e330dc15": []
}
2016-06-02 01:55:25,917 [virtwho.main DEBUG] MainProcess(86977):MainThread @executor.py:send_report:101 - Report for config "test-esx1" sent

===============After 1h, virt-who check mapping info================
2016-06-02 02:55:20,428 [virtwho.test-esx1 DEBUG] Esx-1(86984):MainThread @virt.py:enqueue:357 - Report for config "test-esx1" gathered, putting to queue for sending
2016-06-02 02:55:20,434 [virtwho.main INFO] MainProcess(86977):MainThread @executor.py:run:250 - Report for config "test-esx1" hasn't changed, not sending

Result:
virt-who won't refresh every 15mins, it refresh host/guest association every 1 hour.

Comment 21 Peter Vreman 2016-10-14 15:32:32 UTC
Confirmed that sending only updates to sat6 when changes are there is working in RHEL7.2

2016-10-14 14:02:51,817 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 14:02:51,852 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 14:02:51,881 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 14:02:51,912 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 14:02:51,943 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 14:17:58,374 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 14:21:19,203 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending
2016-10-14 15:21:19,206 [INFO] @executor.py:250 - Report for config "Library::li-vcenterd01.hilti.com" hasn't changed, not sending

Comment 23 errata-xmlrpc 2016-11-04 05:06:21 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.

https://rhn.redhat.com/errata/RHBA-2016-2387.html