[Users] Excessive syslog logging from vdsm/sampling.py

The syslog on my ovirt nodes is constantly logging errors from sampling.py: Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 513, in _highWrite#012 self._vm._dom.blockInfo(vmDrive.path, 0)#012 File "/usr/share/vdsm/vm.py", line 835, in f#012 ret = attr(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper#012 ret = f(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo#012 if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)#012libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 not assigned to domain Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' These messages might have something to do with reading information/statistics through the API. But I've stopped all my (monitoring) processes using the API. Restarting ovirt-engine and vdsm did not resolve the issue. Both nodes and engine server are running oVirt 3.3.1 on CentOS 6.4 This may be a red herring but the values of disk statistics read through the API are "static"/unchanging. Any clues on whether these messages are serious and any ideas on how to stop them spamming my system logs?

Any ideas on this one? On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 513, in _highWrite#012 self._vm._dom.blockInfo(vmDrive.path, 0)#012 File "/usr/share/vdsm/vm.py", line 835, in f#012 ret = attr(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper#012 ret = f(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo#012 if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)#012libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 not assigned to domain Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
These messages might have something to do with reading information/statistics through the API. But I've stopped all my (monitoring) processes using the API.
Restarting ovirt-engine and vdsm did not resolve the issue.
Both nodes and engine server are running oVirt 3.3.1 on CentOS 6.4
This may be a red herring but the values of disk statistics read through the API are "static"/unchanging.
Any clues on whether these messages are serious and any ideas on how to stop them spamming my system logs?

On 12/17/2013 09:04 AM, Sander Grendelman wrote:
Any ideas on this one?
On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 513, in _highWrite#012 self._vm._dom.blockInfo(vmDrive.path, 0)#012 File "/usr/share/vdsm/vm.py", line 835, in f#012 ret = attr(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper#012 ret = f(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo#012 if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)#012libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 not assigned to domain Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
These messages might have something to do with reading information/statistics through the API. But I've stopped all my (monitoring) processes using the API.
Restarting ovirt-engine and vdsm did not resolve the issue.
Both nodes and engine server are running oVirt 3.3.1 on CentOS 6.4
This may be a red herring but the values of disk statistics read through the API are "static"/unchanging.
Any clues on whether these messages are serious and any ideas on how to stop them spamming my system logs?
Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
vdsm version? is a floppy attached? which type of storage domain?

On 12/18/2013 10:21 AM, Itamar Heim wrote:
On 12/17/2013 09:04 AM, Sander Grendelman wrote:
Any ideas on this one?
On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 513, in _highWrite#012 self._vm._dom.blockInfo(vmDrive.path, 0)#012 File "/usr/share/vdsm/vm.py", line 835, in f#012 ret = attr(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper#012 ret = f(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo#012 if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)#012libvirtError: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11
not assigned to domain Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
These messages might have something to do with reading information/statistics through the API. But I've stopped all my (monitoring) processes using the API.
Restarting ovirt-engine and vdsm did not resolve the issue.
Both nodes and engine server are running oVirt 3.3.1 on CentOS 6.4
This may be a red herring but the values of disk statistics read through the API are "static"/unchanging.
Any clues on whether these messages are serious and any ideas on how to stop them spamming my system logs?
Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
vdsm version? is a floppy attached? which type of storage domain?
-- Regards, Vinzenz Feenstra | Senior Software Engineer RedHat Engineering Virtualization R & D Phone: +420 532 294 625 IRC: vfeenstr or evilissimo Better technology. Faster innovation. Powered by community collaboration. See how it works at redhat.com

