Bug 1125237

Summary: Use libvirt default logging parameters to reduce cost of starting multiple VMs
Product: Red Hat Enterprise Virtualization Manager Reporter: Yuri Obshansky <yobshans>
Component: vdsmAssignee: Mooli Tayer <mtayer>
Status: CLOSED ERRATA QA Contact: Yuri Obshansky <yobshans>
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.4.1-1CC: aburden, bazulay, danken, ecohen, gklein, iheim, juwu, lpeer, michal.skrivanek, mtayer, oourfali, pstehlik, ybronhei, yeylon, yobshans
Target Milestone: ---   
Target Release: 3.5.0   
Hardware: x86_64   
OS: Linux   
Whiteboard: infra
Fixed In Version: vt2.2 Doc Type: Release Note
Doc Text:
Previously, the logging level of libvirt was set to debug mode, which greatly increased log file size and negatively impacted performance for production environments. Now, the default logging level of libvirt is used and verbosity is decreased. If /run/systemd/journal/socket exists on the machine, libvirt's log file may be changed to journal. Refer to http://libvirt.org/logging.html for more information on the journal change.
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-02-11 21:12:19 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:
Bug Depends On:    
Bug Blocks: 1142923, 1156165    
Attachments:
Description Flags
libvirt log
none
vdsm log
none
Screenshot none

Description Yuri Obshansky 2014-07-31 11:46:08 UTC
Description of problem:
Default logging level configuration of VDSM and libvirt is DEBUG 
which leads to increase of log files size and impact on performance.
It is not good idea for Production environment 
(scale and performance tests performed on similar to production environments).
My last scale test showed the growth of libvirt.log file from 879 Kb up to 1.5 Gb during less 2 hours.
As result I got "Low disk space" error.

At the same time I verified what's an impact of DEBUG logging on vdsm performance. 
The scenario is: create VMs on HOST (64 CPUs and 400 G RAM) till RHEVM starts to move VMs status to "Not responding" or vdsm raises exceptions "SSLError: bad write retry" (see details in bug 1102147).
Results:   
DEBUG level - host can manage 182 VMs
ERROR level - host can manage 205 VMs
i.e. ~ 10% performance improvement only by change logging level. 

Logging level changed at:
libvirt - /etc/libvirt/libvirtd.conf
vdsm - /etc/vdsm/logger.conf 

Version-Release number of selected component (if applicable):
RHEVM 3.4.1-0.23.el6ev
OS Version: RHEV Hypervisor - 6.5 - 20140624.0.el6ev
Kernel Version: 2.6.32 - 431.20.3.el6.x86_64
KVM Version: 0.12.1.2 - 2.415.el6_5.10
LIBVIRT Version: libvirt-0.10.2-29.el6_5.9
VDSM Version: vdsm-4.14.7-3.el6ev

How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Comment 1 Yuri Obshansky 2014-07-31 11:47:31 UTC
Created attachment 922879 [details]
libvirt log

Comment 2 Yuri Obshansky 2014-07-31 11:48:41 UTC
Created attachment 922880 [details]
vdsm log

Comment 3 Yuri Obshansky 2014-07-31 11:49:12 UTC
Created attachment 922881 [details]
Screenshot

Comment 4 Oved Ourfali 2014-08-03 05:23:46 UTC
Yaniv - thoughts on that?

Comment 5 Michal Skrivanek 2014-08-05 08:35:52 UTC
note patch 28869 about vdsm log format discussion

other than that there is a general disagreement on that, solution needs to be discussed on devel list

Comment 6 Yaniv Bronhaim 2014-08-08 19:01:27 UTC
We won't change vdsm log level nor the format.
about libvirt log level, [1] is supposed to use libvirt defaults ([2]) and should fix the too verbose issue

just need to verify that against libvirt version.

[1] http://gerrit.ovirt.org/#/c/31135/2/lib/vdsm/tool/configurator.py,cm
[2] http://libvirt.org/logging.html

Comment 7 Barak 2014-08-26 11:56:13 UTC
Danken any thoughts whether this should be handled at all ?

Comment 8 Dan Kenigsberg 2014-08-26 16:06:56 UTC
As Yaniv said - I find DEBUG in vdsm still useful for hard bugs. libvirt.log is less helpful for me recently, so I support dropping our tweaks to it.

This report is interesting, but I'd like to see hard numbers now that the silly bug 1102147 is resolved.

Comment 9 Dan Kenigsberg 2014-08-26 17:29:51 UTC
Yuri, could you repeat your measurements with Vdsm-4.16.2, preferably with http://gerrit.ovirt.org/#/c/31135/ applied, too?

Comment 10 Mooli Tayer 2014-09-01 13:41:23 UTC
> Yuri, could you repeat your measurements with Vdsm-4.16.2, preferably with http://gerrit.ovirt.org/#/c/31135/ applied, too?

master now contains 31135

Comment 11 Yuri Obshansky 2014-09-01 13:54:37 UTC
I cannot do it. It is a little bit problematic. We test only released version of RHEVM since we have a very large environment.

Comment 13 Mooli Tayer 2014-09-17 10:39:55 UTC
Might need to communicate to customers:

This might cause changing of libvirt's log file from
/var/log/libvirt to journal in accordance with libvirt's
defaults. This happens when /run/systemd/journal/socket
exists on the machine see:
http://libvirt.org/logging.html

