Bug 1281715 - running virt-who in big vmware environments results in to fast growing logfiles
running virt-who in big vmware environments results in to fast growing logfiles
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: virt-who (Show other bugs)
6.8
All All
medium Severity medium
: pre-dev-freeze
: 6.8
Assigned To: Radek Novacek
gaoshang
:
Depends On:
Blocks: 1296845 1292736 1355624
  Show dependency treegraph
 
Reported: 2015-11-13 04:20 EST by Christian Horn
Modified: 2016-11-30 19:36 EST (History)
11 users (show)

See Also:
Fixed In Version: virt-who-0.16-1.el6
Doc Type: Bug Fix
Doc Text:
Previously, virt-who was very verbose when writing to its log file. As a result, the log file grew very quickly, especially in large environments. Now, virt-who logs significantly less information in non-debug mode, and the log file thus grows slower.
Story Points: ---
Clone Of:
: 1292736 1355624 (view as bug list)
Environment:
Last Closed: 2016-05-10 19:56:45 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 2049753 None None None Never

  None (edit)
Description Christian Horn 2015-11-13 04:20:59 EST
Description of problem:

A first customer is hitting some new limits here with running virt-who 0.14-1.el7sat against a VCenter with about 600 ESXi hosts and 6500 VMs. 
While this seems to work fine after implementing 
https://access.redhat.com/solutions/2048593, we see our logs fill up pretty quickly on both the machine where virt-who is running and the Satellite.

On the virt-who machine it's /var/log/rhsm/rhsm.log which grows around 50MB/h.
On the Satellite it's /var/log/foreman/production.log which is growing at the same rate.
Both logs include the *whole* JSON dump of virt-who data on each submit run. As these runs are triggered by ESXi API events, they happen pretty often in our environment, resulting in the above mentioned log increase.

I did not see a good way in virt-who or subscription-manager
to restrict this logging.  

Version-Release number of selected component (if applicable):
virt-who 0.14-1.el7sat

How reproducible:
always

Steps to Reproduce:
1. run virt-who in an environment with 600 ESXi hosts and 6500 VMs or more

Additional info:
- should the JSON be only printed in debug mode?  Currently its printed always.
- should virt-who have some kind of threshold to not submit such big chunks every minute.
- workaround exists in running logrotate (much) more often
Comment 2 Radek Novacek 2015-11-16 04:33:55 EST
I think it would be reasonable to limit number of VM infos logged without the debug enabled.

My suggestion is change the logging format a bit:
* without the DEBUG enabled, log something like this:
[INFO] Sending update in hosts-to-guests mapping: 4 hypervisor with 42 guest found
* with the DEBUG enabled, next log entry with appear containing whole host-to-guest association JSON (basically the same we have now in the INFO entry)

This will reduce the log file size without DEBUG enabled significantly. And for debugging purposes full JSON can be enabled.

You you agree with this solution? Suggestions are welcome.
Comment 3 Radek Novacek 2015-11-16 04:34:56 EST
Moving this bug to the virt-who component.
Comment 5 Christian Horn 2015-11-16 05:13:28 EST
Looks good to me.  The current logging is way to verbose for "actually debug is disabled in config".
Comment 6 Marcel Gazdík 2015-11-16 08:50:40 EST
Yep, this looks good.
Comment 7 Radek Novacek 2015-12-08 07:56:26 EST
Suggested change is applied upstream:

https://github.com/virt-who/virt-who/commit/5109d5c22e18eda8cbfc6649127c515161cced2c
Comment 8 Radek Novacek 2015-12-17 07:31:15 EST
Fixed by rebase to virt-who-0.16-1.el6.
Comment 10 Christian Horn 2015-12-18 03:46:42 EST
It hurts us having to wait until rhel6.8GA for this.  We are applying 
https://github.com/virt-who/virt-who/commit/5109d5c22e18eda8cbfc6649127c515161cced2c now manually, but it hurts ofcourse having to track this change for future updates.

Will the fixed virt-who be in satellite channels earlier than rhel6.8GA?
Comment 11 Radek Novacek 2015-12-22 02:10:24 EST
We don't plan to fix it currently in the satellite channel, but it could be done if needed.