- vdsm-4.13.0-11.el6.x86_64 - FC storage domain - no floppies attached to VMs as far as I know (any way to test this?) On Wed, Dec 18, 2013 at 10:21 AM, Itamar Heim <iheim@redhat.com> wrote:
On 12/17/2013 09:04 AM, Sander Grendelman wrote:
Any ideas on this one?
On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 513, in _highWrite#012 self._vm._dom.blockInfo(vmDrive.path, 0)#012 File "/usr/share/vdsm/vm.py", line 835, in f#012 ret = attr(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper#012 ret = f(*args, **kwargs)#012 File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1797, in blockInfo#012 if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)#012libvirtError: invalid argument: invalid path
/rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 not assigned to domain Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format' Dec 16 11:22:48 gnkvm01 vdsm vm.Vm ERROR vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
These messages might have something to do with reading information/statistics through the API. But I've stopped all my (monitoring) processes using the API.
Restarting ovirt-engine and vdsm did not resolve the issue.
Both nodes and engine server are running oVirt 3.3.1 on CentOS 6.4
This may be a red herring but the values of disk statistics read through the API are "static"/unchanging.
Any clues on whether these messages are serious and any ideas on how to stop them spamming my system logs?
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
vdsm version? is a floppy attached? which type of storage domain?

----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Itamar Heim" <iheim@redhat.com> Cc: users@ovirt.org, "Michal Skrivanek" <mskrivan@redhat.com> Sent: Wednesday, December 18, 2013 11:40:36 AM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
- vdsm-4.13.0-11.el6.x86_64 - FC storage domain - no floppies attached to VMs as far as I know (any way to test this?)
On Wed, Dec 18, 2013 at 10:21 AM, Itamar Heim <iheim@redhat.com> wrote:
On 12/17/2013 09:04 AM, Sander Grendelman wrote:
Any ideas on this one?
On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
This is not spam, but a real error in the code: Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#012Traceback (most recent call last): File "/usr/share/vdsm/sampling.py", line 351, in collectstatsFunction() File "/usr/share/vdsm/sampling.py", line 226, in __call__ retValue = self._function(*args, **kwargs) File "/usr/share/vdsm/vm.py", line 509, in _highWrite if not vmDrive.blockDev or vmDrive.format != 'cow': AttributeError: 'Drive' object has no attribute 'format' We should check why vmDrive does not have the format attribute in your case. The best way to resolve this would be to open a bug and attach vdsm logs, which may explain why this is happening. Thanks for reporting it! Thanks, Nir

----- Original Message -----
----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Itamar Heim" <iheim@redhat.com> Cc: users@ovirt.org, "Michal Skrivanek" <mskrivan@redhat.com> Sent: Wednesday, December 18, 2013 11:40:36 AM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
- vdsm-4.13.0-11.el6.x86_64 - FC storage domain - no floppies attached to VMs as far as I know (any way to test this?)
On Wed, Dec 18, 2013 at 10:21 AM, Itamar Heim <iheim@redhat.com> wrote:
On 12/17/2013 09:04 AM, Sander Grendelman wrote:
Any ideas on this one?
On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
This is not spam, but a real error in the code:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#012Traceback (most recent call last): File "/usr/share/vdsm/sampling.py", line 351, in collectstatsFunction() File "/usr/share/vdsm/sampling.py", line 226, in __call__ retValue = self._function(*args, **kwargs) File "/usr/share/vdsm/vm.py", line 509, in _highWrite if not vmDrive.blockDev or vmDrive.format != 'cow': AttributeError: 'Drive' object has no attribute 'format'
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
The best way to resolve this would be to open a bug and attach vdsm logs, which may explain why this is happening.
Thanks for reporting it!
Thanks, Nir
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users

