[Users] ::VolumeGroupReplaceTagError::

Ayal Baron abaron at redhat.com
Mon Jul 22 10:42:49 UTC 2013



----- 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