[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