Comment 14 Julie 2014-09-18 00:21:39 UTC
(In reply to Mooli Tayer from comment #13)
> Might need to communicate to customers:
> 
> This might cause changing of libvirt's log file from
> /var/log/libvirt to journal in accordance with libvirt's
> defaults. This happens when /run/systemd/journal/socket
> exists on the machine see:
> http://libvirt.org/logging.html
hi Mooli,
    Please select the correct Doc Type and provide the doc text ASAP for this bug to make it in the 3.5 Beta Manager Release Notes. If this bug is not required for release notes, please set the require_release_note flag to -.

Cheers,
Julie

Comment 15 Yuri Obshansky 2014-12-23 09:39:11 UTC
I tried verify bug on
RHEV-M 3.5.0-0.22.el6ev
RHEL - 6Server - 6.6.0.2.el6
libvirt-0.10.2-46.el6_6.1
vdsm-4.16.7.6-1.el6ev
I didn't find any log configuration in /etc/libvirt/libvirtd.conf 
Example:
## beginning of configuration section by vdsm-4.13.0
auth_unix_rw="sasl"
ca_file="/etc/pki/vdsm/certs/cacert.pem"
cert_file="/etc/pki/vdsm/certs/vdsmcert.pem"
host_uuid="5e149724-613c-43c6-b5f0-72ac8ac1f63d"
keepalive_interval=-1
key_file="/etc/pki/vdsm/keys/vdsmkey.pem"
listen_addr="0.0.0.0"
unix_sock_group="qemu"
unix_sock_rw_perms="0770"
## end of configuration section by vdsm-4.13.0
In spite that log level is ERROR as I can determine from 
/var/log/libvirt/libvirtd.log
where only error printouts

The question: where can I verify libvirt log configuration?

Comment 16 Mooli Tayer 2014-12-23 10:09:50 UTC
The fix for this issue was to remove custom libvirt log configuration[1].
I'm not sure what you mean by verify libvirt log configuration. 

The default log behavior is mentioned in the release note for this bug
(see "Doc Text"). you can also grep for "log_outputs|log_filters" at libvirtd.conf.

Comment 17 Yuri Obshansky 2014-12-23 10:33:18 UTC
I read release note, and it is not clear. 
This statement - "Now, the default logging level of libvirt is used and verbosity is decreased." 
What level of default logging level? INFO? ERROR?
When you said "remove custom libvirt log configuration"?
Does it mean that we are not able to change logging level?

What do I need?
I should verify that in current version libvirt default logging level is not DEBUG.

I grep 
[root@ucs1-b420-1 ~]# cat /etc/libvirt/libvirtd.conf |grep log_outputs
#log_outputs="3:syslog:libvirtd"
[root@ucs1-b420-1 ~]# cat /etc/libvirt/libvirtd.conf |grep log_filters
#log_filters="3:remote 4:event"
And all are commented

How can I verify this bug?

Comment 18 Mooli Tayer 2014-12-23 15:37:32 UTC
(In reply to Yuri Obshansky from comment #17)
> I read release note, and it is not clear. 
> This statement - "Now, the default logging level of libvirt is used and
> verbosity is decreased." 
> What level of default logging level? INFO? ERROR?

What ever default libvirt is using. The point is we no longer touch it.

"...
3 or "warn": log warnings and errors, that's the default value
"[1]

[1]from libvirt docs, linked in the release note:
http://libvirt.org/logging.html

> When you said "remove custom libvirt log configuration"?
> Does it mean that we are not able to change logging level?

It does not mean that we are not able. we do not want to change the default anymore -  that is due to this bug and also due to the reason mentioned by Dan in the commit: http://gerrit.ovirt.org/#/c/31135/

> 
> What do I need?
> I should verify that in current version libvirt default logging level is not
> DEBUG.

You are not checking libvirt or it's defaults... 
vdsm previously used to override default configuration in the "## beginning of configuration section by vdsm ..." section. It does not do so anymore.
what you wrote below is a verification of that.

> 
> I grep 
> [root@ucs1-b420-1 ~]# cat /etc/libvirt/libvirtd.conf |grep log_outputs
> #log_outputs="3:syslog:libvirtd"
> [root@ucs1-b420-1 ~]# cat /etc/libvirt/libvirtd.conf |grep log_filters
> #log_filters="3:remote 4:event"
> And all are commented
> 
> How can I verify this bug?

To verify I think you need to check the problem and not the solution:

Comment 19 Mooli Tayer 2014-12-23 15:40:58 UTC
Ignore the last sentence.

Comment 20 Yuri Obshansky 2014-12-23 16:00:27 UTC
I cannot ignore the last sentence. It was impolite.
I know what I need to do.

Release note is not clear.

Bug didn't reproduce on:
- RHEV-M 3.5.0-0.22.el6ev
- RHEL - 6Server - 6.6.0.2.el6
- libvirt-0.10.2-46.el6_6.1
- vdsm-4.16.7.6-1.el6ev
 
Moved to verified

Comment 21 Mooli Tayer 2014-12-23 16:19:58 UTC
I did not mean to offend you.
I do not think that you do not know what to do.

What I meant is this:
Since the original bug was about starting vm's the solution should be tested by starting vms. At second look I saw that the logging issue was mentioned in the header and is not only part of the solution so I dropped my idea.

If you have a suggestion on improving the release note please provide it.

Comment 23 errata-xmlrpc 2015-02-11 21:12:19 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-2015-0159.html