----- Original Message -----
From: "Ayal Baron" <abaron@redhat.com> To: "Nir Soffer" <nsoffer@redhat.com> Cc: "Sander Grendelman" <sander@grendelman.com>, "Michal Skrivanek" <mskrivan@redhat.com>, users@ovirt.org Sent: Wednesday, December 18, 2013 1:27:36 PM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
----- Original Message -----
----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Itamar Heim" <iheim@redhat.com> Cc: users@ovirt.org, "Michal Skrivanek" <mskrivan@redhat.com> Sent: Wednesday, December 18, 2013 11:40:36 AM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
- vdsm-4.13.0-11.el6.x86_64 - FC storage domain - no floppies attached to VMs as far as I know (any way to test this?)
On Wed, Dec 18, 2013 at 10:21 AM, Itamar Heim <iheim@redhat.com> wrote:
On 12/17/2013 09:04 AM, Sander Grendelman wrote:
Any ideas on this one?
On Mon, Dec 16, 2013 at 11:31 AM, Sander Grendelman <sander@grendelman.com> wrote:
The syslog on my ovirt nodes is constantly logging errors from sampling.py:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#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/vm.py", line 509, in _highWrite#012 if not vmDrive.blockDev or vmDrive.format != 'cow':#012AttributeError: 'Drive' object has no attribute 'format'
This is not spam, but a real error in the code:
Dec 16 11:22:47 gnkvm01 vdsm vm.Vm ERROR vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1733dc0>#012Traceback (most recent call last): File "/usr/share/vdsm/sampling.py", line 351, in collectstatsFunction() File "/usr/share/vdsm/sampling.py", line 226, in __call__ retValue = self._function(*args, **kwargs) File "/usr/share/vdsm/vm.py", line 509, in _highWrite if not vmDrive.blockDev or vmDrive.format != 'cow': AttributeError: 'Drive' object has no attribute 'format'
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
Then this patch should fix your problem: http://gerrit.ovirt.org/22518

On Wed, Dec 18, 2013 at 1:01 PM, Nir Soffer <nsoffer@redhat.com> wrote:
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
Then this patch should fix your problem: http://gerrit.ovirt.org/22518
I applied this patch and restarted vdsmd on both nodes (maintenance->restart->activate). The errors still occur, but it is limited to fewer machines ( see [1] ). - Almost all VMs were imported with virt-v2v (not only the VMs with errors). - Almost all VMs were migrated to another storage domain (offline). - Migration to another host was done with all VMs The current vdsm logs for both are attached to this e-mail. Please let me know if you need any additional information. [1]: unique sampling.py errors on both nodes. #### Node 1 ## Before patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats vmId=`3e481c73-57df-4dc3-8b1c-421a74308a5e`::Stats vmId=`57dbe688-4e18-4358-aa3e-f3f6022ef9b3`::Stats vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats vmId=`6df65698-4995-4c75-9433-75affe9b9c38`::Stats vmId=`9260c69c-93a2-4f8a-b5e9-eaab5e4f4708`::Stats vmId=`9edb3e08-f098-4633-a122-e5ba29ae12ea`::Stats vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats ## After patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats #### Node 2 ## Before patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`00317758-16fe-4ac6-b9fd-d522c9908861`::Stats vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`06405f12-d763-4bd6-b5e5-997e3f6bb1f6`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats vmId=`1bba8930-9c04-4c5c-8b15-c9fe14022cb5`::Stats vmId=`2036c21d-e0a4-4d55-a9a7-4cd9dd9d250d`::Stats vmId=`5fff0cc7-24e4-4e4a-b220-ba49f9145060`::Stats vmId=`86708f62-fcc6-4d0f-978a-3788a61f9775`::Stats vmId=`9b8e6d07-295c-404d-a672-efc94a24b6bc`::Stats vmId=`aa0445b6-8ca5-4557-9f9b-ee543d6435df`::Stats ## After patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats

