Thread-12::DEBUG::2012-04-19 12:29:53,779::hsm::359::Storage.HSM::(__cleanStorageRepository) Started cleaning storage repository at '/rhev/data-center'
Thread-18::DEBUG::2012-04-19 12:29:53,780::misc::1101::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-12::DEBUG::2012-04-19 12:29:53,781::hsm::391::Storage.HSM::(__cleanStorageRepository) White list: ['/rhev/data-center/hsm-tasks', '/rhev/data-center/hsm-tasks/*', '/rhev/data-center/mnt']
Thread-18::DEBUG::2012-04-19 12:29:53,781::misc::1103::SamplingMethod::(__call__) Got in to sampling method
Thread-12::DEBUG::2012-04-19 12:29:53,781::hsm::392::Storage.HSM::(__cleanStorageRepository) Mount list: ['/rhev/data-center/mnt/cmcd-db-vip.in.hwlab:_vmstore_ovirt']
Thread-18::DEBUG::2012-04-19 12:29:53,781::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
Thread-12::DEBUG::2012-04-19 12:29:53,781::hsm::394::Storage.HSM::(__cleanStorageRepository) Cleaning leftovers
Thread-12::DEBUG::2012-04-19 12:29:53,786::hsm::437::Storage.HSM::(__cleanStorageRepository) Finished cleaning storage repository at '/rhev/data-center'
Thread-18::DEBUG::2012-04-19 12:29:53,794::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
Thread-18::DEBUG::2012-04-19 12:29:53,795::misc::1111::SamplingMethod::(__call__) Returning last result
Thread-18::DEBUG::2012-04-19 12:29:55,715::__init__::1164::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/multipath' (cwd None)
Thread-18::DEBUG::2012-04-19 12:29:55,760::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-18::DEBUG::2012-04-19 12:29:55,760::lvm::474::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,761::lvm::476::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,761::lvm::486::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,761::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,761::lvm::507::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,762::lvm::509::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,762::misc::1111::SamplingMethod::(__call__) Returning last result
Thread-18::DEBUG::2012-04-19 12:29:55,762::lvm::366::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:55,763::__init__::1164::Storage.Misc.excCmd::(_log) '/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 = [ \\"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 e12a0f53-ee72-44bc-ad26-93f9b4613c6c' (cwd None)
Thread-18::DEBUG::2012-04-19 12:29:55,781::__init__::1164::Storage.Misc.excCmd::(_log) FAILED: <err> = '  Volume group "e12a0f53-ee72-44bc-ad26-93f9b4613c6c" not found\n'; <rc> = 5
Thread-18::WARNING::2012-04-19 12:29:55,782::lvm::370::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] ['  Volume group "e12a0f53-ee72-44bc-ad26-93f9b4613c6c" not found']
Thread-18::DEBUG::2012-04-19 12:29:55,782::lvm::393::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:56,392::fileSD::101::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/cmcd-db-vip.in.hwlab:_vmstore_ovirt/e12a0f53-ee72-44bc-ad26-93f9b4613c6c
Thread-18::DEBUG::2012-04-19 12:29:56,393::persistentDict::175::Storage.PersistentDict::(__init__) Created a persistant dict with FileMetadataRW backend
Thread-18::DEBUG::2012-04-19 12:29:56,403::persistentDict::216::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=glusternfs', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1', 'POOL_DESCRIPTION=Default', 'POOL_DOMAINS=e12a0f53-ee72-44bc-ad26-93f9b4613c6c:Active', 'POOL_SPM_ID=1', 'POOL_SPM_LVER=0', 'POOL_UUID=af5bcc86-898a-11e1-9632-003048c85226', 'REMOTE_PATH=cmcd-db-vip.in.hwlab:/vmstore/ovirt', 'ROLE=Master', 'SDUUID=e12a0f53-ee72-44bc-ad26-93f9b4613c6c', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=3b71084c285a0ba4f74aaba162dae64224b6d8ff']
Thread-18::DEBUG::2012-04-19 12:29:56,407::fileSD::324::Storage.StorageDomain::(imageGarbageCollector) Removing remnants of deleted images []
Thread-18::DEBUG::2012-04-19 12:29:56,407::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'e12a0f53-ee72-44bc-ad26-93f9b4613c6c_imageNS'
Thread-18::DEBUG::2012-04-19 12:29:56,408::resourceManager::379::ResourceManager::(registerNamespace) Registering namespace 'e12a0f53-ee72-44bc-ad26-93f9b4613c6c_volumeNS'
Thread-18::DEBUG::2012-04-19 12:29:56,408::sp::1460::Storage.StoragePool::(getMasterDomain) Master domain e12a0f53-ee72-44bc-ad26-93f9b4613c6c verified, version 1
Thread-18::DEBUG::2012-04-19 12:29:56,408::misc::1101::SamplingMethod::(__call__) Trying to enter sampling method (storage.sp.updateMonitoringThreads)
Thread-18::DEBUG::2012-04-19 12:29:56,409::misc::1103::SamplingMethod::(__call__) Got in to sampling method
Thread-18::DEBUG::2012-04-19 12:29:56,413::persistentDict::216::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=glusternfs', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1', 'POOL_DESCRIPTION=Default', 'POOL_DOMAINS=e12a0f53-ee72-44bc-ad26-93f9b4613c6c:Active', 'POOL_SPM_ID=1', 'POOL_SPM_LVER=0', 'POOL_UUID=af5bcc86-898a-11e1-9632-003048c85226', 'REMOTE_PATH=cmcd-db-vip.in.hwlab:/vmstore/ovirt', 'ROLE=Master', 'SDUUID=e12a0f53-ee72-44bc-ad26-93f9b4613c6c', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=3b71084c285a0ba4f74aaba162dae64224b6d8ff']
Thread-18::DEBUG::2012-04-19 12:29:56,414::sp::1490::Storage.StoragePool::(updateMonitoringThreads) sp `af5bcc86-898a-11e1-9632-003048c85226` started monitoring domain `e12a0f53-ee72-44bc-ad26-93f9b4613c6c`
Thread-18::DEBUG::2012-04-19 12:29:56,415::misc::1111::SamplingMethod::(__call__) Returning last result
Thread-18::DEBUG::2012-04-19 12:29:56,417::lvm::366::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-18::DEBUG::2012-04-19 12:29:56,417::__init__::1164::Storage.Misc.excCmd::(_log) '/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 = [ \\"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' (cwd None)
Thread-18::DEBUG::2012-04-19 12:29:56,444::__init__::1164::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '  No volume groups found\n'; <rc> = 0
Thread-18::DEBUG::2012-04-19 12:29:56,444::lvm::393::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-18::INFO::2012-04-19 12:29:56,447::sp::1062::Storage.StoragePool::(_linkStorageDomain) Linking /rhev/data-center/mnt/cmcd-db-vip.in.hwlab:_vmstore_ovirt/e12a0f53-ee72-44bc-ad26-93f9b4613c6c to /rhev/data-center/af5bcc86-898a-11e1-9632-003048c85226/e12a0f53-ee72-44bc-ad26-93f9b4613c6c
Thread-18::INFO::2012-04-19 12:29:56,448::sp::1062::Storage.StoragePool::(_linkStorageDomain) Linking /rhev/data-center/mnt/cmcd-db-vip.in.hwlab:_vmstore_ovirt/e12a0f53-ee72-44bc-ad26-93f9b4613c6c to /rhev/data-center/af5bcc86-898a-11e1-9632-003048c85226/mastersd
Thread-18::DEBUG::2012-04-19 12:29:56,448::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.af5bcc86-898a-11e1-9632-003048c85226'
Thread-18::DEBUG::2012-04-19 12:29:56,449::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.af5bcc86-898a-11e1-9632-003048c85226' (0 active users)
Thread-18::DEBUG::2012-04-19 12:29:56,449::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.af5bcc86-898a-11e1-9632-003048c85226' is free, finding out if anyone is waiting for it.
Thread-18::DEBUG::2012-04-19 12:29:56,449::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.af5bcc86-898a-11e1-9632-003048c85226', Clearing records.
Thread-18::INFO::2012-04-19 12:29:56,449::logUtils::39::dispatcher::(wrapper) Run and protect: connectStoragePool, Return response: True
Thread-18::DEBUG::2012-04-19 12:29:56,450::task::1172::TaskManager.Task::(prepare) Task=`7f46d378-c3b9-41ed-9ede-33e7e69cd440`::finished: True
Thread-18::DEBUG::2012-04-19 12:29:56,450::task::588::TaskManager.Task::(_updateState) Task=`7f46d378-c3b9-41ed-9ede-33e7e69cd440`::moving from state preparing -> state finished