Bug 823252 - [ovirt] [vdsm] vm logging is redirected to console and creating noise
Summary: [ovirt] [vdsm] vm logging is redirected to console and creating noise
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: oVirt
Classification: Retired
Component: vdsm
Version: unspecified
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
: ---
Assignee: Mark Wu
QA Contact:
URL:
Whiteboard: infra
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-05-20 11:07 UTC by Haim
Modified: 2014-01-13 00:52 UTC (History)
9 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2013-01-30 22:51:28 UTC
oVirt Team: ---
Embargoed:


Attachments (Terms of Use)

Description Haim 2012-05-20 11:07:18 UTC
Description of problem:

using latest vdsm on master branch, I get the following logs redirected to my console (tty):

-----------------------------------------------------------------------------
 �<15>vdsm vm.Vm DEBUG vmId=`67e5d1ee-eea0-4e77-bbe8-80db6ac3d7af`::Disk hdc stats not available

Message from syslogd@purple-vds2 at May 20 14:00:14 ...
 �<15>vdsm vm.Vm DEBUG vmId=`67e5d1ee-eea0-4e77-bbe8-80db6ac3d7af`::Disk vda stats not available

Message from syslogd@purple-vds2 at May 20 14:00:14 ...
 �<15>vdsm vm.Vm DEBUG vmId=`67e5d1ee-eea0-4e77-bbe8-80db6ac3d7af`::Disk vdb stats not available

Message from syslogd@purple-vds2 at May 20 14:00:14 ...
 �<15>vdsm vm.Vm DEBUG vmId=`67e5d1ee-eea0-4e77-bbe8-80db6ac3d7af`::Disk hdc latency not available

Message from syslogd@purple-vds2 at May 20 14:00:14 ...
 �<15>vdsm vm.Vm DEBUG vmId=`67e5d1ee-eea0-4e77-bbe8-80db6ac3d7af`::Disk vda latency not available

Message from syslogd@purple-vds2 at May 20 14:00:14 ...
 �<15>vdsm vm.Vm DEBUG vmId=`67e5d1ee-eea0-4e77-bbe8-80db6ac3d7af`::Disk vdb latency not available

-----------------------------------------------------------------------------

This create lots of noise which increases when you add more vms and becomes impossible in certain stage (100 vms).

Comment 1 Haim 2012-05-20 11:08:20 UTC
I guess it was introduced by 142ba0169493c68727def49215dd5144392e61e6: Configure vdsm to use syslog

Comment 2 Mark Wu 2012-05-23 02:40:10 UTC
Actually, the default log level of the facility 'user' is INFO, so only the vdsm messages whose priority is above or equal to INFO will be displayed on system log file (/var/log/messages).  But we do find some DEBUG level messages are also printed as it's reported in this bug.

To debug the problem, I configured vdsm using UDP for syslog and used wireshark to capture the packet. I found the problem is caused by unicode handling in SysLogHandler. If the type of message is uicode, it encode it into utf-8, and puts codecs.BOM_UTF8(BOM_UTF8 = '\xef\xbb\xbf',) before the  
priority and facility code (here is <15>) as per RFC 5424. That's why we see a garbage code before. <15>

But unfortunately, rsyslog can't handle the message properly. So it can't decode the message level and just print it even it's DEBUG level. Actually, I am not sure it's a bug of rsyslog or pythong logging module. But I found python already changed unicode handling code in SysLogHandler:
http://bugs.python.org/issue14452

I haven't checked if the latest python package on Fedora17 includes the fix.

Additionally, we have a patch to raise the vdsm syslog level to WARNING. It helps to reduce the noise for syslog, but should not help on this bug. 

And I am not sure why the messages appeared in console. I guess it's related to the configuration of rsyslog. By default, it should just be logged to /var/log/messages.

Comment 3 Mark Wu 2012-05-23 02:47:19 UTC
The patched in last comment is:
http://gerrit.ovirt.org/#change,4654

Comment 4 Itamar Heim 2012-05-29 06:28:20 UTC
i see patch is merged, so this should be in MODIFIED status?

Comment 5 Mark Wu 2012-05-29 08:20:44 UTC
Itamar,
I believe that patch can't resolve this problem. It should be a bug of python logging module, which is fixed in latest release of python 2.7. I will check if the fix is included in Fedora 17.

Comment 6 Itamar Heim 2013-01-30 22:51:28 UTC
Closing old bugs. If this issue is still relevant/important in current version, please re-open the bug.


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