----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Nir Soffer" <nsoffer@redhat.com> Cc: "Michal Skrivanek" <mskrivan@redhat.com>, users@ovirt.org, "Ayal Baron" <abaron@redhat.com> Sent: Wednesday, December 18, 2013 4:00:21 PM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
On Wed, Dec 18, 2013 at 1:01 PM, Nir Soffer <nsoffer@redhat.com> wrote:
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
Then this patch should fix your problem: http://gerrit.ovirt.org/22518
I applied this patch and restarted vdsmd on both nodes (maintenance->restart->activate). The errors still occur, but it is limited to fewer machines ( see [1] ).
- Almost all VMs were imported with virt-v2v (not only the VMs with errors). - Almost all VMs were migrated to another storage domain (offline). - Migration to another host was done with all VMs
The current vdsm logs for both are attached to this e-mail. Please let me know if you need any additional information.
[1]: unique sampling.py errors on both nodes.
#### Node 1 ## Before patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats vmId=`3e481c73-57df-4dc3-8b1c-421a74308a5e`::Stats vmId=`57dbe688-4e18-4358-aa3e-f3f6022ef9b3`::Stats vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats vmId=`6df65698-4995-4c75-9433-75affe9b9c38`::Stats vmId=`9260c69c-93a2-4f8a-b5e9-eaab5e4f4708`::Stats vmId=`9edb3e08-f098-4633-a122-e5ba29ae12ea`::Stats vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
## After patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats
#### Node 2 ## Before patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`00317758-16fe-4ac6-b9fd-d522c9908861`::Stats vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`06405f12-d763-4bd6-b5e5-997e3f6bb1f6`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats vmId=`1bba8930-9c04-4c5c-8b15-c9fe14022cb5`::Stats vmId=`2036c21d-e0a4-4d55-a9a7-4cd9dd9d250d`::Stats vmId=`5fff0cc7-24e4-4e4a-b220-ba49f9145060`::Stats vmId=`86708f62-fcc6-4d0f-978a-3788a61f9775`::Stats vmId=`9b8e6d07-295c-404d-a672-efc94a24b6bc`::Stats vmId=`aa0445b6-8ca5-4557-9f9b-ee543d6435df`::Stats
## After patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
Thanks Sander! Michal, do you want to check this? Nir

----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Nir Soffer" <nsoffer@redhat.com> Cc: "Michal Skrivanek" <mskrivan@redhat.com>, users@ovirt.org, "Ayal Baron" <abaron@redhat.com> Sent: Wednesday, December 18, 2013 4:00:21 PM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
On Wed, Dec 18, 2013 at 1:01 PM, Nir Soffer <nsoffer@redhat.com> wrote:
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
Then this patch should fix your problem: http://gerrit.ovirt.org/22518
I applied this patch and restarted vdsmd on both nodes (maintenance->restart->activate). The errors still occur, but it is limited to fewer machines ( see [1] ).
- Almost all VMs were imported with virt-v2v (not only the VMs with errors). - Almost all VMs were migrated to another storage domain (offline). - Migration to another host was done with all VMs
The current vdsm logs for both are attached to this e-mail. Please let me know if you need any additional information.
[1]: unique sampling.py errors on both nodes.
#### Node 1 ## Before patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats vmId=`3e481c73-57df-4dc3-8b1c-421a74308a5e`::Stats vmId=`57dbe688-4e18-4358-aa3e-f3f6022ef9b3`::Stats vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats vmId=`6df65698-4995-4c75-9433-75affe9b9c38`::Stats vmId=`9260c69c-93a2-4f8a-b5e9-eaab5e4f4708`::Stats vmId=`9edb3e08-f098-4633-a122-e5ba29ae12ea`::Stats vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
## After patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats
#### Node 2 ## Before patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`00317758-16fe-4ac6-b9fd-d522c9908861`::Stats vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`06405f12-d763-4bd6-b5e5-997e3f6bb1f6`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats vmId=`1bba8930-9c04-4c5c-8b15-c9fe14022cb5`::Stats vmId=`2036c21d-e0a4-4d55-a9a7-4cd9dd9d250d`::Stats vmId=`5fff0cc7-24e4-4e4a-b220-ba49f9145060`::Stats vmId=`86708f62-fcc6-4d0f-978a-3788a61f9775`::Stats vmId=`9b8e6d07-295c-404d-a672-efc94a24b6bc`::Stats vmId=`aa0445b6-8ca5-4557-9f9b-ee543d6435df`::Stats
## After patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
Well in node1.log, we have 7687 errors: $ grep 'has no attribute' vdsm-node1.log | wc -l 7687 But no such errors in vdsm-node2.log: $ grep 'has no attribute' vdsm-node2.log | wc -l 0 Can you explain what is the difference between node1.log and node2.log? Can you send before and after log files, or point to the time in the log where you started the version with the patch? Thanks, Nir

