Dear All,
After we updated our hypervisors to :
vdsm-4.16.7-1.gitdb83943.el6.x86_64
vdsm-python-4.16.7-1.gitdb83943.el6.noarch
vdsm-python-zombiereaper-4.16.7-1.gitdb83943.el6.noarch
vdsm-xmlrpc-4.16.7-1.gitdb83943.el6.noarch
vdsm-yajsonrpc-4.16.7-1.gitdb83943.el6.noarch
vdsm-jsonrpc-4.16.7-1.gitdb83943.el6.noarch
vdsm-cli-4.16.7-1.gitdb83943.el6.noarch
We don't have access to our storage domain anymore. He jsut doesn't see the
disks anymore...
I added the vdsm log and engine log. I'm clueless... BEfore he did see the
storage domains, now after the system update he doesn't anymore...
Thanks in advance,
Kind regards,
Koen
[root@ovirtmgmt01prod ~]# tail -f /var/log/ovirt-engine/engine.log
2014-12-04 08:58:50,192 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-96) Command HSMGetAllTasksStatusesVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e) execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM: ()
2014-12-04 08:59:20,247 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (DefaultQuartzScheduler_Worker-96) Command ConnectStoragePoolVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, vdsId = dfddc678-f8ee-45eb-897a-885c83de870e, storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, masterVersion = 8) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 08:59:20,248 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-96) IrsBroker::Failed::GetStoragePoolInfoVDS due to: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue)
2014-12-04 08:59:30,418 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-45) Command HSMGetAllTasksStatusesVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e) execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM: ()
2014-12-04 08:59:47,985 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-45) Domain eb912657-8a8c-4173-9d24-92d2b09a773c:StoragePoolDMZ03 was reported by all hosts in status UP as problematic. Not moving the domain to NonOperational because it is being reconstructed now.
2014-12-04 08:59:50,188 WARN [org.ovirt.engine.core.bll.scheduling.policyunits.EvenGuestDistributionBalancePolicyUnit] (DefaultQuartzScheduler_Worker-68) There is no host with less than 5 running guests
2014-12-04 08:59:50,189 WARN [org.ovirt.engine.core.bll.scheduling.PolicyUnitImpl] (DefaultQuartzScheduler_Worker-68) All hosts are over-utilized, cant balance the cluster SandyBridgeCluster
2014-12-04 09:00:00,469 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (DefaultQuartzScheduler_Worker-45) Command ConnectStoragePoolVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, vdsId = dfddc678-f8ee-45eb-897a-885c83de870e, storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, masterVersion = 8) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 09:00:00,470 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-45) IrsBroker::Failed::GetStoragePoolInfoVDS due to: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue)
2014-12-04 09:00:10,597 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-81) Command HSMGetAllTasksStatusesVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e) execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM: ()
2014-12-04 09:00:40,718 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (DefaultQuartzScheduler_Worker-81) Command ConnectStoragePoolVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, vdsId = dfddc678-f8ee-45eb-897a-885c83de870e, storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, masterVersion = 8) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 09:00:40,719 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-81) IrsBroker::Failed::GetStoragePoolInfoVDS due to: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue)
2014-12-04 09:00:50,439 WARN [org.ovirt.engine.core.bll.scheduling.policyunits.EvenGuestDistributionBalancePolicyUnit] (DefaultQuartzScheduler_Worker-1) There is no host with less than 5 running guests
2014-12-04 09:00:50,442 WARN [org.ovirt.engine.core.bll.scheduling.PolicyUnitImpl] (DefaultQuartzScheduler_Worker-1) All hosts are over-utilized, cant balance the cluster SandyBridgeCluster
2014-12-04 09:00:50,863 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-40) Command HSMGetAllTasksStatusesVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e) execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM: ()
2014-12-04 09:01:20,929 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (DefaultQuartzScheduler_Worker-40) Command ConnectStoragePoolVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, vdsId = dfddc678-f8ee-45eb-897a-885c83de870e, storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, masterVersion = 8) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 09:01:20,932 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-40) IrsBroker::Failed::GetStoragePoolInfoVDS due to: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue)
2014-12-04 09:01:31,110 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-57) Command HSMGetAllTasksStatusesVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e) execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM: ()
2014-12-04 09:01:50,657 WARN [org.ovirt.engine.core.bll.scheduling.policyunits.EvenGuestDistributionBalancePolicyUnit] (DefaultQuartzScheduler_Worker-82) There is no host with less than 5 running guests
2014-12-04 09:01:50,659 WARN [org.ovirt.engine.core.bll.scheduling.PolicyUnitImpl] (DefaultQuartzScheduler_Worker-82) All hosts are over-utilized, cant balance the cluster SandyBridgeCluster
2014-12-04 09:01:52,886 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-37) [1082f14c] Command GetVGInfoVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, VGID=N7wm36-uh0L-kvee-vfuH-wdLF-TikC-bAdfZi) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 09:01:52,888 ERROR [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-37) [1082f14c] Command org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: java.util.concurrent.TimeoutException (Failed with error VDS_NETWORK_ERROR and code 5022)
2014-12-04 09:01:55,291 WARN [org.ovirt.engine.core.bll.ForceSelectSPMCommand] (ajp--127.0.0.1-8702-3) [6dbfe13] CanDoAction of action ForceSelectSPM failed. Reasons:VAR__ACTION__FORCE_SELECT,VAR__TYPE__SPM,$VdsName mercury2,ACTION_TYPE_FAILED_IMAGE_REPOSITORY_NOT_FOUND
2014-12-04 09:02:01,171 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (DefaultQuartzScheduler_Worker-57) Command ConnectStoragePoolVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, vdsId = dfddc678-f8ee-45eb-897a-885c83de870e, storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, masterVersion = 8) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 09:02:01,174 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-57) IrsBroker::Failed::GetStoragePoolInfoVDS due to: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue)
2014-12-04 09:02:31,784 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-37) [1082f14c] Command ConnectStoragePoolVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e, vdsId = dfddc678-f8ee-45eb-897a-885c83de870e, storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, masterVersion = 8) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
2014-12-04 09:02:31,786 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-8-thread-37) [1082f14c] IrsBroker::Failed::ActivateStorageDomainVDS due to: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue)
2014-12-04 09:02:31,798 ERROR [org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand] (org.ovirt.thread.pool-8-thread-37) [1082f14c] Command org.ovirt.engine.core.bll.storage.ActivateStorageDomainCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.irsbroker.IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Could not connect host to Data Center(Storage issue) (Failed with error ENGINE and code 5001)
2014-12-04 09:02:31,837 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-37) [1082f14c] Correlation ID: 101946aa, Job ID: 20e9269f-b5a5-4d44-a87b-3fd7a3a837e5, Call Stack: null, Custom Event ID: -1, Message: Failed to activate Storage Domain StoragePoolDMZ03 (Data Center DMZ) by admin
2014-12-04 09:02:32,026 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-95) Command HSMGetAllTasksStatusesVDSCommand(HostName = mercury2, HostId = dfddc678-f8ee-45eb-897a-885c83de870e) execution failed. Exception: IRSNonOperationalException: IRSGenericException: IRSErrorException: IRSNonOperationalException: Not SPM: ()
Thread-36::ERROR::2014-12-04 08:55:02,320::task::866::Storage.TaskManager.Task::(_setError) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 873, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 609, in getSpmStatus
pool = self.getPool(spUUID)
File "/usr/share/vdsm/storage/hsm.py", line 325, in getPool
raise se.StoragePoolUnknown(spUUID)
StoragePoolUnknown: Unknown pool id, pool not connected: ('1d03dc05-008b-4d14-97ce-b17bd714183d',)
Thread-36::DEBUG::2014-12-04 08:55:02,321::task::885::Storage.TaskManager.Task::(_run) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::Task._run: 34788a4b-7c57-477b-ab09-0d8f5a07216f ('1d03dc05-008b-4d14-97ce-b17bd714183d',) {} failed - stopping task
Thread-36::DEBUG::2014-12-04 08:55:02,321::task::1217::Storage.TaskManager.Task::(stop) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::stopping in state preparing (force False)
Thread-36::DEBUG::2014-12-04 08:55:02,321::task::993::Storage.TaskManager.Task::(_decref) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::ref 1 aborting True
Thread-36::INFO::2014-12-04 08:55:02,322::task::1171::Storage.TaskManager.Task::(prepare) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309
Thread-36::DEBUG::2014-12-04 08:55:02,322::task::1176::Storage.TaskManager.Task::(prepare) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::Prepare: aborted: Unknown pool id, pool not connected
Thread-36::DEBUG::2014-12-04 08:55:02,322::task::993::Storage.TaskManager.Task::(_decref) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::ref 0 aborting True
Thread-36::DEBUG::2014-12-04 08:55:02,322::task::928::Storage.TaskManager.Task::(_doAbort) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::Task._doAbort: force False
Thread-36::DEBUG::2014-12-04 08:55:02,323::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-36::DEBUG::2014-12-04 08:55:02,323::task::595::Storage.TaskManager.Task::(_updateState) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::moving from state preparing -> state aborting
Thread-36::DEBUG::2014-12-04 08:55:02,323::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::_aborting: recover policy none
Thread-36::DEBUG::2014-12-04 08:55:02,324::task::595::Storage.TaskManager.Task::(_updateState) Task=`34788a4b-7c57-477b-ab09-0d8f5a07216f`::moving from state aborting -> state failed
Thread-36::DEBUG::2014-12-04 08:55:02,324::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-36::DEBUG::2014-12-04 08:55:02,324::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-36::ERROR::2014-12-04 08:55:02,324::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': "Unknown pool id, pool not connected: ('1d03dc05-008b-4d14-97ce-b17bd714183d',)", 'code': 309}}
Thread-36::DEBUG::2014-12-04 08:55:02,393::BindingXMLRPC::318::vds::(wrapper) client [10.110.57.31]
Thread-36::DEBUG::2014-12-04 08:55:02,394::task::595::Storage.TaskManager.Task::(_updateState) Task=`7548aaeb-3c38-4c11-a0a2-551a37ca7af5`::moving from state init -> state preparing
Thread-36::INFO::2014-12-04 08:55:02,394::logUtils::44::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='1d03dc05-008b-4d14-97ce-b17bd714183d', hostID=1, msdUUID='eb912657-8a8c-4173-9d24-92d2b09a773c', masterVersion=7, domainsMap=None, options=None)
Thread-36::DEBUG::2014-12-04 08:55:02,395::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.HsmDomainMonitorLock`ReqID=`ef71eb03-b73e-47c2-8c27-e7a22453eeb5`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1011' at 'connectStoragePool'
Thread-36::DEBUG::2014-12-04 08:55:02,395::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.HsmDomainMonitorLock' for lock type 'exclusive'
Thread-36::DEBUG::2014-12-04 08:55:02,396::resourceManager::577::Storage.ResourceManager::(registerResource) Resource 'Storage.HsmDomainMonitorLock' is currently locked, Entering queue (10 in queue)
Thread-35::DEBUG::2014-12-04 08:55:14,578::BindingXMLRPC::318::vds::(wrapper) client [10.110.57.31]
Thread-35::DEBUG::2014-12-04 08:55:14,579::task::595::Storage.TaskManager.Task::(_updateState) Task=`cfb4d5b0-f405-4510-b36a-1054b703edc8`::moving from state init -> state preparing
Thread-35::INFO::2014-12-04 08:55:14,580::logUtils::44::dispatcher::(wrapper) Run and protect: getDeviceList(storageType=2, options={})
Thread-35::DEBUG::2014-12-04 08:55:14,580::misc::741::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Detector thread::DEBUG::2014-12-04 08:55:32,427::protocoldetector::166::vds.MultiProtocolAcceptor::(_add_connection) Adding connection from 10.110.57.31:40803
Detector thread::DEBUG::2014-12-04 08:55:32,428::protocoldetector::177::vds.MultiProtocolAcceptor::(_remove_connection) Connection removed from 10.110.57.31:40803
Detector thread::DEBUG::2014-12-04 08:55:32,428::protocoldetector::203::vds.MultiProtocolAcceptor::(_handle_connection_read) Detected protocol xml from 10.110.57.31:40803
Detector thread::DEBUG::2014-12-04 08:55:32,429::BindingXMLRPC::1172::XmlDetector::(handleSocket) xml over http detected from ('10.110.57.31', 40803)
Thread-37::DEBUG::2014-12-04 08:55:32,436::task::595::Storage.TaskManager.Task::(_updateState) Task=`0ac2f9c8-b24b-4ddd-999a-2c7ad3602982`::moving from state init -> state preparing
Thread-37::INFO::2014-12-04 08:55:32,436::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-37::INFO::2014-12-04 08:55:32,437::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'eb912657-8a8c-4173-9d24-92d2b09a773c': {'code': 0, 'version': -1, 'acquired': False, 'delay': '0', 'lastCheck': '292.3', 'valid': True}}
Thread-37::DEBUG::2014-12-04 08:55:32,437::task::1191::Storage.TaskManager.Task::(prepare) Task=`0ac2f9c8-b24b-4ddd-999a-2c7ad3602982`::finished: {'eb912657-8a8c-4173-9d24-92d2b09a773c': {'code': 0, 'version': -1, 'acquired': False, 'delay': '0', 'lastCheck': '292.3', 'valid': True}}
Thread-37::DEBUG::2014-12-04 08:55:32,438::task::595::Storage.TaskManager.Task::(_updateState) Task=`0ac2f9c8-b24b-4ddd-999a-2c7ad3602982`::moving from state preparing -> state finished
Thread-37::DEBUG::2014-12-04 08:55:32,438::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-37::DEBUG::2014-12-04 08:55:32,438::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::DEBUG::2014-12-04 08:55:32,439::task::993::Storage.TaskManager.Task::(_decref) Task=`0ac2f9c8-b24b-4ddd-999a-2c7ad3602982`::ref 0 aborting False
Thread-28::DEBUG::2014-12-04 08:55:42,005::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0
Thread-28::DEBUG::2014-12-04 08:55:42,006::lvm::489::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-28::DEBUG::2014-12-04 08:55:42,006::lvm::491::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-28::DEBUG::2014-12-04 08:55:42,007::lvm::500::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-28::DEBUG::2014-12-04 08:55:42,007::lvm::502::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-28::DEBUG::2014-12-04 08:55:42,008::lvm::520::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-28::DEBUG::2014-12-04 08:55:42,008::lvm::522::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-28::DEBUG::2014-12-04 08:55:42,009::misc::751::Storage.SamplingMethod::(__call__) Returning last result
Thread-34::DEBUG::2014-12-04 08:55:42,009::misc::743::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-28::ERROR::2014-12-04 08:55:42,010::sdc::137::Storage.StorageDomainCache::(_findDomain) looking for unfetched domain eb912657-8a8c-4173-9d24-92d2b09a773c
Thread-34::DEBUG::2014-12-04 08:55:42,011::misc::741::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-28::ERROR::2014-12-04 08:55:42,012::sdc::154::Storage.StorageDomainCache::(_findUnfetchedDomain) looking for domain eb912657-8a8c-4173-9d24-92d2b09a773c
Thread-34::DEBUG::2014-12-04 08:55:42,013::misc::743::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-28::DEBUG::2014-12-04 08:55:42,015::lvm::365::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-34::DEBUG::2014-12-04 08:55:42,015::iscsi::403::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds
Thread-34::DEBUG::2014-12-04 08:55:42,019::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) /usr/bin/sudo -n /sbin/iscsiadm -m session -R (cwd None)
Thread-28::DEBUG::2014-12-04 08:55:42,042::lvm::288::Storage.Misc.excCmd::(cmd) /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 obtain_device_list_from_udev=0 filter = [ '\''a|/dev/mapper/36005076802810d489000000000000062|/dev/mapper/36005076802810d48e0000000000000ae|/dev/mapper/36005076802810d48e0000000000000de|'\'', '\''r|.*|'\'' ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 use_lvmetad=0 } backup { retain_min = 50 retain_days = 0 } ' --noheadings --units b --nosuffix --separator '|' --ignoreskippedcluster -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free,lv_count,pv_count,pv_name eb912657-8a8c-4173-9d24-92d2b09a773c (cwd None)
Thread-34::DEBUG::2014-12-04 08:55:42,057::misc::751::Storage.SamplingMethod::(__call__) Returning last result
Thread-34::DEBUG::2014-12-04 08:55:42,063::multipath::110::Storage.Misc.excCmd::(rescan) /usr/bin/sudo -n /sbin/multipath (cwd None)
Thread-37::DEBUG::2014-12-04 08:55:42,449::BindingXMLRPC::318::vds::(wrapper) client [10.110.57.31]
Thread-37::DEBUG::2014-12-04 08:55:42,451::task::595::Storage.TaskManager.Task::(_updateState) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::moving from state init -> state preparing
Thread-37::INFO::2014-12-04 08:55:42,451::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='1d03dc05-008b-4d14-97ce-b17bd714183d', options=None)
Thread-37::ERROR::2014-12-04 08:55:42,452::task::866::Storage.TaskManager.Task::(_setError) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 873, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 609, in getSpmStatus
pool = self.getPool(spUUID)
File "/usr/share/vdsm/storage/hsm.py", line 325, in getPool
raise se.StoragePoolUnknown(spUUID)
StoragePoolUnknown: Unknown pool id, pool not connected: ('1d03dc05-008b-4d14-97ce-b17bd714183d',)
Thread-37::DEBUG::2014-12-04 08:55:42,453::task::885::Storage.TaskManager.Task::(_run) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::Task._run: 50cd8469-971c-4bd1-a0dd-0cc011fbbc68 ('1d03dc05-008b-4d14-97ce-b17bd714183d',) {} failed - stopping task
Thread-37::DEBUG::2014-12-04 08:55:42,453::task::1217::Storage.TaskManager.Task::(stop) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::stopping in state preparing (force False)
Thread-37::DEBUG::2014-12-04 08:55:42,453::task::993::Storage.TaskManager.Task::(_decref) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::ref 1 aborting True
Thread-37::INFO::2014-12-04 08:55:42,454::task::1171::Storage.TaskManager.Task::(prepare) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309
Thread-37::DEBUG::2014-12-04 08:55:42,454::task::1176::Storage.TaskManager.Task::(prepare) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::Prepare: aborted: Unknown pool id, pool not connected
Thread-37::DEBUG::2014-12-04 08:55:42,454::task::993::Storage.TaskManager.Task::(_decref) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::ref 0 aborting True
Thread-37::DEBUG::2014-12-04 08:55:42,454::task::928::Storage.TaskManager.Task::(_doAbort) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::Task._doAbort: force False
Thread-37::DEBUG::2014-12-04 08:55:42,455::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::DEBUG::2014-12-04 08:55:42,455::task::595::Storage.TaskManager.Task::(_updateState) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::moving from state preparing -> state aborting
Thread-37::DEBUG::2014-12-04 08:55:42,455::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::_aborting: recover policy none
Thread-37::DEBUG::2014-12-04 08:55:42,456::task::595::Storage.TaskManager.Task::(_updateState) Task=`50cd8469-971c-4bd1-a0dd-0cc011fbbc68`::moving from state aborting -> state failed
Thread-37::DEBUG::2014-12-04 08:55:42,456::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-37::DEBUG::2014-12-04 08:55:42,456::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::ERROR::2014-12-04 08:55:42,457::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': "Unknown pool id, pool not connected: ('1d03dc05-008b-4d14-97ce-b17bd714183d',)", 'code': 309}}
Thread-37::DEBUG::2014-12-04 08:55:42,469::BindingXMLRPC::318::vds::(wrapper) client [10.110.57.31]
Thread-37::DEBUG::2014-12-04 08:55:42,469::task::595::Storage.TaskManager.Task::(_updateState) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::moving from state init -> state preparing
Thread-37::INFO::2014-12-04 08:55:42,470::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None)
Thread-37::ERROR::2014-12-04 08:55:42,470::task::866::Storage.TaskManager.Task::(_setError) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 873, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 2168, in getAllTasksStatuses
raise se.SpmStatusError()
SpmStatusError: Not SPM: ()
Thread-37::DEBUG::2014-12-04 08:55:42,471::task::885::Storage.TaskManager.Task::(_run) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::Task._run: 0bcba35f-5fc5-4589-b991-95eb6f36f371 () {} failed - stopping task
Thread-37::DEBUG::2014-12-04 08:55:42,471::task::1217::Storage.TaskManager.Task::(stop) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::stopping in state preparing (force False)
Thread-37::DEBUG::2014-12-04 08:55:42,471::task::993::Storage.TaskManager.Task::(_decref) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::ref 1 aborting True
Thread-37::INFO::2014-12-04 08:55:42,472::task::1171::Storage.TaskManager.Task::(prepare) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::aborting: Task is aborted: 'Not SPM' - code 654
Thread-37::DEBUG::2014-12-04 08:55:42,472::task::1176::Storage.TaskManager.Task::(prepare) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::Prepare: aborted: Not SPM
Thread-37::DEBUG::2014-12-04 08:55:42,472::task::993::Storage.TaskManager.Task::(_decref) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::ref 0 aborting True
Thread-37::DEBUG::2014-12-04 08:55:42,472::task::928::Storage.TaskManager.Task::(_doAbort) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::Task._doAbort: force False
Thread-37::DEBUG::2014-12-04 08:55:42,473::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::DEBUG::2014-12-04 08:55:42,473::task::595::Storage.TaskManager.Task::(_updateState) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::moving from state preparing -> state aborting
Thread-37::DEBUG::2014-12-04 08:55:42,473::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::_aborting: recover policy none
Thread-37::DEBUG::2014-12-04 08:55:42,474::task::595::Storage.TaskManager.Task::(_updateState) Task=`0bcba35f-5fc5-4589-b991-95eb6f36f371`::moving from state aborting -> state failed
Thread-37::DEBUG::2014-12-04 08:55:42,474::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-37::DEBUG::2014-12-04 08:55:42,474::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::ERROR::2014-12-04 08:55:42,474::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': 'Not SPM: ()', 'code': 654}}
Thread-37::DEBUG::2014-12-04 08:55:42,581::BindingXMLRPC::318::vds::(wrapper) client [10.110.57.31]
Thread-37::DEBUG::2014-12-04 08:55:42,582::task::595::Storage.TaskManager.Task::(_updateState) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::moving from state init -> state preparing
Thread-37::INFO::2014-12-04 08:55:42,582::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='1d03dc05-008b-4d14-97ce-b17bd714183d', options=None)
Thread-37::ERROR::2014-12-04 08:55:42,583::task::866::Storage.TaskManager.Task::(_setError) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 873, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/logUtils.py", line 45, in wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 609, in getSpmStatus
pool = self.getPool(spUUID)
File "/usr/share/vdsm/storage/hsm.py", line 325, in getPool
raise se.StoragePoolUnknown(spUUID)
StoragePoolUnknown: Unknown pool id, pool not connected: ('1d03dc05-008b-4d14-97ce-b17bd714183d',)
Thread-37::DEBUG::2014-12-04 08:55:42,583::task::885::Storage.TaskManager.Task::(_run) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::Task._run: 6c75242b-4b88-4c10-9ee6-4f9678e47686 ('1d03dc05-008b-4d14-97ce-b17bd714183d',) {} failed - stopping task
Thread-37::DEBUG::2014-12-04 08:55:42,584::task::1217::Storage.TaskManager.Task::(stop) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::stopping in state preparing (force False)
Thread-37::DEBUG::2014-12-04 08:55:42,584::task::993::Storage.TaskManager.Task::(_decref) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::ref 1 aborting True
Thread-37::INFO::2014-12-04 08:55:42,584::task::1171::Storage.TaskManager.Task::(prepare) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309
Thread-37::DEBUG::2014-12-04 08:55:42,585::task::1176::Storage.TaskManager.Task::(prepare) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::Prepare: aborted: Unknown pool id, pool not connected
Thread-37::DEBUG::2014-12-04 08:55:42,585::task::993::Storage.TaskManager.Task::(_decref) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::ref 0 aborting True
Thread-37::DEBUG::2014-12-04 08:55:42,585::task::928::Storage.TaskManager.Task::(_doAbort) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::Task._doAbort: force False
Thread-37::DEBUG::2014-12-04 08:55:42,585::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::DEBUG::2014-12-04 08:55:42,586::task::595::Storage.TaskManager.Task::(_updateState) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::moving from state preparing -> state aborting
Thread-37::DEBUG::2014-12-04 08:55:42,586::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::_aborting: recover policy none
Thread-37::DEBUG::2014-12-04 08:55:42,586::task::595::Storage.TaskManager.Task::(_updateState) Task=`6c75242b-4b88-4c10-9ee6-4f9678e47686`::moving from state aborting -> state failed
Thread-37::DEBUG::2014-12-04 08:55:42,587::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-37::DEBUG::2014-12-04 08:55:42,587::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37::ERROR::2014-12-04 08:55:42,587::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': "Unknown pool id, pool not connected: ('1d03dc05-008b-4d14-97ce-b17bd714183d',)", 'code': 309}}
Thread-37::DEBUG::2014-12-04 08:55:42,613::BindingXMLRPC::318::vds::(wrapper) client [10.110.57.31]
Thread-37::DEBUG::2014-12-04 08:55:42,613::task::595::Storage.TaskManager.Task::(_updateState) Task=`51cd7fe2-0463-47c3-aa0f-06a5fc0fd5e3`::moving from state init -> state preparing
Thread-37::INFO::2014-12-04 08:55:42,614::logUtils::44::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='1d03dc05-008b-4d14-97ce-b17bd714183d', hostID=1, msdUUID='eb912657-8a8c-4173-9d24-92d2b09a773c', masterVersion=7, domainsMap=None, options=None)
Thread-37::DEBUG::2014-12-04 08:55:42,615::resourceManager::198::Storage.ResourceManager.Request::(__init__) ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc700b2f-acbc-4eb5-a53d-0806404923c7`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1011' at 'connectStoragePool'
Thread-37::DEBUG::2014-12-04 08:55:42,615::resourceManager::542::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.HsmDomainMonitorLock' for lock type 'exclusive'
Thread-37::DEBUG::2014-12-04 08:55:42,616::resourceManager::577::Storage.ResourceManager::(registerResource) Resource 'Storage.HsmDomainMonitorLock' is currently locked, Entering queue (11 in queue)
Detector thread::DEBUG::2014-12-04 08:55:44,747::protocoldetector::166::vds.MultiProtocolAcceptor::(_add_connection) Adding connection from 10.110.57.31:46093
Detector thread::DEBUG::2014-12-04 08:55:44,748::protocoldetector::177::vds.MultiProtocolAcceptor::(_remove_connection) Connection removed from 10.110.57.31:46093
Detector thread::DEBUG::2014-12-04 08:55:44,748::protocoldetector::203::vds.MultiProtocolAcceptor::(_handle_connection_read) Detected protocol xml from 10.110.57.31:46093
Detector thread::DEBUG::2014-12-04 08:55:44,748::BindingXMLRPC::1172::XmlDetector::(handleSocket) xml over http detected from ('10.110.57.31', 46093)
Thread-38::DEBUG::2014-12-04 08:55:47,825::task::595::Storage.TaskManager.Task::(_updateState) Task=`5d84118b-f7fc-47f6-9a96-f890bdc90d1c`::moving from state init -> state preparing
Thread-38::INFO::2014-12-04 08:55:47,826::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-38::INFO::2014-12-04 08:55:47,827::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'eb912657-8a8c-4173-9d24-92d2b09a773c': {'code': 0, 'version': -1, 'acquired': False, 'delay': '0', 'lastCheck': '307.7', 'valid': True}}
Thread-38::DEBUG::2014-12-04 08:55:47,827::task::1191::Storage.TaskManager.Task::(prepare) Task=`5d84118b-f7fc-47f6-9a96-f890bdc90d1c`::finished: {'eb912657-8a8c-4173-9d24-92d2b09a773c': {'code': 0, 'version': -1, 'acquired': False, 'delay': '0', 'lastCheck': '307.7', 'valid': True}}
Thread-38::DEBUG::2014-12-04 08:55:47,828::task::595::Storage.TaskManager.Task::(_updateState) Task=`5d84118b-f7fc-47f6-9a96-f890bdc90d1c`::moving from state preparing -> state finished
Thread-38::DEBUG::2014-12-04 08:55:47,828::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-38::DEBUG::2014-12-04 08:55:47,828::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38::DEBUG::2014-12-04 08:55:47,828::task::993::Storage.TaskManager.Task::(_decref) Task=`5d84118b-f7fc-47f6-9a96-f890bdc90d1c`::ref 0 aborting False
Thread-34::DEBUG::2014-12-04 08:55:50,042::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0
Thread-34::DEBUG::2014-12-04 08:55:50,043::lvm::489::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm reload operation' is holding the operation mutex, waiting...
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
