1:17 p.m.
---------- Forwarded message ----------
From: "Koen Vanoppen" <vanoppen.koen(a)gmail.com>
Date: Feb 28, 2014 8:08 AM
Subject: Re: [Users] Migration Failed
To: "Dan Kenigsberg" <danken(a)redhat.com>
Cc:
Never mind... God damned... :-D
Found the error. Apparently with the move to fibre, someone put a hosts
entry in the /etc/hosts file for buran... To this wrong IP... Thanks again
everyone for the support. It did help me to find the solution.
Thanks!!
2014-02-28 8:03 GMT+01:00 Koen Vanoppen <vanoppen.koen(a)gmail.com>:
The ping I receive on hostX to buran is the IP from the previous
iscsi
address. But due some network issues we moved everything from iscsi to
fibre... But how can it be they still receive the ip from the iscsi?
Kind regards,
Koen
2014-02-28 7:55 GMT+01:00 Koen Vanoppen <vanoppen.koen(a)gmail.com>:
But moving from buran to soyuz does work. But as you can see in the logs,
> moving from X to buran, doesn't...
>
>
> 2014-02-28 7:51 GMT+01:00 Koen Vanoppen <vanoppen.koen(a)gmail.com>:
>
> Sorry for the late answers btw... Busy days here...
>>
>> This is the result from the ping:
>> From buran.brusselsairport.aero (10.110.X.X) icmp_seq=1 Destination
>> Host Prohibited
>> From buran.brusselsairport.aero (10.110.X.X) icmp_seq=2 Destination
>> Host Prohibited
>>
>> If I ping from one of the hypervisors i get a totaly different ip... and
>> of course a host unreachable. Would it be better if I would just remove the
>> host and re-add it?
>>
>> Kind regards,
>>
>> Koen
>>
>>
>> 2014-02-28 7:48 GMT+01:00 Koen Vanoppen <vanoppen.koen(a)gmail.com>:
>>
>> Ok, here is the vdsm log output. He claims he has no route to the
>>> host... But why? They are both in the same data center... (Moving VM from
>>> soyuz --> buran):
>>>
>>> Thread-1062381::DEBUG::2014-02-28
>>> 07:45:44,236::BindingXMLRPC::981::vds::(wrapper) return vmMigrate with
>>> {'status': {'message': 'Migration in progress',
'code': 0}, 'progress': 0}
>>> Thread-1062382::DEBUG::2014-02-28
>>> 07:45:44,236::vm::180::vm.Vm::(_setupVdsConnection)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::Destination server is:
>>> buran.brusselsairport.aero:54321
>>> Thread-1062382::DEBUG::2014-02-28
>>> 07:45:44,237::vm::182::vm.Vm::(_setupVdsConnection)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::Initiating connection with
>>> destination
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:44,581::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> 'dd
>>>
if=/rhev/data-center/cbbb821c-0523-4639-b453-9371ff5dc7b1/mastersd/dom_md/inbox
>>> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:44,717::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes
(1.0 MB)
>>> copied, 0.046894 s, 21.8 MB/s\n'; <rc> = 0
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,877::BindingXMLRPC::177::vds::(wrapper) client [10.110.57.30]
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,884::task::579::TaskManager.Task::(_updateState)
>>> Task=`9e1e642a-2dfb-4519-8f98-f98bb520fc5e`::moving from state init ->
>>> state preparing
>>> Thread-1062383::INFO::2014-02-28
>>> 07:45:44,887::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getSpmStatus(spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
options=None)
>>> Thread-1062383::INFO::2014-02-28
>>> 07:45:44,888::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getSpmStatus, Return response: {'spm_st': {'spmId': 2,
'spmStatus': 'SPM',
>>> 'spmLver': 1}}
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,888::task::1168::TaskManager.Task::(prepare)
>>> Task=`9e1e642a-2dfb-4519-8f98-f98bb520fc5e`::finished: {'spm_st':
{'spmId':
>>> 2, 'spmStatus': 'SPM', 'spmLver': 1}}
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,888::task::579::TaskManager.Task::(_updateState)
>>> Task=`9e1e642a-2dfb-4519-8f98-f98bb520fc5e`::moving from state preparing
->
>>> state finished
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,889::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,889::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-1062383::DEBUG::2014-02-28
>>> 07:45:44,889::task::974::TaskManager.Task::(_decref)
>>> Task=`9e1e642a-2dfb-4519-8f98-f98bb520fc5e`::ref 0 aborting False
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,895::BindingXMLRPC::177::vds::(wrapper) client [10.110.57.30]
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,895::task::579::TaskManager.Task::(_updateState)
>>> Task=`8862a9b6-a0da-440f-858f-3aec8df12e3f`::moving from state init ->
>>> state preparing
>>> Thread-1062384::INFO::2014-02-28
>>> 07:45:44,896::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getStoragePoolInfo(spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> options=None)
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,897::resourceManager::197::ResourceManager.Request::(__init__)
>>>
ResName=`Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1`ReqID=`30e9c6a5-9be6-42c3-ac2a-1159a5619995`::Request
>>> was made in '/usr/share/vdsm/storage/hsm.py' line '2552' at
>>> 'getStoragePoolInfo'
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,897::resourceManager::541::ResourceManager::(registerResource)
>>> Trying to register resource
'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1'
>>> for lock type 'shared'
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,898::resourceManager::600::ResourceManager::(registerResource)
>>> Resource 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1' is free. Now
>>> locking as 'shared' (1 active user)
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,898::resourceManager::237::ResourceManager.Request::(grant)
>>>
ResName=`Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1`ReqID=`30e9c6a5-9be6-42c3-ac2a-1159a5619995`::Granted
>>> request
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,899::task::811::TaskManager.Task::(resourceAcquired)
>>> Task=`8862a9b6-a0da-440f-858f-3aec8df12e3f`::_resourcesAcquired:
>>> Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1 (shared)
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,899::task::974::TaskManager.Task::(_decref)
>>> Task=`8862a9b6-a0da-440f-858f-3aec8df12e3f`::ref 1 aborting False
>>> Thread-1062384::INFO::2014-02-28
>>> 07:45:44,901::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getStoragePoolInfo, Return response: {'info': {'spm_id': 2,
'master_uuid':
>>> '5d2c10af-23bb-4112-9d05-d0c4e65f80ef', 'name':
'TestDev', 'version': '3',
>>> 'domains':
>>>
u'1988ca23-e1ac-4831-bc57-768d01b0f1d1:Active,5d2c10af-23bb-4112-9d05-d0c4e65f80ef:Active,983782c7-e157-43e4-a3a3-b84d64530b96:Active,50cf24a4-d1ef-4105-a9a5-b81d91339175:Active',
>>> 'pool_status': 'connected', 'isoprefix':
>>>
'/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111',
>>> 'type': 'FCP', 'master_ver': 1, 'lver': 1},
'dominfo':
>>> {u'1988ca23-e1ac-4831-bc57-768d01b0f1d1': {'status':
u'Active', 'diskfree':
>>> '300379275264', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'5d2c10af-23bb-4112-9d05-d0c4e65f80ef': {'status':
u'Active', 'diskfree':
>>> '69524783104', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'983782c7-e157-43e4-a3a3-b84d64530b96': {'status':
u'Active', 'diskfree':
>>> '169114337280', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'status':
u'Active', 'diskfree':
>>> '7559184384', 'alerts': [], 'version': 0,
'disktotal': '21891121152'}}}
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,901::task::1168::TaskManager.Task::(prepare)
>>> Task=`8862a9b6-a0da-440f-858f-3aec8df12e3f`::finished: {'info':
{'spm_id':
>>> 2, 'master_uuid': '5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
'name':
>>> 'TestDev', 'version': '3', 'domains':
>>>
u'1988ca23-e1ac-4831-bc57-768d01b0f1d1:Active,5d2c10af-23bb-4112-9d05-d0c4e65f80ef:Active,983782c7-e157-43e4-a3a3-b84d64530b96:Active,50cf24a4-d1ef-4105-a9a5-b81d91339175:Active',
>>> 'pool_status': 'connected', 'isoprefix':
>>>
'/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111',
>>> 'type': 'FCP', 'master_ver': 1, 'lver': 1},
'dominfo':
>>> {u'1988ca23-e1ac-4831-bc57-768d01b0f1d1': {'status':
u'Active', 'diskfree':
>>> '300379275264', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'5d2c10af-23bb-4112-9d05-d0c4e65f80ef': {'status':
u'Active', 'diskfree':
>>> '69524783104', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'983782c7-e157-43e4-a3a3-b84d64530b96': {'status':
u'Active', 'diskfree':
>>> '169114337280', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'status':
u'Active', 'diskfree':
>>> '7559184384', 'alerts': [], 'version': 0,
'disktotal': '21891121152'}}}
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,902::task::579::TaskManager.Task::(_updateState)
>>> Task=`8862a9b6-a0da-440f-858f-3aec8df12e3f`::moving from state preparing
->
>>> state finished
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,902::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources
>>> {'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1': < ResourceRef
>>> 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1', isValid:
'True' obj:
>>> 'None'>}
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,903::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,903::resourceManager::615::ResourceManager::(releaseResource)
>>> Trying to release resource
'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1'
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,904::resourceManager::634::ResourceManager::(releaseResource)
>>> Released resource 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1' (0
active
>>> users)
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,904::resourceManager::640::ResourceManager::(releaseResource)
>>> Resource 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1' is free,
finding
>>> out if anyone is waiting for it.
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,904::resourceManager::648::ResourceManager::(releaseResource) No
>>> one is waiting for resource
'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> Clearing records.
>>> Thread-1062384::DEBUG::2014-02-28
>>> 07:45:44,905::task::974::TaskManager.Task::(_decref)
>>> Task=`8862a9b6-a0da-440f-858f-3aec8df12e3f`::ref 0 aborting False
>>> Thread-1062385::DEBUG::2014-02-28
>>> 07:45:45,852::task::579::TaskManager.Task::(_updateState)
>>> Task=`2dc97e57-449e-4335-ba9b-c69d22e968d4`::moving from state init ->
>>> state preparing
>>> Thread-1062385::INFO::2014-02-28
>>> 07:45:45,852::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> repoStats(options=None)
>>> Thread-1062385::INFO::2014-02-28
>>> 07:45:45,853::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> repoStats, Return response:
{u'1988ca23-e1ac-4831-bc57-768d01b0f1d1':
>>> {'delay': '0.000139105', 'lastCheck': '6.2',
'code': 0, 'valid': True,
>>> 'version': 3}, '5d2c10af-23bb-4112-9d05-d0c4e65f80ef':
{'delay':
>>> '0.000157599', 'lastCheck': '4.6', 'code': 0,
'valid': True, 'version': 3},
>>> u'983782c7-e157-43e4-a3a3-b84d64530b96': {'delay':
'0.000136455',
>>> 'lastCheck': '4.3', 'code': 0, 'valid': True,
'version': 3},
>>> '50cf24a4-d1ef-4105-a9a5-b81d91339175': {'delay':
'0.000406695',
>>> 'lastCheck': '5.3', 'code': 0, 'valid': True,
'version': 0}}
>>> Thread-1062385::DEBUG::2014-02-28
>>> 07:45:45,853::task::1168::TaskManager.Task::(prepare)
>>> Task=`2dc97e57-449e-4335-ba9b-c69d22e968d4`::finished:
>>> {u'1988ca23-e1ac-4831-bc57-768d01b0f1d1': {'delay':
'0.000139105',
>>> 'lastCheck': '6.2', 'code': 0, 'valid': True,
'version': 3},
>>> '5d2c10af-23bb-4112-9d05-d0c4e65f80ef': {'delay':
'0.000157599',
>>> 'lastCheck': '4.6', 'code': 0, 'valid': True,
'version': 3},
>>> u'983782c7-e157-43e4-a3a3-b84d64530b96': {'delay':
'0.000136455',
>>> 'lastCheck': '4.3', 'code': 0, 'valid': True,
'version': 3},
>>> '50cf24a4-d1ef-4105-a9a5-b81d91339175': {'delay':
'0.000406695',
>>> 'lastCheck': '5.3', 'code': 0, 'valid': True,
'version': 0}}
>>> Thread-1062385::DEBUG::2014-02-28
>>> 07:45:45,854::task::579::TaskManager.Task::(_updateState)
>>> Task=`2dc97e57-449e-4335-ba9b-c69d22e968d4`::moving from state preparing
->
>>> state finished
>>> Thread-1062385::DEBUG::2014-02-28
>>> 07:45:45,854::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-1062385::DEBUG::2014-02-28
>>> 07:45:45,855::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-1062385::DEBUG::2014-02-28
>>> 07:45:45,855::task::974::TaskManager.Task::(_decref)
>>> Task=`2dc97e57-449e-4335-ba9b-c69d22e968d4`::ref 0 aborting False
>>> Thread-914330::DEBUG::2014-02-28
>>> 07:45:45,984::task::579::TaskManager.Task::(_updateState)
>>> Task=`b67d671f-340a-4a53-9532-aed8e8b1456e`::moving from state init ->
>>> state preparing
>>> Thread-914330::INFO::2014-02-28
>>> 07:45:45,987::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='64df4085-2d8d-4c30-b983-a0049fa7db03',
>>> volUUID='64a8ee5d-b847-4e6d-97fc-9390b8da9ede', options=None)
>>> Thread-914330::INFO::2014-02-28
>>> 07:45:45,991::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '1073741824',
'apparentsize':
>>> '1073741824'}
>>> Thread-914330::DEBUG::2014-02-28
>>> 07:45:45,992::task::1168::TaskManager.Task::(prepare)
>>> Task=`b67d671f-340a-4a53-9532-aed8e8b1456e`::finished: {'truesize':
>>> '1073741824', 'apparentsize': '1073741824'}
>>> Thread-914330::DEBUG::2014-02-28
>>> 07:45:45,993::task::579::TaskManager.Task::(_updateState)
>>> Task=`b67d671f-340a-4a53-9532-aed8e8b1456e`::moving from state preparing
->
>>> state finished
>>> Thread-914330::DEBUG::2014-02-28
>>> 07:45:45,995::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-914330::DEBUG::2014-02-28
>>> 07:45:45,996::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-914330::DEBUG::2014-02-28
>>> 07:45:45,997::task::974::TaskManager.Task::(_decref)
>>> Task=`b67d671f-340a-4a53-9532-aed8e8b1456e`::ref 0 aborting False
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:46,749::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> 'dd
>>>
if=/rhev/data-center/cbbb821c-0523-4639-b453-9371ff5dc7b1/mastersd/dom_md/inbox
>>> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:46,905::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes
(1.0 MB)
>>> copied, 0.0441819 s, 23.2 MB/s\n'; <rc> = 0
>>> Thread-1062382::ERROR::2014-02-28
>>> 07:45:47,240::vm::188::vm.Vm::(_setupVdsConnection)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::Error initiating connection
>>> Traceback (most recent call last):
>>> File "/usr/share/vdsm/vm.py", line 183, in _setupVdsConnection
>>> status = self.destServer.getVmStats(self._vm.id)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1199, in __call__
>>> return self.__send(self.__name, args)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1489, in
__request
>>> verbose=self.__verbose
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1235, in request
>>> self.send_content(h, request_body)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1349, in
send_content
>>> connection.endheaders()
>>> File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
>>> self._send_output()
>>> File "/usr/lib64/python2.6/httplib.py", line 780, in
_send_output
>>> self.send(msg)
>>> File "/usr/lib64/python2.6/httplib.py", line 739, in send
>>> self.connect()
>>> File "/usr/share/vdsm/kaxmlrpclib.py", line 151, in connect
>>> SecureXMLRPCServer.VerifyingHTTPSConnection.connect(self)
>>> File
"/usr/lib64/python2.6/site-packages/vdsm/SecureXMLRPCServer.py",
>>> line 188, in connect
>>> sock = socket.create_connection((self.host, self.port),
>>> self.timeout)
>>> File "/usr/lib64/python2.6/socket.py", line 567, in
create_connection
>>> raise error, msg
>>> error: [Errno 113] No route to host
>>> Thread-1062382::DEBUG::2014-02-28
>>> 07:45:47,245::vm::232::vm.Vm::(_prepareGuest)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::Migration started
>>> Thread-1062382::DEBUG::2014-02-28 07:45:47,274::vm::314::vm.Vm::(run)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::migration semaphore acquired
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:48,928::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> 'dd
>>>
if=/rhev/data-center/cbbb821c-0523-4639-b453-9371ff5dc7b1/mastersd/dom_md/inbox
>>> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>>> Thread-5543::DEBUG::2014-02-28
>>> 07:45:49,662::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
>>> iflag=direct if=/dev/1988ca23-e1ac-4831-bc57-768d01b0f1d1/metadata bs=4096
>>> count=1' (cwd None)
>>> Thread-5543::DEBUG::2014-02-28
>>> 07:45:49,726::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
>>> <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB)
copied,
>>> 0.000179751 s, 22.8 MB/s\n'; <rc> = 0
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:49,779::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes
(1.0 MB)
>>> copied, 0.479458 s, 2.1 MB/s\n'; <rc> = 0
>>> Thread-1062382::ERROR::2014-02-28
>>> 07:45:50,240::vm::238::vm.Vm::(_recover)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::[Errno 113] No route to host
>>> Thread-623::DEBUG::2014-02-28
>>> 07:45:50,545::fileSD::239::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
>>> iflag=direct
if=/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/dom_md/metadata
>>> bs=4096 count=1' (cwd None)
>>> Thread-623::DEBUG::2014-02-28
>>> 07:45:50,573::fileSD::239::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
>>> <err> = '0+1 records in\n0+1 records out\n479 bytes (479 B)
copied,
>>> 0.000479018 s, 1000 kB/s\n'; <rc> = 0
>>> Thread-677219::DEBUG::2014-02-28
>>> 07:45:50,748::task::579::TaskManager.Task::(_updateState)
>>> Task=`2d1201c9-6c29-40ce-aaf6-5ec52be3f5dd`::moving from state init ->
>>> state preparing
>>> Thread-677219::INFO::2014-02-28
>>> 07:45:50,748::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='6e17acdd-4cc0-4903-86c3-e354a5020436',
>>> volUUID='4b6a6646-7fec-42bd-a6be-798f54f29e6f', options=None)
>>> Thread-677219::INFO::2014-02-28
>>> 07:45:50,749::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '5368709120',
'apparentsize':
>>> '5368709120'}
>>> Thread-677219::DEBUG::2014-02-28
>>> 07:45:50,750::task::1168::TaskManager.Task::(prepare)
>>> Task=`2d1201c9-6c29-40ce-aaf6-5ec52be3f5dd`::finished: {'truesize':
>>> '5368709120', 'apparentsize': '5368709120'}
>>> Thread-677219::DEBUG::2014-02-28
>>> 07:45:50,750::task::579::TaskManager.Task::(_updateState)
>>> Task=`2d1201c9-6c29-40ce-aaf6-5ec52be3f5dd`::moving from state preparing
->
>>> state finished
>>> Thread-677219::DEBUG::2014-02-28
>>> 07:45:50,750::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-677219::DEBUG::2014-02-28
>>> 07:45:50,751::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-677219::DEBUG::2014-02-28
>>> 07:45:50,751::task::974::TaskManager.Task::(_decref)
>>> Task=`2d1201c9-6c29-40ce-aaf6-5ec52be3f5dd`::ref 0 aborting False
>>> Thread-505346::DEBUG::2014-02-28
>>> 07:45:50,971::task::579::TaskManager.Task::(_updateState)
>>> Task=`a88bfc16-9821-442e-b563-21b7c60578a2`::moving from state init ->
>>> state preparing
>>> Thread-505346::INFO::2014-02-28
>>> 07:45:50,972::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='d06c7100-64b5-481e-a620-73a91c8f8972',
>>> volUUID='93fb3163-2098-47e0-9069-69c047a87ae8', options=None)
>>> Thread-505346::INFO::2014-02-28
>>> 07:45:50,972::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '5368709120',
'apparentsize':
>>> '5368709120'}
>>> Thread-505346::DEBUG::2014-02-28
>>> 07:45:50,973::task::1168::TaskManager.Task::(prepare)
>>> Task=`a88bfc16-9821-442e-b563-21b7c60578a2`::finished: {'truesize':
>>> '5368709120', 'apparentsize': '5368709120'}
>>> Thread-505346::DEBUG::2014-02-28
>>> 07:45:50,973::task::579::TaskManager.Task::(_updateState)
>>> Task=`a88bfc16-9821-442e-b563-21b7c60578a2`::moving from state preparing
->
>>> state finished
>>> Thread-505346::DEBUG::2014-02-28
>>> 07:45:50,973::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-505346::DEBUG::2014-02-28
>>> 07:45:50,974::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-505346::DEBUG::2014-02-28
>>> 07:45:50,974::task::974::TaskManager.Task::(_decref)
>>> Task=`a88bfc16-9821-442e-b563-21b7c60578a2`::ref 0 aborting False
>>> Thread-147::DEBUG::2014-02-28
>>> 07:45:51,236::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
>>> iflag=direct if=/dev/5d2c10af-23bb-4112-9d05-d0c4e65f80ef/metadata bs=4096
>>> count=1' (cwd None)
>>> Thread-147::DEBUG::2014-02-28
>>> 07:45:51,269::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
>>> <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB)
copied,
>>> 0.000178573 s, 22.9 MB/s\n'; <rc> = 0
>>> Thread-4123::DEBUG::2014-02-28
>>> 07:45:51,524::blockSD::595::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
>>> iflag=direct if=/dev/983782c7-e157-43e4-a3a3-b84d64530b96/metadata bs=4096
>>> count=1' (cwd None)
>>> Thread-4123::DEBUG::2014-02-28
>>> 07:45:51,556::blockSD::595::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
>>> <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB)
copied,
>>> 0.00017962 s, 22.8 MB/s\n'; <rc> = 0
>>> Thread-145024::DEBUG::2014-02-28
>>> 07:45:51,566::task::579::TaskManager.Task::(_updateState)
>>> Task=`952ea2ea-d189-4c2a-a56b-2c5339cff1e0`::moving from state init ->
>>> state preparing
>>> Thread-145024::INFO::2014-02-28
>>> 07:45:51,566::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='e7e25a1c-3d8b-4baf-8f14-5b76b8b4181d',
>>> volUUID='47eb08e4-747b-4ec2-a3fd-12bf91a1d3be', options=None)
>>> Thread-145024::INFO::2014-02-28
>>> 07:45:51,567::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '5368709120',
'apparentsize':
>>> '5368709120'}
>>> Thread-145024::DEBUG::2014-02-28
>>> 07:45:51,567::task::1168::TaskManager.Task::(prepare)
>>> Task=`952ea2ea-d189-4c2a-a56b-2c5339cff1e0`::finished: {'truesize':
>>> '5368709120', 'apparentsize': '5368709120'}
>>> Thread-145024::DEBUG::2014-02-28
>>> 07:45:51,567::task::579::TaskManager.Task::(_updateState)
>>> Task=`952ea2ea-d189-4c2a-a56b-2c5339cff1e0`::moving from state preparing
->
>>> state finished
>>> Thread-145024::DEBUG::2014-02-28
>>> 07:45:51,568::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-145024::DEBUG::2014-02-28
>>> 07:45:51,568::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-145024::DEBUG::2014-02-28
>>> 07:45:51,568::task::974::TaskManager.Task::(_decref)
>>> Task=`952ea2ea-d189-4c2a-a56b-2c5339cff1e0`::ref 0 aborting False
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:51,798::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> 'dd
>>>
if=/rhev/data-center/cbbb821c-0523-4639-b453-9371ff5dc7b1/mastersd/dom_md/inbox
>>> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>>> Thread-144577::DEBUG::2014-02-28
>>> 07:45:51,897::task::579::TaskManager.Task::(_updateState)
>>> Task=`0aefb5af-15b3-49c0-a9b1-88f78d4b916d`::moving from state init ->
>>> state preparing
>>> Thread-144577::INFO::2014-02-28
>>> 07:45:51,925::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='983782c7-e157-43e4-a3a3-b84d64530b96',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='915a06d6-ae09-4410-be2b-c9c4db4dda7c',
>>> volUUID='b199f071-8e45-4254-99e7-3b9212c293f2', options=None)
>>> Thread-144577::INFO::2014-02-28
>>> 07:45:51,933::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '21474836480',
'apparentsize':
>>> '21474836480'}
>>> Thread-144577::DEBUG::2014-02-28
>>> 07:45:51,937::task::1168::TaskManager.Task::(prepare)
>>> Task=`0aefb5af-15b3-49c0-a9b1-88f78d4b916d`::finished: {'truesize':
>>> '21474836480', 'apparentsize': '21474836480'}
>>> Thread-144577::DEBUG::2014-02-28
>>> 07:45:51,942::task::579::TaskManager.Task::(_updateState)
>>> Task=`0aefb5af-15b3-49c0-a9b1-88f78d4b916d`::moving from state preparing
->
>>> state finished
>>> Thread-144577::DEBUG::2014-02-28
>>> 07:45:51,943::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-144577::DEBUG::2014-02-28
>>> 07:45:51,945::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-144577::DEBUG::2014-02-28
>>> 07:45:51,946::task::974::TaskManager.Task::(_decref)
>>> Task=`0aefb5af-15b3-49c0-a9b1-88f78d4b916d`::ref 0 aborting False
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:52,005::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes
(1.0 MB)
>>> copied, 0.0611125 s, 16.8 MB/s\n'; <rc> = 0
>>> Thread-1062382::ERROR::2014-02-28
>>> 07:45:53,241::vm::243::vm.Vm::(_recover)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::Failed to destroy remote VM
>>> Traceback (most recent call last):
>>> File "/usr/share/vdsm/vm.py", line 241, in _recover
>>> self.destServer.destroy(self._vm.id)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1199, in __call__
>>> return self.__send(self.__name, args)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1489, in
__request
>>> verbose=self.__verbose
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1235, in request
>>> self.send_content(h, request_body)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1349, in
send_content
>>> connection.endheaders()
>>> File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
>>> self._send_output()
>>> File "/usr/lib64/python2.6/httplib.py", line 780, in
_send_output
>>> self.send(msg)
>>> File "/usr/lib64/python2.6/httplib.py", line 739, in send
>>> self.connect()
>>> File "/usr/share/vdsm/kaxmlrpclib.py", line 151, in connect
>>> SecureXMLRPCServer.VerifyingHTTPSConnection.connect(self)
>>> File
"/usr/lib64/python2.6/site-packages/vdsm/SecureXMLRPCServer.py",
>>> line 188, in connect
>>> sock = socket.create_connection((self.host, self.port),
>>> self.timeout)
>>> File "/usr/lib64/python2.6/socket.py", line 567, in
create_connection
>>> raise error, msg
>>> error: [Errno 113] No route to host
>>> Thread-1062382::ERROR::2014-02-28 07:45:53,272::vm::337::vm.Vm::(run)
>>> vmId=`a3f94aee-e224-4fd8-8448-fc48017088da`::Failed to migrate
>>> Traceback (most recent call last):
>>> File "/usr/share/vdsm/vm.py", line 323, in run
>>> self._startUnderlyingMigration()
>>> File "/usr/share/vdsm/vm.py", line 355, in
_startUnderlyingMigration
>>> response = self.destServer.migrationCreate(self._machineParams)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1199, in __call__
>>> return self.__send(self.__name, args)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1489, in
__request
>>> verbose=self.__verbose
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1235, in request
>>> self.send_content(h, request_body)
>>> File "/usr/lib64/python2.6/xmlrpclib.py", line 1349, in
send_content
>>> connection.endheaders()
>>> File "/usr/lib64/python2.6/httplib.py", line 908, in endheaders
>>> self._send_output()
>>> File "/usr/lib64/python2.6/httplib.py", line 780, in
_send_output
>>> self.send(msg)
>>> File "/usr/lib64/python2.6/httplib.py", line 739, in send
>>> self.connect()
>>> File "/usr/share/vdsm/kaxmlrpclib.py", line 151, in connect
>>> SecureXMLRPCServer.VerifyingHTTPSConnection.connect(self)
>>> File
"/usr/lib64/python2.6/site-packages/vdsm/SecureXMLRPCServer.py",
>>> line 188, in connect
>>> sock = socket.create_connection((self.host, self.port),
>>> self.timeout)
>>> File "/usr/lib64/python2.6/socket.py", line 567, in
create_connection
>>> raise error, msg
>>> error: [Errno 113] No route to host
>>> Thread-143613::DEBUG::2014-02-28
>>> 07:45:53,639::task::579::TaskManager.Task::(_updateState)
>>> Task=`9aff0027-f758-4474-930c-6459f5f14a4e`::moving from state init ->
>>> state preparing
>>> Thread-145283::DEBUG::2014-02-28
>>> 07:45:53,643::task::579::TaskManager.Task::(_updateState)
>>> Task=`470100ed-def6-4d7a-9f08-24862d534e0f`::moving from state init ->
>>> state preparing
>>> Thread-143613::INFO::2014-02-28
>>> 07:45:53,652::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='1988ca23-e1ac-4831-bc57-768d01b0f1d1',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='30a5b214-e7eb-4a98-8c4f-3f5c5f17ee90',
>>> volUUID='e1fb7e46-afb7-429a-9fac-7b4dcdc30151', options=None)
>>> Thread-145283::INFO::2014-02-28
>>> 07:45:53,654::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize(sdUUID='5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
>>> spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> imgUUID='abcec233-bfe5-48c9-876d-23725010b547',
>>> volUUID='44d0fb51-d5d5-4952-a55e-ae1ff5fdc4c4', options=None)
>>> Thread-143613::INFO::2014-02-28
>>> 07:45:53,663::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '21474836480',
'apparentsize':
>>> '21474836480'}
>>> Thread-145283::INFO::2014-02-28
>>> 07:45:53,664::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getVolumeSize, Return response: {'truesize': '10737418240',
'apparentsize':
>>> '10737418240'}
>>> Thread-143613::DEBUG::2014-02-28
>>> 07:45:53,669::task::1168::TaskManager.Task::(prepare)
>>> Task=`9aff0027-f758-4474-930c-6459f5f14a4e`::finished: {'truesize':
>>> '21474836480', 'apparentsize': '21474836480'}
>>> Thread-145283::DEBUG::2014-02-28
>>> 07:45:53,671::task::1168::TaskManager.Task::(prepare)
>>> Task=`470100ed-def6-4d7a-9f08-24862d534e0f`::finished: {'truesize':
>>> '10737418240', 'apparentsize': '10737418240'}
>>> Thread-143613::DEBUG::2014-02-28
>>> 07:45:53,674::task::579::TaskManager.Task::(_updateState)
>>> Task=`9aff0027-f758-4474-930c-6459f5f14a4e`::moving from state preparing
->
>>> state finished
>>> Thread-145283::DEBUG::2014-02-28
>>> 07:45:53,675::task::579::TaskManager.Task::(_updateState)
>>> Task=`470100ed-def6-4d7a-9f08-24862d534e0f`::moving from state preparing
->
>>> state finished
>>> Thread-143613::DEBUG::2014-02-28
>>> 07:45:53,677::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-145283::DEBUG::2014-02-28
>>> 07:45:53,678::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-143613::DEBUG::2014-02-28
>>> 07:45:53,679::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-145283::DEBUG::2014-02-28
>>> 07:45:53,680::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-143613::DEBUG::2014-02-28
>>> 07:45:53,682::task::974::TaskManager.Task::(_decref)
>>> Task=`9aff0027-f758-4474-930c-6459f5f14a4e`::ref 0 aborting False
>>> Thread-145283::DEBUG::2014-02-28
>>> 07:45:53,683::task::974::TaskManager.Task::(_decref)
>>> Task=`470100ed-def6-4d7a-9f08-24862d534e0f`::ref 0 aborting False
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:54,027::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> 'dd
>>>
if=/rhev/data-center/cbbb821c-0523-4639-b453-9371ff5dc7b1/mastersd/dom_md/inbox
>>> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
>>> Dummy-223::DEBUG::2014-02-28
>>> 07:45:54,162::storage_mailbox::733::Storage.Misc.excCmd::(_checkForMail)
>>> SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes
(1.0 MB)
>>> copied, 0.049987 s, 20.5 MB/s\n'; <rc> = 0
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,970::BindingXMLRPC::177::vds::(wrapper) client [10.110.57.30]
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,971::task::579::TaskManager.Task::(_updateState)
>>> Task=`21158aca-9ec0-433c-9cbe-3d06c0e9db3e`::moving from state init ->
>>> state preparing
>>> Thread-1062389::INFO::2014-02-28
>>> 07:45:54,972::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getSpmStatus(spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
options=None)
>>> Thread-1062389::INFO::2014-02-28
>>> 07:45:54,972::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getSpmStatus, Return response: {'spm_st': {'spmId': 2,
'spmStatus': 'SPM',
>>> 'spmLver': 1}}
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,973::task::1168::TaskManager.Task::(prepare)
>>> Task=`21158aca-9ec0-433c-9cbe-3d06c0e9db3e`::finished: {'spm_st':
{'spmId':
>>> 2, 'spmStatus': 'SPM', 'spmLver': 1}}
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,973::task::579::TaskManager.Task::(_updateState)
>>> Task=`21158aca-9ec0-433c-9cbe-3d06c0e9db3e`::moving from state preparing
->
>>> state finished
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,973::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources {}
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,974::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-1062389::DEBUG::2014-02-28
>>> 07:45:54,974::task::974::TaskManager.Task::(_decref)
>>> Task=`21158aca-9ec0-433c-9cbe-3d06c0e9db3e`::ref 0 aborting False
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,979::BindingXMLRPC::177::vds::(wrapper) client [10.110.57.30]
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,980::task::579::TaskManager.Task::(_updateState)
>>> Task=`7b2ebce0-748c-43d7-9b11-49e8edc744b3`::moving from state init ->
>>> state preparing
>>> Thread-1062390::INFO::2014-02-28
>>> 07:45:54,980::logUtils::44::dispatcher::(wrapper) Run and protect:
>>> getStoragePoolInfo(spUUID='cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> options=None)
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,981::resourceManager::197::ResourceManager.Request::(__init__)
>>>
ResName=`Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1`ReqID=`b0243651-7244-4799-bbd4-163874d4f8f9`::Request
>>> was made in '/usr/share/vdsm/storage/hsm.py' line '2552' at
>>> 'getStoragePoolInfo'
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,981::resourceManager::541::ResourceManager::(registerResource)
>>> Trying to register resource
'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1'
>>> for lock type 'shared'
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,982::resourceManager::600::ResourceManager::(registerResource)
>>> Resource 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1' is free. Now
>>> locking as 'shared' (1 active user)
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,982::resourceManager::237::ResourceManager.Request::(grant)
>>>
ResName=`Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1`ReqID=`b0243651-7244-4799-bbd4-163874d4f8f9`::Granted
>>> request
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,983::task::811::TaskManager.Task::(resourceAcquired)
>>> Task=`7b2ebce0-748c-43d7-9b11-49e8edc744b3`::_resourcesAcquired:
>>> Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1 (shared)
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,983::task::974::TaskManager.Task::(_decref)
>>> Task=`7b2ebce0-748c-43d7-9b11-49e8edc744b3`::ref 1 aborting False
>>> Thread-1062390::INFO::2014-02-28
>>> 07:45:54,985::logUtils::47::dispatcher::(wrapper) Run and protect:
>>> getStoragePoolInfo, Return response: {'info': {'spm_id': 2,
'master_uuid':
>>> '5d2c10af-23bb-4112-9d05-d0c4e65f80ef', 'name':
'TestDev', 'version': '3',
>>> 'domains':
>>>
u'1988ca23-e1ac-4831-bc57-768d01b0f1d1:Active,5d2c10af-23bb-4112-9d05-d0c4e65f80ef:Active,983782c7-e157-43e4-a3a3-b84d64530b96:Active,50cf24a4-d1ef-4105-a9a5-b81d91339175:Active',
>>> 'pool_status': 'connected', 'isoprefix':
>>>
'/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111',
>>> 'type': 'FCP', 'master_ver': 1, 'lver': 1},
'dominfo':
>>> {u'1988ca23-e1ac-4831-bc57-768d01b0f1d1': {'status':
u'Active', 'diskfree':
>>> '300379275264', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'5d2c10af-23bb-4112-9d05-d0c4e65f80ef': {'status':
u'Active', 'diskfree':
>>> '69524783104', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'983782c7-e157-43e4-a3a3-b84d64530b96': {'status':
u'Active', 'diskfree':
>>> '169114337280', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'status':
u'Active', 'diskfree':
>>> '7559184384', 'alerts': [], 'version': 0,
'disktotal': '21891121152'}}}
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,985::task::1168::TaskManager.Task::(prepare)
>>> Task=`7b2ebce0-748c-43d7-9b11-49e8edc744b3`::finished: {'info':
{'spm_id':
>>> 2, 'master_uuid': '5d2c10af-23bb-4112-9d05-d0c4e65f80ef',
'name':
>>> 'TestDev', 'version': '3', 'domains':
>>>
u'1988ca23-e1ac-4831-bc57-768d01b0f1d1:Active,5d2c10af-23bb-4112-9d05-d0c4e65f80ef:Active,983782c7-e157-43e4-a3a3-b84d64530b96:Active,50cf24a4-d1ef-4105-a9a5-b81d91339175:Active',
>>> 'pool_status': 'connected', 'isoprefix':
>>>
'/rhev/data-center/mnt/vega.brusselsairport.aero:_var_lib_exports_iso/50cf24a4-d1ef-4105-a9a5-b81d91339175/images/11111111-1111-1111-1111-111111111111',
>>> 'type': 'FCP', 'master_ver': 1, 'lver': 1},
'dominfo':
>>> {u'1988ca23-e1ac-4831-bc57-768d01b0f1d1': {'status':
u'Active', 'diskfree':
>>> '300379275264', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'5d2c10af-23bb-4112-9d05-d0c4e65f80ef': {'status':
u'Active', 'diskfree':
>>> '69524783104', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'983782c7-e157-43e4-a3a3-b84d64530b96': {'status':
u'Active', 'diskfree':
>>> '169114337280', 'alerts': [], 'version': 3,
'disktotal': '536468258816'},
>>> u'50cf24a4-d1ef-4105-a9a5-b81d91339175': {'status':
u'Active', 'diskfree':
>>> '7559184384', 'alerts': [], 'version': 0,
'disktotal': '21891121152'}}}
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,986::task::579::TaskManager.Task::(_updateState)
>>> Task=`7b2ebce0-748c-43d7-9b11-49e8edc744b3`::moving from state preparing
->
>>> state finished
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,986::resourceManager::939::ResourceManager.Owner::(releaseAll)
>>> Owner.releaseAll requests {} resources
>>> {'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1': < ResourceRef
>>> 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1', isValid:
'True' obj:
>>> 'None'>}
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,987::resourceManager::976::ResourceManager.Owner::(cancelAll)
>>> Owner.cancelAll requests {}
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,987::resourceManager::615::ResourceManager::(releaseResource)
>>> Trying to release resource
'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1'
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,987::resourceManager::634::ResourceManager::(releaseResource)
>>> Released resource 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1' (0
active
>>> users)
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,988::resourceManager::640::ResourceManager::(releaseResource)
>>> Resource 'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1' is free,
finding
>>> out if anyone is waiting for it.
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,988::resourceManager::648::ResourceManager::(releaseResource) No
>>> one is waiting for resource
'Storage.cbbb821c-0523-4639-b453-9371ff5dc7b1',
>>> Clearing records.
>>> Thread-1062390::DEBUG::2014-02-28
>>> 07:45:54,988::task::974::TaskManager.Task::(_decref)
>>> Task=`7b2ebce0-748c-43d7-9b11-49e8edc744b3`::ref 0 aborting False
>>> ^C
>>>
>>>
>>>
>>> 2014-02-27 15:38 GMT+01:00 Dan Kenigsberg <danken(a)redhat.com>:
>>>
>>> On Thu, Feb 27, 2014 at 10:42:54AM +0100, Koen Vanoppen wrote:
>>>> > Sorry...
>>>> > I added the correct one now
>>>>
>>>> Still, I fail to find the relevant ::ERROR:: line about migration.
>>>> But as Michal mentioned, "Could not connect to peer VDS" means
that
>>>> source vdsm failed to contact the destination one.
>>>>
>>>> This can stem from physical or logical network problem.
>>>> Can you ping from source to dest?
>>>> Can what happens when you log into source host and run
>>>>
>>>> vdsClient -s fqdn-of-destination-host list
>>>>
>>>> ? do you get any response? What happens if you disable your firewall?
>>>>
>>>> Regards,
>>>> Dan.
>>>>
>>>
>>>
>>
>
3948
days inactive
3948
days old
0 comments
1 participants
participants (1)
-
Koen Vanoppen