On Wed, Dec 18, 2013 at 4:10 PM, Nir Soffer <nsoffer@redhat.com> wrote:
Well in node1.log, we have 7687 errors: $ grep 'has no attribute' vdsm-node1.log | wc -l 7687
But no such errors in vdsm-node2.log: $ grep 'has no attribute' vdsm-node2.log | wc -l 0
Can you explain what is the difference between node1.log and node2.log?
Two different ovirt nodes (node 1 = gnkvm01, node 2 = gnkvm02). Configuration should be identical. Node 1 was put in maintenance before vdsm restart. Node 2 vdsmd was restarted without maintenance (with one running testvm).
Can you send before and after log files, or point to the time in the log where you started the version with the patch?
On node1 vdsmd was restarted at 13:33 On node2 vdsmd was restarted at 13:49 I've don't have vdsm logfiles from before the problem was observed, only syslog files.

----- Original Message -----
On Wed, Dec 18, 2013 at 4:10 PM, Nir Soffer <nsoffer@redhat.com> wrote:
Well in node1.log, we have 7687 errors: $ grep 'has no attribute' vdsm-node1.log | wc -l 7687
But no such errors in vdsm-node2.log: $ grep 'has no attribute' vdsm-node2.log | wc -l 0
Can you explain what is the difference between node1.log and node2.log?
Two different ovirt nodes (node 1 = gnkvm01, node 2 = gnkvm02).
Configuration should be identical. Node 1 was put in maintenance before vdsm restart.
This means all VMs on it were migrated first.
Node 2 vdsmd was restarted without maintenance (with one running testvm).
Can you send before and after log files, or point to the time in the log where you started the version with the patch?
On node1 vdsmd was restarted at 13:33 On node2 vdsmd was restarted at 13:49
I've don't have vdsm logfiles from before the problem was observed, only syslog files.

----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Nir Soffer" <nsoffer@redhat.com> Cc: "Michal Skrivanek" <mskrivan@redhat.com>, users@ovirt.org, "Ayal Baron" <abaron@redhat.com> Sent: Wednesday, December 18, 2013 4:00:21 PM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
On Wed, Dec 18, 2013 at 1:01 PM, Nir Soffer <nsoffer@redhat.com> wrote:
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
Then this patch should fix your problem: http://gerrit.ovirt.org/22518
I applied this patch and restarted vdsmd on both nodes (maintenance->restart->activate). The errors still occur, but it is limited to fewer machines ( see [1] ).
- Almost all VMs were imported with virt-v2v (not only the VMs with errors). - Almost all VMs were migrated to another storage domain (offline). - Migration to another host was done with all VMs
The current vdsm logs for both are attached to this e-mail. Please let me know if you need any additional information.
[1]: unique sampling.py errors on both nodes.
#### Node 1 ## Before patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats vmId=`3e481c73-57df-4dc3-8b1c-421a74308a5e`::Stats vmId=`57dbe688-4e18-4358-aa3e-f3f6022ef9b3`::Stats vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats vmId=`6df65698-4995-4c75-9433-75affe9b9c38`::Stats vmId=`9260c69c-93a2-4f8a-b5e9-eaab5e4f4708`::Stats vmId=`9edb3e08-f098-4633-a122-e5ba29ae12ea`::Stats vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
## After patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats
#### Node 2 ## Before patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`00317758-16fe-4ac6-b9fd-d522c9908861`::Stats vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`06405f12-d763-4bd6-b5e5-997e3f6bb1f6`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats vmId=`1bba8930-9c04-4c5c-8b15-c9fe14022cb5`::Stats vmId=`2036c21d-e0a4-4d55-a9a7-4cd9dd9d250d`::Stats vmId=`5fff0cc7-24e4-4e4a-b220-ba49f9145060`::Stats vmId=`86708f62-fcc6-4d0f-978a-3788a61f9775`::Stats vmId=`9b8e6d07-295c-404d-a672-efc94a24b6bc`::Stats vmId=`aa0445b6-8ca5-4557-9f9b-ee543d6435df`::Stats
## After patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
I think I understand your logs: On node1 you started vdsm with the patch on 2013-12-18 13:33:18. The error "object has no attribute 'format'" is gone with this patch. On node2 I don't see this error at all, and I don't see a restart of vdsm. Maybe the entire log was generated with the patch? It would be nice if you open a bug for this issue. So one problem is gone, but you have other problems: Thread-361::DEBUG::2013-12-18 14:41:42,512::libvirtconnection::108::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc not assigned to domain $ grep 'not assigned to domain' vdsm-node1.log | wc -l 11488 $ grep 'not assigned to domain' vdsm-node2.log | wc -l 3326 $ grep 'not assigned to domain' vdsm-node1.log | awk '{print $6}' | sort -u /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/47015859-1995-4ce2-880c-a3c7068a67dd/341b32d6-4276-454d-b3f0-789b705c99cc /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc $ grep 'not assigned to domain' vdsm-node2.log | awk '{print $6}' | sort -u /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 This issue deserve its own bug.

