[ovirt-users] ovirt local datacenter/cluster using zfs local storage for storage domain?

Mon Nov 17 16:05:13 EST 2014

Hello all,

I'm exploring using oVirt 3.5 as the management engine for a new cluster I am building. I don't really need high availability and I have 3 servers with fast SSDs on local storage I'd like to use, preferably using ZFS to ensure reliability of the storage.

I set up a brand new CentOS 6.6 minimal install and have been able to get oVirt up using the all-in-one plugin. I can use local storage (the default EXT4 LVM filesystem CentOS sets up) to setup a local data center for each of the servers but have run into issues when I try to provision a ZFS filesystem as a local storage domain. I'm using ZFS on Linux 0.6.3.

I first had multipath.conf issues, which prevented me from even setting up a zpool using the local disks. After blacklisting the local disks in /etc/multipath.conf, I was able to get zfs up and running and create the local domains, but I get errors when I try to create a storage Domain of type: Data / Local on Host and point at the ZFS path (/vmstore/isos) (PS: I'm not trying to create an ISO domain, it's just a directory name isos)

The error message that comes up is "Error while executing action New Local Storage Domain: Storage Domain target is unsupported".

Has anyone tried this before? I am able to set up an NFS export of the ZFS folder as a Storage Domain (using directions here: http://virt.guru/2014/02/25/installing-ovirt-with-shared-local-storage/) but if possible, I'd like to skip the NFS layer if I can and just go directly to the hardware.

The supervdsm.log shows:
MainProcess|Thread-1734::DEBUG::2014-11-17 15:50:31,350::supervdsmServer::101::SuperVdsm.ServerCallback::(wrapper) call validateAccess with ('qemu', ('qemu', 'kvm'), u'/vmstore/isos', 5) {}
MainProcess|Thread-1734::DEBUG::2014-11-17 15:50:31,356::supervdsmServer::108::SuperVdsm.ServerCallback::(wrapper) return validateAccess with None
MainProcess|Thread-1735::DEBUG::2014-11-17 15:50:31,436::supervdsmServer::101::SuperVdsm.ServerCallback::(wrapper) call validateAccess with ('qemu', ('qemu', 'kvm'), u'/vmstore/isos', 5) {}
MainProcess|Thread-1735::DEBUG::2014-11-17 15:50:31,441::supervdsmServer::108::SuperVdsm.ServerCallback::(wrapper) return validateAccess with None
MainProcess|Thread-1736::DEBUG::2014-11-17 15:50:31,519::supervdsmServer::101::SuperVdsm.ServerCallback::(wrapper) call hbaRescan with () {}
MainProcess|Thread-1736::INFO::2014-11-17 15:50:31,520::hba::54::Storage.HBA::(rescan) Rescanning HBAs
MainProcess|Thread-1736::DEBUG::2014-11-17 15:50:31,520::supervdsmServer::108::SuperVdsm.ServerCallback::(wrapper) return hbaRescan with None
MainProcess|Thread-1736::DEBUG::2014-11-17 15:50:32,100::supervdsmServer::101::SuperVdsm.ServerCallback::(wrapper) call validateAccess with ('qemu', ('qemu', 'kvm'), u'/rhev/data-center/mnt/_vmstore_isos', 5) {}
MainProcess|Thread-1736::DEBUG::2014-11-17 15:50:32,105::supervdsmServer::108::SuperVdsm.ServerCallback::(wrapper) return validateAccess with None
MainProcess|Thread-1744::DEBUG::2014-11-17 15:50:32,278::supervdsmServer::101::SuperVdsm.ServerCallback::(wrapper) call hbaRescan with () {}
MainProcess|Thread-1744::INFO::2014-11-17 15:50:32,279::hba::54::Storage.HBA::(rescan) Rescanning HBAs
MainProcess|Thread-1744::DEBUG::2014-11-17 15:50:32,279::supervdsmServer::108::SuperVdsm.ServerCallback::(wrapper) return hbaRescan with None

And the vdsm.log shows:
Thread-1732::DEBUG::2014-11-17 15:50:31,032::task::595::Storage.TaskManager.Task::(_updateState) Task=`82d29b1b-0c33-4078-887b-476d95f4b1a1`::moving from state init -> state preparing
Thread-1732::INFO::2014-11-17 15:50:31,032::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-1732::INFO::2014-11-17 15:50:31,033::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'158ef830-da69-48b4-95b0-3615d6fb5b00': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000627117', 'lastCheck': '8.2', 'valid': True}}
Thread-1732::DEBUG::2014-11-17 15:50:31,033::task::1191::Storage.TaskManager.Task::(prepare) Task=`82d29b1b-0c33-4078-887b-476d95f4b1a1`::finished: {u'158ef830-da69-48b4-95b0-3615d6fb5b00': {'code': 0, 'version': 3, 'acquired': True, 'delay': '0.000627117', 'lastCheck': '8.2', 'valid': True}}
Thread-1732::DEBUG::2014-11-17 15:50:31,033::task::595::Storage.TaskManager.Task::(_updateState) Task=`82d29b1b-0c33-4078-887b-476d95f4b1a1`::moving from state preparing -> state finished
Thread-1732::DEBUG::2014-11-17 15:50:31,034::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1732::DEBUG::2014-11-17 15:50:31,034::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1732::DEBUG::2014-11-17 15:50:31,034::task::993::Storage.TaskManager.Task::(_decref) Task=`82d29b1b-0c33-4078-887b-476d95f4b1a1`::ref 0 aborting False
Thread-1732::DEBUG::2014-11-17 15:50:31,042::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2014-11-17 15:50:31,060::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SEND'>
JsonRpcServer::DEBUG::2014-11-17 15:50:31,062::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1733::DEBUG::2014-11-17 15:50:31,066::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2014-11-17 15:50:31,338::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SEND'>
JsonRpcServer::DEBUG::2014-11-17 15:50:31,341::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1734::DEBUG::2014-11-17 15:50:31,341::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.connectStorageServer' in bridge with {u'connectionParams': [{u'id': u'00000000-0000-0000-0000-000000000000', u'connection': u'/vmstore/isos', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'password': u'', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 4}
Thread-1734::DEBUG::2014-11-17 15:50:31,344::task::595::Storage.TaskManager.Task::(_updateState) Task=`4088bef4-489c-41a4-bcd4-d5f1906378b9`::moving from state init -> state preparing
Thread-1734::INFO::2014-11-17 15:50:31,345::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=4, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'connection': u'/vmstore/isos', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'password': '******', u'id': u'00000000-0000-0000-0000-000000000000', u'port': u''}], options=None)
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,346::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,346::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,347::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,347::__init__::375::IOProcess::(_processLogs) (2321) Got request for method 'access'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,347::__init__::375::IOProcess::(_processLogs) (2321) Queuing response
Thread-1734::DEBUG::2014-11-17 15:50:31,357::hsm::2389::Storage.HSM::(__prefetchDomains) local _path: /vmstore/isos
Thread-1734::DEBUG::2014-11-17 15:50:31,358::hsm::2396::Storage.HSM::(__prefetchDomains) Found SD uuids: ()
Thread-1734::DEBUG::2014-11-17 15:50:31,358::hsm::2452::Storage.HSM::(connectStorageServer) knownSDs: {158ef830-da69-48b4-95b0-3615d6fb5b00: storage.localFsSD.findDomain, ac821c1f-b7ca-4534-a10f-9b98c325a070: storage.nfsSD.findDomain}
Thread-1734::INFO::2014-11-17 15:50:31,358::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]}
Thread-1734::DEBUG::2014-11-17 15:50:31,359::task::1191::Storage.TaskManager.Task::(prepare) Task=`4088bef4-489c-41a4-bcd4-d5f1906378b9`::finished: {'statuslist': [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]}
Thread-1734::DEBUG::2014-11-17 15:50:31,359::task::595::Storage.TaskManager.Task::(_updateState) Task=`4088bef4-489c-41a4-bcd4-d5f1906378b9`::moving from state preparing -> state finished
Thread-1734::DEBUG::2014-11-17 15:50:31,359::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1734::DEBUG::2014-11-17 15:50:31,359::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1734::DEBUG::2014-11-17 15:50:31,360::task::993::Storage.TaskManager.Task::(_decref) Task=`4088bef4-489c-41a4-bcd4-d5f1906378b9`::ref 0 aborting False
Thread-1734::DEBUG::2014-11-17 15:50:31,360::__init__::498::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.connectStorageServer' in bridge with [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]
Thread-1734::DEBUG::2014-11-17 15:50:31,361::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2014-11-17 15:50:31,425::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SEND'>
JsonRpcServer::DEBUG::2014-11-17 15:50:31,428::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1735::DEBUG::2014-11-17 15:50:31,428::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.connectStorageServer' in bridge with {u'connectionParams': [{u'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa', u'connection': u'/vmstore/isos', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'password': u'', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 4}
Thread-1735::DEBUG::2014-11-17 15:50:31,431::task::595::Storage.TaskManager.Task::(_updateState) Task=`1cdc582f-bca2-49c1-a48d-4463f53f0481`::moving from state init -> state preparing
Thread-1735::INFO::2014-11-17 15:50:31,431::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=4, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'connection': u'/vmstore/isos', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'password': '******', u'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa', u'port': u''}], options=None)
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,433::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,433::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,433::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,433::__init__::375::IOProcess::(_processLogs) (2322) Got request for method 'access'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:31,434::__init__::375::IOProcess::(_processLogs) (2322) Queuing response
Thread-1735::DEBUG::2014-11-17 15:50:31,442::hsm::2389::Storage.HSM::(__prefetchDomains) local _path: /vmstore/isos
Thread-1735::DEBUG::2014-11-17 15:50:31,442::hsm::2396::Storage.HSM::(__prefetchDomains) Found SD uuids: ()
Thread-1735::DEBUG::2014-11-17 15:50:31,443::hsm::2452::Storage.HSM::(connectStorageServer) knownSDs: {158ef830-da69-48b4-95b0-3615d6fb5b00: storage.localFsSD.findDomain, ac821c1f-b7ca-4534-a10f-9b98c325a070: storage.nfsSD.findDomain}
Thread-1735::INFO::2014-11-17 15:50:31,443::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa'}]}
Thread-1735::DEBUG::2014-11-17 15:50:31,443::task::1191::Storage.TaskManager.Task::(prepare) Task=`1cdc582f-bca2-49c1-a48d-4463f53f0481`::finished: {'statuslist': [{'status': 0, 'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa'}]}
Thread-1735::DEBUG::2014-11-17 15:50:31,444::task::595::Storage.TaskManager.Task::(_updateState) Task=`1cdc582f-bca2-49c1-a48d-4463f53f0481`::moving from state preparing -> state finished
Thread-1735::DEBUG::2014-11-17 15:50:31,444::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1735::DEBUG::2014-11-17 15:50:31,444::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1735::DEBUG::2014-11-17 15:50:31,444::task::993::Storage.TaskManager.Task::(_decref) Task=`1cdc582f-bca2-49c1-a48d-4463f53f0481`::ref 0 aborting False
Thread-1735::DEBUG::2014-11-17 15:50:31,445::__init__::498::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.connectStorageServer' in bridge with [{'status': 0, 'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa'}]
Thread-1735::DEBUG::2014-11-17 15:50:31,445::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2014-11-17 15:50:31,451::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SEND'>
Thread-1736::DEBUG::2014-11-17 15:50:31,454::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StorageDomain.create' in bridge with {u'name': u'test', u'domainType': 4, u'domainClass': 1, u'typeArgs': u'/vmstore/isos', u'version': u'3', u'storagedomainID': u'c46aa2c4-c405-45eb-b7fd-71f627d1c546'}
JsonRpcServer::DEBUG::2014-11-17 15:50:31,454::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1736::DEBUG::2014-11-17 15:50:31,459::task::595::Storage.TaskManager.Task::(_updateState) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::moving from state init -> state preparing
Thread-1736::INFO::2014-11-17 15:50:31,459::logUtils::44::dispatcher::(wrapper) Run and protect: createStorageDomain(storageType=4, sdUUID=u'c46aa2c4-c405-45eb-b7fd-71f627d1c546', domainName=u'test', typeSpecificArg=u'/vmstore/isos', domClass=1, domVersion=u'3', options=None)
Thread-1736::DEBUG::2014-11-17 15:50:31,459::misc::741::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-1736::DEBUG::2014-11-17 15:50:31,460::misc::743::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-1736::DEBUG::2014-11-17 15:50:31,460::misc::741::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-1736::DEBUG::2014-11-17 15:50:31,460::misc::743::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-1736::DEBUG::2014-11-17 15:50:31,461::iscsi::403::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds
Thread-1736::DEBUG::2014-11-17 15:50:31,461::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) /usr/bin/sudo -n /sbin/iscsiadm -m session -R (cwd None)
Thread-1736::DEBUG::2014-11-17 15:50:31,517::misc::751::Storage.SamplingMethod::(__call__) Returning last result
Thread-1736::DEBUG::2014-11-17 15:50:31,521::multipath::110::Storage.Misc.excCmd::(rescan) /usr/bin/sudo -n /sbin/multipath (cwd None)
Thread-1736::DEBUG::2014-11-17 15:50:31,705::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0
Thread-1736::DEBUG::2014-11-17 15:50:31,706::lvm::489::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,707::lvm::491::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,707::lvm::500::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,708::lvm::502::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,708::lvm::520::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,708::lvm::522::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,709::misc::751::Storage.SamplingMethod::(__call__) Returning last result
Thread-1736::ERROR::2014-11-17 15:50:31,709::sdc::137::Storage.StorageDomainCache::(_findDomain) looking for unfetched domain c46aa2c4-c405-45eb-b7fd-71f627d1c546
Thread-1736::ERROR::2014-11-17 15:50:31,709::sdc::154::Storage.StorageDomainCache::(_findUnfetchedDomain) looking for domain c46aa2c4-c405-45eb-b7fd-71f627d1c546
Thread-1736::DEBUG::2014-11-17 15:50:31,710::lvm::365::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-1736::DEBUG::2014-11-17 15:50:31,712::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 = [ '\''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 c46aa2c4-c405-45eb-b7fd-71f627d1c546 (cwd None)
Thread-1736::DEBUG::2014-11-17 15:50:32,049::lvm::288::Storage.Misc.excCmd::(cmd) FAILED: <err> = '  Volume group "c46aa2c4-c405-45eb-b7fd-71f627d1c546" not found\n  Skipping volume group c46aa2c4-c405-45eb-b7fd-71f627d1c546\n'; <rc> = 5
Thread-1736::WARNING::2014-11-17 15:50:32,052::lvm::370::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] ['  Volume group "c46aa2c4-c405-45eb-b7fd-71f627d1c546" not found', '  Skipping volume group c46aa2c4-c405-45eb-b7fd-71f627d1c546']
Thread-1736::DEBUG::2014-11-17 15:50:32,052::lvm::407::Storage.OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,060::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,061::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,062::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,062::__init__::375::IOProcess::(_processLogs) (2323) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,062::__init__::375::IOProcess::(_processLogs) (2323) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,064::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,065::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,065::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,065::__init__::375::IOProcess::(_processLogs) (2324) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,066::__init__::375::IOProcess::(_processLogs) (2324) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,067::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,068::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,069::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,069::__init__::375::IOProcess::(_processLogs) (2325) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,069::__init__::375::IOProcess::(_processLogs) (2325) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,079::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,082::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,082::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,083::__init__::375::IOProcess::(_processLogs) (2326) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,083::__init__::375::IOProcess::(_processLogs) (2326) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,085::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,086::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,086::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,087::__init__::375::IOProcess::(_processLogs) (2327) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,087::__init__::375::IOProcess::(_processLogs) (2327) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,089::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,089::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,090::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,090::__init__::375::IOProcess::(_processLogs) (2328) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,090::__init__::375::IOProcess::(_processLogs) (2328) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,092::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,093::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,093::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,093::__init__::375::IOProcess::(_processLogs) (2329) Got request for method 'glob'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,093::__init__::375::IOProcess::(_processLogs) (2329) Queuing response
Thread-1736::ERROR::2014-11-17 15:50:32,095::sdc::143::Storage.StorageDomainCache::(_findDomain) domain c46aa2c4-c405-45eb-b7fd-71f627d1c546 not found
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
    dom = findMethod(sdUUID)
  File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
    raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist: (u'c46aa2c4-c405-45eb-b7fd-71f627d1c546',)