I would recommend to alter logrotate configuration for /var/log/rhsm/rhsm.log to control size of that file.
Comment 12 Christian Horn 2015-12-22 08:08:15 EST
(In reply to Radek Novacek from comment #11)
> We don't plan to fix it currently in the satellite channel, but it could be
> done if needed.
Ok.

> I would recommend to alter logrotate configuration for
> /var/log/rhsm/rhsm.log to control size of that file.
We do, but we consider this a workaround as it requires customers first to notice the logging which is more verbose than required (i.e. in having filesystems filling up), and then implement the workaround.  We should aim at logging the right amount in the first place for best user experience.

We have documented this in a kbase now.
Comment 13 Liushihui 2016-02-25 23:00:53 EST
Verified it on virt-who-0.16-4.el6.noarch since virt-who won't generate host/guest mapping JSON data in log but show "Sending update in hosts-to-guests mapping for config "env/cmdline": X hypervisors and X guests found" when disable VIRTWHO_DEBUG.

Verified version:
virt-who-0.16-4.el6.noarch
subscription-manager-1.16.8-2.el6.x86_64
python-rhsm-1.16.6-1.el6.x86_64

Verified process:
1 Register system to satellite6.1
2 Configure virt-who run at hyperv mode and disable VIRTWHO_DEBUG. 
[root@sgi-xe500-01 rhsm]#  cat /etc/sysconfig/virt-who  | grep -v ^# | grep -v ^$
VIRTWHO_DEBUG=0
VIRTWHO_INTERVAL=2
VIRTWHO_HYPERV=1
VIRTWHO_HYPERV_OWNER=7715246
VIRTWHO_HYPERV_ENV=7715246
VIRTWHO_HYPERV_SERVER=10.73.5.212
VIRTWHO_HYPERV_USERNAME=administrator
VIRTWHO_HYPERV_PASSWORD=Welcome1
3 Restart virt-who service and check virt-who's log
[root@sgi-xe500-01 rhsm]# service virt-who restart
Stopping virt-who: [  OK  ]
Starting virt-who: [  OK  ]
[root@sgi-xe500-01 rhsm]# tail -f /var/log/rhsm/rhsm.log
2016-02-25 22:25:28,841 [INFO]  @virtwho.py:305 - Report for config "env/cmdline" haven't changed, not sending
2016-02-25 22:25:30,134 [INFO]  @virtwho.py:630 - Using reporter_id='sgi-xe500-01.rhts.eng.bos.redhat.com'
2016-02-25 22:25:30,137 [INFO]  @virtwho.py:722 - Using configuration "env/cmdline" ("hyperv" mode)
2016-02-25 22:25:44,800 [INFO]  @subscriptionmanager.py:185 - Sending update in hosts-to-guests mapping for config "env/cmdline": 1 hypervisors and 1 guests found
4 Configure virt-who run at hyperv mode and enable VIRTWHO_DEBUG.
[root@sgi-xe500-01 rhsm]#  cat /etc/sysconfig/virt-who  | grep -v ^# | grep -v ^$
VIRTWHO_DEBUG=1
VIRTWHO_INTERVAL=2
VIRTWHO_HYPERV=1
VIRTWHO_HYPERV_OWNER=7715246
VIRTWHO_HYPERV_ENV=7715246
VIRTWHO_HYPERV_SERVER=10.73.5.212
VIRTWHO_HYPERV_USERNAME=administrator
VIRTWHO_HYPERV_PASSWORD=Welcome1
5 Restart virt-who service and check virt-who's log
[root@sgi-xe500-01 rhsm]# service virt-who restart
Stopping virt-who: [  OK  ]
Starting virt-who: [  OK  ]
[root@sgi-xe500-01 rhsm]# tail -f /var/log/rhsm/rhsm.log
2016-02-25 22:18:38,419 [virtwho.main DEBUG] MainProcess(3369):MainThread @subscriptionmanager.py:hypervisorCheckIn:186 - Host-to-guest mapping: {
    "564D80F1-61F0-8510-87BF-57F9EC6122D7": [
        {
            "guestId": "8329390B-8359-F646-9176-27D738580E81", 
            "state": 5, 
            "attributes": {
                "active": 0, 
                "hypervisorVersion": "6.3.9600.16404", 
                "virtWhoType": "hyperv", 
                "hypervisorType": "hyperv"
            }
        }
    ]
}

Result:
1.VIRTWHO_DEBUG enabled, virt-who log will containing whole host-to-guest association JSON
2.VIRTWHO_DEBUG disabled, virt-who log won't containing whole host-to-guest association JSON, it reduce the log file size significantly.
Comment 15 errata-xmlrpc 2016-05-10 19:56:45 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.

https://rhn.redhat.com/errata/RHEA-2016-0859.html

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