----- Original Message -----
From: "Nir Soffer" <nsoffer@redhat.com> To: "Sander Grendelman" <sander@grendelman.com> Cc: users@ovirt.org, "Michal Skrivanek" <mskrivan@redhat.com> Sent: Wednesday, December 18, 2013 5:46:37 PM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
----- Original Message -----
From: "Sander Grendelman" <sander@grendelman.com> To: "Nir Soffer" <nsoffer@redhat.com> Cc: "Michal Skrivanek" <mskrivan@redhat.com>, users@ovirt.org, "Ayal Baron" <abaron@redhat.com> Sent: Wednesday, December 18, 2013 4:00:21 PM Subject: Re: [Users] Excessive syslog logging from vdsm/sampling.py
On Wed, Dec 18, 2013 at 1:01 PM, Nir Soffer <nsoffer@redhat.com> wrote:
We should check why vmDrive does not have the format attribute in your case.
Probably because this was checked during migration it's a race between migration finish and monitoring checking this. You can see the error repeated in other cases as well (in bugzilla): 988047, 994534
Then this patch should fix your problem: http://gerrit.ovirt.org/22518
I applied this patch and restarted vdsmd on both nodes (maintenance->restart->activate). The errors still occur, but it is limited to fewer machines ( see [1] ).
- Almost all VMs were imported with virt-v2v (not only the VMs with errors). - Almost all VMs were migrated to another storage domain (offline). - Migration to another host was done with all VMs
The current vdsm logs for both are attached to this e-mail. Please let me know if you need any additional information.
[1]: unique sampling.py errors on both nodes.
#### Node 1 ## Before patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`0ae3a3d7-ead9-4c0d-9df0-3901b6e6859c`::Stats vmId=`22654002-cbef-454d-b001-7823da5f592f`::Stats vmId=`3e481c73-57df-4dc3-8b1c-421a74308a5e`::Stats vmId=`57dbe688-4e18-4358-aa3e-f3f6022ef9b3`::Stats vmId=`66aa5555-2299-4d93-931d-b7a2e421b7e9`::Stats vmId=`6df65698-4995-4c75-9433-75affe9b9c38`::Stats vmId=`9260c69c-93a2-4f8a-b5e9-eaab5e4f4708`::Stats vmId=`9edb3e08-f098-4633-a122-e5ba29ae12ea`::Stats vmId=`c6f56584-1ccd-4c02-be94-897a4e747d34`::Stats vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
## After patch [root@gnkvm01 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats
#### Node 2 ## Before patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages-20131215 | awk '/sampling.py/ {print $8}' | sort -u vmId=`00317758-16fe-4ac6-b9fd-d522c9908861`::Stats vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::Stats vmId=`06405f12-d763-4bd6-b5e5-997e3f6bb1f6`::Stats vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::Stats vmId=`1bba8930-9c04-4c5c-8b15-c9fe14022cb5`::Stats vmId=`2036c21d-e0a4-4d55-a9a7-4cd9dd9d250d`::Stats vmId=`5fff0cc7-24e4-4e4a-b220-ba49f9145060`::Stats vmId=`86708f62-fcc6-4d0f-978a-3788a61f9775`::Stats vmId=`9b8e6d07-295c-404d-a672-efc94a24b6bc`::Stats vmId=`aa0445b6-8ca5-4557-9f9b-ee543d6435df`::Stats
## After patch [root@gnkvm02 ~]# tail -n 2000 /var/log/messages | awk '/sampling.py/ {print $8}' | sort -u vmId=`d3dae626-279b-4bcf-afc4-7a3c198a3035`::Stats
I think I understand your logs:
On node1 you started vdsm with the patch on 2013-12-18 13:33:18.
The error "object has no attribute 'format'" is gone with this patch.
On node2 I don't see this error at all, and I don't see a restart of vdsm. Maybe the entire log was generated with the patch?
It would be nice if you open a bug for this issue.
So one problem is gone, but you have other problems:
Thread-361::DEBUG::2013-12-18 14:41:42,512::libvirtconnection::108::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 8 edom: 10 level: 2 message: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc not assigned to domain
$ grep 'not assigned to domain' vdsm-node1.log | wc -l 11488 $ grep 'not assigned to domain' vdsm-node2.log | wc -l 3326
$ grep 'not assigned to domain' vdsm-node1.log | awk '{print $6}' | sort -u /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11 /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/47015859-1995-4ce2-880c-a3c7068a67dd/341b32d6-4276-454d-b3f0-789b705c99cc /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc
$ grep 'not assigned to domain' vdsm-node2.log | awk '{print $6}' | sort -u /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/347f2238-c018-4370-94df-bd1e81f8b854/9e5dad95-73ea-4e5c-aa13-522efd9bad11
This issue deserve its own bug.
The version you run has several problems: 1. Sometimes drive does not have a format attribute. We do not know yet why this happens. 2. Sometimes sampling drive fails because the drive path is unknown to libvirt. This may be a non-existing drive that should have been removed. We do not know yet why this happens. 3. When such error happen, and you have multiple disks on a vm, sampling stop and next disks in the disk list are skipped. This can explain why your disk stats are constant. 4. The errors spam your vdsm log and syslog These 3 patches do not fix the underlying problems causing the errors, but improve error handling and decrease log spam. 1. http://gerrit.ovirt.org/22518 - vm: Avoid log spamming when drive format is undefined This is a cleaner replacement for the patch you already applied, and required by the next two patches. This patch is likely to be merged to master 2. http://gerrit.ovirt.org/22575 - vm: Continue to sample after errors This patch fix error handling so failure to sample one disk does not effect sampling of other disks. You should see disk stats for "good" drives even if you have one "bad" drive on a vm. 3. http://gerrit.ovirt.org/22576 - vm: Decrease log spam for expected errors This patch logs one line for expected errors instead of 15 lines traceback, reducing log spam. It will be nice if you test these patches and report the results. You ping me on #vdsm if you like to discuss this or need more help. Thanks, Nir

