[Users] ::VolumeGroupReplaceTagError::
Pavia Daniele
dan.pavia at eng.it
Mon Jul 22 10:53:21 UTC 2013
Hi Ayal,
my bad, noob mistake. Fed19 host is running lvm2-2.02.98-9.fc19.x86_64,
the Fed18 machines are running lvm2-2.02.98-4.fc18.x86_64, they're all
coming from the stable repos. Think this gap in versions could be the cause?
Cheers,
Daniele
On 07/22/2013 12:42 PM, Ayal Baron wrote:
>
> ----- Original Message -----
>> Hi Ayal,
>> thanks for your reply! Well, I just realized that I didn't give the
>> whole picture: I've got a Fed18 3.2 engine and a Fed18 host running as
>> SPM. I added a second Fed19 host whose log you're looking at right now.
>> So, yes - that's the Fed19 host trying to become SPM when the Fed18 host
>> goes in maintenance. As far as I understand, the error message you've
>> found makes me think there's something missing when the Fed19 host tries
>> to vgchange the tags on the storage domain's volume group:
>>
>> # vgs
>> VG #PV #LV #SN Attr VSize VFree
>> a646d974-19be-4a8d-bf68-a3974d46a823 1 17 0 wz--n- 511.62g 473.12g
>> fedora 1 3 0 wz--n- 67.50g 0
>>
>> Now, if I manually run the same command on the Fed19 while it's trying
>> to be elected as SPM:
>>
>> /usr/bin/sudo -n /sbin/lvm vgchange --config " devices { preferred_names
>> = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0
>> disable_after_error_count=3 filter = [
>> \\"a%360060160f4d03100dc456812fdb3e211%\\", \\"r%.*%\\" ] } global {
>> locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup {
>> retain_min = 50 retain_days = 0 } " --deltag MDT_POOL_SPM_LVER=18
>> --deltag MDT_POOL_SPM_ID=-1 --deltag
>> MDT__SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c --addtag
>> MDT_POOL_SPM_ID=1 --addtag
>> MDT__SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074 --addtag
>> MDT_POOL_SPM_LVER=19 a646d974-19be-4a8d-bf68-a3974d46a823
>>
>> Parse error at byte 31 (line 1): expected a value
>> Failed to set overridden configuration entries.
>> Run `vgchange --help' for more information.
>>
>> Does this ring a bell?
> This looks like shell issues (you cannot simply copy the command from the log and run it as it goes through some shell processing when run from python.
> What version of lvm do you have on this host?
>
>> Cheers,
>> Daniele
>>
>> On 07/21/2013 01:03 PM, Ayal Baron wrote:
>>> Hi Daniele,
>>>
>>> Your lvm version seems wrong:
>>>
>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>> 11:01:07,161::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
>>> /sbin/lvm vgchange ... --deltag MDT_POOL_SPM_LVER=18 --deltag
>>> MDT_POOL_SPM_ID=-1 --deltag
>>> MDT__SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c --addtag
>>> MDT_POOL_SPM_ID=1 --addtag
>>> MDT__SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074 --addtag
>>> MDT_POOL_SPM_LVER=19 a646d974-19be-4a8d-bf68-a3974d46a823'
>>>
>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>> 11:01:07,200::misc::84::Storage.Misc.excCmd::(<lambda>) FAILED: <err> = '
>>> /dev/mapper/360060160f4d03100dc456812fdb3e211: lseek 18446744073575333888
>>> failed: Invalid argument\n'; <rc> = 5
>>>
>>> I'm guessing this is the Fedora 18?
>>> Can you attach the vdsm.log for the Fedora 19 as well?
>>>
>>> ----- Original Message -----
>>>> Hello everybody,
>>>> I've been experimenting a bit with Fedora 19 + vdsm and I'm getting this
>>>> funny VolumeGroupReplaceTagError . I've got a 3.2 engine running with two
>>>> hosts, a Fed18 and a Fed19, both sporting vdsm-4.10.3-17. I can run VMs on
>>>> both hostss but I can't migrate them and, worst of them all, the engine
>>>> can't elect the Fe19 host as SPM - it just keeps trying and trying to no
>>>> avail. What's even weirder is that the Fed19's vdsm keeps complaining
>>>> about
>>>> not being able to find the storage, even when VMs are up and running on
>>>> the
>>>> very same host. Both hosts are accessing the same LUN via fibre channel.
>>>>
>>>> here is an excerpt from the offending vdsm running a VM:
>>>>
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,078::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
>>>> /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"]
>>>> ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
>>>> filter = [ \\"a%360060160f4d03100dc456812fdb3e211%\\", \\"r%.*%\\" ] }
>>>> global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup
>>>> {
>>>> retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix
>>>> --separator | -o
>>>> uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free
>>>> a646d974-19be-4a8d-bf68-a3974d46a823' (cwd None)
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,115::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
>>>> '';
>>>> <rc> = 0
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,117::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload
>>>> operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,117::persistentDict::234::Storage.PersistentDict::(refresh) read
>>>> lines
>>>> (VGTagMetadataRW)=[u'PV0=pv:mpathb,uuid:TMIy2w-1GR2-DW93-SETn-AhJG-yXfA-mHYwWW,pestart:0,pecount:4093,mapoffset:0',
>>>> 'VERSION=3', 'LOGBLKSIZE=512', 'DESCRIPTION=provisioning1',
>>>> 'LEASERETRIES=3', 'LOCKRENEWALINTERVALSEC=5', 'LOCKPOLICY=',
>>>> 'PHYBLKSIZE=512', 'SDUUID=a646d974-19be-4a8d-bf68-a3974d46a823',
>>>> 'CLASS=Data', 'TYPE=FCP', 'VGUUID=bqt7AY-kDVm-rZnW-IMI6-83Zy-5Go2-HvNY6Y',
>>>> 'IOOPTIMEOUTSEC=10', 'LEASETIMESEC=60', 'MASTER_VERSION=1',
>>>> 'POOL_UUID=c923d5bb-ea08-44ea-937d-10eea4485ae2', 'ROLE=Master',
>>>> 'POOL_DESCRIPTION=AreaProvisioning',
>>>> u'POOL_DOMAINS=a646d974-19be-4a8d-bf68-a3974d46a823:Active,53b27dc5-fa49-4257-962d-b475e160d7b3:Active',
>>>> 'POOL_SPM_LVER=18', 'POOL_SPM_ID=-1',
>>>> '_SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c']
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,118::persistentDict::167::Storage.PersistentDict::(transaction)
>>>> Starting transaction
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,118::persistentDict::173::Storage.PersistentDict::(transaction)
>>>> Flushing changes
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,119::persistentDict::299::Storage.PersistentDict::(flush) about
>>>> to
>>>> write lines (VGTagMetadataRW)=['CLASS=Data', 'DESCRIPTION=provisioning1',
>>>> 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
>>>> 'LOCKRENEWALINTERVALSEC=5', 'LOGBLKSIZE=512', 'MASTER_VERSION=1',
>>>> 'PHYBLKSIZE=512', 'POOL_DESCRIPTION=AreaProvisioning',
>>>> u'POOL_DOMAINS=a646d974-19be-4a8d-bf68-a3974d46a823:Active,53b27dc5-fa49-4257-962d-b475e160d7b3:Active',
>>>> 'POOL_SPM_ID=1', 'POOL_SPM_LVER=19',
>>>> 'POOL_UUID=c923d5bb-ea08-44ea-937d-10eea4485ae2',
>>>> u'PV0=pv:mpathb,uuid:TMIy2w-1GR2-DW93-SETn-AhJG-yXfA-mHYwWW,pestart:0,pecount:4093,mapoffset:0',
>>>> 'ROLE=Master', 'SDUUID=a646d974-19be-4a8d-bf68-a3974d46a823', 'TYPE=FCP',
>>>> 'VERSION=3', 'VGUUID=bqt7AY-kDVm-rZnW-IMI6-83Zy-5Go2-HvNY6Y',
>>>> '_SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074']
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,119::lvm::483::OperationMutex::(_invalidatevgs) Operation 'lvm
>>>> invalidate operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,119::lvm::485::OperationMutex::(_invalidatevgs) Operation 'lvm
>>>> invalidate operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,120::lvm::493::OperationMutex::(_invalidatelvs) Operation 'lvm
>>>> invalidate operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,120::lvm::505::OperationMutex::(_invalidatelvs) Operation 'lvm
>>>> invalidate operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,120::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload
>>>> operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,121::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
>>>> /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"]
>>>> ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
>>>> filter = [ \\"a%360060160f4d03100dc456812fdb3e211%\\", \\"r%.*%\\" ] }
>>>> global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup
>>>> {
>>>> retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix
>>>> --separator | -o
>>>> uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free
>>>> a646d974-19be-4a8d-bf68-a3974d46a823' (cwd None)
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,157::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
>>>> '';
>>>> <rc> = 0
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,159::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload
>>>> operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,160::blockSD::300::storage.Metadata.VGTagMetadataRW::(writelines)
>>>> Updating metadata adding=MDT_POOL_SPM_ID=1,
>>>> MDT__SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074,
>>>> MDT_POOL_SPM_LVER=19 removing=MDT_POOL_SPM_ID=-1,
>>>> MDT__SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c,
>>>> MDT_POOL_SPM_LVER=18
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,161::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
>>>> /sbin/lvm vgchange --config " devices { preferred_names =
>>>> [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0
>>>> disable_after_error_count=3 filter = [
>>>> \\"a%360060160f4d03100dc456812fdb3e211%\\", \\"r%.*%\\" ] } global {
>>>> locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup {
>>>> retain_min = 50 retain_days = 0 } " --deltag MDT_POOL_SPM_LVER=18 --deltag
>>>> MDT_POOL_SPM_ID=-1 --deltag
>>>> MDT__SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c --addtag
>>>> MDT_POOL_SPM_ID=1 --addtag
>>>> MDT__SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074 --addtag
>>>> MDT_POOL_SPM_LVER=19 a646d974-19be-4a8d-bf68-a3974d46a823' (cwd None)
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,200::misc::84::Storage.Misc.excCmd::(<lambda>) FAILED: <err> = '
>>>> /dev/mapper/360060160f4d03100dc456812fdb3e211: lseek 18446744073575333888
>>>> failed: Invalid argument\n'; <rc> = 5
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,204::lvm::483::OperationMutex::(_invalidatevgs) Operation 'lvm
>>>> invalidate operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,204::lvm::485::OperationMutex::(_invalidatevgs) Operation 'lvm
>>>> invalidate operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::WARNING::2013-07-18
>>>> 11:01:07,205::persistentDict::178::Storage.PersistentDict::(transaction)
>>>> Error in transaction, rolling back changes
>>>> Traceback (most recent call last):
>>>> File "/usr/share/vdsm/storage/persistentDict.py", line 174, in transaction
>>>> self.flush(self._metadata)
>>>> File "/usr/share/vdsm/storage/persistentDict.py", line 300, in flush
>>>> self._metaRW.writelines(lines)
>>>> File "/usr/share/vdsm/storage/blockSD.py", line 301, in writelines
>>>> lvm.changeVGTags(self._vgName, delTags=toRemove, addTags=toAdd)
>>>> File "/usr/share/vdsm/storage/lvm.py", line 1219, in changeVGTags
>>>> (vgName, ", ".join(delTags), ", ".join(addTags), err[-1]))
>>>> VolumeGroupReplaceTagError: Replace Volume Group tag error:
>>>> ('vg:a646d974-19be-4a8d-bf68-a3974d46a823 del:MDT_POOL_SPM_LVER=18,
>>>> MDT_POOL_SPM_ID=-1,
>>>> MDT__SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c
>>>> add:MDT_POOL_SPM_ID=1,
>>>> MDT__SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074,
>>>> MDT_POOL_SPM_LVER=19 ( /dev/mapper/360060160f4d03100dc456812fdb3e211:
>>>> lseek
>>>> 18446744073575333888 failed: Invalid argument)',)
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,206::persistentDict::299::Storage.PersistentDict::(flush) about
>>>> to
>>>> write lines (VGTagMetadataRW)=['CLASS=Data', 'DESCRIPTION=provisioning1',
>>>> 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
>>>> 'LOCKRENEWALINTERVALSEC=5', 'LOGBLKSIZE=512', 'MASTER_VERSION=1',
>>>> 'PHYBLKSIZE=512', 'POOL_DESCRIPTION=AreaProvisioning',
>>>> u'POOL_DOMAINS=a646d974-19be-4a8d-bf68-a3974d46a823:Active,53b27dc5-fa49-4257-962d-b475e160d7b3:Active',
>>>> 'POOL_SPM_ID=-1', 'POOL_SPM_LVER=18',
>>>> 'POOL_UUID=c923d5bb-ea08-44ea-937d-10eea4485ae2',
>>>> u'PV0=pv:mpathb,uuid:TMIy2w-1GR2-DW93-SETn-AhJG-yXfA-mHYwWW,pestart:0,pecount:4093,mapoffset:0',
>>>> 'ROLE=Master', 'SDUUID=a646d974-19be-4a8d-bf68-a3974d46a823', 'TYPE=FCP',
>>>> 'VERSION=3', 'VGUUID=bqt7AY-kDVm-rZnW-IMI6-83Zy-5Go2-HvNY6Y',
>>>> '_SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c']
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,206::lvm::483::OperationMutex::(_invalidatevgs) Operation 'lvm
>>>> invalidate operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,206::lvm::485::OperationMutex::(_invalidatevgs) Operation 'lvm
>>>> invalidate operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,207::lvm::493::OperationMutex::(_invalidatelvs) Operation 'lvm
>>>> invalidate operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,207::lvm::505::OperationMutex::(_invalidatelvs) Operation 'lvm
>>>> invalidate operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,207::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload
>>>> operation' got the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,208::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo -n
>>>> /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"]
>>>> ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
>>>> filter = [ \\"a%360060160f4d03100dc456812fdb3e211%\\", \\"r%.*%\\" ] }
>>>> global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup
>>>> {
>>>> retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix
>>>> --separator | -o
>>>> uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free
>>>> a646d974-19be-4a8d-bf68-a3974d46a823' (cwd None)
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,244::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> =
>>>> '';
>>>> <rc> = 0
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::DEBUG::2013-07-18
>>>> 11:01:07,246::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload
>>>> operation' released the operation mutex
>>>> 9b238eef-380f-4fd4-aca1-465f675b7656::ERROR::2013-07-18
>>>> 11:01:07,247::sp::314::Storage.StoragePool::(startSpm) Unexpected error
>>>> Traceback (most recent call last):
>>>> File "/usr/share/vdsm/storage/sp.py", line 268, in startSpm
>>>> PMDK_SPM_ID: self.id}, __securityOverride=True)
>>>> File "/usr/share/vdsm/storage/securable.py", line 68, in wrapper
>>>> return f(self, *args, **kwargs)
>>>> File "/usr/share/vdsm/storage/sp.py", line 1478, in setMetaParams
>>>> self._metadata.update(params)
>>>> File "/usr/share/vdsm/storage/persistentDict.py", line 121, in update
>>>> self._dict.update(metadata)
>>>> File "/usr/share/vdsm/storage/persistentDict.py", line 214, in update
>>>> self._metadata.update(metadata)
>>>> File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
>>>> self.gen.next()
>>>> File "/usr/share/vdsm/storage/persistentDict.py", line 174, in transaction
>>>> self.flush(self._metadata)
>>>> File "/usr/share/vdsm/storage/persistentDict.py", line 300, in flush
>>>> self._metaRW.writelines(lines)
>>>> File "/usr/share/vdsm/storage/blockSD.py", line 301, in writelines
>>>> lvm.changeVGTags(self._vgName, delTags=toRemove, addTags=toAdd)
>>>> File "/usr/share/vdsm/storage/lvm.py", line 1219, in changeVGTags
>>>> (vgName, ", ".join(delTags), ", ".join(addTags), err[-1]))
>>>> VolumeGroupReplaceTagError: Replace Volume Group tag error:
>>>> ('vg:a646d974-19be-4a8d-bf68-a3974d46a823 del:MDT_POOL_SPM_LVER=18,
>>>> MDT_POOL_SPM_ID=-1,
>>>> MDT__SHA_CKSUM=7d5585b7b7adeabd4cb193ea6f3e5af06bd8f64c
>>>> add:MDT_POOL_SPM_ID=1,
>>>> MDT__SHA_CKSUM=79a6a0705dc0011d7f44f24b5c639f5d8baae074,
>>>> MDT_POOL_SPM_LVER=19 ( /dev/mapper/360060160f4d03100dc456812fdb3e211:
>>>> lseek
>>>> 18446744073575333888 failed: Invalid argument)',)
>>>>
>>>> meanwhile, on the engine side of the thing (same behaviour at a different
>>>> time of the day):
>>>>
>>>> 2013-07-18 15:19:18,736 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-10) [1cdd7d6f] START,
>>>> HSMClearTaskVDSCommand(HostName = heidi, HostId =
>>>> 7c0f1d65-750e-458c-95ac-90846d4755bf,
>>>> taskId=4879a4ab-41fc-4991-a93b-7407a21701e0), log id: bff1ad1
>>>> 2013-07-18 15:19:18,745 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-10) [1cdd7d6f] FINISH,
>>>> HSMClearTaskVDSCommand, log id: bff1ad1
>>>> 2013-07-18 15:19:18,746 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-10) [1cdd7d6f] FINISH, SpmStartVDSCommand,
>>>> return:
>>>> org.ovirt.engine.core.common.businessentities.SpmStatusResult at 1939957e,
>>>> log
>>>> id: 72518013
>>>> 2013-07-18 15:19:18,749 INFO
>>>> [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand]
>>>> (DefaultQuartzScheduler_Worker-10) [13859022] Running command:
>>>> SetStoragePoolStatusCommand internal: true. Entities affected : ID:
>>>> c923d5bb-ea08-44ea-937d-10eea4485ae2 Type: StoragePool
>>>> 2013-07-18 15:19:18,783 INFO
>>>> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
>>>> (DefaultQuartzScheduler_Worker-10) [13859022] No string for
>>>> SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC type. Use default Log
>>>> 2013-07-18 15:19:18,790 ERROR
>>>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>>>> (DefaultQuartzScheduler_Worker-10) [13859022]
>>>> IrsBroker::Failed::GetStoragePoolInfoVDS due to:
>>>> IrsSpmStartFailedException:
>>>> IRSGenericException: IRSErrorException: SpmStart failed
>>>> 2013-07-18 15:19:28,893 INFO
>>>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] hostFromVds::selectedVds -
>>>> heidi, spmStatus Free, storage pool AreaProvisioning
>>>> 2013-07-18 15:19:28,899 INFO
>>>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] starting spm on vds heidi,
>>>> storage pool AreaProvisioning, prevId -1, LVER 18
>>>> 2013-07-18 15:19:28,925 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] START,
>>>> SpmStartVDSCommand(HostName = heidi, HostId =
>>>> 7c0f1d65-750e-458c-95ac-90846d4755bf, storagePoolId =
>>>> c923d5bb-ea08-44ea-937d-10eea4485ae2, prevId=-1, prevLVER=18,
>>>> storagePoolFormatType=V3, recoveryMode=Manual, SCSIFencing=false), log id:
>>>> 1101aacc
>>>> 2013-07-18 15:19:28,942 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] spmStart polling started:
>>>> taskId = 03d8ee8f-cf3d-42c5-be4a-a9136f5e9fa1
>>>> 2013-07-18 15:19:29,974 ERROR
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] Failed in HSMGetTaskStatusVDS
>>>> method
>>>> 2013-07-18 15:19:29,976 ERROR
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] Error code
>>>> VolumeGroupReplaceTagError and error message VDSGenericException:
>>>> VDSErrorException: Failed to HSMGetTaskStatusVDS, error = Replace Volume
>>>> Group tag error
>>>> 2013-07-18 15:19:29,977 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] spmStart polling ended:
>>>> taskId
>>>> = 03d8ee8f-cf3d-42c5-be4a-a9136f5e9fa1 task status = finished
>>>> 2013-07-18 15:19:29,978 ERROR
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] Start SPM Task failed -
>>>> result:
>>>> cleanSuccess, message: VDSGenericException: VDSErrorException: Failed to
>>>> HSMGetTaskStatusVDS, error = Replace Volume Group tag error
>>>> 2013-07-18 15:19:29,985 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] spmStart polling ended, spm
>>>> status: Free
>>>> 2013-07-18 15:19:30,010 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] START,
>>>> HSMClearTaskVDSCommand(HostName = heidi, HostId =
>>>> 7c0f1d65-750e-458c-95ac-90846d4755bf,
>>>> taskId=03d8ee8f-cf3d-42c5-be4a-a9136f5e9fa1), log id: 115a9661
>>>> 2013-07-18 15:19:30,018 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] FINISH,
>>>> HSMClearTaskVDSCommand,
>>>> log id: 115a9661
>>>> 2013-07-18 15:19:30,019 INFO
>>>> [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [19567f5a] FINISH, SpmStartVDSCommand,
>>>> return:
>>>> org.ovirt.engine.core.common.businessentities.SpmStatusResult at 5246c32d,
>>>> log
>>>> id: 1101aacc
>>>> 2013-07-18 15:19:30,022 INFO
>>>> [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [23b7e98e] Running command:
>>>> SetStoragePoolStatusCommand internal: true. Entities affected : ID:
>>>> c923d5bb-ea08-44ea-937d-10eea4485ae2 Type: StoragePool
>>>> 2013-07-18 15:19:30,054 INFO
>>>> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
>>>> (DefaultQuartzScheduler_Worker-5) [23b7e98e] No string for
>>>> SYSTEM_CHANGE_STORAGE_POOL_STATUS_PROBLEMATIC type. Use default Log
>>>> 2013-07-18 15:19:30,061 ERROR
>>>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>>>> (DefaultQuartzScheduler_Worker-5) [23b7e98e]
>>>> IrsBroker::Failed::GetStoragePoolInfoVDS due to:
>>>> IrsSpmStartFailedException:
>>>> IRSGenericException: IRSErrorException: SpmStart failed
>>>>
>>>> the whole vdsm log is attached. Got any clues?
>>>>
>>>> Thanks,
>>>> Daniele Pavia
>>>>
>>>> Engineering I.I.
>>>> R&D Labs
>>>>
>>>>
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users at ovirt.org
>>>> http://lists.ovirt.org/mailman/listinfo/users
>>>>
>>> _______________________________________________
>>> Users mailing list
>>> Users at ovirt.org
>>> http://lists.ovirt.org/mailman/listinfo/users
>>
More information about the Users
mailing list