[Users] Unable to activate data center after host reboot.
Ian Forde
ianforde at gmail.com
Sat Apr 27 14:35:23 UTC 2013
I noticed that you're getting a 304 error. There was just a case of that
when starting a DC. Check the list archives going back the last 4-5 days
and see if that scenario applies to you...
On Apr 27, 2013 7:25 AM, "Steven Wiltshire" <stevenwiltshire at gmail.com>
wrote:
> Hi,
>
> I am using NFS storage, although it is local.
>
> Looking in to the NFS problems further, I read the NFS troubleshooting
> section of the oVirt wiki and made a few changes. nfs-check.py gives me the
> following:
>
> ------------------------------**------------------------------**------
> Current hostname: bigserver - IP addr 10.0.0.154
> Trying to /bin/mount -t nfs 10.0.0.154:/home/vm/data/data.**..
> Executing NFS tests..
> Removing vdsmTest file..
> Status of tests [OK]
> Disconnecting from NFS Server..
> Done!
> ------------------------------**------------------------------**------
>
> Success! Or so it seems, because when the machine boots there are no NFS
> shares mounted. When I attempt to activate the data centre in the oVirt web
> admin tool, the activation fails but an NFS share is mounted:
>
> ------------------------------**------------------------------**------
> 10.0.0.154:/home/vm/data/data on /rhev/data-center/mnt/10.0.0.**154:_home_vm_data_data
> type nfs (rw,relatime,vers=3,rsize=**1048576,wsize=1048576,namlen=**
> 255,soft,nosharecache,proto=**tcp,timeo=600,retrans=6,sec=**
> sys,mountaddr=10.0.0.154,**mountvers=3,mountport=20048,**
> mountproto=udp,local_lock=**none,addr=10.0.0.154)
> ------------------------------**------------------------------**------
>
> Here is the engine.log associated with trying to activate the data centre:
>
> ------------------------------**------------------------------**------
> 2013-04-27 22:45:01,229 INFO [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) Lock Acquired to object EngineLock [exclusiveLocks= key:
> org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand val
> ue: 025062dd-d69e-40ac-9031-**c080b51647ae
> , sharedLocks= ]
> 2013-04-27 22:45:01,231 INFO [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) Running command: ActivateStorageDomainCommand internal:
> false. Entities affected : ID: 025062dd-d69e-40ac-9031-**c080b51647a
> e Type: Storage
> 2013-04-27 22:45:01,243 INFO [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) Lock freed to object EngineLock [exclusiveLocks= key:
> org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand value:
> 025062dd-d69e-40ac-9031-**c080b51647ae
> , sharedLocks= ]
> 2013-04-27 22:45:01,244 INFO [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) ActivateStorage Domain. Before Connect all hosts to
> pool. Time:4/27/13 10:45 PM
> 2013-04-27 22:45:01,285 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ValidateStorageServerConnectio**nVDSCommand] (pool-5-thread-50) START,
> ValidateStorageServerConnectio**nVDSCommand(vdsId =
> aeac7aa6-8840-11e1-99aa-**7fbd3e56e26e, storage
> PoolId = 00000000-0000-0000-0000-**000000000000, storageType = NFS,
> connectionList = [{ id: 60e73855-daa2-45f5-9c59-**5973ca89e830,
> connection: 10.0.0.154:/home/vm/data/data };]), log id: 27174693
> 2013-04-27 22:45:01,400 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ValidateStorageServerConnectio**nVDSCommand] (pool-5-thread-50) FINISH,
> ValidateStorageServerConnectio**nVDSCommand, return:
> {60e73855-daa2-45f5-9c59-**5973ca89e830=0}, l
> og id: 27174693
> 2013-04-27 22:45:01,402 INFO [org.ovirt.engine.core.bll.**storage.**ConnectStorageToVdsCommand]
> (pool-5-thread-50) Running command: ConnectStorageToVdsCommand internal:
> true. Entities affected : ID: aaa00000-0000-0000-0000-**123456789aaa Typ
> e: System
> 2013-04-27 22:45:01,412 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ConnectStorageServerVDSCommand**] (pool-5-thread-50) START,
> ConnectStorageServerVDSCommand**(vdsId = aeac7aa6-8840-11e1-99aa-**7fbd3e56e26e,
> storagePoolId = 00000000-0000
> -0000-0000-000000000000, storageType = NFS, connectionList = [{ id:
> 60e73855-daa2-45f5-9c59-**5973ca89e830, connection: 10.0.0.154:/home/vm/data/data
> };]), log id: 397edfdf
> 2013-04-27 22:45:01,447 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ConnectStorageServerVDSCommand**] (pool-5-thread-50) FINISH,
> ConnectStorageServerVDSCommand**, return: {60e73855-daa2-45f5-9c59-**5973ca89e830=0},
> log id: 397edfdf
> 2013-04-27 22:45:01,450 INFO [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) ActivateStorage Domain. After Connect all hosts to pool.
> Time:4/27/13 10:45 PM
> 2013-04-27 22:45:01,451 INFO [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **ActivateStorageDomainVDSComman**d] (pool-5-thread-44) START,
> ActivateStorageDomainVDSComman**d(storagePoolId = 2b633f9a-8840-11e1-9ed7-
> **17e6c491db84, ignoreFailoverLimit = false, compatabilityVersion = null,
> storageDomainId = 025062dd-d69e-40ac-9031-**c080b51647ae), log id:
> 4a58fee6
> 2013-04-27 22:45:30,061 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **BrokerCommandBase] (QuartzScheduler_Worker-95) Command
> org.ovirt.engine.core.**vdsbroker.vdsbroker.**ConnectStoragePoolVDSCommand
> return value
> Class Name: org.ovirt.engine.core.**vdsbroker.vdsbroker.**
> StatusOnlyReturnForXmlRpc
> mStatus Class Name: org.ovirt.engine.core.**
> vdsbroker.vdsbroker.**StatusForXmlRpc
> mCode 304
> mMessage Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
>
>
> 2013-04-27 22:45:30,062 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **BrokerCommandBase] (QuartzScheduler_Worker-95) Vds: BigServer
> 2013-04-27 22:45:30,062 ERROR [org.ovirt.engine.core.**vdsbroker.VDSCommandBase]
> (QuartzScheduler_Worker-95) Command ConnectStoragePoolVDS execution failed.
> Exception: IRSNoMasterDomainException: IRSGenericException:
> IRSErrorException: IRSNoMasterDomainException: Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> 2013-04-27 22:45:30,063 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ConnectStoragePoolVDSCommand] (QuartzScheduler_Worker-95) FINISH,
> ConnectStoragePoolVDSCommand, log id: 1891eb24
> 2013-04-27 22:45:30,064 INFO [org.ovirt.engine.core.utils.**transaction.**TransactionSupport]
> (QuartzScheduler_Worker-95) transaction rolled back
> 2013-04-27 22:45:30,064 ERROR [org.ovirt.engine.core.**
> vdsbroker.irsbroker.**IrsBrokerCommand] (QuartzScheduler_Worker-95)
> IrsBroker::Failed::**GetStoragePoolInfoVDS
> 2013-04-27 22:45:30,065 ERROR [org.ovirt.engine.core.**
> vdsbroker.irsbroker.**IrsBrokerCommand] (QuartzScheduler_Worker-95)
> Exception: IRSGenericException: IRSErrorException:
> IRSNoMasterDomainException: Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> 2013-04-27 22:45:30,086 WARN [org.ovirt.engine.core.bll.**storage.**
> ReconstructMasterDomainCommand**] (QuartzScheduler_Worker-95) CanDoAction
> of action ReconstructMasterDomain failed. Reasons:VAR__ACTION__**
> RECONSTRUCT_MASTER,VAR__TYPE__**STORAGE__DOMAIN,ACTION_TYPE_**
> FAILED_STORAGE_DOMAIN_STATUS_**ILLEGAL2
> 2013-04-27 22:45:30,120 INFO [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (pool-5-thread-44) hostFromVds::selectedVds -
> BigServer, spmStatus Unknown_Pool, storage pool Default
> 2013-04-27 22:45:30,146 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ConnectStoragePoolVDSCommand] (pool-5-thread-44) START,
> ConnectStoragePoolVDSCommand(**vdsId = aeac7aa6-8840-11e1-99aa-**7fbd3e56e26e,
> storagePoolId = 2b633f9a-8840-11e1-9ed7-**17e6c491db84, vds_spm_id = 1,
> masterDomainId = 025062dd-d69e-40ac-9031-**c080b51647ae, masterVersion =
> 1), log id: 460d5550
> 2013-04-27 22:45:43,303 INFO [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (QuartzScheduler_Worker-7) starting
> ProcessDomainRecovery for domain 503e6677-2d51-4668-ab17-**f914bdb57c19
> 2013-04-27 22:45:43,327 WARN [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (QuartzScheduler_Worker-7) domain
> 503e6677-2d51-4668-ab17-**f914bdb57c19 was reported by all hosts in
> status UP as problematic. Moving the Domain to NonOperational.
> 2013-04-27 22:45:43,335 INFO [org.ovirt.engine.core.bll.**storage.**
> HandleFailedStorageDomainComma**nd] (QuartzScheduler_Worker-7) Running
> command: HandleFailedStorageDomainComma**nd internal: true. Entities
> affected : ID: 503e6677-2d51-4668-ab17-**f914bdb57c19 Type: Storage
> 2013-04-27 22:45:43,344 WARN [org.ovirt.engine.core.bll.**storage.**
> DeactivateStorageDomainCommand**] (QuartzScheduler_Worker-7) CanDoAction
> of action DeactivateStorageDomain failed. Reasons:VAR__TYPE__STORAGE__**
> DOMAIN,VAR__ACTION__**DEACTIVATE,ACTION_TYPE_FAILED_**
> STORAGE_DOMAIN_STATUS_ILLEGAL
> 2013-04-27 22:45:43,349 ERROR [org.ovirt.engine.core.bll.**storage.**
> HandleFailedStorageDomainComma**nd] (QuartzScheduler_Worker-7)
> Transaction rolled-back for command: org.ovirt.engine.core.bll.**storage.*
> *HandleFailedStorageDomainComma**nd.
> 2013-04-27 22:45:43,350 INFO [org.ovirt.engine.core.dal.**
> dbbroker.auditloghandling.**AuditLogDirector] (QuartzScheduler_Worker-7)
> No string for UNASSIGNED type. Use default Log
> 2013-04-27 22:45:43,351 INFO [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (QuartzScheduler_Worker-8) starting
> ProcessDomainRecovery for domain d30604e3-3ca8-470a-8da4-**18c9402f7504
> 2013-04-27 22:45:43,360 WARN [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (QuartzScheduler_Worker-8) domain
> d30604e3-3ca8-470a-8da4-**18c9402f7504 was reported by all hosts in
> status UP as problematic. Moving the Domain to NonOperational.
> 2013-04-27 22:45:43,368 INFO [org.ovirt.engine.core.bll.**storage.**
> HandleFailedStorageDomainComma**nd] (QuartzScheduler_Worker-8) Running
> command: HandleFailedStorageDomainComma**nd internal: true. Entities
> affected : ID: d30604e3-3ca8-470a-8da4-**18c9402f7504 Type: Storage
> 2013-04-27 22:45:43,376 WARN [org.ovirt.engine.core.bll.**storage.**
> DeactivateStorageDomainCommand**] (QuartzScheduler_Worker-8) CanDoAction
> of action DeactivateStorageDomain failed. Reasons:VAR__TYPE__STORAGE__**
> DOMAIN,VAR__ACTION__**DEACTIVATE,ACTION_TYPE_FAILED_**
> STORAGE_DOMAIN_STATUS_ILLEGAL
> 2013-04-27 22:45:43,381 ERROR [org.ovirt.engine.core.bll.**storage.**
> HandleFailedStorageDomainComma**nd] (QuartzScheduler_Worker-8)
> Transaction rolled-back for command: org.ovirt.engine.core.bll.**storage.*
> *HandleFailedStorageDomainComma**nd.
> 2013-04-27 22:45:43,381 INFO [org.ovirt.engine.core.dal.**
> dbbroker.auditloghandling.**AuditLogDirector] (QuartzScheduler_Worker-8)
> No string for UNASSIGNED type. Use default Log
> 2013-04-27 22:45:48,445 WARN [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (QuartzScheduler_Worker-23) domain
> 503e6677-2d51-4668-ab17-**f914bdb57c19 in problem. vds: BigServer
> 2013-04-27 22:46:34,040 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **BrokerCommandBase] (pool-5-thread-44) Command org.ovirt.engine.core.**
> vdsbroker.vdsbroker.**ConnectStoragePoolVDSCommand return value
> Class Name: org.ovirt.engine.core.**vdsbroker.vdsbroker.**
> StatusOnlyReturnForXmlRpc
> mStatus Class Name: org.ovirt.engine.core.**
> vdsbroker.vdsbroker.**StatusForXmlRpc
> mCode 304
> mMessage Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
>
>
> 2013-04-27 22:46:34,040 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **BrokerCommandBase] (pool-5-thread-44) Vds: BigServer
> 2013-04-27 22:46:34,040 ERROR [org.ovirt.engine.core.**vdsbroker.VDSCommandBase]
> (pool-5-thread-44) Command ConnectStoragePoolVDS execution failed.
> Exception: IRSNoMasterDomainException: IRSGenericException:
> IRSErrorException: IRSNoMasterDomainException: Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> 2013-04-27 22:46:34,041 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ConnectStoragePoolVDSCommand] (pool-5-thread-44) FINISH,
> ConnectStoragePoolVDSCommand, log id: 460d5550
> 2013-04-27 22:46:34,042 INFO [org.ovirt.engine.core.utils.**transaction.**TransactionSupport]
> (pool-5-thread-44) transaction rolled back
> 2013-04-27 22:46:34,042 ERROR [org.ovirt.engine.core.**
> vdsbroker.irsbroker.**IrsBrokerCommand] (pool-5-thread-44)
> IrsBroker::Failed::**ActivateStorageDomainVDS
> 2013-04-27 22:46:34,043 ERROR [org.ovirt.engine.core.**
> vdsbroker.irsbroker.**IrsBrokerCommand] (pool-5-thread-44) Exception:
> IRSGenericException: IRSErrorException: IRSNoMasterDomainException: Cannot
> find master domain: 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> 2013-04-27 22:46:34,058 WARN [org.ovirt.engine.core.bll.**storage.**
> ReconstructMasterDomainCommand**] (pool-5-thread-44) CanDoAction of
> action ReconstructMasterDomain failed. Reasons:VAR__ACTION__**
> RECONSTRUCT_MASTER,VAR__TYPE__**STORAGE__DOMAIN,ACTION_TYPE_**
> FAILED_STORAGE_DOMAIN_STATUS_**ILLEGAL2
> 2013-04-27 22:46:34,059 INFO [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **ActivateStorageDomainVDSComman**d] (pool-5-thread-44) FINISH,
> ActivateStorageDomainVDSComman**d, log id: 4a58fee6
> 2013-04-27 22:46:34,059 ERROR [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) Command org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand
> throw Vdc Bll exception. With error message VdcBLLException:
> org.ovirt.engine.core.**vdsbroker.irsbroker.**IRSNoMasterDomainException:
> IRSGenericException: IRSErrorException: IRSNoMasterDomainException: Cannot
> find master domain: 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> 2013-04-27 22:46:34,067 INFO [org.ovirt.engine.core.bll.**storage.**ActivateStorageDomainCommand]
> (pool-5-thread-44) Command [id=7fe48e9f-b3c3-455e-a869-**7cde583084cf]:
> Compensating CHANGED_STATUS_ONLY of org.ovirt.engine.core.common.**
> businessentities.storage_pool_**iso_map; snapshot: EntityStatusSnapshot
> [id=storagePoolId = 2b633f9a-8840-11e1-9ed7-**17e6c491db84, storageId =
> 025062dd-d69e-40ac-9031-**c080b51647ae, status=InActive].
> 2013-04-27 22:46:34,094 INFO [org.ovirt.engine.core.**vdsbroker.irsbroker.
> **IrsBrokerCommand] (QuartzScheduler_Worker-93) hostFromVds::selectedVds
> - BigServer, spmStatus Unknown_Pool, storage pool Default
> 2013-04-27 22:46:34,106 INFO [org.ovirt.engine.core.**vdsbroker.vdsbroker.
> **ConnectStoragePoolVDSCommand] (QuartzScheduler_Worker-93) START,
> ConnectStoragePoolVDSCommand(**vdsId = aeac7aa6-8840-11e1-99aa-**7fbd3e56e26e,
> storagePoolId = 2b633f9a-8840-11e1-9ed7-**17e6c491db84, vds_spm_id = 1,
> masterDomainId = 025062dd-d69e-40ac-9031-**c080b51647ae, masterVersion =
> 1), log id: 9632afe
> ------------------------------**------------------------------**------
>
> Here is vdsm.log for the same time period:
>
> ------------------------------**------------------------------**------
> Thread-309::DEBUG::2013-04-27 22:45:01,297::clientIF::261::**
> Storage.Dispatcher.Protect::(**wrapper) [10.0.0.154]
> Thread-309::DEBUG::2013-04-27 22:45:01,298::task::588::**
> TaskManager.Task::(_**updateState) Task=`da5d1ac1-8b0e-4a9a-bd28-**24c30125654a`::moving
> from state init -> state preparing
> Thread-309::INFO::2013-04-27 22:45:01,299::logUtils::37::**dispatcher::(wrapper)
> Run and protect: validateStorageServerConnectio**n(domType=1,
> spUUID='00000000-0000-0000-**0000-000000000000', conList=[{'connection':
> '10.0.0.154:/home/vm/data/d
> ata', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id':
> '60e73855-daa2-45f5-9c59-**5973ca89e830', 'port': ''}], options=None)
> Thread-309::INFO::2013-04-27 22:45:01,300::storage_**
> connection::188::Storage.**ServerConnection::(validate) Request to
> validate NFS storage server
> Thread-309::DEBUG::2013-04-27 22:45:01,301::mount::111::**Storage.Misc.excCmd::(_runcmd)
> '/usr/bin/sudo -n /bin/mount -t nfs -o soft,nosharecache,timeo=600,**retrans=6
> 10.0.0.154:/home/vm/data/data /tmp/tmpXShfR0' (cwd None)
> Thread-309::DEBUG::2013-04-27 22:45:01,348::mount::111::**Storage.Misc.excCmd::(_runcmd)
> '/usr/bin/sudo -n /bin/umount /tmp/tmpXShfR0' (cwd None)
> Thread-309::INFO::2013-04-27 22:45:01,394::logUtils::39::**dispatcher::(wrapper)
> Run and protect: validateStorageServerConnectio**n, Return response:
> {'statuslist': [{'status': 0, 'id': '60e73855-daa2-45f5-9c59-**
> 5973ca89e830'}]}
> Thread-309::DEBUG::2013-04-27 22:45:01,395::task::1174::**TaskManager.Task::(prepare)
> Task=`da5d1ac1-8b0e-4a9a-bd28-**24c30125654a`::finished: {'statuslist':
> [{'status': 0, 'id': '60e73855-daa2-45f5-9c59-**5973ca89e830'}]}
> Thread-309::DEBUG::2013-04-27 22:45:01,396::task::588::**
> TaskManager.Task::(_**updateState) Task=`da5d1ac1-8b0e-4a9a-bd28-**24c30125654a`::moving
> from state preparing -> state finished
> Thread-309::DEBUG::2013-04-27 22:45:01,397::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-309::DEBUG::2013-04-27 22:45:01,397::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-309::DEBUG::2013-04-27 22:45:01,398::task::980::**TaskManager.Task::(_decref)
> Task=`da5d1ac1-8b0e-4a9a-bd28-**24c30125654a`::ref 0 aborting False
> Thread-310::DEBUG::2013-04-27 22:45:01,424::clientIF::261::**
> Storage.Dispatcher.Protect::(**wrapper) [10.0.0.154]
> Thread-310::DEBUG::2013-04-27 22:45:01,425::task::588::**
> TaskManager.Task::(_**updateState) Task=`6e1d398a-02dc-423d-b500-**6f7f8ccb20e7`::moving
> from state init -> state preparing
> Thread-310::INFO::2013-04-27 22:45:01,425::logUtils::37::**dispatcher::(wrapper)
> Run and protect: connectStorageServer(domType=**1,
> spUUID='00000000-0000-0000-**0000-000000000000', conList=[{'connection':
> '10.0.0.154:/home/vm/data/**data', 'iqn'
> : '', 'portal': '', 'user': '', 'password': '******', 'id':
> '60e73855-daa2-45f5-9c59-**5973ca89e830', 'port': ''}], options=None)
> Thread-310::INFO::2013-04-27 22:45:01,426::storage_**
> connection::146::Storage.**ServerConnection::(connect) Request to connect
> NFS storage server
> Thread-310::DEBUG::2013-04-27 22:45:01,438::lvm::460::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-310::DEBUG::2013-04-27 22:45:01,438::lvm::462::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-310::DEBUG::2013-04-27 22:45:01,439::lvm::472::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-310::DEBUG::2013-04-27 22:45:01,440::lvm::474::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-310::DEBUG::2013-04-27 22:45:01,440::lvm::493::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-310::DEBUG::2013-04-27 22:45:01,441::lvm::495::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-310::INFO::2013-04-27 22:45:01,442::logUtils::39::**dispatcher::(wrapper)
> Run and protect: connectStorageServer, Return response: {'statuslist':
> [{'status': 0, 'id': '60e73855-daa2-45f5-9c59-**5973ca89e830'}]}
> Thread-310::DEBUG::2013-04-27 22:45:01,442::task::1174::**TaskManager.Task::(prepare)
> Task=`6e1d398a-02dc-423d-b500-**6f7f8ccb20e7`::finished: {'statuslist':
> [{'status': 0, 'id': '60e73855-daa2-45f5-9c59-**5973ca89e830'}]}
> Thread-310::DEBUG::2013-04-27 22:45:01,443::task::588::**
> TaskManager.Task::(_**updateState) Task=`6e1d398a-02dc-423d-b500-**6f7f8ccb20e7`::moving
> from state preparing -> state finished
> Thread-310::DEBUG::2013-04-27 22:45:01,443::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-310::DEBUG::2013-04-27 22:45:01,444::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-310::DEBUG::2013-04-27 22:45:01,444::task::980::**TaskManager.Task::(_decref)
> Task=`6e1d398a-02dc-423d-b500-**6f7f8ccb20e7`::ref 0 aborting False
> Thread-314::DEBUG::2013-04-27 22:45:07,704::task::588::**
> TaskManager.Task::(_**updateState) Task=`f43264f4-0160-4737-8e1a-**1322b35cfe3f`::moving
> from state init -> state preparing
> Thread-314::INFO::2013-04-27 22:45:07,705::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-314::INFO::2013-04-27 22:45:07,705::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-314::DEBUG::2013-04-27 22:45:07,706::task::1174::**TaskManager.Task::(prepare)
> Task=`f43264f4-0160-4737-8e1a-**1322b35cfe3f`::finished: {}
> Thread-314::DEBUG::2013-04-27 22:45:07,706::task::588::**
> TaskManager.Task::(_**updateState) Task=`f43264f4-0160-4737-8e1a-**1322b35cfe3f`::moving
> from state preparing -> state finished
> Thread-314::DEBUG::2013-04-27 22:45:07,707::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-314::DEBUG::2013-04-27 22:45:07,708::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-314::DEBUG::2013-04-27 22:45:07,708::task::980::**TaskManager.Task::(_decref)
> Task=`f43264f4-0160-4737-8e1a-**1322b35cfe3f`::ref 0 aborting False
> Thread-320::DEBUG::2013-04-27 22:45:17,899::task::588::**
> TaskManager.Task::(_**updateState) Task=`b3c57791-d573-4dc5-99ef-**9f17578a54d2`::moving
> from state init -> state preparing
> Thread-320::INFO::2013-04-27 22:45:17,900::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-320::INFO::2013-04-27 22:45:17,901::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-320::DEBUG::2013-04-27 22:45:17,901::task::1174::**TaskManager.Task::(prepare)
> Task=`b3c57791-d573-4dc5-99ef-**9f17578a54d2`::finished: {}
> Thread-320::DEBUG::2013-04-27 22:45:17,902::task::588::**
> TaskManager.Task::(_**updateState) Task=`b3c57791-d573-4dc5-99ef-**9f17578a54d2`::moving
> from state preparing -> state finished
> Thread-320::DEBUG::2013-04-27 22:45:17,902::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-320::DEBUG::2013-04-27 22:45:17,903::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-320::DEBUG::2013-04-27 22:45:17,904::task::980::**TaskManager.Task::(_decref)
> Task=`b3c57791-d573-4dc5-99ef-**9f17578a54d2`::ref 0 aborting False
> Thread-326::DEBUG::2013-04-27 22:45:28,062::task::588::**
> TaskManager.Task::(_**updateState) Task=`4cec58af-afca-4003-a3d0-**789ed881116f`::moving
> from state init -> state preparing
> Thread-326::INFO::2013-04-27 22:45:28,063::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-326::INFO::2013-04-27 22:45:28,063::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-326::DEBUG::2013-04-27 22:45:28,064::task::1174::**TaskManager.Task::(prepare)
> Task=`4cec58af-afca-4003-a3d0-**789ed881116f`::finished: {}
> Thread-326::DEBUG::2013-04-27 22:45:28,065::task::588::**
> TaskManager.Task::(_**updateState) Task=`4cec58af-afca-4003-a3d0-**789ed881116f`::moving
> from state preparing -> state finished
> Thread-326::DEBUG::2013-04-27 22:45:28,065::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-326::DEBUG::2013-04-27 22:45:28,066::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-326::DEBUG::2013-04-27 22:45:28,066::task::980::**TaskManager.Task::(_decref)
> Task=`4cec58af-afca-4003-a3d0-**789ed881116f`::ref 0 aborting False
> Thread-286::ERROR::2013-04-27 22:45:30,046::sdc::113::**
> Storage.StorageDomainCache::(_**findDomain) Error while looking for
> domain `025062dd-d69e-40ac-9031-**c080b51647ae`
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/sdc.**py", line 109, in _findDomain
> return mod.findDomain(sdUUID)
> File "/usr/share/vdsm/storage/**nfsSD.py", line 149, in findDomain
> return NfsStorageDomain(**NfsStorageDomain.**findDomainPath(sdUUID))
> File "/usr/share/vdsm/storage/**fileSD.py", line 104, in __init__
> sdUUID = metadata[sd.DMDK_SDUUID]
> File "/usr/share/vdsm/storage/**persistentDict.py", line 75, in
> __getitem__
> return dec(self._dict[key])
> File "/usr/share/vdsm/storage/**persistentDict.py", line 183, in
> __getitem__
> with self._accessWrapper():
> File "/usr/lib64/python2.7/**contextlib.py", line 17, in __enter__
> return self.gen.next()
> File "/usr/share/vdsm/storage/**persistentDict.py", line 137, in
> _accessWrapper
> self.refresh()
> File "/usr/share/vdsm/storage/**persistentDict.py", line 214, in refresh
> lines = self._metaRW.readlines()
> File "/usr/share/vdsm/storage/**fileSD.py", line 71, in readlines
> return misc.stripNewLines(self._oop.**directReadLines(self._**
> metafile))
> File "/usr/share/vdsm/storage/**processPool.py", line 53, in wrapper
> return self.runExternally(func, *args, **kwds)
> File "/usr/share/vdsm/storage/**processPool.py", line 64, in
> runExternally
> return self._procPool.runExternally(***args, **kwargs)
> File "/usr/share/vdsm/storage/**processPool.py", line 145, in
> runExternally
> raise Timeout("Operation Stuck")
> Timeout: Operation Stuck
> Thread-286::DEBUG::2013-04-27 22:45:30,048::resourceManager:**
> :535::ResourceManager::(**releaseResource) Trying to release resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84'
> Thread-286::DEBUG::2013-04-27 22:45:30,049::resourceManager:**
> :550::ResourceManager::(**releaseResource) Released resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' (0 active users)
> Thread-286::DEBUG::2013-04-27 22:45:30,049::resourceManager:**
> :555::ResourceManager::(**releaseResource) Resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' is free, finding out if
> anyone is waiting for it.
> Thread-286::DEBUG::2013-04-27 22:45:30,050::resourceManager:**
> :562::ResourceManager::(**releaseResource) No one is waiting for resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84', Clearing records.
> Thread-286::ERROR::2013-04-27 22:45:30,051::task::855::**TaskManager.Task::(_setError)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::Unexpected error
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/task.**py", line 863, in _run
> return fn(*args, **kargs)
> File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
> res = f(*args, **kwargs)
> File "/usr/share/vdsm/storage/hsm.**py", line 721, in connectStoragePool
> return self._connectStoragePool(**spUUID, hostID, scsiKey, msdUUID,
> masterVersion, options)
> File "/usr/share/vdsm/storage/hsm.**py", line 763, in
> _connectStoragePool
> res = pool.connect(hostID, scsiKey, msdUUID, masterVersion)
> File "/usr/share/vdsm/storage/sp.**py", line 624, in connect
> self.__rebuild(msdUUID=**msdUUID, masterVersion=masterVersion)
> File "/usr/share/vdsm/storage/sp.**py", line 1097, in __rebuild
> self.masterDomain = self.getMasterDomain(msdUUID=**msdUUID,
> masterVersion=masterVersion)
> File "/usr/share/vdsm/storage/sp.**py", line 1435, in getMasterDomain
> raise se.StoragePoolMasterNotFound(**self.spUUID, msdUUID)
> StoragePoolMasterNotFound: Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> Thread-286::DEBUG::2013-04-27 22:45:30,052::task::874::**TaskManager.Task::(_run)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::Task._run:
> a7d4f658-136b-46f5-9458-**f86f059498b1 ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',
> 1, '2b633f9a-8840-11e1-9ed7-**17e6c491db84', '025062dd-d69e-40ac-9031-**c080b51647ae',
> 1) {} failed - stopping task
> Thread-286::DEBUG::2013-04-27 22:45:30,052::task::1201::**TaskManager.Task::(stop)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::stopping in state
> preparing (force False)
> Thread-286::DEBUG::2013-04-27 22:45:30,053::task::980::**TaskManager.Task::(_decref)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::ref 1 aborting True
> Thread-286::INFO::2013-04-27 22:45:30,053::task::1159::**TaskManager.Task::(prepare)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::aborting: Task is aborted:
> 'Cannot find master domain' - code 304
> Thread-286::DEBUG::2013-04-27 22:45:30,054::task::1164::**TaskManager.Task::(prepare)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::Prepare: aborted: Cannot
> find master domain
> Thread-286::DEBUG::2013-04-27 22:45:30,054::task::980::**TaskManager.Task::(_decref)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::ref 0 aborting True
> Thread-286::DEBUG::2013-04-27 22:45:30,055::task::915::**TaskManager.Task::(_doAbort)
> Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::Task._doAbort: force False
> Thread-286::DEBUG::2013-04-27 22:45:30,055::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-286::DEBUG::2013-04-27 22:45:30,056::task::588::**
> TaskManager.Task::(_**updateState) Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::moving
> from state preparing -> state aborting
> Thread-286::DEBUG::2013-04-27 22:45:30,056::task::537::**
> TaskManager.Task::(__state_**aborting) Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::_aborting:
> recover policy none
> Thread-286::DEBUG::2013-04-27 22:45:30,057::task::588::**
> TaskManager.Task::(_**updateState) Task=`a7d4f658-136b-46f5-9458-**f86f059498b1`::moving
> from state aborting -> state failed
> Thread-286::DEBUG::2013-04-27 22:45:30,057::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-286::DEBUG::2013-04-27 22:45:30,058::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-286::ERROR::2013-04-27 22:45:30,059::dispatcher::90::**
> Storage.Dispatcher.Protect::(**run) {'status': {'message': "Cannot find
> master domain: 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'", 'code': 304}}
> Thread-329::DEBUG::2013-04-27 22:45:30,107::clientIF::261::**
> Storage.Dispatcher.Protect::(**wrapper) [10.0.0.154]
> Thread-329::DEBUG::2013-04-27 22:45:30,108::task::588::**
> TaskManager.Task::(_**updateState) Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::moving
> from state init -> state preparing
> Thread-329::INFO::2013-04-27 22:45:30,109::logUtils::37::**dispatcher::(wrapper)
> Run and protect: getSpmStatus(spUUID='2b633f9a-**8840-11e1-9ed7-17e6c491db84',
> options=None)
> Thread-329::ERROR::2013-04-27 22:45:30,110::task::855::**TaskManager.Task::(_setError)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::Unexpected error
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/task.**py", line 863, in _run
> return fn(*args, **kargs)
> File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
> res = f(*args, **kwargs)
> File "/usr/share/vdsm/storage/hsm.**py", line 438, in getSpmStatus
> pool = self.getPool(spUUID)
> File "/usr/share/vdsm/storage/hsm.**py", line 186, in getPool
> raise se.StoragePoolUnknown(spUUID)
> StoragePoolUnknown: Unknown pool id, pool not connected:
> ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',)
> Thread-329::DEBUG::2013-04-27 22:45:30,110::task::874::**TaskManager.Task::(_run)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::Task._run:
> 162609d1-b21e-49ac-b4e6-**061283cfa375 ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',)
> {} failed - stopping task
> Thread-329::DEBUG::2013-04-27 22:45:30,111::task::1201::**TaskManager.Task::(stop)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::stopping in state
> preparing (force False)
> Thread-329::DEBUG::2013-04-27 22:45:30,111::task::980::**TaskManager.Task::(_decref)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::ref 1 aborting True
> Thread-329::INFO::2013-04-27 22:45:30,112::task::1159::**TaskManager.Task::(prepare)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::aborting: Task is aborted:
> 'Unknown pool id, pool not connected' - code 309
> Thread-329::DEBUG::2013-04-27 22:45:30,112::task::1164::**TaskManager.Task::(prepare)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::Prepare: aborted: Unknown
> pool id, pool not connected
> Thread-329::DEBUG::2013-04-27 22:45:30,113::task::980::**TaskManager.Task::(_decref)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::ref 0 aborting True
> Thread-329::DEBUG::2013-04-27 22:45:30,114::task::915::**TaskManager.Task::(_doAbort)
> Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::Task._doAbort: force False
> Thread-329::DEBUG::2013-04-27 22:45:30,114::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-329::DEBUG::2013-04-27 22:45:30,115::task::588::**
> TaskManager.Task::(_**updateState) Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::moving
> from state preparing -> state aborting
> Thread-329::DEBUG::2013-04-27 22:45:30,115::task::537::**
> TaskManager.Task::(__state_**aborting) Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::_aborting:
> recover policy none
> Thread-329::DEBUG::2013-04-27 22:45:30,116::task::588::**
> TaskManager.Task::(_**updateState) Task=`162609d1-b21e-49ac-b4e6-**061283cfa375`::moving
> from state aborting -> state failed
> Thread-329::DEBUG::2013-04-27 22:45:30,116::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-329::DEBUG::2013-04-27 22:45:30,117::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-329::ERROR::2013-04-27 22:45:30,117::dispatcher::90::**
> Storage.Dispatcher.Protect::(**run) {'status': {'message': "Unknown pool
> id, pool not connected: ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',)",
> 'code': 309}}
> Thread-331::DEBUG::2013-04-27 22:45:30,159::clientIF::261::**
> Storage.Dispatcher.Protect::(**wrapper) [10.0.0.154]
> Thread-331::DEBUG::2013-04-27 22:45:30,160::task::588::**
> TaskManager.Task::(_**updateState) Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::moving
> from state init -> state preparing
> Thread-331::INFO::2013-04-27 22:45:30,161::logUtils::37::**dispatcher::(wrapper)
> Run and protect: connectStoragePool(spUUID='**2b633f9a-8840-11e1-9ed7-**17e6c491db84',
> hostID=1, scsiKey='2b633f9a-8840-11e1-**9ed7-17e6c491db84',
> msdUUID='025062dd-d69e-40ac-**9031-c080b51647ae', masterVersion=1,
> options=None)
> Thread-331::DEBUG::2013-04-27 22:45:30,162::resourceManager:**
> :175::ResourceManager.Request:**:(__init__) ResName=`Storage.2b633f9a-**
> 8840-11e1-9ed7-17e6c491db84`**ReqID=`f6f7913c-4cb2-4811-**baa8-431b4e4eac91`::Request
> was made in '/usr/share/vdsm/storage/hsm.**py' line '747' at
> '_connectStoragePool'
> Thread-331::DEBUG::2013-04-27 22:45:30,162::resourceManager:**
> :483::ResourceManager::(**registerResource) Trying to register resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' for lock type 'exclusive'
> Thread-331::DEBUG::2013-04-27 22:45:30,163::resourceManager:**
> :525::ResourceManager::(**registerResource) Resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' is free. Now locking as
> 'exclusive' (1 active user)
> Thread-331::DEBUG::2013-04-27 22:45:30,164::resourceManager:**
> :212::ResourceManager.Request:**:(grant) ResName=`Storage.2b633f9a-**
> 8840-11e1-9ed7-17e6c491db84`**ReqID=`f6f7913c-4cb2-4811-**baa8-431b4e4eac91`::Granted
> request
> Thread-331::INFO::2013-04-27 22:45:30,165::sp::608::**Storage.StoragePool::(connect)
> Connect host #1 to the storage pool 2b633f9a-8840-11e1-9ed7-**17e6c491db84
> with master domain: 025062dd-d69e-40ac-9031-**c080b51647ae (ver = 1)
> Thread-331::DEBUG::2013-04-27 22:45:30,166::lvm::460::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:30,166::lvm::462::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:30,167::lvm::472::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:30,167::lvm::474::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:30,168::lvm::493::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:30,169::lvm::495::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:30,169::misc::1017::**SamplingMethod::(__call__)
> Trying to enter sampling method (storage.sdc.refreshStorage)
> Thread-331::DEBUG::2013-04-27 22:45:30,170::misc::1019::**SamplingMethod::(__call__)
> Got in to sampling method
> Thread-331::DEBUG::2013-04-27 22:45:30,170::misc::1017::**SamplingMethod::(__call__)
> Trying to enter sampling method (storage.iscsi.rescan)
> Thread-331::DEBUG::2013-04-27 22:45:30,171::misc::1019::**SamplingMethod::(__call__)
> Got in to sampling method
> Thread-331::DEBUG::2013-04-27 22:45:30,172::iscsi::389::**Storage.Misc.excCmd::(rescan)
> '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
> Thread-331::DEBUG::2013-04-27 22:45:30,194::iscsi::389::**Storage.Misc.excCmd::(rescan)
> FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
> Thread-331::DEBUG::2013-04-27 22:45:30,195::misc::1027::**SamplingMethod::(__call__)
> Returning last result
> Thread-331::DEBUG::2013-04-27 22:45:31,778::multipath::71::**Storage.Misc.excCmd::(rescan)
> '/usr/bin/sudo -n /sbin/multipath' (cwd None)
> Thread-331::DEBUG::2013-04-27 22:45:31,807::multipath::71::**Storage.Misc.excCmd::(rescan)
> SUCCESS: <err> = ''; <rc> = 0
> Thread-331::DEBUG::2013-04-27 22:45:31,808::lvm::460::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,808::lvm::462::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,809::lvm::472::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,810::lvm::474::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,810::lvm::493::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,811::lvm::495::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,811::misc::1027::**SamplingMethod::(__call__)
> Returning last result
> Thread-331::DEBUG::2013-04-27 22:45:31,812::lvm::352::**OperationMutex::(_reloadvgs)
> Operation 'lvm reload operation' got the operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,815::lvm::287::**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 filter = [ \\"a%**
> 36782bcb063f75600162a25c119f14**819%\\", \\"r%.*%\\" ] } global {
> locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup {
> retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix
> --separator | -o uuid,name,attr,size,free,**extent_size,extent_count,free_
> **count,tags,vg_mda_size,vg_mda_**free 025062dd-d69e-40ac-9031-**c080b51647ae'
> (cwd None)
> Thread-331::DEBUG::2013-04-27 22:45:31,934::lvm::287::**Storage.Misc.excCmd::(cmd)
> FAILED: <err> = ' Volume group "025062dd-d69e-40ac-9031-**c080b51647ae"
> not found\n'; <rc> = 5
> Thread-331::WARNING::2013-04-**27 22:45:31,937::lvm::356::**Storage.LVM::(_reloadvgs)
> lvm vgs failed: 5 [] [' Volume group "025062dd-d69e-40ac-9031-**c080b51647ae"
> not found']
> Thread-331::DEBUG::2013-04-27 22:45:31,938::lvm::379::**OperationMutex::(_reloadvgs)
> Operation 'lvm reload operation' released the operation mutex
> Thread-331::DEBUG::2013-04-27 22:45:31,958::fileSD::98::**
> Storage.StorageDomain::(__**init__) Reading domain in path
> /rhev/data-center/mnt/10.0.0.**154:_home_vm_data_data/**
> 025062dd-d69e-40ac-9031-**c080b51647ae
> Thread-331::DEBUG::2013-04-27 22:45:31,960::persistentDict::**
> 175::Storage.PersistentDict::(**__init__) Created a persistant dict with
> FileMetadataRW backend
> Thread-336::DEBUG::2013-04-27 22:45:38,237::task::588::**
> TaskManager.Task::(_**updateState) Task=`1a7e26c3-d715-4cac-bce5-**d0ddd21ab373`::moving
> from state init -> state preparing
> Thread-336::INFO::2013-04-27 22:45:38,238::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-336::INFO::2013-04-27 22:45:38,238::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-336::DEBUG::2013-04-27 22:45:38,239::task::1174::**TaskManager.Task::(prepare)
> Task=`1a7e26c3-d715-4cac-bce5-**d0ddd21ab373`::finished: {}
> Thread-336::DEBUG::2013-04-27 22:45:38,240::task::588::**
> TaskManager.Task::(_**updateState) Task=`1a7e26c3-d715-4cac-bce5-**d0ddd21ab373`::moving
> from state preparing -> state finished
> Thread-336::DEBUG::2013-04-27 22:45:38,240::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-336::DEBUG::2013-04-27 22:45:38,241::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-336::DEBUG::2013-04-27 22:45:38,241::task::980::**TaskManager.Task::(_decref)
> Task=`1a7e26c3-d715-4cac-bce5-**d0ddd21ab373`::ref 0 aborting False
> Thread-342::DEBUG::2013-04-27 22:45:48,395::task::588::**
> TaskManager.Task::(_**updateState) Task=`cf4c41c0-e453-4493-9a68-**b4044d0f0124`::moving
> from state init -> state preparing
> Thread-342::INFO::2013-04-27 22:45:48,396::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-342::INFO::2013-04-27 22:45:48,396::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-342::DEBUG::2013-04-27 22:45:48,397::task::1174::**TaskManager.Task::(prepare)
> Task=`cf4c41c0-e453-4493-9a68-**b4044d0f0124`::finished: {}
> Thread-342::DEBUG::2013-04-27 22:45:48,397::task::588::**
> TaskManager.Task::(_**updateState) Task=`cf4c41c0-e453-4493-9a68-**b4044d0f0124`::moving
> from state preparing -> state finished
> Thread-342::DEBUG::2013-04-27 22:45:48,398::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-342::DEBUG::2013-04-27 22:45:48,399::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-342::DEBUG::2013-04-27 22:45:48,399::task::980::**TaskManager.Task::(_decref)
> Task=`cf4c41c0-e453-4493-9a68-**b4044d0f0124`::ref 0 aborting False
> Thread-348::DEBUG::2013-04-27 22:45:58,557::task::588::**
> TaskManager.Task::(_**updateState) Task=`b536de2b-6e78-43a9-b2b1-**3667b51828df`::moving
> from state init -> state preparing
> Thread-348::INFO::2013-04-27 22:45:58,558::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-348::INFO::2013-04-27 22:45:58,558::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-348::DEBUG::2013-04-27 22:45:58,559::task::1174::**TaskManager.Task::(prepare)
> Task=`b536de2b-6e78-43a9-b2b1-**3667b51828df`::finished: {}
> Thread-348::DEBUG::2013-04-27 22:45:58,560::task::588::**
> TaskManager.Task::(_**updateState) Task=`b536de2b-6e78-43a9-b2b1-**3667b51828df`::moving
> from state preparing -> state finished
> Thread-348::DEBUG::2013-04-27 22:45:58,560::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-348::DEBUG::2013-04-27 22:45:58,561::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-348::DEBUG::2013-04-27 22:45:58,561::task::980::**TaskManager.Task::(_decref)
> Task=`b536de2b-6e78-43a9-b2b1-**3667b51828df`::ref 0 aborting False
> Thread-354::DEBUG::2013-04-27 22:46:08,718::task::588::**
> TaskManager.Task::(_**updateState) Task=`a8e24fe3-5490-480c-a497-**ee3f291698b0`::moving
> from state init -> state preparing
> Thread-354::INFO::2013-04-27 22:46:08,719::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-354::INFO::2013-04-27 22:46:08,720::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-354::DEBUG::2013-04-27 22:46:08,720::task::1174::**TaskManager.Task::(prepare)
> Task=`a8e24fe3-5490-480c-a497-**ee3f291698b0`::finished: {}
> Thread-354::DEBUG::2013-04-27 22:46:08,721::task::588::**
> TaskManager.Task::(_**updateState) Task=`a8e24fe3-5490-480c-a497-**ee3f291698b0`::moving
> from state preparing -> state finished
> Thread-354::DEBUG::2013-04-27 22:46:08,721::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-354::DEBUG::2013-04-27 22:46:08,722::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-354::DEBUG::2013-04-27 22:46:08,722::task::980::**TaskManager.Task::(_decref)
> Task=`a8e24fe3-5490-480c-a497-**ee3f291698b0`::ref 0 aborting False
> Thread-360::DEBUG::2013-04-27 22:46:18,879::task::588::**
> TaskManager.Task::(_**updateState) Task=`9febbab9-7bae-4df5-9d16-**5e89397ae101`::moving
> from state init -> state preparing
> Thread-360::INFO::2013-04-27 22:46:18,880::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-360::INFO::2013-04-27 22:46:18,880::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-360::DEBUG::2013-04-27 22:46:18,881::task::1174::**TaskManager.Task::(prepare)
> Task=`9febbab9-7bae-4df5-9d16-**5e89397ae101`::finished: {}
> Thread-360::DEBUG::2013-04-27 22:46:18,882::task::588::**
> TaskManager.Task::(_**updateState) Task=`9febbab9-7bae-4df5-9d16-**5e89397ae101`::moving
> from state preparing -> state finished
> Thread-360::DEBUG::2013-04-27 22:46:18,882::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-360::DEBUG::2013-04-27 22:46:18,883::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-360::DEBUG::2013-04-27 22:46:18,883::task::980::**TaskManager.Task::(_decref)
> Task=`9febbab9-7bae-4df5-9d16-**5e89397ae101`::ref 0 aborting False
> Thread-366::DEBUG::2013-04-27 22:46:29,039::task::588::**
> TaskManager.Task::(_**updateState) Task=`f0468880-10a0-429b-8fce-**547289a14fd1`::moving
> from state init -> state preparing
> Thread-366::INFO::2013-04-27 22:46:29,040::logUtils::37::**dispatcher::(wrapper)
> Run and protect: repoStats(options=None)
> Thread-366::INFO::2013-04-27 22:46:29,041::logUtils::39::**dispatcher::(wrapper)
> Run and protect: repoStats, Return response: {}
> Thread-366::DEBUG::2013-04-27 22:46:29,041::task::1174::**TaskManager.Task::(prepare)
> Task=`f0468880-10a0-429b-8fce-**547289a14fd1`::finished: {}
> Thread-366::DEBUG::2013-04-27 22:46:29,042::task::588::**
> TaskManager.Task::(_**updateState) Task=`f0468880-10a0-429b-8fce-**547289a14fd1`::moving
> from state preparing -> state finished
> Thread-366::DEBUG::2013-04-27 22:46:29,042::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-366::DEBUG::2013-04-27 22:46:29,043::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-366::DEBUG::2013-04-27 22:46:29,043::task::980::**TaskManager.Task::(_decref)
> Task=`f0468880-10a0-429b-8fce-**547289a14fd1`::ref 0 aborting False
> Thread-331::ERROR::2013-04-27 22:46:34,024::sdc::113::**
> Storage.StorageDomainCache::(_**findDomain) Error while looking for
> domain `025062dd-d69e-40ac-9031-**c080b51647ae`
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/sdc.**py", line 109, in _findDomain
> return mod.findDomain(sdUUID)
> File "/usr/share/vdsm/storage/**nfsSD.py", line 149, in findDomain
> return NfsStorageDomain(**NfsStorageDomain.**findDomainPath(sdUUID))
> File "/usr/share/vdsm/storage/**fileSD.py", line 104, in __init__
> sdUUID = metadata[sd.DMDK_SDUUID]
> File "/usr/share/vdsm/storage/**persistentDict.py", line 75, in
> __getitem__
> return dec(self._dict[key])
> File "/usr/share/vdsm/storage/**persistentDict.py", line 183, in
> __getitem__
> with self._accessWrapper():
> File "/usr/lib64/python2.7/**contextlib.py", line 17, in __enter__
> return self.gen.next()
> File "/usr/share/vdsm/storage/**persistentDict.py", line 137, in
> _accessWrapper
> self.refresh()
> File "/usr/share/vdsm/storage/**persistentDict.py", line 214, in refresh
> lines = self._metaRW.readlines()
> File "/usr/share/vdsm/storage/**fileSD.py", line 71, in readlines
> return misc.stripNewLines(self._oop.**directReadLines(self._**
> metafile))
> File "/usr/share/vdsm/storage/**processPool.py", line 53, in wrapper
> return self.runExternally(func, *args, **kwds)
> File "/usr/share/vdsm/storage/**processPool.py", line 64, in
> runExternally
> return self._procPool.runExternally(***args, **kwargs)
> File "/usr/share/vdsm/storage/**processPool.py", line 145, in
> runExternally
> raise Timeout("Operation Stuck")
> Timeout: Operation Stuck
> Thread-331::DEBUG::2013-04-27 22:46:34,026::resourceManager:**
> :535::ResourceManager::(**releaseResource) Trying to release resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84'
> Thread-331::DEBUG::2013-04-27 22:46:34,027::resourceManager:**
> :550::ResourceManager::(**releaseResource) Released resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' (0 active users)
> Thread-331::DEBUG::2013-04-27 22:46:34,028::resourceManager:**
> :555::ResourceManager::(**releaseResource) Resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' is free, finding out if
> anyone is waiting for it.
> Thread-331::DEBUG::2013-04-27 22:46:34,028::resourceManager:**
> :562::ResourceManager::(**releaseResource) No one is waiting for resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84', Clearing records.
> Thread-331::ERROR::2013-04-27 22:46:34,029::task::855::**TaskManager.Task::(_setError)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::Unexpected error
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/task.**py", line 863, in _run
> return fn(*args, **kargs)
> File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
> res = f(*args, **kwargs)
> File "/usr/share/vdsm/storage/hsm.**py", line 721, in connectStoragePool
> return self._connectStoragePool(**spUUID, hostID, scsiKey, msdUUID,
> masterVersion, options)
> File "/usr/share/vdsm/storage/hsm.**py", line 763, in
> _connectStoragePool
> res = pool.connect(hostID, scsiKey, msdUUID, masterVersion)
> File "/usr/share/vdsm/storage/sp.**py", line 624, in connect
> self.__rebuild(msdUUID=**msdUUID, masterVersion=masterVersion)
> File "/usr/share/vdsm/storage/sp.**py", line 1097, in __rebuild
> self.masterDomain = self.getMasterDomain(msdUUID=**msdUUID,
> masterVersion=masterVersion)
> File "/usr/share/vdsm/storage/sp.**py", line 1435, in getMasterDomain
> raise se.StoragePoolMasterNotFound(**self.spUUID, msdUUID)
> StoragePoolMasterNotFound: Cannot find master domain:
> 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'
> Thread-331::DEBUG::2013-04-27 22:46:34,030::task::874::**TaskManager.Task::(_run)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::Task._run:
> 4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0 ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',
> 1, '2b633f9a-8840-11e1-9ed7-**17e6c491db84', '025062dd-d69e-40ac-9031-**c080b51647ae',
> 1) {} failed - stopping task
> Thread-331::DEBUG::2013-04-27 22:46:34,030::task::1201::**TaskManager.Task::(stop)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::stopping in state
> preparing (force False)
> Thread-331::DEBUG::2013-04-27 22:46:34,031::task::980::**TaskManager.Task::(_decref)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::ref 1 aborting True
> Thread-331::INFO::2013-04-27 22:46:34,032::task::1159::**TaskManager.Task::(prepare)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::aborting: Task is aborted:
> 'Cannot find master domain' - code 304
> Thread-331::DEBUG::2013-04-27 22:46:34,032::task::1164::**TaskManager.Task::(prepare)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::Prepare: aborted: Cannot
> find master domain
> Thread-331::DEBUG::2013-04-27 22:46:34,033::task::980::**TaskManager.Task::(_decref)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::ref 0 aborting True
> Thread-331::DEBUG::2013-04-27 22:46:34,033::task::915::**TaskManager.Task::(_doAbort)
> Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::Task._doAbort: force False
> Thread-331::DEBUG::2013-04-27 22:46:34,034::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-331::DEBUG::2013-04-27 22:46:34,034::task::588::**
> TaskManager.Task::(_**updateState) Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::moving
> from state preparing -> state aborting
> Thread-331::DEBUG::2013-04-27 22:46:34,035::task::537::**
> TaskManager.Task::(__state_**aborting) Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::_aborting:
> recover policy none
> Thread-331::DEBUG::2013-04-27 22:46:34,035::task::588::**
> TaskManager.Task::(_**updateState) Task=`4a7f87fa-cbbc-41de-a457-**bfe6a87e00a0`::moving
> from state aborting -> state failed
> Thread-331::DEBUG::2013-04-27 22:46:34,036::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-331::DEBUG::2013-04-27 22:46:34,036::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-331::ERROR::2013-04-27 22:46:34,037::dispatcher::90::**
> Storage.Dispatcher.Protect::(**run) {'status': {'message': "Cannot find
> master domain: 'spUUID=2b633f9a-8840-11e1-**9ed7-17e6c491db84,
> msdUUID=025062dd-d69e-40ac-**9031-c080b51647ae'", 'code': 304}}
> Thread-371::DEBUG::2013-04-27 22:46:34,082::clientIF::261::**
> Storage.Dispatcher.Protect::(**wrapper) [10.0.0.154]
> Thread-371::DEBUG::2013-04-27 22:46:34,083::task::588::**
> TaskManager.Task::(_**updateState) Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::moving
> from state init -> state preparing
> Thread-371::INFO::2013-04-27 22:46:34,084::logUtils::37::**dispatcher::(wrapper)
> Run and protect: getSpmStatus(spUUID='2b633f9a-**8840-11e1-9ed7-17e6c491db84',
> options=None)
> Thread-371::ERROR::2013-04-27 22:46:34,084::task::855::**TaskManager.Task::(_setError)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::Unexpected error
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/task.**py", line 863, in _run
> return fn(*args, **kargs)
> File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
> res = f(*args, **kwargs)
> File "/usr/share/vdsm/storage/hsm.**py", line 438, in getSpmStatus
> pool = self.getPool(spUUID)
> File "/usr/share/vdsm/storage/hsm.**py", line 186, in getPool
> raise se.StoragePoolUnknown(spUUID)
> StoragePoolUnknown: Unknown pool id, pool not connected:
> ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',)
> Thread-371::DEBUG::2013-04-27 22:46:34,085::task::874::**TaskManager.Task::(_run)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::Task._run:
> e8ba0700-30eb-4467-b1d0-**fbbd7636441b ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',)
> {} failed - stopping task
> Thread-371::DEBUG::2013-04-27 22:46:34,086::task::1201::**TaskManager.Task::(stop)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::stopping in state
> preparing (force False)
> Thread-371::DEBUG::2013-04-27 22:46:34,086::task::980::**TaskManager.Task::(_decref)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::ref 1 aborting True
> Thread-371::INFO::2013-04-27 22:46:34,087::task::1159::**TaskManager.Task::(prepare)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::aborting: Task is aborted:
> 'Unknown pool id, pool not connected' - code 309
> Thread-371::DEBUG::2013-04-27 22:46:34,087::task::1164::**TaskManager.Task::(prepare)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::Prepare: aborted: Unknown
> pool id, pool not connected
> Thread-371::DEBUG::2013-04-27 22:46:34,088::task::980::**TaskManager.Task::(_decref)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::ref 0 aborting True
> Thread-371::DEBUG::2013-04-27 22:46:34,088::task::915::**TaskManager.Task::(_doAbort)
> Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::Task._doAbort: force False
> Thread-371::DEBUG::2013-04-27 22:46:34,089::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-371::DEBUG::2013-04-27 22:46:34,089::task::588::**
> TaskManager.Task::(_**updateState) Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::moving
> from state preparing -> state aborting
> Thread-371::DEBUG::2013-04-27 22:46:34,090::task::537::**
> TaskManager.Task::(__state_**aborting) Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::_aborting:
> recover policy none
> Thread-371::DEBUG::2013-04-27 22:46:34,090::task::588::**
> TaskManager.Task::(_**updateState) Task=`e8ba0700-30eb-4467-b1d0-**fbbd7636441b`::moving
> from state aborting -> state failed
> Thread-371::DEBUG::2013-04-27 22:46:34,091::resourceManager:**
> :806::ResourceManager.Owner::(**releaseAll) Owner.releaseAll requests {}
> resources {}
> Thread-371::DEBUG::2013-04-27 22:46:34,092::resourceManager:**
> :841::ResourceManager.Owner::(**cancelAll) Owner.cancelAll requests {}
> Thread-371::ERROR::2013-04-27 22:46:34,092::dispatcher::90::**
> Storage.Dispatcher.Protect::(**run) {'status': {'message': "Unknown pool
> id, pool not connected: ('2b633f9a-8840-11e1-9ed7-**17e6c491db84',)",
> 'code': 309}}
> Thread-372::DEBUG::2013-04-27 22:46:34,116::clientIF::261::**
> Storage.Dispatcher.Protect::(**wrapper) [10.0.0.154]
> Thread-372::DEBUG::2013-04-27 22:46:34,117::task::588::**
> TaskManager.Task::(_**updateState) Task=`4a764a93-93ca-432b-ac1d-**ca18c36f4b47`::moving
> from state init -> state preparing
> Thread-372::INFO::2013-04-27 22:46:34,118::logUtils::37::**dispatcher::(wrapper)
> Run and protect: connectStoragePool(spUUID='**2b633f9a-8840-11e1-9ed7-**17e6c491db84',
> hostID=1, scsiKey='2b633f9a-8840-11e1-**9ed7-17e6c491db84',
> msdUUID='025062dd-d69e-40ac-**9031-c080b51647ae', masterVersion=1,
> options=None)
> Thread-372::DEBUG::2013-04-27 22:46:34,119::resourceManager:**
> :175::ResourceManager.Request:**:(__init__) ResName=`Storage.2b633f9a-**
> 8840-11e1-9ed7-17e6c491db84`**ReqID=`da6e89ed-9d5c-46d7-**831a-53f401443358`::Request
> was made in '/usr/share/vdsm/storage/hsm.**py' line '747' at
> '_connectStoragePool'
> Thread-372::DEBUG::2013-04-27 22:46:34,119::resourceManager:**
> :483::ResourceManager::(**registerResource) Trying to register resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' for lock type 'exclusive'
> Thread-372::DEBUG::2013-04-27 22:46:34,120::resourceManager:**
> :525::ResourceManager::(**registerResource) Resource
> 'Storage.2b633f9a-8840-11e1-**9ed7-17e6c491db84' is free. Now locking as
> 'exclusive' (1 active user)
> Thread-372::DEBUG::2013-04-27 22:46:34,120::resourceManager:**
> :212::ResourceManager.Request:**:(grant) ResName=`Storage.2b633f9a-**
> 8840-11e1-9ed7-17e6c491db84`**ReqID=`da6e89ed-9d5c-46d7-**831a-53f401443358`::Granted
> request
> Thread-372::INFO::2013-04-27 22:46:34,121::sp::608::**Storage.StoragePool::(connect)
> Connect host #1 to the storage pool 2b633f9a-8840-11e1-9ed7-**17e6c491db84
> with master domain: 025062dd-d69e-40ac-9031-**c080b51647ae (ver = 1)
> Thread-372::DEBUG::2013-04-27 22:46:34,122::lvm::460::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:34,123::lvm::462::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:34,124::lvm::472::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:34,124::lvm::474::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:34,125::lvm::493::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:34,126::lvm::495::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:34,126::misc::1017::**SamplingMethod::(__call__)
> Trying to enter sampling method (storage.sdc.refreshStorage)
> Thread-372::DEBUG::2013-04-27 22:46:34,127::misc::1019::**SamplingMethod::(__call__)
> Got in to sampling method
> Thread-372::DEBUG::2013-04-27 22:46:34,127::misc::1017::**SamplingMethod::(__call__)
> Trying to enter sampling method (storage.iscsi.rescan)
> Thread-372::DEBUG::2013-04-27 22:46:34,128::misc::1019::**SamplingMethod::(__call__)
> Got in to sampling method
> Thread-372::DEBUG::2013-04-27 22:46:34,128::iscsi::389::**Storage.Misc.excCmd::(rescan)
> '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
> Thread-372::DEBUG::2013-04-27 22:46:34,151::iscsi::389::**Storage.Misc.excCmd::(rescan)
> FAILED: <err> = 'iscsiadm: No session found.\n'; <rc> = 21
> Thread-372::DEBUG::2013-04-27 22:46:34,152::misc::1027::**SamplingMethod::(__call__)
> Returning last result
> Thread-372::DEBUG::2013-04-27 22:46:35,735::multipath::71::**Storage.Misc.excCmd::(rescan)
> '/usr/bin/sudo -n /sbin/multipath' (cwd None)
> Thread-372::DEBUG::2013-04-27 22:46:35,764::multipath::71::**Storage.Misc.excCmd::(rescan)
> SUCCESS: <err> = ''; <rc> = 0
> Thread-372::DEBUG::2013-04-27 22:46:35,765::lvm::460::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,766::lvm::462::**OperationMutex::(_
> **invalidateAllPvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,766::lvm::472::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,767::lvm::474::**OperationMutex::(_
> **invalidateAllVgs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,768::lvm::493::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' got the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,768::lvm::495::**OperationMutex::(_
> **invalidateAllLvs) Operation 'lvm invalidate operation' released the
> operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,769::misc::1027::**SamplingMethod::(__call__)
> Returning last result
> Thread-372::DEBUG::2013-04-27 22:46:35,770::lvm::352::**OperationMutex::(_reloadvgs)
> Operation 'lvm reload operation' got the operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,772::lvm::287::**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 filter = [ \\"a%**
> 36782bcb063f75600162a25c119f14**819%\\", \\"r%.*%\\" ] } global {
> locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup {
> retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix
> --separator | -o uuid,name,attr,size,free,**extent_size,extent_count,free_
> **count,tags,vg_mda_size,vg_mda_**free 025062dd-d69e-40ac-9031-**c080b51647ae'
> (cwd None)
> Thread-372::DEBUG::2013-04-27 22:46:35,874::lvm::287::**Storage.Misc.excCmd::(cmd)
> FAILED: <err> = ' Volume group "025062dd-d69e-40ac-9031-**c080b51647ae"
> not found\n'; <rc> = 5
> Thread-372::WARNING::2013-04-**27 22:46:35,877::lvm::356::**Storage.LVM::(_reloadvgs)
> lvm vgs failed: 5 [] [' Volume group "025062dd-d69e-40ac-9031-**c080b51647ae"
> not found']
> Thread-372::DEBUG::2013-04-27 22:46:35,878::lvm::379::**OperationMutex::(_reloadvgs)
> Operation 'lvm reload operation' released the operation mutex
> Thread-372::DEBUG::2013-04-27 22:46:35,898::fileSD::98::**
> Storage.StorageDomain::(__**init__) Reading domain in path
> /rhev/data-center/mnt/10.0.0.**154:_home_vm_data_data/**
> 025062dd-d69e-40ac-9031-**c080b51647ae
> ------------------------------**------------------------------**------
>
> Now, one interesting aspect I've noticed is that when I reboot the server,
> the mounted NFS shares change. As I mentioned earlier, in this instance
> there were no NFS shares mounted when the machine booted and none were
> mounted until I tried to activate the data centre. I subsequently rebooted
> the server after making some changes to nfsmount.conf, and upon booting the
> ISO share was mounted. Intrigued, I rebooted again and both the ISO and
> Export shares were mounted, but not the data share.
>
> Do you - or does anybody - have any further insight?
>
> Thanks for your help so far - looking in to the NFS side of things is
> giving some interesting results, and I'm sure that we're on the path to
> great success.
>
> --Steven.
> ______________________________**_________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/**mailman/listinfo/users<http://lists.ovirt.org/mailman/listinfo/users>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20130427/4ecd11ab/attachment-0001.html>
More information about the Users
mailing list