Hi Nir, I've applied the patches on both nodes, attached are syslogs and vdsm logs _after_ the patches were applied. It seems like the amount of logging is decreasing slightly. The disk statistics do not seem to get updated however. Unfortunately I don't have a lot of time to do extra testing today.

The "not assigned to domain"-errors appear to be for thin provisioned disks and for snapshots (which are also shown as thin provisioned by the engine). One of the errors has gone away once I removed all snapshots from the VM. Three recurring errors remain: [root@gnkvm02 ~]# tail -n 1000 /var/log/messages | awk '/not assigned to domain/ {print $8}' | sort | uniq -c 333 vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/02944008-af6a-4901-b889-1f5fbd02bbd1: 332 vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/a2da1070-8de7-4e1f-b736-4c88d089a5cc: 335 vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::b526b148-b810-47c6-9bdd-4fd8d8226855/341b32d6-4276-454d-b3f0-789b705c99cc: [root@gnkvm02 ~]# The first two are for the two thin provisioned disks of a VM with three disks. The last one is for a VM with one preallocated disk which has a snapshot. The syslog is spammed every two seconds by these three messages. Dec 23 16:16:44 gnkvm02 vdsm vm.Vm ERROR vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::b526b148-b810-47c6-9bdd-4fd8d8226855/341b32d6-4276-454d-b3f0-789b705c99cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/47015859-1995-4ce2-880c-a3c7068a67dd/341b32d6-4276-454d-b3f0-789b705c99cc not assigned to domain Dec 23 16:16:46 gnkvm02 vdsm vm.Vm ERROR vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/a2da1070-8de7-4e1f-b736-4c88d089a5cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc not assigned to domain Dec 23 16:16:46 gnkvm02 vdsm vm.Vm ERROR vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/02944008-af6a-4901-b889-1f5fbd02bbd1: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/bcbe3bc8-895d-40be-898b-9e425eefe167/02944008-af6a-4901-b889-1f5fbd02bbd1 not assigned to domain Dec 23 16:16:46 gnkvm02 vdsm vm.Vm ERROR vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::b526b148-b810-47c6-9bdd-4fd8d8226855/341b32d6-4276-454d-b3f0-789b705c99cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/47015859-1995-4ce2-880c-a3c7068a67dd/341b32d6-4276-454d-b3f0-789b705c99cc not assigned to domain Dec 23 16:16:48 gnkvm02 vdsm vm.Vm ERROR vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/a2da1070-8de7-4e1f-b736-4c88d089a5cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc not assigned to domain Dec 23 16:16:48 gnkvm02 vdsm vm.Vm ERROR vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/02944008-af6a-4901-b889-1f5fbd02bbd1: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/bcbe3bc8-895d-40be-898b-9e425eefe167/02944008-af6a-4901-b889-1f5fbd02bbd1 not assigned to domain Dec 23 16:16:48 gnkvm02 vdsm vm.Vm ERROR vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::b526b148-b810-47c6-9bdd-4fd8d8226855/341b32d6-4276-454d-b3f0-789b705c99cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/47015859-1995-4ce2-880c-a3c7068a67dd/341b32d6-4276-454d-b3f0-789b705c99cc not assigned to domain Dec 23 16:16:50 gnkvm02 vdsm vm.Vm ERROR vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/a2da1070-8de7-4e1f-b736-4c88d089a5cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/c928f2c7-9ba0-496f-8be9-b8804fdc1a6d/a2da1070-8de7-4e1f-b736-4c88d089a5cc not assigned to domain Dec 23 16:16:50 gnkvm02 vdsm vm.Vm ERROR vmId=`007ca72e-d0d0-4477-87d4-fb60328cd882`::b526b148-b810-47c6-9bdd-4fd8d8226855/02944008-af6a-4901-b889-1f5fbd02bbd1: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/bcbe3bc8-895d-40be-898b-9e425eefe167/02944008-af6a-4901-b889-1f5fbd02bbd1 not assigned to domain Dec 23 16:16:50 gnkvm02 vdsm vm.Vm ERROR vmId=`1075a178-a4c6-4a8f-a199-56401cd0652f`::b526b148-b810-47c6-9bdd-4fd8d8226855/341b32d6-4276-454d-b3f0-789b705c99cc: invalid argument: invalid path /rhev/data-center/mnt/blockSD/b526b148-b810-47c6-9bdd-4fd8d8226855/images/47015859-1995-4ce2-880c-a3c7068a67dd/341b32d6-4276-454d-b3f0-789b705c99cc not assigned to domain On Fri, Dec 20, 2013 at 1:53 PM, Sander Grendelman <sander@grendelman.com>wrote:
Hi Nir,
I've applied the patches on both nodes, attached are syslogs and vdsm logs _after_ the patches were applied. It seems like the amount of logging is decreasing slightly. The disk statistics do not seem to get updated however. Unfortunately I don't have a lot of time to do extra testing today.
participants (5)
-
Ayal Baron
-
Itamar Heim
-
Nir Soffer
-
Sander Grendelman
-
Vinzenz Feenstra