Thread-1736::INFO::2014-11-17 15:50:32,096::localFsSD::73::Storage.StorageDomain::(create) sdUUID=c46aa2c4-c405-45eb-b7fd-71f627d1c546 domainName=test remotePath=/vmstore/isos domClass=1
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,097::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,098::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,098::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,098::__init__::375::IOProcess::(_processLogs) (2330) Got request for method 'access'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,099::__init__::375::IOProcess::(_processLogs) (2330) Queuing response
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,107::__init__::375::IOProcess::(_processLogs) Receiving request...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,107::__init__::375::IOProcess::(_processLogs) Queuing request in the thread pool...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,108::__init__::375::IOProcess::(_processLogs) Extracting request information...
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,108::__init__::375::IOProcess::(_processLogs) (2331) Got request for method 'touch'
ioprocess communication (5073)::DEBUG::2014-11-17 15:50:32,108::__init__::375::IOProcess::(_processLogs) (2331) Queuing response
Thread-1736::ERROR::2014-11-17 15:50:32,109::fileSD::92::Storage.fileSD::(validateFileSystemFeatures) Underlying file system doesn't supportdirect IO
Thread-1736::ERROR::2014-11-17 15:50:32,109::task::866::Storage.TaskManager.Task::(_setError) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::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 2683, in createStorageDomain
    domVersion)
  File "/usr/share/vdsm/storage/localFsSD.py", line 84, in create
    cls._preCreateValidation(sdUUID, mntPoint, remotePath, version)
  File "/usr/share/vdsm/storage/localFsSD.py", line 51, in _preCreateValidation
    fileSD.validateFileSystemFeatures(sdUUID, domPath)
  File "/usr/share/vdsm/storage/fileSD.py", line 94, in validateFileSystemFeatures
    raise se.StorageDomainTargetUnsupported()
