Bug 970133 - [TEXT] vdsm passes a bogus character to syslog - Unable to update the volume
[TEXT] vdsm passes a bogus character to syslog - Unable to update the volume
Status: CLOSED DUPLICATE of bug 845802
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: vdsm (Show other bugs)
3.3.0
Unspecified Unspecified
unspecified Severity low
: ---
: 3.3.0
Assigned To: Sergey Gotliv
storage
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-06-03 09:53 EDT by Jiri Belka
Modified: 2016-02-10 12:19 EST (History)
7 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-06-30 09:51:35 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: Storage
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
vdsm.log (20 bytes, application/x-tar)
2013-06-03 09:55 EDT, Jiri Belka
no flags Details

  None (edit)
Description Jiri Belka 2013-06-03 09:53:58 EDT
Description of problem:
I got this on console

Message from syslogd@dell-r210ii-04 at Jun  3 15:44:14 ...
 �<11>vdsm vm.Vm ERROR vmId=`5e20c541-aaca-4627-bbc5-cd0d19d5e893`::Unable to update the volume 850c028e-af35-41b7-8bf9-87d6d70c4604 (domain: cc4d884d-15d9-4e35-b869-4330245c1b94 image: 8d92254e-c574-4919-8be1-7178bbce912e) for the drive vda

See part in the beginning of the line.

[root@dell-r210ii-04 ~]# grep vdsm /var/log/messages | grep '<[0-9][0-9]>'
Jun  3 15:39:02 dell-r210ii-04 �<11>vdsm vm.Vm ERROR vmId=`5e20c541-aaca-4627-bbc5-cd0d19d5e893`::Unable to update the volume 850c028e-af35-41b7-8bf9-87d6d70c4604 (domain: cc4d884d-15d9-4e35-b869-4330245c1b94 image: 8d92254e-c574-4919-8be1-7178bbce912e) for the drive vda
Jun  3 15:41:02 dell-r210ii-04 �<11>vdsm vm.Vm ERROR vmId=`5e20c541-aaca-4627-bbc5-cd0d19d5e893`::Unable to update the volume 850c028e-af35-41b7-8bf9-87d6d70c4604 (domain: cc4d884d-15d9-4e35-b869-4330245c1b94 image: 8d92254e-c574-4919-8be1-7178bbce912e) for the drive vda
Jun  3 15:44:14 dell-r210ii-04 �<11>vdsm vm.Vm ERROR vmId=`5e20c541-aaca-4627-bbc5-cd0d19d5e893`::Unable to update the volume 850c028e-af35-41b7-8bf9-87d6d70c4604 (domain: cc4d884d-15d9-4e35-b869-4330245c1b94 image: 8d92254e-c574-4919-8be1-7178bbce912e) for the drive vda

Comparison with other vdsm messages

[root@dell-r210ii-04 ~]# egrep 'vdsm.*ERROR' /var/log/messages | tail -n1
Jun  3 15:48:24 dell-r210ii-04 vdsm vm.Vm ERROR vmId=`5e20c541-aaca-4627-bbc5-cd0d19d5e893`::Stats function failed: <AdvancedStatsFunction _sampleDiskLatency at 0x14fc5f0>#012Traceback (most recent call last):#012  File "/usr/share/vdsm/sampling.py", line 351, in collect#012    statsFunction()#012  File "/usr/share/vdsm/sampling.py", line 226, in __call__#012    retValue = self._function(*args, **kwargs)#012  File "/usr/share/vdsm/libvirtvm.py", line 179, in _sampleDiskLatency#012    vmDrive.name, flags=libvirt.VIR_TYPED_PARAM_STRING_OKAY)#012  File "/usr/share/vdsm/libvirtvm.py", line 554, in f#012    raise toe#012TimeoutError: Timed out during operation: cannot acquire state change lock

So seems related only to 'Unable to update the volume' messages.

Version-Release number of selected component (if applicable):
is1 / vdsm-4.10.3-0.416.git5358ed2.el6.x86_64

How reproducible:
100%

Steps to Reproduce:
1. have a running vm
2. block access to storage on vm's host
3.

Actual results:
bogus char in vdsm syslog message

Expected results:
clean message

Additional info:
I got this message after blocking access to storage on the host (iptables -I INPUT -s $storage_ip -j DROP).
Comment 1 Jiri Belka 2013-06-03 09:55:46 EDT
Created attachment 756317 [details]
vdsm.log
Comment 3 Sergey Gotliv 2013-06-30 09:51:35 EDT
The bug is in Python(2.6) implementation of SysLogHandler, which is used by us to handle sys log messages. The problem is already fixed in Python 2.7, but we unfortunately we are still using 2.6 in RHEL.

You can find original Python's bug here:
http://bugs.python.org/issue14452

The following link providing more details about the problem:
http://bugs.centos.org/view.php?id=6447

By the way, messages that don't need formatting are handled correctly, that's the reason why other examples provided in bug description looking just fine.

I backported solution from 2.7 to 2.6 on my machine and verified that it resolves the problem.

*** This bug has been marked as a duplicate of bug 845802 ***

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