Thread-823832::DEBUG::2016-01-20 08:08:36,511::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.connectStorageServer' in bridge with {u'connectionParams': [{u'id': u'00000000-0000-0000-0000-000000000000', u'connection': u't2-gluster01b:arbtest', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 7}
Thread-823832::DEBUG::2016-01-20 08:08:36,512::task::595::Storage.TaskManager.Task::(_updateState) Task=`5613e0b2-79c2-460e-bc85-faf236ab39f6`::moving from state init -> state preparing
Thread-823832::INFO::2016-01-20 08:08:36,512::logUtils::48::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id': u'00000000-0000-0000-0000-000000000000', u'connection': u't2-gluster01b:arbtest', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], options=None)
Thread-823832::DEBUG::2016-01-20 08:08:36,534::fileUtils::143::Storage.fileUtils::(createdir) Creating directory: /rhev/data-center/mnt/glusterSD/t2-gluster01b:arbtest mode: None
Thread-823832::DEBUG::2016-01-20 08:08:36,534::mount::229::Storage.Misc.excCmd::(_runcmd) /usr/bin/sudo -n /usr/bin/systemd-run --scope --slice=vdsm-glusterfs /usr/bin/mount -t glusterfs -o backup-volfile-servers=t2-gluster02b:t2-gluster03b:t2-gluster03b:t2-gluster04b:t2-gluster01b t2-gluster01b:arbtest /rhev/data-center/mnt/glusterSD/t2-gluster01b:arbtest (cwd None)
Thread-823832::DEBUG::2016-01-20 08:08:36,678::__init__::298::IOProcessClient::(_run) Starting IOProcess...
Thread-823832::DEBUG::2016-01-20 08:08:36,705::hsm::2417::Storage.HSM::(__prefetchDomains) glusterDomPath: glusterSD/*
Thread-823835::DEBUG::2016-01-20 08:08:36,710::__init__::298::IOProcessClient::(_run) Starting IOProcess...
Thread-823832::DEBUG::2016-01-20 08:08:36,742::hsm::2429::Storage.HSM::(__prefetchDomains) Found SD uuids: (u'01e65989-18a6-4d01-b2bb-d1ba04e9afdb', u'0e62840d-da29-4d34-80c2-178b61c9ce11', u'1e5b4666-043b-41bd-9896-aa349705126c')
Thread-823832::DEBUG::2016-01-20 08:08:36,742::hsm::2489::Storage.HSM::(connectStorageServer) knownSDs: {0e62840d-da29-4d34-80c2-178b61c9ce11: storage.glusterSD.findDomain, 01e65989-18a6-4d01-b2bb-d1ba04e9afdb: storage.glusterSD.findDomain, 1e5b4666-043b-41bd-9896-aa349705126c: storage.glusterSD.findDomain}
Thread-823832::INFO::2016-01-20 08:08:36,742::logUtils::51::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]}
Thread-823832::DEBUG::2016-01-20 08:08:36,743::task::1191::Storage.TaskManager.Task::(prepare) Task=`5613e0b2-79c2-460e-bc85-faf236ab39f6`::finished: {'statuslist': [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]}
Thread-823832::DEBUG::2016-01-20 08:08:36,743::task::595::Storage.TaskManager.Task::(_updateState) Task=`5613e0b2-79c2-460e-bc85-faf236ab39f6`::moving from state preparing -> state finished
Thread-823832::DEBUG::2016-01-20 08:08:36,743::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-823832::DEBUG::2016-01-20 08:08:36,743::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-823832::DEBUG::2016-01-20 08:08:36,743::task::993::Storage.TaskManager.Task::(_decref) Task=`5613e0b2-79c2-460e-bc85-faf236ab39f6`::ref 0 aborting False
Thread-823832::DEBUG::2016-01-20 08:08:36,743::__init__::533::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.connectStorageServer' in bridge with [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]
Thread-823839::DEBUG::2016-01-20 08:08:36,828::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.connectStorageServer' in bridge with {u'connectionParams': [{u'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64', u'connection': u't2-gluster01b:arbtest', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 7}
Thread-823839::DEBUG::2016-01-20 08:08:36,829::task::595::Storage.TaskManager.Task::(_updateState) Task=`8aad9b06-200d-4003-adca-34a98019e264`::moving from state init -> state preparing
Thread-823839::INFO::2016-01-20 08:08:36,830::logUtils::48::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64', u'connection': u't2-gluster01b:arbtest', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], options=None)
Thread-823839::DEBUG::2016-01-20 08:08:36,831::hsm::2417::Storage.HSM::(__prefetchDomains) glusterDomPath: glusterSD/*
Thread-823839::DEBUG::2016-01-20 08:08:36,848::hsm::2429::Storage.HSM::(__prefetchDomains) Found SD uuids: (u'01e65989-18a6-4d01-b2bb-d1ba04e9afdb', u'0e62840d-da29-4d34-80c2-178b61c9ce11', u'1e5b4666-043b-41bd-9896-aa349705126c')
Thread-823839::DEBUG::2016-01-20 08:08:36,849::hsm::2489::Storage.HSM::(connectStorageServer) knownSDs: {0e62840d-da29-4d34-80c2-178b61c9ce11: storage.glusterSD.findDomain, 01e65989-18a6-4d01-b2bb-d1ba04e9afdb: storage.glusterSD.findDomain, 1e5b4666-043b-41bd-9896-aa349705126c: storage.glusterSD.findDomain}
Thread-823839::INFO::2016-01-20 08:08:36,849::logUtils::51::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64'}]}
Thread-823839::DEBUG::2016-01-20 08:08:36,849::task::1191::Storage.TaskManager.Task::(prepare) Task=`8aad9b06-200d-4003-adca-34a98019e264`::finished: {'statuslist': [{'status': 0, 'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64'}]}
Thread-823839::DEBUG::2016-01-20 08:08:36,849::task::595::Storage.TaskManager.Task::(_updateState) Task=`8aad9b06-200d-4003-adca-34a98019e264`::moving from state preparing -> state finished
Thread-823839::DEBUG::2016-01-20 08:08:36,849::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-823839::DEBUG::2016-01-20 08:08:36,849::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-823839::DEBUG::2016-01-20 08:08:36,849::task::993::Storage.TaskManager.Task::(_decref) Task=`8aad9b06-200d-4003-adca-34a98019e264`::ref 0 aborting False
Thread-823839::DEBUG::2016-01-20 08:08:36,850::__init__::533::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.connectStorageServer' in bridge with [{'status': 0, 'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64'}]
Thread-823846::DEBUG::2016-01-20 08:08:36,855::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StorageDomain.create' in bridge with {u'name': u'arbtest', u'domainType': 7, u'domainClass': 1, u'typeArgs': u't2-gluster01b:arbtest', u'version': u'3', u'storagedomainID': u'3d31af0b-18ad-45c4-90f1-18e2f804f34b'}
Thread-823846::DEBUG::2016-01-20 08:08:36,856::task::595::Storage.TaskManager.Task::(_updateState) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::moving from state init -> state preparing
Thread-823846::INFO::2016-01-20 08:08:36,856::logUtils::48::dispatcher::(wrapper) Run and protect: createStorageDomain(storageType=7, sdUUID=u'3d31af0b-18ad-45c4-90f1-18e2f804f34b', domainName=u'arbtest', typeSpecificArg=u't2-gluster01b:arbtest', domClass=1, domVersion=u'3', options=None)
Thread-823846::DEBUG::2016-01-20 08:08:36,857::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-823846::DEBUG::2016-01-20 08:08:36,857::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-823846::DEBUG::2016-01-20 08:08:36,857::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-823846::DEBUG::2016-01-20 08:08:36,857::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-823846::DEBUG::2016-01-20 08:08:36,857::iscsi::431::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds
Thread-823846::DEBUG::2016-01-20 08:08:36,857::iscsiadm::97::Storage.Misc.excCmd::(_runCmd) /usr/bin/sudo -n /sbin/iscsiadm -m session -R (cwd None)
Thread-823846::DEBUG::2016-01-20 08:08:36,885::misc::760::Storage.SamplingMethod::(__call__) Returning last result
Thread-823846::DEBUG::2016-01-20 08:08:36,885::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.hba.rescan)
Thread-823846::DEBUG::2016-01-20 08:08:36,885::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-823846::DEBUG::2016-01-20 08:08:36,885::hba::56::Storage.HBA::(rescan) Starting scan
Thread-823846::DEBUG::2016-01-20 08:08:36,968::hba::62::Storage.HBA::(rescan) Scan finished
Thread-823846::DEBUG::2016-01-20 08:08:36,968::misc::760::Storage.SamplingMethod::(__call__) Returning last result
Thread-823846::DEBUG::2016-01-20 08:08:36,968::multipath::77::Storage.Misc.excCmd::(rescan) /usr/bin/sudo -n /usr/sbin/multipath (cwd None)
Thread-823846::DEBUG::2016-01-20 08:08:37,030::multipath::77::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0
Thread-823846::DEBUG::2016-01-20 08:08:37,030::utils::676::root::(execCmd) /sbin/udevadm settle --timeout=5 (cwd None)
Thread-823846::DEBUG::2016-01-20 08:08:37,044::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0
Thread-823846::DEBUG::2016-01-20 08:08:37,045::lvm::498::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,045::lvm::500::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,045::lvm::509::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,045::lvm::511::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,045::lvm::529::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,045::lvm::531::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,046::misc::760::Storage.SamplingMethod::(__call__) Returning last result
Thread-823846::ERROR::2016-01-20 08:08:37,046::sdc::138::Storage.StorageDomainCache::(_findDomain) looking for unfetched domain 3d31af0b-18ad-45c4-90f1-18e2f804f34b
Thread-823846::ERROR::2016-01-20 08:08:37,046::sdc::155::Storage.StorageDomainCache::(_findUnfetchedDomain) looking for domain 3d31af0b-18ad-45c4-90f1-18e2f804f34b
Thread-823846::DEBUG::2016-01-20 08:08:37,046::lvm::371::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-823846::DEBUG::2016-01-20 08:08:37,047::lvm::291::Storage.Misc.excCmd::(cmd) /usr/bin/sudo -n /usr/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/3644a84200be317001c56846212b97c61|'\'', '\''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 3d31af0b-18ad-45c4-90f1-18e2f804f34b (cwd None)
Thread-823846::DEBUG::2016-01-20 08:08:37,413::lvm::291::Storage.Misc.excCmd::(cmd) FAILED: <err> = '  Volume group "3d31af0b-18ad-45c4-90f1-18e2f804f34b" not found\n  Cannot process volume group 3d31af0b-18ad-45c4-90f1-18e2f804f34b\n'; <rc> = 5
Thread-823846::WARNING::2016-01-20 08:08:37,413::lvm::376::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] ['  Volume group "3d31af0b-18ad-45c4-90f1-18e2f804f34b" not found', '  Cannot process volume group 3d31af0b-18ad-45c4-90f1-18e2f804f34b']
Thread-823846::DEBUG::2016-01-20 08:08:37,413::lvm::416::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-823853::DEBUG::2016-01-20 08:08:37,432::__init__::298::IOProcessClient::(_run) Starting IOProcess...
Thread-823854::DEBUG::2016-01-20 08:08:37,454::__init__::298::IOProcessClient::(_run) Starting IOProcess...
Thread-823846::ERROR::2016-01-20 08:08:37,497::sdc::144::Storage.StorageDomainCache::(_findDomain) domain 3d31af0b-18ad-45c4-90f1-18e2f804f34b not found
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/sdc.py", line 142, in _findDomain
    dom = findMethod(sdUUID)
  File "/usr/share/vdsm/storage/sdc.py", line 172, in _findUnfetchedDomain
    raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist: (u'3d31af0b-18ad-45c4-90f1-18e2f804f34b',)
Thread-823846::INFO::2016-01-20 08:08:37,498::nfsSD::69::Storage.StorageDomain::(create) sdUUID=3d31af0b-18ad-45c4-90f1-18e2f804f34b domainName=arbtest remotePath=t2-gluster01b:arbtest domClass=1
Thread-823846::DEBUG::2016-01-20 08:08:37,510::__init__::298::IOProcessClient::(_run) Starting IOProcess...
Thread-823846::ERROR::2016-01-20 08:08:37,903::task::866::Storage.TaskManager.Task::(_setError) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::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 49, in wrapper
    res = f(*args, **kwargs)
  File "/usr/share/vdsm/storage/hsm.py", line 2697, in createStorageDomain
    domVersion)
  File "/usr/share/vdsm/storage/nfsSD.py", line 84, in create
    remotePath, storageType, version)
  File "/usr/share/vdsm/storage/fileSD.py", line 264, in _prepareMetadata
    "create meta file '%s' failed: %s" % (metaFile, str(e)))
StorageDomainMetadataCreationError: Error creating a storage domain's metadata: ("create meta file 'outbox' failed: [Errno 5] Input/output error",)
Thread-823846::DEBUG::2016-01-20 08:08:37,904::task::885::Storage.TaskManager.Task::(_run) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::Task._run: 4abe19f6-0e90-41be-ab53-6bf08626e92f (7, u'3d31af0b-18ad-45c4-90f1-18e2f804f34b', u'arbtest', u't2-gluster01b:arbtest', 1, u'3') {} failed - stopping task
Thread-823846::DEBUG::2016-01-20 08:08:37,904::task::1246::Storage.TaskManager.Task::(stop) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::stopping in state preparing (force False)
Thread-823846::DEBUG::2016-01-20 08:08:37,904::task::993::Storage.TaskManager.Task::(_decref) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::ref 1 aborting True
Thread-823846::INFO::2016-01-20 08:08:37,905::task::1171::Storage.TaskManager.Task::(prepare) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::aborting: Task is aborted: "Error creating a storage domain's metadata" - code 362
Thread-823846::DEBUG::2016-01-20 08:08:37,905::task::1176::Storage.TaskManager.Task::(prepare) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::Prepare: aborted: Error creating a storage domain's metadata
Thread-823846::DEBUG::2016-01-20 08:08:37,905::task::993::Storage.TaskManager.Task::(_decref) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::ref 0 aborting True
Thread-823846::DEBUG::2016-01-20 08:08:37,905::task::928::Storage.TaskManager.Task::(_doAbort) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::Task._doAbort: force False
Thread-823846::DEBUG::2016-01-20 08:08:37,905::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-823846::DEBUG::2016-01-20 08:08:37,905::task::595::Storage.TaskManager.Task::(_updateState) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::moving from state preparing -> state aborting
Thread-823846::DEBUG::2016-01-20 08:08:37,905::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::_aborting: recover policy none
Thread-823846::DEBUG::2016-01-20 08:08:37,905::task::595::Storage.TaskManager.Task::(_updateState) Task=`4abe19f6-0e90-41be-ab53-6bf08626e92f`::moving from state aborting -> state failed
Thread-823846::DEBUG::2016-01-20 08:08:37,906::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-823846::DEBUG::2016-01-20 08:08:37,906::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-823846::ERROR::2016-01-20 08:08:37,906::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': 'Error creating a storage domain\'s metadata: ("create meta file \'outbox\' failed: [Errno 5] Input/output error",)', 'code': 362}}
mailbox.SPMMonitor::DEBUG::2016-01-20 08:08:37,972::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) dd if=/rhev/data-center/00000001-0001-0001-0001-00000000037e/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000 (cwd None)
mailbox.SPMMonitor::DEBUG::2016-01-20 08:08:37,992::storage_mailbox::735::Storage.Misc.excCmd::(_checkForMail) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0033988 s, 301 MB/s\n'; <rc> = 0
Thread-823863::DEBUG::2016-01-20 08:08:38,151::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.disconnectStorageServer' in bridge with {u'connectionParams': [{u'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64', u'connection': u't2-gluster01b:arbtest', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 7}
Thread-823863::DEBUG::2016-01-20 08:08:38,152::task::595::Storage.TaskManager.Task::(_updateState) Task=`88d2d366-1f95-4247-87d7-516645984b49`::moving from state init -> state preparing
Thread-823863::INFO::2016-01-20 08:08:38,153::logUtils::48::dispatcher::(wrapper) Run and protect: disconnectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64', u'connection': u't2-gluster01b:arbtest', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], options=None)
Thread-823863::DEBUG::2016-01-20 08:08:38,153::mount::229::Storage.Misc.excCmd::(_runcmd) /usr/bin/sudo -n /usr/bin/umount -f -l /rhev/data-center/mnt/glusterSD/t2-gluster01b:arbtest (cwd None)
Thread-823863::DEBUG::2016-01-20 08:08:38,183::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-823863::DEBUG::2016-01-20 08:08:38,183::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-823863::DEBUG::2016-01-20 08:08:38,183::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-823863::DEBUG::2016-01-20 08:08:38,183::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-823863::DEBUG::2016-01-20 08:08:38,183::iscsi::431::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds
Thread-823863::DEBUG::2016-01-20 08:08:38,184::iscsiadm::97::Storage.Misc.excCmd::(_runCmd) /usr/bin/sudo -n /sbin/iscsiadm -m session -R (cwd None)
Thread-823863::DEBUG::2016-01-20 08:08:38,208::misc::760::Storage.SamplingMethod::(__call__) Returning last result
Thread-823863::DEBUG::2016-01-20 08:08:38,208::misc::750::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.hba.rescan)
Thread-823863::DEBUG::2016-01-20 08:08:38,208::misc::753::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-823863::DEBUG::2016-01-20 08:08:38,208::hba::56::Storage.HBA::(rescan) Starting scan
Thread-823863::DEBUG::2016-01-20 08:08:38,292::hba::62::Storage.HBA::(rescan) Scan finished
Thread-823863::DEBUG::2016-01-20 08:08:38,292::misc::760::Storage.SamplingMethod::(__call__) Returning last result
Thread-823863::DEBUG::2016-01-20 08:08:38,292::multipath::77::Storage.Misc.excCmd::(rescan) /usr/bin/sudo -n /usr/sbin/multipath (cwd None)
Thread-823863::DEBUG::2016-01-20 08:08:38,347::multipath::77::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0
Thread-823863::DEBUG::2016-01-20 08:08:38,347::utils::676::root::(execCmd) /sbin/udevadm settle --timeout=5 (cwd None)
Thread-823863::DEBUG::2016-01-20 08:08:38,361::utils::694::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0
Thread-823863::DEBUG::2016-01-20 08:08:38,362::lvm::498::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-823863::DEBUG::2016-01-20 08:08:38,362::lvm::500::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-823863::DEBUG::2016-01-20 08:08:38,362::lvm::509::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-823863::DEBUG::2016-01-20 08:08:38,362::lvm::511::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-823863::DEBUG::2016-01-20 08:08:38,363::lvm::529::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-823863::DEBUG::2016-01-20 08:08:38,363::lvm::531::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-823863::DEBUG::2016-01-20 08:08:38,363::misc::760::Storage.SamplingMethod::(__call__) Returning last result
Thread-823863::INFO::2016-01-20 08:08:38,363::logUtils::51::dispatcher::(wrapper) Run and protect: disconnectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64'}]}
Thread-823863::DEBUG::2016-01-20 08:08:38,363::task::1191::Storage.TaskManager.Task::(prepare) Task=`88d2d366-1f95-4247-87d7-516645984b49`::finished: {'statuslist': [{'status': 0, 'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64'}]}
Thread-823863::DEBUG::2016-01-20 08:08:38,363::task::595::Storage.TaskManager.Task::(_updateState) Task=`88d2d366-1f95-4247-87d7-516645984b49`::moving from state preparing -> state finished
Thread-823863::DEBUG::2016-01-20 08:08:38,363::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-823863::DEBUG::2016-01-20 08:08:38,363::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-823863::DEBUG::2016-01-20 08:08:38,364::task::993::Storage.TaskManager.Task::(_decref) Task=`88d2d366-1f95-4247-87d7-516645984b49`::ref 0 aborting False
Thread-823863::DEBUG::2016-01-20 08:08:38,364::__init__::533::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.disconnectStorageServer' in bridge with [{'status': 0, 'id': u'2d502b8e-dcab-4c2b-bf5b-600e3465fe64'}]
