[Users] Fwd: Re: Migration Failed
Koen Vanoppen
vanoppen.koen at gmail.com
Sun Mar 2 19:17:26 UTC 2014
---------- Forwarded message ----------
From: "Koen Vanoppen" <vanoppen.koen at gmail.com>
Date: Feb 28, 2014 8:08 AM
Subject: Re: [Users] Migration Failed
To: "Dan Kenigsberg" <danken at 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 at 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 at 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 at 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 at 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 at 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.
>>>>>
>>>>
>>>>
>>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20140302/18cb2ed8/attachment-0001.html>
More information about the Users
mailing list