StorageDomainTargetUnsupported: Storage Domain target is unsupported: ()
Thread-1736::DEBUG::2014-11-17 15:50:32,110::task::885::Storage.TaskManager.Task::(_run) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::Task._run: 54f143dd-2229-4bc1-b639-9017ea3ecdd0 (4, u'c46aa2c4-c405-45eb-b7fd-71f627d1c546', u'test', u'/vmstore/isos', 1, u'3') {} failed - stopping task
Thread-1736::DEBUG::2014-11-17 15:50:32,110::task::1217::Storage.TaskManager.Task::(stop) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::stopping in state preparing (force False)
Thread-1736::DEBUG::2014-11-17 15:50:32,111::task::993::Storage.TaskManager.Task::(_decref) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::ref 1 aborting True
Thread-1736::INFO::2014-11-17 15:50:32,111::task::1171::Storage.TaskManager.Task::(prepare) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::aborting: Task is aborted: 'Storage Domain target is unsupported' - code 399
Thread-1736::DEBUG::2014-11-17 15:50:32,111::task::1176::Storage.TaskManager.Task::(prepare) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::Prepare: aborted: Storage Domain target is unsupported
Thread-1736::DEBUG::2014-11-17 15:50:32,111::task::993::Storage.TaskManager.Task::(_decref) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::ref 0 aborting True
Thread-1736::DEBUG::2014-11-17 15:50:32,112::task::928::Storage.TaskManager.Task::(_doAbort) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::Task._doAbort: force False
Thread-1736::DEBUG::2014-11-17 15:50:32,112::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1736::DEBUG::2014-11-17 15:50:32,112::task::595::Storage.TaskManager.Task::(_updateState) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::moving from state preparing -> state aborting
Thread-1736::DEBUG::2014-11-17 15:50:32,113::task::550::Storage.TaskManager.Task::(__state_aborting) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::_aborting: recover policy none
Thread-1736::DEBUG::2014-11-17 15:50:32,113::task::595::Storage.TaskManager.Task::(_updateState) Task=`54f143dd-2229-4bc1-b639-9017ea3ecdd0`::moving from state aborting -> state failed
Thread-1736::DEBUG::2014-11-17 15:50:32,113::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1736::DEBUG::2014-11-17 15:50:32,113::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1736::ERROR::2014-11-17 15:50:32,114::dispatcher::76::Storage.Dispatcher::(wrapper) {'status': {'message': 'Storage Domain target is unsupported: ()', 'code': 399}}
Thread-1736::DEBUG::2014-11-17 15:50:32,114::stompReactor::163::yajsonrpc.StompServer::(send) Sending response
JsonRpc (StompReactor)::DEBUG::2014-11-17 15:50:32,212::stompReactor::98::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command='SEND'>
Thread-1744::DEBUG::2014-11-17 15:50:32,215::__init__::467::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.disconnectStorageServer' in bridge with {u'connectionParams': [{u'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa', u'connection': u'/vmstore/isos', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'password': u'', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 4}
JsonRpcServer::DEBUG::2014-11-17 15:50:32,215::__init__::504::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request
Thread-1744::DEBUG::2014-11-17 15:50:32,220::task::595::Storage.TaskManager.Task::(_updateState) Task=`11fde6d7-ad39-4b40-bb40-00816fe2c131`::moving from state init -> state preparing
Thread-1744::INFO::2014-11-17 15:50:32,221::logUtils::44::dispatcher::(wrapper) Run and protect: disconnectStorageServer(domType=4, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'connection': u'/vmstore/isos', u'iqn': u'', u'user': u'', u'tpgt': u'1', u'password': '******', u'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa', u'port': u''}], options=None)
Thread-1744::DEBUG::2014-11-17 15:50:32,221::misc::741::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Thread-1744::DEBUG::2014-11-17 15:50:32,222::misc::743::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-1744::DEBUG::2014-11-17 15:50:32,222::misc::741::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-1744::DEBUG::2014-11-17 15:50:32,222::misc::743::Storage.SamplingMethod::(__call__) Got in to sampling method
Thread-1744::DEBUG::2014-11-17 15:50:32,222::iscsi::403::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds
Thread-1744::DEBUG::2014-11-17 15:50:32,223::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) /usr/bin/sudo -n /sbin/iscsiadm -m session -R (cwd None)
Thread-1744::DEBUG::2014-11-17 15:50:32,276::misc::751::Storage.SamplingMethod::(__call__) Returning last result
Thread-1744::DEBUG::2014-11-17 15:50:32,280::multipath::110::Storage.Misc.excCmd::(rescan) /usr/bin/sudo -n /sbin/multipath (cwd None)
Thread-1744::DEBUG::2014-11-17 15:50:32,409::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0
Thread-1744::DEBUG::2014-11-17 15:50:32,410::lvm::489::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-1744::DEBUG::2014-11-17 15:50:32,410::lvm::491::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-1744::DEBUG::2014-11-17 15:50:32,411::lvm::500::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-1744::DEBUG::2014-11-17 15:50:32,411::lvm::502::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-1744::DEBUG::2014-11-17 15:50:32,412::lvm::520::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-1744::DEBUG::2014-11-17 15:50:32,412::lvm::522::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-1744::DEBUG::2014-11-17 15:50:32,412::misc::751::Storage.SamplingMethod::(__call__) Returning last result
Thread-1744::INFO::2014-11-17 15:50:32,413::logUtils::47::dispatcher::(wrapper) Run and protect: disconnectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa'}]}
Thread-1744::DEBUG::2014-11-17 15:50:32,413::task::1191::Storage.TaskManager.Task::(prepare) Task=`11fde6d7-ad39-4b40-bb40-00816fe2c131`::finished: {'statuslist': [{'status': 0, 'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa'}]}
Thread-1744::DEBUG::2014-11-17 15:50:32,414::task::595::Storage.TaskManager.Task::(_updateState) Task=`11fde6d7-ad39-4b40-bb40-00816fe2c131`::moving from state preparing -> state finished
Thread-1744::DEBUG::2014-11-17 15:50:32,414::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-1744::DEBUG::2014-11-17 15:50:32,414::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-1744::DEBUG::2014-11-17 15:50:32,414::task::993::Storage.TaskManager.Task::(_decref) Task=`11fde6d7-ad39-4b40-bb40-00816fe2c131`::ref 0 aborting False
Thread-1744::DEBUG::2014-11-17 15:50:32,415::__init__::498::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.disconnectStorageServer' in bridge with [{'status': 0, 'id': u'deb5a580-6994-4db9-9899-cd05c39c2efa'}]
Thread-1744::DEBUG::2014-11-17 15:50:32,416::stompReactor::163::yajsonrpc.StompServer::(send) Sending response

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20141117/b73027e7/attachment-0001.html>