[Users] Failed to attach Storage Domain export to Data Center
зоррыч
zorro at megatrone.ru
Mon Apr 9 06:19:39 EDT 2012
In an attempt to connect ovirt storage domain fail
[root at noc-2-synt nfs4]# cat b23c7ab6-b1d4-4888-8d4a-adc78e61db38/dom_md/metadata
CLASS=Backup
DESCRIPTION=export
IOOPTIMEOUTSEC=1
LEASERETRIES=3
LEASETIMESEC=5
LOCKPOLICY=
LOCKRENEWALINTERVALSEC=5
MASTER_VERSION=0
POOL_UUID=e3e565d6-8104-11e1-afd2-001cc43ceea0
REMOTE_PATH=10.1.20.2:/home/nfs4
ROLE=Regular
SDUUID=b23c7ab6-b1d4-4888-8d4a-adc78e61db38
TYPE=NFS
VERSION=0
_SHA_CKSUM=d91770b5a0f1956cbfb79a6a59b5291dc5bd2b59
logs:
2012-04-09 06:11:38,628 INFO [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-5-thread-50) Running command: AttachStorageDomainToPoolCommand internal: false. Entities affected : ID: e3e565d6-8104-11e1-afd2-001cc43ceea0 Type: Storage
2012-04-09 06:11:38,658 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-49) START, ValidateStorageServerConnectionVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 651832d2
2012-04-09 06:11:38,658 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-48) START, ValidateStorageServerConnectionVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 69324bf2
2012-04-09 06:11:38,747 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-48) FINISH, ValidateStorageServerConnectionVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 69324bf2
2012-04-09 06:11:38,748 INFO [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-5-thread-48) Running command: ConnectStorageToVdsCommand internal: true. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-04-09 06:11:38,750 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-48) START, ConnectStorageServerVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 1b5bf8d2
2012-04-09 06:11:38,762 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-49) FINISH, ValidateStorageServerConnectionVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 651832d2
2012-04-09 06:11:38,763 INFO [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-5-thread-49) Running command: ConnectStorageToVdsCommand internal: true. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-04-09 06:11:38,765 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-49) START, ConnectStorageServerVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 59f6a186
2012-04-09 06:11:38,775 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-48) FINISH, ConnectStorageServerVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 1b5bf8d2
2012-04-09 06:11:38,791 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-49) FINISH, ConnectStorageServerVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 59f6a186
2012-04-09 06:11:38,792 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (pool-5-thread-50) START, AttachStorageDomainVDSCommand(storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = e3e565d6-8104-11e1-afd2-001cc43ceea0), log id: 58a14aa
2012-04-09 06:11:38,816 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-5-thread-50) Failed in AttachStorageDomainVDS method
2012-04-09 06:11:38,817 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-5-thread-50) Error code StorageDomainActionError and error message IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error in storage domain action: ('sdUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0, spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0',)
2012-04-09 06:11:38,817 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-50) IrsBroker::Failed::AttachStorageDomainVDS due to: IRSErrorException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error in storage domain action: ('sdUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0, spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0',)
2012-04-09 06:11:38,836 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-5-thread-50) START, SpmStopVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0), log id: fbb0af9
2012-04-09 06:11:38,848 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-5-thread-50) SpmStopVDSCommand::Stopping SPM on vds 10.2.20.8, pool id e3e565d6-8104-11e1-afd2-001cc43ceea0
2012-04-09 06:11:39,915 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-5-thread-50) FINISH, SpmStopVDSCommand, log id: fbb0af9
2012-04-09 06:11:39,915 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-50) Irs placed on server null failed. Proceed Failover
2012-04-09 06:11:39,923 INFO [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (pool-5-thread-50) Running command: SetStoragePoolStatusCommand internal: true. Entities affected : ID: e3e565d6-8104-11e1-afd2-001cc43ceea0 Type: StoragePool
2012-04-09 06:11:39,948 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-50) hostFromVds::selectedVds - 10.1.20.7, spmStatus Free, storage pool Default
2012-04-09 06:11:39,953 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-50) starting spm on vds 10.1.20.7, storage pool Default, prevId -1, LVER 13
2012-04-09 06:11:39,955 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-5-thread-50) START, SpmStartVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0, prevId=-1, prevLVER=13, storagePoolFormatType=V1, recoveryMode=Manual, SCSIFencing=false), log id: 3eff326c
2012-04-09 06:11:39,971 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-5-thread-50) spmStart polling started: taskId = e6db13d3-1c55-4d11-9fbc-8abf50c635ae
^C
From: Rami Vaknin [mailto:rvaknin at redhat.com]
Sent: Monday, April 09, 2012 1:27 PM
To: зоррыч
Cc: users at ovirt.org
Subject: Re: [Users] Failed to attach Storage Domain export to Data Center
On 04/08/2012 07:05 PM, зоррыч wrote:
I found the metadata in the file ./dom_md/metadata
Changed “b23c7ab6-b1d4-4888-8d4a-adc78e61db38” to “e3e565d6-8104-11e1-afd2-001cc43ceea0” (SDUUID)
It's wrong, you should change that in POOL_UUID and not in SDUUID (my fault, by spuuid I meant to the POOL_UUID).
The data I gave the command:
[root at noc-3-synt ~]# vdsClient -s 0 getConnectedStoragePoolsList
e3e565d6-8104-11e1-afd2-001cc43ceea0
Found in checksum vdsm.log:
Thread-36836::WARNING::2012-04-08 11:19:47,945::persistentDict::242::Storage.PersistentDict::(refresh) data seal is broken metadata declares `4df87518878fd0d74932917b83aba9672f92dff2` should be `d91770b5a0f1956cbfb79a6a59b5291dc5bd2b59` (lines={'VERSION': '0', 'LEASETIMESEC': '5', 'DESCRIPTION': 'export', 'LOCKPOLICY': '', 'LEASERETRIES': '3', 'SDUUID': 'e3e565d6-8104-11e1-afd2-001cc43ceea0', 'REMOTE_PATH': '10.1.20.2:/home/nfs4', 'MASTER_VERSION': '0', 'IOOPTIMEOUTSEC': '1', 'ROLE': 'Regular', 'LOCKRENEWALINTERVALSEC': '5', 'POOL_UUID': '801e35d4-7405-11e1-b152-001cc43ceea0', 'TYPE': 'NFS', 'CLASS': 'Backup'})
MetaDataSealIsBroken: Meta Data seal is broken (checksum mismatch): 'cksum = 4df87518878fd0d74932917b83aba9672f92dff2, computed_cksum = d91770b5a0f1956cbfb79a6a59b5291dc5bd2b59'
Changed it.
As a result, the metadata file:
[root at noc-2-synt dom_md]# cat metadata
CLASS=Backup
DESCRIPTION=export
IOOPTIMEOUTSEC=1
LEASERETRIES=3
LEASETIMESEC=5
LOCKPOLICY=
LOCKRENEWALINTERVALSEC=5
MASTER_VERSION=0
POOL_UUID=801e35d4-7405-11e1-b152-001cc43ceea0
REMOTE_PATH=10.1.20.2:/home/nfs4
ROLE=Regular
SDUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0
TYPE=NFS
VERSION=0
_SHA_CKSUM=d91770b5a0f1956cbfb79a6a59b5291dc5bd2b59
attachment to the ovirt fails:
Thread-35311::INFO::2012-04-08 11:25:54,668::fileSD::244::Storage.StorageDomain::(getStats) sdUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0 [Errno 2] No such file or directory: '/rhev/data-center/mnt/10.1.20.2:_home_nfs4/e3e565d6-8104-11e1-afd2-001cc43ceea0'
Thread-35311::ERROR::2012-04-08 11:25:54,669::task::868::TaskManager.Task::(_setError) Unexpected error
I renamed the folder that contains the data to e3e565d6-8104-11e1-afd2-001cc43ceea0 for b23c7ab6-b1d4-4888-8d4a-adc78e61db38 (SDUUID)
attachment to the ovirt fails =(
messages:
Error while executing action AttachStorageDomainToPool: Error in storage domain action
engine.log:
2012-04-08 11:53:10,557 INFO [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-5-thread-49) Running command: AttachStorageDomainToPoolCommand internal: false. Entities affected : ID: e3e565d6-8104-11e1-afd2-001cc43ceea0 Type: Storage
2012-04-08 11:53:10,583 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-46) START, ValidateStorageServerConnectionVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 3dbf104d
2012-04-08 11:53:10,583 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-50) START, ValidateStorageServerConnectionVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 4ac74ee6
2012-04-08 11:53:10,685 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-50) FINISH, ValidateStorageServerConnectionVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 4ac74ee6
2012-04-08 11:53:10,686 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 Type: System
2012-04-08 11:53:10,689 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-50) START, ConnectStorageServerVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 53bd874a
2012-04-08 11:53:10,690 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-46) FINISH, ValidateStorageServerConnectionVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 3dbf104d
2012-04-08 11:53:10,691 INFO [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-5-thread-46) Running command: ConnectStorageToVdsCommand internal: true. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-04-08 11:53:10,693 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-46) START, ConnectStorageServerVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 3129fd68
2012-04-08 11:53:10,714 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-50) FINISH, ConnectStorageServerVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 53bd874a
2012-04-08 11:53:10,716 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-46) FINISH, ConnectStorageServerVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 3129fd68
2012-04-08 11:53:10,718 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (pool-5-thread-49) START, AttachStorageDomainVDSCommand(storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = e3e565d6-8104-11e1-afd2-001cc43ceea0), log id: 2b559a22
2012-04-08 11:53:10,737 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-5-thread-49) Failed in AttachStorageDomainVDS method
2012-04-08 11:53:10,737 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase] (pool-5-thread-49) Error code StorageDomainActionError and error message IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error in storage domain action: ('sdUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0, spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0',)
2012-04-08 11:53:10,738 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-49) IrsBroker::Failed::AttachStorageDomainVDS due to: IRSErrorException: IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error in storage domain action: ('sdUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0, spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0',)
2012-04-08 11:53:10,752 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-5-thread-49) START, SpmStopVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0), log id: 6b2f2dd2
2012-04-08 11:53:10,764 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-5-thread-49) SpmStopVDSCommand::Stopping SPM on vds 10.1.20.7, pool id e3e565d6-8104-11e1-afd2-001cc43ceea0
2012-04-08 11:53:11,843 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (pool-5-thread-49) FINISH, SpmStopVDSCommand, log id: 6b2f2dd2
2012-04-08 11:53:11,843 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-49) Irs placed on server null failed. Proceed Failover
2012-04-08 11:53:11,850 INFO [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (pool-5-thread-49) Running command: SetStoragePoolStatusCommand internal: true. Entities affected : ID: e3e565d6-8104-11e1-afd2-001cc43ceea0 Type: StoragePool
2012-04-08 11:53:11,881 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-49) hostFromVds::selectedVds - 10.2.20.8, spmStatus Free, storage pool Default
2012-04-08 11:53:11,886 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-49) starting spm on vds 10.2.20.8, storage pool Default, prevId -1, LVER 8
2012-04-08 11:53:11,888 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-5-thread-49) START, SpmStartVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0, prevId=-1, prevLVER=8, storagePoolFormatType=V1, recoveryMode=Manual, SCSIFencing=false), log id: 382e702
2012-04-08 11:53:11,905 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (pool-5-thread-49) spmStart polling started: taskId = f65c40e4-956f-4c01-ab3f-5c43f2853806
Vdsm.log:
Thread-38311::INFO::2012-04-08 11:54:32,427::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: getStoragePoolInfo, Return response: {'status': {'message': 'OK', 'code': 0}, 'info': {'spm_id': 2, 'master_uuid': '4f1199ec-9cdb-4efe-91eb-587faeec2099', 'name': 'Default', 'version': '0', 'domains': '4f1199ec-9cdb-4efe-91eb-587faeec2099:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'NFS', 'master_ver': 1, 'lver': 10}, 'dominfo': {'4f1199ec-9cdb-4efe-91eb-587faeec2099': {'status': 'Active', 'diskfree': '490079256576', 'alerts': [], 'disktotal': '516524343296'}}}
Thread-38312::DEBUG::2012-04-08 11:54:32,952::clientIF::239::Storage.Dispatcher.Protect::(wrapper) [10.1.20.2]
Thread-38312::INFO::2012-04-08 11:54:32,952::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: validateStorageServerConnection, args: (domType=1, spUUID=00000000-0000-0000-0000-000000000000, conList=[{'connection': '10.1.20.2:/home/nfs4', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f', 'port': ''}])
Thread-38312::DEBUG::2012-04-08 11:54:32,953::task::495::TaskManager.Task::(_debug) Task 7899228e-1fc3-4fe0-bbcd-84cb4aa1ef11: moving from state init -> state preparing
Thread-38312::INFO::2012-04-08 11:54:32,953::storage_connection::127::Storage.ServerConnection::(validate) Request to validate NFS storage server
Thread-38312::INFO::2012-04-08 11:54:32,953::storage_connection::53::Storage.ServerConnection::(__validateConnectionParams) conList=[{'connection': '10.1.20.2:/home/nfs4', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f', 'port': ''}]
Thread-38312::DEBUG::2012-04-08 11:54:32,955::fileUtils::83::Storage.Misc.excCmd::(mount) '/usr/bin/sudo -n /bin/mount -o soft,timeo=600,retrans=6,nosharecache,vers=3 -t nfs 10.1.20.2:/home/nfs4 /tmp/tmplHltd0' (cwd None)
Thread-38312::DEBUG::2012-04-08 11:54:32,987::fileUtils::83::Storage.Misc.excCmd::(mount) SUCCESS: <err> = ''; <rc> = 0
Thread-38312::DEBUG::2012-04-08 11:54:32,994::fileUtils::112::Storage.Misc.excCmd::(umount) '/usr/bin/sudo -n /bin/umount -t nfs -f /tmp/tmplHltd0' (cwd None)
Thread-38312::DEBUG::2012-04-08 11:54:33,021::fileUtils::112::Storage.Misc.excCmd::(umount) SUCCESS: <err> = ''; <rc> = 0
Thread-38312::DEBUG::2012-04-08 11:54:33,022::task::495::TaskManager.Task::(_debug) Task 7899228e-1fc3-4fe0-bbcd-84cb4aa1ef11: finished: {'statuslist': [{'status': 0, 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f'}]}
Thread-38312::DEBUG::2012-04-08 11:54:33,023::task::495::TaskManager.Task::(_debug) Task 7899228e-1fc3-4fe0-bbcd-84cb4aa1ef11: moving from state preparing -> state finished
Thread-38312::DEBUG::2012-04-08 11:54:33,023::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-38312::DEBUG::2012-04-08 11:54:33,024::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38312::DEBUG::2012-04-08 11:54:33,024::task::495::TaskManager.Task::(_debug) Task 7899228e-1fc3-4fe0-bbcd-84cb4aa1ef11: ref 0 aborting False
Thread-38312::INFO::2012-04-08 11:54:33,024::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: validateStorageServerConnection, Return response: {'status': {'message': 'OK', 'code': 0}, 'statuslist': [{'status': 0, 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f'}]}
Thread-38313::DEBUG::2012-04-08 11:54:33,037::clientIF::239::Storage.Dispatcher.Protect::(wrapper) [10.1.20.2]
Thread-38313::INFO::2012-04-08 11:54:33,037::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: connectStorageServer, args: (domType=1, spUUID=00000000-0000-0000-0000-000000000000, conList=[{'connection': '10.1.20.2:/home/nfs4', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f', 'port': ''}])
Thread-38313::DEBUG::2012-04-08 11:54:33,038::task::495::TaskManager.Task::(_debug) Task 83b36131-7378-4f69-841d-b82637362295: moving from state init -> state preparing
Thread-38313::INFO::2012-04-08 11:54:33,038::storage_connection::95::Storage.ServerConnection::(connect) Request to connect NFS storage server
Thread-38313::INFO::2012-04-08 11:54:33,038::storage_connection::53::Storage.ServerConnection::(__validateConnectionParams) conList=[{'connection': '10.1.20.2:/home/nfs4', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f', 'port': ''}]
Thread-38313::DEBUG::2012-04-08 11:54:33,048::lvm::547::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-38313::DEBUG::2012-04-08 11:54:33,048::lvm::549::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-38313::DEBUG::2012-04-08 11:54:33,049::lvm::559::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-38313::DEBUG::2012-04-08 11:54:33,049::lvm::561::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-38313::DEBUG::2012-04-08 11:54:33,049::lvm::580::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-38313::DEBUG::2012-04-08 11:54:33,050::lvm::582::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-38313::DEBUG::2012-04-08 11:54:33,050::task::495::TaskManager.Task::(_debug) Task 83b36131-7378-4f69-841d-b82637362295: finished: {'statuslist': [{'status': 0, 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f'}]}
Thread-38313::DEBUG::2012-04-08 11:54:33,050::task::495::TaskManager.Task::(_debug) Task 83b36131-7378-4f69-841d-b82637362295: moving from state preparing -> state finished
Thread-38313::DEBUG::2012-04-08 11:54:33,051::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-38313::DEBUG::2012-04-08 11:54:33,051::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38313::DEBUG::2012-04-08 11:54:33,051::task::495::TaskManager.Task::(_debug) Task 83b36131-7378-4f69-841d-b82637362295: ref 0 aborting False
Thread-38313::INFO::2012-04-08 11:54:33,051::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: connectStorageServer, Return response: {'status': {'message': 'OK', 'code': 0}, 'statuslist': [{'status': 0, 'id': 'aef7de23-f271-45f3-853b-9e7b7be6607f'}]}
Thread-38314::DEBUG::2012-04-08 11:54:33,062::clientIF::239::Storage.Dispatcher.Protect::(wrapper) [10.1.20.2]
Thread-38314::INFO::2012-04-08 11:54:33,062::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: attachStorageDomain, args: ( sdUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0 spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0)
Thread-38314::DEBUG::2012-04-08 11:54:33,063::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: moving from state init -> state preparing
Thread-38314::DEBUG::2012-04-08 11:54:33,063::resourceManager::155::ResourceManager.Request::(__init__) ResName=`Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0`ReqID=`a97b6096-7b1a-4f93-b0c0-322399c2ac3a`::Request was made in '/usr/share/vdsm/storage/spm.py' line '1072' at 'public_attachStorageDomain'
Thread-38314::DEBUG::2012-04-08 11:54:33,064::resourceManager::463::ResourceManager::(registerResource) Trying to register resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' for lock type 'exclusive'
Thread-38314::DEBUG::2012-04-08 11:54:33,064::resourceManager::505::ResourceManager::(registerResource) Resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' is free. Now locking as 'exclusive' (1 active user)
Thread-38314::DEBUG::2012-04-08 11:54:33,064::resourceManager::192::ResourceManager.Request::(grant) ResName=`Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0`ReqID=`a97b6096-7b1a-4f93-b0c0-322399c2ac3a`::Granted request
Thread-38314::DEBUG::2012-04-08 11:54:33,065::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: _resourcesAcquired: Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 (exclusive)
Thread-38314::DEBUG::2012-04-08 11:54:33,065::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: ref 1 aborting False
Thread-38314::ERROR::2012-04-08 11:54:33,065::task::868::TaskManager.Task::(_setError) Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 876, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/storage/spm.py", line 115, in run
return self.func(*args, **kwargs)
File "/usr/share/vdsm/storage/spm.py", line 1073, in public_attachStorageDomain
vars.task.getExclusiveLock(STORAGE, sdUUID)
File "/usr/share/vdsm/storage/task.py", line 1311, in getExclusiveLock
self.resOwner.acquire(namespace, resName, resourceManager.LockType.exclusive, timeout)
File "/usr/share/vdsm/storage/resourceManager.py", line 673, in acquire
raise ValueError("Owner %s: acquire: resource %s is already acquired" % (str(self), fullName))
ValueError: Owner 2b306544-6fcc-443b-9ea6-23ae4b71d422: acquire: resource Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 is already acquired
Thread-38314::DEBUG::2012-04-08 11:54:33,066::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: Task._run: 2b306544-6fcc-443b-9ea6-23ae4b71d422 ('e3e565d6-8104-11e1-afd2-001cc43ceea0', 'e3e565d6-8104-11e1-afd2-001cc43ceea0') {} failed - stopping task
Thread-38314::DEBUG::2012-04-08 11:54:33,066::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: stopping in state preparing (force False)
Thread-38314::DEBUG::2012-04-08 11:54:33,067::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: ref 1 aborting True
Thread-38314::INFO::2012-04-08 11:54:33,067::task::1171::TaskManager.Task::(prepare) aborting: Task is aborted: 'Owner 2b306544-6fcc-443b-9ea6-23ae4b71d422: acquire: resource Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 is already acquired' - code 100
Thread-38314::DEBUG::2012-04-08 11:54:33,067::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: Prepare: aborted: Owner 2b306544-6fcc-443b-9ea6-23ae4b71d422: acquire: resource Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 is already acquired
Thread-38314::DEBUG::2012-04-08 11:54:33,067::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: ref 0 aborting True
Thread-38314::DEBUG::2012-04-08 11:54:33,068::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: Task._doAbort: force False
Thread-38314::DEBUG::2012-04-08 11:54:33,068::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38314::DEBUG::2012-04-08 11:54:33,068::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: moving from state preparing -> state aborting
Thread-38314::DEBUG::2012-04-08 11:54:33,069::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: _aborting: recover policy none
Thread-38314::DEBUG::2012-04-08 11:54:33,069::task::495::TaskManager.Task::(_debug) Task 2b306544-6fcc-443b-9ea6-23ae4b71d422: moving from state aborting -> state failed
Thread-38314::DEBUG::2012-04-08 11:54:33,069::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0': < ResourceRef 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0', isValid: 'True' obj: 'None'>}
Thread-38314::DEBUG::2012-04-08 11:54:33,069::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38314::DEBUG::2012-04-08 11:54:33,070::resourceManager::515::ResourceManager::(releaseResource) Trying to release resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0'
Thread-38314::DEBUG::2012-04-08 11:54:33,070::resourceManager::530::ResourceManager::(releaseResource) Released resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' (0 active users)
Thread-38314::DEBUG::2012-04-08 11:54:33,070::resourceManager::535::ResourceManager::(releaseResource) Resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' is free, finding out if anyone is waiting for it.
Thread-38314::DEBUG::2012-04-08 11:54:33,071::resourceManager::542::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0', Clearing records.
Thread-38314::ERROR::2012-04-08 11:54:33,071::dispatcher::106::Storage.Dispatcher.Protect::(run) Owner 2b306544-6fcc-443b-9ea6-23ae4b71d422: acquire: resource Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 is already acquired
Thread-38314::ERROR::2012-04-08 11:54:33,071::dispatcher::107::Storage.Dispatcher.Protect::(run) Traceback (most recent call last):
File "/usr/share/vdsm/storage/dispatcher.py", line 96, in run
result = ctask.prepare(self.func, *args, **kwargs)
File "/usr/share/vdsm/storage/task.py", line 1178, in prepare
raise self.error
ValueError: Owner 2b306544-6fcc-443b-9ea6-23ae4b71d422: acquire: resource Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 is already acquired
Thread-38315::DEBUG::2012-04-08 11:54:33,086::clientIF::239::Storage.Dispatcher.Protect::(wrapper) [10.1.20.2]
Thread-38315::INFO::2012-04-08 11:54:33,086::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: getSpmStatus, args: ( spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0)
Thread-38315::DEBUG::2012-04-08 11:54:33,086::task::495::TaskManager.Task::(_debug) Task 04c6f0a0-6010-4c40-a888-8c59b1e69de3: moving from state init -> state preparing
Thread-38315::DEBUG::2012-04-08 11:54:33,087::spm::688::Storage.SPM::(public_getSpmStatus) spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0: spmStatus=SPM spmLver=10 spmId=2
Thread-38315::DEBUG::2012-04-08 11:54:33,087::task::495::TaskManager.Task::(_debug) Task 04c6f0a0-6010-4c40-a888-8c59b1e69de3: finished: {'spm_st': {'spmId': 2, 'spmStatus': 'SPM', 'spmLver': 10}}
Thread-38315::DEBUG::2012-04-08 11:54:33,087::task::495::TaskManager.Task::(_debug) Task 04c6f0a0-6010-4c40-a888-8c59b1e69de3: moving from state preparing -> state finished
Thread-38315::DEBUG::2012-04-08 11:54:33,088::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-38315::DEBUG::2012-04-08 11:54:33,088::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38315::DEBUG::2012-04-08 11:54:33,088::task::495::TaskManager.Task::(_debug) Task 04c6f0a0-6010-4c40-a888-8c59b1e69de3: ref 0 aborting False
Thread-38315::INFO::2012-04-08 11:54:33,089::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: getSpmStatus, Return response: {'status': {'message': 'OK', 'code': 0}, 'spm_st': {'spmId': 2, 'spmStatus': 'SPM', 'spmLver': 10}}
Thread-38316::DEBUG::2012-04-08 11:54:33,101::clientIF::239::Storage.Dispatcher.Protect::(wrapper) [10.1.20.2]
Thread-38316::INFO::2012-04-08 11:54:33,102::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: getAllTasksStatuses, args: ()
Thread-38316::DEBUG::2012-04-08 11:54:33,102::task::495::TaskManager.Task::(_debug) Task 6714a525-c7c6-4132-90a3-da21b312d7fd: moving from state init -> state preparing
Thread-38316::DEBUG::2012-04-08 11:54:33,102::taskManager::92::TaskManager::(getAllTasksStatuses) Entry.
Thread-38316::DEBUG::2012-04-08 11:54:33,102::taskManager::97::TaskManager::(getAllTasksStatuses) Return: {}
Thread-38316::DEBUG::2012-04-08 11:54:33,103::task::495::TaskManager.Task::(_debug) Task 6714a525-c7c6-4132-90a3-da21b312d7fd: finished: {'allTasksStatus': {}}
Thread-38316::DEBUG::2012-04-08 11:54:33,103::task::495::TaskManager.Task::(_debug) Task 6714a525-c7c6-4132-90a3-da21b312d7fd: moving from state preparing -> state finished
Thread-38316::DEBUG::2012-04-08 11:54:33,103::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-38316::DEBUG::2012-04-08 11:54:33,104::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38316::DEBUG::2012-04-08 11:54:33,104::task::495::TaskManager.Task::(_debug) Task 6714a525-c7c6-4132-90a3-da21b312d7fd: ref 0 aborting False
Thread-38316::INFO::2012-04-08 11:54:33,104::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: getAllTasksStatuses, Return response: {'status': {'message': 'OK', 'code': 0}, 'allTasksStatus': {}}
Thread-38317::DEBUG::2012-04-08 11:54:33,113::clientIF::239::Storage.Dispatcher.Protect::(wrapper) [10.1.20.2]
Thread-38317::INFO::2012-04-08 11:54:33,113::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: spmStop, args: ( spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0)
Thread-38317::DEBUG::2012-04-08 11:54:33,114::task::495::TaskManager.Task::(_debug) Task 6bec12b5-5e5b-49d8-a6d3-e8f2a5ef06bf: moving from state init -> state preparing
Thread-38317::DEBUG::2012-04-08 11:54:33,114::spm::547::Storage.SPM::(public_spmStop) spUUID=e3e565d6-8104-11e1-afd2-001cc43ceea0
Thread-38317::DEBUG::2012-04-08 11:54:33,114::taskManager::105::TaskManager::(getAllTasks) Entry.
Thread-38317::DEBUG::2012-04-08 11:54:33,114::taskManager::110::TaskManager::(getAllTasks) Return: {}
Thread-38317::DEBUG::2012-04-08 11:54:33,115::resourceManager::155::ResourceManager.Request::(__init__) ResName=`Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0`ReqID=`417fa7c5-958c-4001-8944-d64df2b44f43`::Request was made in '/usr/share/vdsm/storage/spm.py' line '573' at 'public_spmStop'
Thread-38317::DEBUG::2012-04-08 11:54:33,115::resourceManager::463::ResourceManager::(registerResource) Trying to register resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' for lock type 'exclusive'
Thread-38317::DEBUG::2012-04-08 11:54:33,116::resourceManager::505::ResourceManager::(registerResource) Resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' is free. Now locking as 'exclusive' (1 active user)
Thread-38317::DEBUG::2012-04-08 11:54:33,116::resourceManager::192::ResourceManager.Request::(grant) ResName=`Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0`ReqID=`417fa7c5-958c-4001-8944-d64df2b44f43`::Granted request
Thread-38317::DEBUG::2012-04-08 11:54:33,116::task::495::TaskManager.Task::(_debug) Task 6bec12b5-5e5b-49d8-a6d3-e8f2a5ef06bf: _resourcesAcquired: Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0 (exclusive)
Thread-38317::DEBUG::2012-04-08 11:54:33,117::task::495::TaskManager.Task::(_debug) Task 6bec12b5-5e5b-49d8-a6d3-e8f2a5ef06bf: ref 1 aborting False
Thread-38317::DEBUG::2012-04-08 11:54:33,117::resourceManager::155::ResourceManager.Request::(__init__) ResName=`Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0`ReqID=`b1954479-bdb7-47d3-a42c-b672fe788ca4`::Request was made in '/usr/share/vdsm/storage/spm.py' line '584' at '_stop'
Thread-38317::DEBUG::2012-04-08 11:54:33,117::resourceManager::463::ResourceManager::(registerResource) Trying to register resource 'Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0' for lock type 'exclusive'
Thread-38317::DEBUG::2012-04-08 11:54:33,118::resourceManager::505::ResourceManager::(registerResource) Resource 'Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0' is free. Now locking as 'exclusive' (1 active user)
Thread-38317::DEBUG::2012-04-08 11:54:33,118::resourceManager::192::ResourceManager.Request::(grant) ResName=`Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0`ReqID=`b1954479-bdb7-47d3-a42c-b672fe788ca4`::Granted request
Thread-38317::DEBUG::2012-04-08 11:54:33,119::resourceManager::515::ResourceManager::(releaseResource) Trying to release resource 'Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0'
Thread-38317::DEBUG::2012-04-08 11:54:33,119::resourceManager::530::ResourceManager::(releaseResource) Released resource 'Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0' (0 active users)
Thread-38317::DEBUG::2012-04-08 11:54:33,119::resourceManager::535::ResourceManager::(releaseResource) Resource 'Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0' is free, finding out if anyone is waiting for it.
Thread-38317::DEBUG::2012-04-08 11:54:33,119::resourceManager::542::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.upgrade_e3e565d6-8104-11e1-afd2-001cc43ceea0', Clearing records.
Thread-38317::DEBUG::2012-04-08 11:54:33,120::taskManager::118::TaskManager::(unloadTasks) Entry.
Thread-38317::DEBUG::2012-04-08 11:54:33,120::taskManager::122::TaskManager::(unloadTasks) Return
Thread-38317::DEBUG::2012-04-08 11:54:33,121::spm::201::Storage.SPM::(__cleanupMasterMount) master `/rhev/data-center/mnt/blockSD/e5a63624-716e-4bb4-ae60-cd4d7aae9ed2/master` is not mounted, skipping
Thread-38317::DEBUG::2012-04-08 11:54:33,121::spm::290::Storage.SPM::(__cleanupSPM) cleaning up SPM: e3e565d6-8104-11e1-afd2-001cc43ceea0
Thread-38317::DEBUG::2012-04-08 11:54:33,121::persistentDict::140::Storage.PersistentDict::(transaction) Starting transaction
Thread-38317::DEBUG::2012-04-08 11:54:33,122::persistentDict::146::Storage.PersistentDict::(transaction) Flushing changes
Thread-38317::DEBUG::2012-04-08 11:54:33,122::persistentDict::265::Storage.PersistentDict::(flush) about to write lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=main', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1', 'POOL_DESCRIPTION=Default', 'POOL_DOMAINS=4f1199ec-9cdb-4efe-91eb-587faeec2099:Active', 'POOL_SPM_ID=-1', 'POOL_SPM_LVER=10', 'POOL_UUID=e3e565d6-8104-11e1-afd2-001cc43ceea0', 'REMOTE_PATH=nfs.corp:/share', 'ROLE=Master', 'SDUUID=4f1199ec-9cdb-4efe-91eb-587faeec2099', 'TYPE=NFS', 'VERSION=0', '_SHA_CKSUM=1d1cd722cad65ebb2edfa75641c30a5b97302f84']
Thread-38317::DEBUG::2012-04-08 11:54:33,128::persistentDict::148::Storage.PersistentDict::(transaction) Finished transaction
Thread-38317::INFO::2012-04-08 11:54:33,129::safelease::83::ClusterLock::(release) Releasing cluster lock for domain 4f1199ec-9cdb-4efe-91eb-587faeec2099
Thread-38317::DEBUG::2012-04-08 11:54:33,129::safelease::84::Storage.Misc.excCmd::(release) '/usr/libexec/vdsm/spmstop.sh 4f1199ec-9cdb-4efe-91eb-587faeec2099' (cwd /usr/libexec/vdsm/)
Thread-38317::DEBUG::2012-04-08 11:54:34,164::safelease::84::Storage.Misc.excCmd::(release) SUCCESS: <err> = ''; <rc> = 0
Thread-38317::DEBUG::2012-04-08 11:54:34,165::safelease::87::ClusterLock::(release) Cluster lock released successfully
Thread-38317::DEBUG::2012-04-08 11:54:34,165::task::495::TaskManager.Task::(_debug) Task 6bec12b5-5e5b-49d8-a6d3-e8f2a5ef06bf: finished: None
Thread-38317::DEBUG::2012-04-08 11:54:34,165::task::495::TaskManager.Task::(_debug) Task 6bec12b5-5e5b-49d8-a6d3-e8f2a5ef06bf: moving from state preparing -> state finished
Thread-38317::DEBUG::2012-04-08 11:54:34,166::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0': < ResourceRef 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0', isValid: 'True' obj: 'None'>}
Thread-38317::DEBUG::2012-04-08 11:54:34,166::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38317::DEBUG::2012-04-08 11:54:34,166::resourceManager::515::ResourceManager::(releaseResource) Trying to release resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0'
Thread-38317::DEBUG::2012-04-08 11:54:34,167::resourceManager::530::ResourceManager::(releaseResource) Released resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' (0 active users)
Thread-38317::DEBUG::2012-04-08 11:54:34,167::resourceManager::535::ResourceManager::(releaseResource) Resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0' is free, finding out if anyone is waiting for it.
Thread-38317::DEBUG::2012-04-08 11:54:34,167::resourceManager::542::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.e3e565d6-8104-11e1-afd2-001cc43ceea0', Clearing records.
Thread-38317::DEBUG::2012-04-08 11:54:34,168::task::495::TaskManager.Task::(_debug) Task 6bec12b5-5e5b-49d8-a6d3-e8f2a5ef06bf: ref 0 aborting False
Thread-38317::INFO::2012-04-08 11:54:34,168::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: spmStop, Return response: {'status': {'message': 'OK', 'code': 0}}
Thread-38318::INFO::2012-04-08 11:54:34,395::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: repoStats, args: ()
Thread-38318::DEBUG::2012-04-08 11:54:34,395::task::495::TaskManager.Task::(_debug) Task 612d6da8-5aa1-4f72-89b4-14c3101b0cec: moving from state init -> state preparing
Thread-38318::DEBUG::2012-04-08 11:54:34,395::task::495::TaskManager.Task::(_debug) Task 612d6da8-5aa1-4f72-89b4-14c3101b0cec: finished: {'4f1199ec-9cdb-4efe-91eb-587faeec2099': {'delay': '0.00149178504944', 'lastCheck': 1333900465.46615, 'valid': True, 'code': 0}}
Thread-38318::DEBUG::2012-04-08 11:54:34,396::task::495::TaskManager.Task::(_debug) Task 612d6da8-5aa1-4f72-89b4-14c3101b0cec: moving from state preparing -> state finished
Thread-38318::DEBUG::2012-04-08 11:54:34,396::resourceManager::786::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-38318::DEBUG::2012-04-08 11:54:34,396::resourceManager::821::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-38318::DEBUG::2012-04-08 11:54:34,397::task::495::TaskManager.Task::(_debug) Task 612d6da8-5aa1-4f72-89b4-14c3101b0cec: ref 0 aborting False
From: Rami Vaknin [mailto:rvaknin at redhat.com]
Sent: Sunday, April 08, 2012 7:02 PM
To: зоррыч
Subject: Re: [Users] Failed to attach Storage Domain export to Data Center
On 04/08/2012 03:48 PM, зоррыч wrote:
1. Change the spuuid in the domain's metadata file to be the spuuid of the new datacenter (the metadata can be found in dom_md/ dir somewhere inside the stoarge domain's directories tree), you can take the new spuuid from any host running on the new data center by running:
vdsClient -s 0 getConnectedStoragePoolsList
2. Try to attach the storage domain again, this time it will fail due to broken checksum on the metadata file, go to vdsm.log of the spm and look for "checksum", it will tell you what the right checksum should be like, copy it to the metadata file.
This time the attachment should work.
Hi.
Thank you for the help you provided me in the mailing list.
I dropped the settings using the ovirt - engine-cleanup
Ovirt reinstalled and tried to restore the virtual machine from the export of storage domain.
If you try an attachment domain ovirt error:
Error while executing action AttachStorageDomainToPool: The Domain is already used by another Data Center.<br/>In order to use it, detach it from the Data Center it is currently attached to.
In the logs:
2012-04-08 08:39:49,898 INFO [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-5-thread-50) Running command: AttachStorageDomainToPoolCommand internal: false. Entities affected : ID: b23c7ab6-b1d4-4888-8d4a-adc78e61db38 Type: Storage
2012-04-08 08:39:49,925 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-48) START, ValidateStorageServerConnectionVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 1985db9c
2012-04-08 08:39:49,925 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-47) START, ValidateStorageServerConnectionVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 17f02ea3
2012-04-08 08:39:50,004 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-47) FINISH, ValidateStorageServerConnectionVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 17f02ea3
2012-04-08 08:39:50,005 INFO [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-5-thread-47) Running command: ConnectStorageToVdsCommand internal: true. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-04-08 08:39:50,008 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-47) START, ConnectStorageServerVDSCommand(vdsId = 270e3720-8105-11e1-a3ed-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 6f4db784
2012-04-08 08:39:50,009 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ValidateStorageServerConnectionVDSCommand] (pool-5-thread-48) FINISH, ValidateStorageServerConnectionVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 1985db9c
2012-04-08 08:39:50,010 INFO [org.ovirt.engine.core.bll.storage.ConnectStorageToVdsCommand] (pool-5-thread-48) Running command: ConnectStorageToVdsCommand internal: true. Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type: System
2012-04-08 08:39:50,013 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-48) START, ConnectStorageServerVDSCommand(vdsId = 1bb3653a-8105-11e1-9eda-001cc43ceea0, storagePoolId = 00000000-0000-0000-0000-000000000000, storageType = NFS, connectionList = [{ id: aef7de23-f271-45f3-853b-9e7b7be6607f, connection: 10.1.20.2:/home/nfs4 };]), log id: 42baf149
2012-04-08 08:39:50,031 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-47) FINISH, ConnectStorageServerVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 6f4db784
2012-04-08 08:39:50,035 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (pool-5-thread-48) FINISH, ConnectStorageServerVDSCommand, return: {aef7de23-f271-45f3-853b-9e7b7be6607f=0}, log id: 42baf149
2012-04-08 08:39:50,037 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (pool-5-thread-50) START, AttachStorageDomainVDSCommand(storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = b23c7ab6-b1d4-4888-8d4a-adc78e61db38), log id: 6f22bcac
2012-04-08 08:39:53,186 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (pool-5-thread-50) IrsBroker::Failed::AttachStorageDomainVDS due to: IrsOperationFailedNoFailoverException: IRSGenericException: IRSErrorException: Storage domain already attached to pool: 'domain=b23c7ab6-b1d4-4888-8d4a-adc78e61db38, pool=801e35d4-7405-11e1-b152-001cc43ceea0'
2012-04-08 08:39:53,186 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand] (pool-5-thread-50) FINISH, AttachStorageDomainVDSCommand, log id: 6f22bcac
2012-04-08 08:39:53,186 ERROR [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-5-thread-50) Command org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand throw Vdc Bll exception. With error message VdcBLLException: org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException: IRSGenericException: IRSErrorException: Storage domain already attached to pool: 'domain=b23c7ab6-b1d4-4888-8d4a-adc78e61db38, pool=801e35d4-7405-11e1-b152-001cc43ceea0'
2012-04-08 08:39:53,190 INFO [org.ovirt.engine.core.bll.storage.AttachStorageDomainToPoolCommand] (pool-5-thread-50) Command [id=b717db6a-a582-49ba-92c1-6bb09340789a]: Compensating NEW_ENTITY_ID of org.ovirt.engine.core.common.businessentities.storage_pool_iso_map; snapshot: storagePoolId = e3e565d6-8104-11e1-afd2-001cc43ceea0, storageId = b23c7ab6-b1d4-4888-8d4a-adc78e61db38.
I did not deactivate the export domain before clearing the configuration. How can I be in this case? I can manually remove the flag of the domain?
_______________________________________________
Users mailing list
Users at ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
--
Thanks,
Rami Vaknin, QE @ Red Hat, TLV, IL.
--
Thanks,
Rami Vaknin, QE @ Red Hat, TLV, IL.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20120409/f6934bea/attachment-0002.html>
More information about the Users
mailing list