Re: [ovirt-users] Ovirt3.6

26 Oct 2015

      In the engine log this time I can see:

java.net.UnknownHostException: cstlb1: cstlb1: unknown error

which means that the name of the host is not known and this is the
issue why the engine is not able to connect.

On Mon, Oct 26, 2015 at 10:37 AM, Budur Nagaraju <nbudoor@gmail.com> wrote:
...
Attached is the log details.
On Mon, Oct 26, 2015 at 1:35 PM, Piotr Kliczewski
<piotr.kliczewski@gmail.com> wrote:
...
I can see that the dates do not match with engine log that you
provided earlier. Please provided vdsm log from the same time frame so
we could see
why the connection failed. I only found this issue in vdsm logs that
you provided:
Thread-493088::ERROR::2015-10-19
07:24:26,102::config::103::ovirt_hosted_engine_ha.env.config::(_load)
Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not
available [[Errno 2] No such file or directory:
'/etc/ovirt-hosted-engine/hosted-engine.conf']
Thread-493088::ERROR::2015-10-19
07:24:26,102::config::103::ovirt_hosted_engine_ha.env.config::(_load)
Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available
[[Errno 2] No such file or directory:
'/etc/ovirt-hosted-engine/vm.conf']
Thread-493088::ERROR::2015-10-19
07:24:26,103::API::1723::vds::(_getHaInfo) failed to retrieve Hosted
Engine HA info
Traceback (most recent call last):
  File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo
  File
"/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py",
line 100, in get_all_stats
  File
"/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py",
line 173, in _configure_broker_conn
  File
"/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py",
line 129, in get
Exception: Configuration value not found:
file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID
On Mon, Oct 26, 2015 at 9:00 AM, Budur Nagaraju <nbudoor@gmail.com> wrote:
...
Below are the logs,
BVEFbYm5nbGFiLnBzZWN1cmUubmV0XV0+PC9Pcmdhbml6YXRpb24+DQogICAgICAgICAgICA8L1VzZXJEYXRhPg0KICAgICAgICAgICAgPEltYWdlSW5zdGFsbD4NCiAgICAgICAgICAgICAgICA8T1NJbWFnZT4NCiAgICAgICAgICAgICAgICAgICAgPEluc3RhbGxUb0F2YWlsYWJsZVBhcnRpdGlvbj50cnVlPC9JbnN0YWxsVG9BdmFpbGFibGVQYXJ0aXRpb24+DQogICAgICAgICAgICAgICAgPC9PU0ltYWdlPg0KICAgICAgICAgICAgPC9JbWFnZUluc3RhbGw+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLUludGVybmF0aW9uYWwtQ29yZS1XaW5QRSIgcHJvY2Vzc29yQXJjaGl0ZWN0dXJlPSJ4ODYiIHB1YmxpY0tleVRva2VuPSIzMWJmMzg1NmFkMzY0ZTM1IiBsYW5ndWFnZT0ibmV1dHJhbCIgdmVyc2lvblNjb3BlPSJub25TeFMiIHhtbG5zOndjbT0iaHR0cDovL3NjaGVtYXMubWljcm9zb2Z0LmNvbS9XTUlDb25maWcvMjAwMi9TdGF0ZSIgeG1sbnM6eHNpPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxL1hNTFNjaGVtYS1pbnN0YW5jZSI+DQogICAgICAgICAgICA8U2V0dXBVSUxhbmd1YWdlPg0KICAgICAgICAgICAgICAgIDxVSUxhbmd1YWdlPjwhW0NEQVRBW2VuX1VTXV0+PC9VSUxhbmd1YWdlPg0KICAgICAgICAgICAgPC9TZXR1cFVJTGFuZ3VhZ2U+DQogICAgICAgICAgICA8SW5wdXRMb2NhbGU+PCFbQ0RBVEFbZW5fVVNdXT48L0lucHV0TG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgICAgICA8U3lzdGVtTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9TeXN0ZW1Mb2NhbGU+DQogICAgICAgICAgICA8VXNlckxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvVXNlckxvY2FsZT4NCiAgICAgICAgPC9jb21wb25lbnQ+DQogICAgPC9zZXR0aW5ncz4NCiAgICA8c2V0dGluZ3MgcGFzcz0ic3BlY2lhbGl6ZSI+DQogICAgICAgIDxjb21wb25lbnQgbmFtZT0iTWljcm9zb2Z0LVdpbmRvd3MtU2hlbGwtU2V0dXAiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPERpc3BsYXk+DQogICAgICAgICAgICAgICAgPENvbG9yRGVwdGg+MzI8L0NvbG9yRGVwdGg+DQogICAgICAgICAgICAgICAgPERQST45NjwvRFBJPg0KICAgICAgICAgICAgICAgIDxIb3Jpem9udGFsUmVzb2x1dGlvbj4xMDI0PC9Ib3Jpem9udGFsUmVzb2x1dGlvbj4NCiAgICAgICAgICAgICAgICA8UmVmcmVzaFJhdGU+NzU8L1JlZnJlc2hSYXRlPg0KICAgICAgICAgICAgICAgIDxWZXJ0aWNhbFJlc29sdXRpb24+NzY4PC9WZXJ0aWNhbFJlc29sdXRpb24+DQogICAgICAgICAgICA8L0Rpc3BsYXk+DQogICAgICAgICAgICA8Q29tcHV0ZXJOYW1lPjwhW0NEQVRBW1Rlc3Qtd2luOC0xXV0+PC9Db21wdXRlck5hbWU+DQogICAgICAgICAgICA8VGltZVpvbmU+PCFbQ0RBVEFbR01UIFN0YW5kYXJkIFRpbWVdXT48L1RpbWVab25lPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICAgICAgPGNvbXBvbmVudCBuYW1lPSJNaWNyb3NvZnQtV2luZG93cy1JbnRlcm5hdGlvbmFsLUNvcmUiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElucHV0TG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9JbnB1dExvY2FsZT4NCiAgICAgICAgICAgIDxVc2VyTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9Vc2VyTG9jYWxlPg0KICAgICAgICAgICAgPFN5c3RlbUxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvU3lzdGVtTG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLVVuYXR0ZW5kZWRKb2luIiBwcm9jZXNzb3JBcmNoaXRlY3R1cmU9ImFtZDY0IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElkZW50aWZpY2F0aW9uPg0KICAgICAgICAgICAgICAgIDxDcmVkZW50aWFscz4NCiAgICAgICAgICAgICAgICAgICAgPERvbWFpbj48IVtDREFUQVtdXT48L0RvbWFpbj4NCiAgICAgICAgICAgICAgICAgICAgPFBhc3N3b3JkPjwhW0NEQVRBW11dPjwvUGFzc3dvcmQ+DQogICAgICAgICAgICAgICAgICAgIDxVc2VybmFtZT48IVtDREFUQVtdXT48L1VzZXJuYW1lPg0KICAgICAgICAgICAgICAgIDwvQ3JlZGVudGlhbHM+DQogICAgICAgICAgICAgICAgPEpvaW5Eb21haW4+PCFbQ0RBVEFbXV0+PC9Kb2luRG9tYWluPg0KICAgICAgICAgICAgICAgIDxNYWNoaW5lT2JqZWN0T1U+PCFbQ0RBVEFbXV0+PC9NYWNoaW5lT2JqZWN0T1U+DQogICAgICAgICAgICA8L0lkZW50aWZpY2F0aW9uPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICA8L3NldHRpbmdzPg0KICAgIDxzZXR0aW5ncyBwYXNzPSJvb2JlU3lzdGVtIj4NCiAgICAgICAgPGNvbXBvbmVudCBuYW1lPSJNaWNyb3NvZnQtV2luZG93cy1JbnRlcm5hdGlvbmFsLUNvcmUiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElucHV0TG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9JbnB1dExvY2FsZT4NCiAgICAgICAgICAgIDxVc2VyTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9Vc2VyTG9jYWxlPg0KICAgICAgICAgICAgPFN5c3RlbUxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvU3lzdGVtTG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLVNoZWxsLVNldHVwIiBwcm9jZXNzb3JBcmNoaXRlY3R1cmU9ImFtZDY0IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPE9PQkU+DQogICAgICAgICAgICAgICAgPFByb3RlY3RZb3VyUEM+MjwvUHJvdGVjdFlvdXJQQz4NCiAgICAgICAgICAgICAgICA8TmV0d29ya0xvY2F0aW9uPldvcms8L05ldHdvcmtMb2NhdGlvbj4NCiAgICAgICAgICAgICAgICA8SGlkZUVVTEFQYWdlPnRydWU8L0hpZGVFVUxBUGFnZT4NCiAgICAgICAgICAgIDwvT09CRT4NCiAgICAgICAgICAgIDxVc2VyQWNjb3VudHM+DQogICAgICAgICAgICAgICAgPEFkbWluaXN0cmF0b3JQYXNzd29yZD4NCiAgICAgICAgICAgICAgICAgICAgPFZhbHVlPjwhW0NEQVRBW0VtYmUxbXBsc11dPjwvVmFsdWU+DQogICAgICAgICAgICAgICAgICAgIDxQbGFpblRleHQ+dHJ1ZTwvUGxhaW5UZXh0Pg0KICAgICAgICAgICAgICAgIDwvQWRtaW5pc3RyYXRvclBhc3N3b3JkPg0KICAgICAgICAgICAgICAgIDxMb2NhbEFjY291bnRzPg0KICAgICAgICAgICAgICAgICAgICA8TG9jYWxBY2NvdW50IHdjbTphY3Rpb249ImFkZCI+DQogICAgICAgICAgICAgICAgICAgICAgICA8UGFzc3dvcmQ+DQogICAgICAgICAgICAgICAgICAgICAgICAgICAgPFZhbHVlPjwhW0NEQVRBW0VtYmUxbXBsc11dPjwvVmFsdWU+DQogICAgICAgICAgICAgICAgICAgICAgICAgICAgPFBsYWluVGV4dD50cnVlPC9QbGFpblRleHQ+DQogICAgICAgICAgICAgICAgICAgICAgICA8L1Bhc3N3b3JkPg0KICAgICAgICAgICAgICAgICAgICAgICAgPEdyb3VwPmFkbWluaXN0cmF0b3JzPC9Hcm91cD4NCiAgICAgICAgICAgICAgICAgICAgICAgIDxOYW1lPnVzZXI8L05hbWU+DQogICAgICAgICAgICAgICAgICAgICAgICA8RGlzcGxheU5hbWU+dXNlcjwvRGlzcGxheU5hbWU+DQogICAgICAgICAgICAgICAgICAgIDwvTG9jYWxBY2NvdW50Pg0KICAgICAgICAgICAgICAgIDwvTG9jYWxBY2NvdW50cz4NCiAgICAgICAgICAgIDwvVXNlckFjY291bnRzPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICA8L3NldHRpbmdzPg0KICAgIDxjcGk6b2ZmbGluZUltYWdlIGNwaTpzb3VyY2U9IndpbTpkOi9zb3VyY2VzL2luc3RhbGwud2ltI1dpbmRvd3MgOCBFTlRFUlBSSVNFIiB4bWxuczpjcGk9InVybjpzY2hlbWFzLW1pY3Jvc29mdC1jb206Y3BpIi8+DQo8L3VuYXR0ZW5kPg0K'}}},
u'readonly': u'true', 'deviceType': u'disk', u'deviceId':
u'c86868ec-4eae-4fb4-b395-165fd3d31ac2', u'shared': u'false', u'device':
u'floppy', u'path': u'', u'type': u'disk'}, {u'device': u'qxl',
u'specParams': {u'vram': u'32768', u'heads': u'1'}, 'deviceType':
u'video',
u'type': u'video', u'deviceId':
u'a62472d7-007a-403a-9880-d7e62d9e9a02'},
{u'index': u'2', u'iface': u'ide', u'specParams': {u'path': u''},
u'readonly': u'true', 'deviceType': u'disk', u'deviceId':
u'fc33f0e3-3a7c-4dc2-a4c5-0d8134766c4d', u'shared': u'false', u'device':
u'cdrom', u'path':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso',
u'type': u'disk'}, {u'index': 0, u'iface': u'ide', u'type': u'disk',
u'format': u'cow', u'bootOrder': u'1', u'address': {u'bus': u'0',
u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'},
u'volumeID': u'27589b5c-0c6f-4551-8199-e80c870c9d2a', u'imageID':
u'91dce925-129e-4de5-a5af-bbdbe9d80224', u'specParams': {}, u'readonly':
u'false', u'domainID': u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
'deviceType': u'disk', u'deviceId':
u'91dce925-129e-4de5-a5af-bbdbe9d80224',
u'poolID': u'a24369bc-3e57-451b-a21c-422c5aa7b1e5', u'device': u'disk',
u'shared': u'false', u'propagateErrors': u'off', u'optional': u'false'},
{u'nicModel': u'pv', u'macAddr': u'00:1a:4a:79:9e:06', u'linkActive':
u'true', u'network': u'ovirtmgmt', u'filter': u'vdsm-no-mac-spoofing',
u'specParams': {u'inbound': {}, u'outbound': {}}, 'deviceType':
u'interface', u'deviceId': u'4c57d9ac-b4cf-4602-9c0f-fd034cb91aba',
u'address': {u'slot': u'0x03', u'bus': u'0x00', u'domain': u'0x0000',
u'type': u'pci', u'function': u'0x0'}, u'device': u'bridge', u'type':
u'interface'}, {u'specParams': {}, 'deviceType': u'sound', u'deviceId':
u'14cc528b-dd7c-4047-8f7c-224c67100163', u'address': {u'slot': u'0x04',
u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function':
u'0x0'}, u'device': u'ich6', u'type': u'sound'}, {u'index': u'0',
u'specParams': {}, 'deviceType': u'controller', u'deviceId':
u'5151af56-76f6-43c9-9ac5-7df7525ea04b', u'address': {u'slot': u'0x05',
u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function':
u'0x0'}, u'device': u'scsi', u'model': u'virtio-scsi', u'type':
u'controller'}, {u'specParams': {}, 'deviceType': u'controller',
u'deviceId': u'0b738f8b-7f8d-4740-ad24-2458387e330b', u'address':
{u'slot':
u'0x06', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci',
u'function': u'0x0'}, u'device': u'virtio-serial', u'type':
u'controller'}],
u'timeOffset': u'19800', u'maxVCpus': u'16', u'spiceSecureChannels':
u'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard',
u'display': u'qxl'}
Thread-493084::DEBUG::2015-10-19
07:24:22,481::task::595::Storage.TaskManager.Task::(_updateState)
Task=`8b23488e-3ef1-45b0-b86b-819ef8bed42c`::moving from state init ->
state
preparing
Thread-493083::DEBUG::2015-10-19
07:24:22,481::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
Thread-493084::INFO::2015-10-19
07:24:22,483::logUtils::44::dispatcher::(wrapper) Run and protect:
getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5',
imgUUID=u'91dce925-129e-4de5-a5af-bbdbe9d80224',
volUUID=u'27589b5c-0c6f-4551-8199-e80c870c9d2a', options=None)
Thread-493084::INFO::2015-10-19
07:24:22,487::logUtils::47::dispatcher::(wrapper) Run and protect:
getVolumeSize, Return response: {'truesize': '200704', 'apparentsize':
'197120'}
Thread-493084::DEBUG::2015-10-19
07:24:22,487::task::1191::Storage.TaskManager.Task::(prepare)
Task=`8b23488e-3ef1-45b0-b86b-819ef8bed42c`::finished: {'truesize':
'200704', 'apparentsize': '197120'}
Thread-493084::DEBUG::2015-10-19
07:24:22,487::task::595::Storage.TaskManager.Task::(_updateState)
Task=`8b23488e-3ef1-45b0-b86b-819ef8bed42c`::moving from state preparing
->
state finished
Thread-493084::DEBUG::2015-10-19
07:24:22,487::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-493084::DEBUG::2015-10-19
07:24:22,487::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-493084::DEBUG::2015-10-19
07:24:22,488::task::993::Storage.TaskManager.Task::(_decref)
Task=`8b23488e-3ef1-45b0-b86b-819ef8bed42c`::ref 0 aborting False
Thread-493084::INFO::2015-10-19
07:24:22,522::clientIF::337::vds::(prepareVolumePath) prepared volume
path:
/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img
Thread-493084::INFO::2015-10-19
07:24:22,522::clientIF::337::vds::(prepareVolumePath) prepared volume
path:
/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso
Thread-493084::DEBUG::2015-10-19
07:24:22,523::task::595::Storage.TaskManager.Task::(_updateState)
Task=`202bd711-ec83-485f-82fb-ddcbef85d00c`::moving from state init ->
state
preparing
Thread-493084::INFO::2015-10-19
07:24:22,523::logUtils::44::dispatcher::(wrapper) Run and protect:
prepareImage(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5',
imgUUID=u'91dce925-129e-4de5-a5af-bbdbe9d80224',
leafUUID=u'27589b5c-0c6f-4551-8199-e80c870c9d2a')
Thread-493084::DEBUG::2015-10-19
07:24:22,524::resourceManager::198::Storage.ResourceManager.Request::(__init__)
ResName=`Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302`ReqID=`c7667eb5-ac03-4f00-bfe2-65ea9d34faca`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '3226' at
'prepareImage'
Thread-493084::DEBUG::2015-10-19
07:24:22,524::resourceManager::542::Storage.ResourceManager::(registerResource)
Trying to register resource
'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302'
for lock type 'shared'
Thread-493084::DEBUG::2015-10-19
07:24:22,525::resourceManager::601::Storage.ResourceManager::(registerResource)
Resource 'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302' is free. Now
locking
as 'shared' (1 active user)
Thread-493084::DEBUG::2015-10-19
07:24:22,525::resourceManager::238::Storage.ResourceManager.Request::(grant)
ResName=`Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302`ReqID=`c7667eb5-ac03-4f00-bfe2-65ea9d34faca`::Granted
request
Thread-493084::DEBUG::2015-10-19
07:24:22,526::task::827::Storage.TaskManager.Task::(resourceAcquired)
Task=`202bd711-ec83-485f-82fb-ddcbef85d00c`::_resourcesAcquired:
Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302 (shared)
Thread-493084::DEBUG::2015-10-19
07:24:22,527::task::993::Storage.TaskManager.Task::(_decref)
Task=`202bd711-ec83-485f-82fb-ddcbef85d00c`::ref 1 aborting False
Thread-493084::DEBUG::2015-10-19
07:24:22,545::fileSD::521::Storage.StorageDomain::(activateVolumes)
Fixing
permissions on
/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a
Thread-493084::DEBUG::2015-10-19
07:24:22,546::fileSD::521::Storage.StorageDomain::(activateVolumes)
Fixing
permissions on
/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403
Thread-493084::DEBUG::2015-10-19
07:24:22,547::fileUtils::142::Storage.fileUtils::(createdir) Creating
directory: /var/run/vdsm/storage/49d4a9cd-946d-41e0-a7ae-f2620f010302
Thread-493084::WARNING::2015-10-19
07:24:22,547::fileUtils::149::Storage.fileUtils::(createdir) Dir
/var/run/vdsm/storage/49d4a9cd-946d-41e0-a7ae-f2620f010302 already
exists
Thread-493084::DEBUG::2015-10-19
07:24:22,547::fileSD::496::Storage.StorageDomain::(createImageLinks)
Creating symlink from
/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224
to
/var/run/vdsm/storage/49d4a9cd-946d-41e0-a7ae-f2620f010302/91dce925-129e-4de5-a5af-bbdbe9d80224
Thread-493084::DEBUG::2015-10-19
07:24:22,550::fileVolume::529::Storage.Volume::(validateVolumePath)
validate
path for 27589b5c-0c6f-4551-8199-e80c870c9d2a
Thread-493084::DEBUG::2015-10-19
07:24:22,553::fileVolume::529::Storage.Volume::(validateVolumePath)
validate
path for 60d7aa2a-9850-43f2-a523-64c9dda8e403
Thread-493084::INFO::2015-10-19
07:24:22,555::logUtils::47::dispatcher::(wrapper) Run and protect:
prepareImage, Return response: {'info': {'domainID':
u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'volType': 'path',
'leaseOffset':
0, 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'volumeID': u'27589b5c-0c6f-4551-8199-e80c870c9d2a', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224'}, 'path':
u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'imgVolumesInfo': [{'domainID': u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
'volType': 'path', 'leaseOffset': 0, 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'volumeID': u'27589b5c-0c6f-4551-8199-e80c870c9d2a', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224'}, {'domainID':
u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'volType': 'path',
'leaseOffset':
0, 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403',
'volumeID': u'60d7aa2a-9850-43f2-a523-64c9dda8e403', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224'}]}
Thread-493084::DEBUG::2015-10-19
07:24:22,555::task::1191::Storage.TaskManager.Task::(prepare)
Task=`202bd711-ec83-485f-82fb-ddcbef85d00c`::finished: {'info':
{'domainID':
u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'volType': 'path',
'leaseOffset':
0, 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'volumeID': u'27589b5c-0c6f-4551-8199-e80c870c9d2a', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224'}, 'path':
u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'imgVolumesInfo': [{'domainID': u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
'volType': 'path', 'leaseOffset': 0, 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'volumeID': u'27589b5c-0c6f-4551-8199-e80c870c9d2a', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224'}, {'domainID':
u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'volType': 'path',
'leaseOffset':
0, 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403',
'volumeID': u'60d7aa2a-9850-43f2-a523-64c9dda8e403', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224'}]}
Thread-493084::DEBUG::2015-10-19
07:24:22,556::task::595::Storage.TaskManager.Task::(_updateState)
Task=`202bd711-ec83-485f-82fb-ddcbef85d00c`::moving from state preparing
->
state finished
Thread-493084::DEBUG::2015-10-19
07:24:22,556::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources
{u'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302': < ResourceRef
'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302', isValid: 'True' obj:
'None'>}
Thread-493084::DEBUG::2015-10-19
07:24:22,556::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-493084::DEBUG::2015-10-19
07:24:22,556::resourceManager::616::Storage.ResourceManager::(releaseResource)
Trying to release resource
'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302'
Thread-493084::DEBUG::2015-10-19
07:24:22,556::resourceManager::635::Storage.ResourceManager::(releaseResource)
Released resource 'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302' (0
active
users)
Thread-493084::DEBUG::2015-10-19
07:24:22,556::resourceManager::641::Storage.ResourceManager::(releaseResource)
Resource 'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302' is free, finding
out
if anyone is waiting for it.
Thread-493084::DEBUG::2015-10-19
07:24:22,557::resourceManager::649::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.49d4a9cd-946d-41e0-a7ae-f2620f010302', Clearing records.
Thread-493084::DEBUG::2015-10-19
07:24:22,557::task::993::Storage.TaskManager.Task::(_decref)
Task=`202bd711-ec83-485f-82fb-ddcbef85d00c`::ref 0 aborting False
Thread-493084::INFO::2015-10-19
07:24:22,557::clientIF::337::vds::(prepareVolumePath) prepared volume
path:
/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a
Thread-493084::DEBUG::2015-10-19
07:24:22,581::utils::739::root::(execCmd)
/usr/libexec/vdsm/hooks/before_vm_start/50_hostedengine (cwd None)
Thread-493084::DEBUG::2015-10-19
07:24:22,747::utils::759::root::(execCmd)
SUCCESS: <err> = ''; <rc> = 0
Thread-493084::INFO::2015-10-19
07:24:22,748::hooks::100::root::(_runHooksDir)
Thread-493084::DEBUG::2015-10-19 07:24:22,748::vm::3313::vm.Vm::(_run)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::<?xml version="1.0"
encoding="utf-8"?>
<domain type="kvm">
        <name>Test-win8-1</name>
        <uuid>523a9aa2-f60c-4cd7-963a-da678e692218</uuid>
        <memory>2097152</memory>
        <currentMemory>2097152</currentMemory>
        <vcpu current="1">16</vcpu>
        <devices>
                <channel type="unix">
                        <target name="com.redhat.rhevm.vdsm"
type="virtio"/>
                        <source mode="bind"
path="/var/lib/libvirt/qemu/channels/523a9aa2-f60c-4cd7-963a-da678e692218.com.redhat.rhevm.vdsm"/>
                </channel>
                <channel type="unix">
                        <target name="org.qemu.guest_agent.0"
type="virtio"/>
                        <source mode="bind"
path="/var/lib/libvirt/qemu/channels/523a9aa2-f60c-4cd7-963a-da678e692218.org.qemu.guest_agent.0"/>
                </channel>
                <input bus="ps2" type="mouse"/>
                <sound model="ich6">
                        <address bus="0x00" domain="0x0000"
function="0x0"
slot="0x04" type="pci"/>
                </sound>
                <memballoon model="none"/>
                <controller index="0" model="virtio-scsi" type="scsi">
                        <address bus="0x00" domain="0x0000"
function="0x0"
slot="0x05" type="pci"/>
                </controller>
                <controller index="0" ports="16" type="virtio-serial">
                        <address bus="0x00" domain="0x0000"
function="0x0"
slot="0x06" type="pci"/>
                </controller>
                <video>
                        <model heads="1" type="qxl" vram="32768"/>
                </video>
                <graphics autoport="yes" keymap="en-us" passwd="*****"
passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1" type="spice">
                        <channel mode="secure" name="main"/>
                        <channel mode="secure" name="inputs"/>
                        <channel mode="secure" name="cursor"/>
                        <channel mode="secure" name="playback"/>
                        <channel mode="secure" name="record"/>
                        <channel mode="secure" name="display"/>
                        <channel mode="secure" name="usbredir"/>
                        <channel mode="secure" name="smartcard"/>
                        <listen network="vdsm-ovirtmgmt"
type="network"/>
                </graphics>
                <interface type="bridge">
                        <address bus="0x00" domain="0x0000"
function="0x0"
slot="0x03" type="pci"/>
                        <mac address="00:1a:4a:79:9e:06"/>
                        <model type="virtio"/>
                        <source bridge="ovirtmgmt"/>
                        <filterref filter="vdsm-no-mac-spoofing"/>
                        <link state="up"/>
                        <bandwidth/>
                </interface>
                <disk device="floppy" snapshot="no" type="file">
                        <source
file="/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img"
startupPolicy="optional"/>
                        <target bus="fdc" dev="fda"/>
                        <readonly/>
                        <serial/>
                </disk>
                <disk device="cdrom" snapshot="no" type="file">
                        <source
file="/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso"
startupPolicy="optional"/>
                        <target bus="ide" dev="hdc"/>
                        <readonly/>
                        <serial/>
                </disk>
                <disk device="disk" snapshot="no" type="file">
                        <address bus="0" controller="0" target="0"
type="drive" unit="0"/>
                        <source
file="/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a"/>
                        <target bus="ide" dev="hda"/>
<serial>91dce925-129e-4de5-a5af-bbdbe9d80224</serial>
                        <boot order="1"/>
                        <driver cache="none" error_policy="stop"
io="threads" name="qemu" type="qcow2"/>
                </disk>
                <channel type="spicevmc">
                        <target name="com.redhat.spice.0"
type="virtio"/>
                </channel>
        </devices>
        <os>
                <type arch="x86_64" machine="rhel6.5.0">hvm</type>
                <smbios mode="sysinfo"/>
        </os>
        <sysinfo type="smbios">
                <system>
                        <entry name="manufacturer">oVirt</entry>
                        <entry name="product">oVirt Node</entry>
                        <entry
name="version">3.5-0.999.201509102313.el7.centos</entry>
                        <entry
name="serial">39333835-3431-4753-4832-323136465732</entry>
                        <entry
name="uuid">523a9aa2-f60c-4cd7-963a-da678e692218</entry>
                </system>
        </sysinfo>
        <clock adjustment="19800" offset="variable">
                <timer name="rtc" tickpolicy="catchup"/>
                <timer name="pit" tickpolicy="delay"/>
                <timer name="hpet" present="no"/>
        </clock>
        <features>
                <acpi/>
        </features>
        <cpu match="exact">
                <model>Penryn</model>
                <topology cores="1" sockets="16" threads="1"/>
        </cpu>
</domain>
Thread-493086::DEBUG::2015-10-19
07:24:23,091::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
libvirtEventLoop::DEBUG::2015-10-19
07:24:23,400::vm::5590::vm.Vm::(_onLibvirtLifecycleEvent)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::event Started detail 0
opaque
None
Thread-493084::DEBUG::2015-10-19
07:24:23,430::vm::5430::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Looking for drive with
attributes {'name': u'fda', 'bootOrder': '', 'boot': [], 'readonly':
True,
'address': {u'bus': u'0', u'controller': u'0', u'type': u'drive',
u'target':
u'0', u'unit': u'0'}, 'path':
u'/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img',
'type': u'floppy'}
Thread-493084::DEBUG::2015-10-19
07:24:23,430::vm::5451::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Matched {'name': (u'fda',
u'fda'), 'bootOrder': ('', None), 'boot': ([], None), 'readonly': (True,
True), 'address': ({u'bus': u'0', u'controller': u'0', u'type':
u'drive',
u'target': u'0', u'unit': u'0'}, {u'bus': u'0', u'controller': u'0',
u'type': u'drive', u'target': u'0', u'unit': u'0'}), 'path':
(u'/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img',
u'/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img'),
'type': (u'floppy', u'floppy')}
Thread-493084::DEBUG::2015-10-19
07:24:23,430::vm::5470::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Matched {'name': (u'fda',
None), 'bootOrder': ('', None), 'boot': ([], None), 'readonly': (True,
None), 'address': ({u'bus': u'0', u'controller': u'0', u'type':
u'drive',
u'target': u'0', u'unit': u'0'}, None), 'path':
(u'/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img',
None), 'type': (u'floppy', None)}
Thread-493084::DEBUG::2015-10-19
07:24:23,431::vm::5430::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Looking for drive with
attributes {'name': u'hda', 'bootOrder': u'1', 'boot': [<DOM Element:
boot
at 0x7fd4281ec200>], 'readonly': False, 'address': {u'bus': u'0',
u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'},
'path':
u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
'type': u'disk'}
Thread-493084::DEBUG::2015-10-19
07:24:23,431::vm::5451::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Matched {'name': (u'hda',
u'hda'), 'bootOrder': (u'1', u'1'), 'boot': ([<DOM Element: boot at
0x7fd4281ec200>], None), 'readonly': (False, False), 'address':
({u'bus':
u'0', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit':
u'0'}, {u'bus': u'0', u'controller': u'0', u'type': u'drive', u'target':
u'0', u'unit': u'0'}), 'path':
(u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a'),
'type': (u'disk', u'disk')}
Thread-493084::DEBUG::2015-10-19
07:24:23,432::vm::5470::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Matched {'name': (u'hda',
None), 'bootOrder': (u'1', None), 'boot': ([<DOM Element: boot at
0x7fd4281ec200>], None), 'readonly': (False, None), 'address': ({u'bus':
u'0', u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit':
u'0'}, None), 'path':
(u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
None), 'type': (u'disk', None)}
Thread-493084::DEBUG::2015-10-19
07:24:23,432::vm::5430::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Looking for drive with
attributes {'name': u'hdc', 'bootOrder': '', 'boot': [], 'readonly':
True,
'address': {u'bus': u'1', u'controller': u'0', u'type': u'drive',
u'target':
u'0', u'unit': u'0'}, 'path':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso',
'type': u'cdrom'}
Thread-493084::DEBUG::2015-10-19
07:24:23,433::vm::5451::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Matched {'name': (u'hdc',
u'hdc'), 'bootOrder': ('', None), 'boot': ([], None), 'readonly': (True,
True), 'address': ({u'bus': u'1', u'controller': u'0', u'type':
u'drive',
u'target': u'0', u'unit': u'0'}, {u'bus': u'1', u'controller': u'0',
u'type': u'drive', u'target': u'0', u'unit': u'0'}), 'path':
(u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso',
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso'),
'type': (u'cdrom', u'cdrom')}
Thread-493084::DEBUG::2015-10-19
07:24:23,433::vm::5470::vm.Vm::(_getUnderlyingDriveInfo)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Matched {'name': (u'hdc',
None), 'bootOrder': ('', None), 'boot': ([], None), 'readonly': (True,
None), 'address': ({u'bus': u'1', u'controller': u'0', u'type':
u'drive',
u'target': u'0', u'unit': u'0'}, None), 'path':
(u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso',
None), 'type': (u'cdrom', None)}
Thread-493084::DEBUG::2015-10-19
07:24:23,507::sampling::418::vm.Vm::(start)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Start statistics collection
Thread-493087::DEBUG::2015-10-19
07:24:23,507::sampling::447::vm.Vm::(run)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Stats thread started
Thread-493084::DEBUG::2015-10-19
07:24:23,509::vmchannels::199::vds::(register) Add fileno 46 to
listener's
channels.
Thread-493087::DEBUG::2015-10-19
07:24:23,509::task::595::Storage.TaskManager.Task::(_updateState)
Task=`ba7564fc-f062-42fd-86b4-341f821c55f0`::moving from state init ->
state
preparing
Thread-493087::INFO::2015-10-19
07:24:23,510::logUtils::44::dispatcher::(wrapper) Run and protect:
getVolumeSize(sdUUID=u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5',
imgUUID=u'91dce925-129e-4de5-a5af-bbdbe9d80224',
volUUID=u'27589b5c-0c6f-4551-8199-e80c870c9d2a', options=None)
Thread-493084::WARNING::2015-10-19
07:24:23,511::vm::4091::vm.Vm::(_readPauseCode)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::_readPauseCode unsupported
by
libvirt vm
Thread-493087::INFO::2015-10-19
07:24:23,514::logUtils::47::dispatcher::(wrapper) Run and protect:
getVolumeSize, Return response: {'truesize': '200704', 'apparentsize':
'197120'}
Thread-493087::DEBUG::2015-10-19
07:24:23,514::task::1191::Storage.TaskManager.Task::(prepare)
Task=`ba7564fc-f062-42fd-86b4-341f821c55f0`::finished: {'truesize':
'200704', 'apparentsize': '197120'}
Thread-493087::DEBUG::2015-10-19
07:24:23,515::task::595::Storage.TaskManager.Task::(_updateState)
Task=`ba7564fc-f062-42fd-86b4-341f821c55f0`::moving from state preparing
->
state finished
Thread-493087::DEBUG::2015-10-19
07:24:23,515::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-493087::DEBUG::2015-10-19
07:24:23,515::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-493084::DEBUG::2015-10-19
07:24:23,515::vm::2307::vm.Vm::(_startUnderlyingVm)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::_ongoingCreations released
Thread-493087::DEBUG::2015-10-19
07:24:23,517::task::993::Storage.TaskManager.Task::(_decref)
Task=`ba7564fc-f062-42fd-86b4-341f821c55f0`::ref 0 aborting False
Thread-493087::DEBUG::2015-10-19
07:24:23,540::libvirtconnection::143::root::(wrapper) Unknown
libvirterror:
ecode: 80 edom: 20 level: 2 message: metadata not found: Requested
metadata
element is not present
VM Channels Listener::DEBUG::2015-10-19
07:24:23,547::vmchannels::107::vds::(_do_add_channels) fileno 46 was
added
to unconnected channels.
VM Channels Listener::DEBUG::2015-10-19
07:24:23,548::vmchannels::133::vds::(_handle_unconnected) Trying to
connect
fileno 46.
VM Channels Listener::DEBUG::2015-10-19
07:24:23,549::guestagent::201::vm.Vm::(_connect)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Attempting connection to
/var/lib/libvirt/qemu/channels/523a9aa2-f60c-4cd7-963a-da678e692218.com.redhat.rhevm.vdsm
VM Channels Listener::DEBUG::2015-10-19
07:24:23,550::guestagent::204::vm.Vm::(_connect)
vmId=`523a9aa2-f60c-4cd7-963a-da678e692218`::Connected to
/var/lib/libvirt/qemu/channels/523a9aa2-f60c-4cd7-963a-da678e692218.com.redhat.rhevm.vdsm
VM Channels Listener::DEBUG::2015-10-19
07:24:23,552::vmchannels::149::vds::(_handle_unconnected) Connecting to
fileno 46 succeeded.
Thread-257233::DEBUG::2015-10-19
07:24:23,854::fileSD::262::Storage.Misc.excCmd::(getReadDelay)
/usr/bin/dd
if=/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/dom_md/metadata
iflag=direct of=/dev/null bs=4096 count=1 (cwd None)
Thread-257233::DEBUG::2015-10-19
07:24:23,866::fileSD::262::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n329 bytes (329 B) copied,
0.000407316 s, 808 kB/s\n'; <rc> = 0
Dummy-330620::DEBUG::2015-10-19
07:24:24,231::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail)
dd
if=/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000 (cwd None)
Dummy-330620::DEBUG::2015-10-19
07:24:24,255::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail)
SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0
MB)
copied, 0.0133547 s, 76.7 MB/s\n'; <rc> = 0
Thread-493088::DEBUG::2015-10-19
07:24:26,098::task::595::Storage.TaskManager.Task::(_updateState)
Task=`a89fc683-1711-4a95-8131-c16af55c0029`::moving from state init ->
state
preparing
Thread-493088::INFO::2015-10-19
07:24:26,099::logUtils::44::dispatcher::(wrapper) Run and protect:
repoStats(options=None)
Thread-493088::INFO::2015-10-19
07:24:26,099::logUtils::47::dispatcher::(wrapper) Run and protect:
repoStats, Return response: {u'342d943d-bccb-49eb-abf5-be9f5a2afbb5':
{'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay':
'0.00353075', 'lastCheck': '7.1', 'valid': True},
u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0, 'actual': True,
'version': 0, 'acquired': True, 'delay': '0.00023087', 'lastCheck':
'7.1',
'valid': True}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'code': 0,
'actual': True, 'version': 3, 'acquired': True, 'delay': '0.000407316',
'lastCheck': '2.2', 'valid': True}}
Thread-493088::DEBUG::2015-10-19
07:24:26,099::task::1191::Storage.TaskManager.Task::(prepare)
Task=`a89fc683-1711-4a95-8131-c16af55c0029`::finished:
{u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'code': 0, 'actual': True,
'version': 0, 'acquired': True, 'delay': '0.00353075', 'lastCheck':
'7.1',
'valid': True}, u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'code': 0,
'actual': True, 'version': 0, 'acquired': True, 'delay': '0.00023087',
'lastCheck': '7.1', 'valid': True},
u'49d4a9cd-946d-41e0-a7ae-f2620f010302':
{'code': 0, 'actual': True, 'version': 3, 'acquired': True, 'delay':
'0.000407316', 'lastCheck': '2.2', 'valid': True}}
Thread-493088::DEBUG::2015-10-19
07:24:26,099::task::595::Storage.TaskManager.Task::(_updateState)
Task=`a89fc683-1711-4a95-8131-c16af55c0029`::moving from state preparing
->
state finished
Thread-493088::DEBUG::2015-10-19
07:24:26,099::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-493088::DEBUG::2015-10-19
07:24:26,100::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-493088::DEBUG::2015-10-19
07:24:26,100::task::993::Storage.TaskManager.Task::(_decref)
Task=`a89fc683-1711-4a95-8131-c16af55c0029`::ref 0 aborting False
Thread-493088::ERROR::2015-10-19
07:24:26,102::config::103::ovirt_hosted_engine_ha.env.config::(_load)
Configuration file '/etc/ovirt-hosted-engine/hosted-engine.conf' not
available [[Errno 2] No such file or directory:
'/etc/ovirt-hosted-engine/hosted-engine.conf']
Thread-493088::ERROR::2015-10-19
07:24:26,102::config::103::ovirt_hosted_engine_ha.env.config::(_load)
Configuration file '/etc/ovirt-hosted-engine/vm.conf' not available
[[Errno
2] No such file or directory: '/etc/ovirt-hosted-engine/vm.conf']
Thread-493088::ERROR::2015-10-19
07:24:26,103::API::1723::vds::(_getHaInfo)
failed to retrieve Hosted Engine HA info
Traceback (most recent call last):
  File "/usr/share/vdsm/API.py", line 1703, in _getHaInfo
  File
"/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py",
line 100, in get_all_stats
  File
"/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/client/client.py",
line 173, in _configure_broker_conn
  File
"/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/env/config.py",
line 129, in get
Exception: Configuration value not found:
file=/etc/ovirt-hosted-engine/hosted-engine.conf, key=sdUUID
Thread-493088::DEBUG::2015-10-19
07:24:26,104::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
Thread-493089::DEBUG::2015-10-19
07:24:26,116::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
Thread-493090::DEBUG::2015-10-19
07:24:26,124::__init__::481::jsonrpc.JsonRpcServer::(_serveRequest)
Calling
'Host.getVMFullList' in bridge with {u'vmList':
[u'523a9aa2-f60c-4cd7-963a-da678e692218']}
Thread-493090::DEBUG::2015-10-19
07:24:26,126::__init__::514::jsonrpc.JsonRpcServer::(_serveRequest)
Return
'Host.getVMFullList' in bridge with [{u'acpiEnable': u'true',
u'emulatedMachine': u'rhel6.5.0', u'vmId':
u'523a9aa2-f60c-4cd7-963a-da678e692218', u'memGuaranteedSize': 1024,
u'transparentHugePages': u'true', 'displaySecurePort': u'5902',
u'spiceSslCipherSuite': u'DEFAULT', u'cpuType': u'Penryn', u'smp': u'1',
'pauseCode': 'NOERR', u'smartcardEnable': u'false', u'custom':
{u'device_82cf1670-4917-4189-bd96-66141daad620device_fbd208db-983e-4086-bf90-c4d8cd741216':
u'VmDevice {vmId=523a9aa2-f60c-4cd7-963a-da678e692218,
deviceId=fbd208db-983e-4086-bf90-c4d8cd741216, device=unix,
type=CHANNEL,
bootOrder=0, specParams={}, address={bus=0, controller=0,
type=virtio-serial, port=2}, managed=false, plugged=true,
readOnly=false,
deviceAlias=channel1, customProperties={}, snapshotId=null,
logicalName=null}', u'device_82cf1670-4917-4189-bd96-66141daad620':
u'VmDevice {vmId=523a9aa2-f60c-4cd7-963a-da678e692218,
deviceId=82cf1670-4917-4189-bd96-66141daad620, device=ide,
type=CONTROLLER,
bootOrder=0, specParams={}, address={slot=0x01, bus=0x00, domain=0x0000,
type=pci, function=0x1}, managed=false, plugged=true, readOnly=false,
deviceAlias=ide0, customProperties={}, snapshotId=null,
logicalName=null}',
u'device_82cf1670-4917-4189-bd96-66141daad620device_fbd208db-983e-4086-bf90-c4d8cd741216device_3ac7440a-7f09-468e-bad2-95758e9f5456device_7fecaa8b-ba6b-4690-af3c-ec473c38d1eb':
u'VmDevice {vmId=523a9aa2-f60c-4cd7-963a-da678e692218,
deviceId=7fecaa8b-ba6b-4690-af3c-ec473c38d1eb, device=unix,
type=CHANNEL,
bootOrder=0, specParams={}, address={bus=0, controller=0,
type=virtio-serial, port=1}, managed=false, plugged=true,
readOnly=false,
deviceAlias=channel0, customProperties={}, snapshotId=null,
logicalName=null}',
u'device_82cf1670-4917-4189-bd96-66141daad620device_fbd208db-983e-4086-bf90-c4d8cd741216device_3ac7440a-7f09-468e-bad2-95758e9f5456':
u'VmDevice {vmId=523a9aa2-f60c-4cd7-963a-da678e692218,
deviceId=3ac7440a-7f09-468e-bad2-95758e9f5456, device=spicevmc,
type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0,
type=virtio-serial, port=3}, managed=false, plugged=true,
readOnly=false,
deviceAlias=channel2, customProperties={}, snapshotId=null,
logicalName=null}'}, u'vmType': u'kvm', u'memSize': 2048,
u'smpCoresPerSocket': u'1', u'vmName': u'Test-win8-1', u'nice': u'0',
'status': 'Up', u'bootMenuEnable': u'false', 'pid': '14998',
u'copyPasteEnable': u'true', 'displayIp': '10.206.68.16', 'displayPort':
'-1', 'guestDiskMapping': {}, 'clientIp': '', u'fileTransferEnable':
u'true', 'nicModel': 'rtl8139,pv', u'keyboardLayout': u'en-us',
u'kvmEnable': u'true', u'displayNetwork': u'ovirtmgmt', u'devices':
[{u'specParams': {}, 'alias': u'sound0', 'deviceType': u'sound',
u'deviceId': u'14cc528b-dd7c-4047-8f7c-224c67100163', u'address':
{u'slot':
u'0x04', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci',
u'function': u'0x0'}, u'device': u'ich6', u'type': u'sound'}, {'device':
'memballoon', 'specParams': {'model': 'none'}, 'deviceType': 'balloon',
'type': 'balloon', 'alias': u'balloon0'}, {u'index': u'0', 'alias':
u'scsi0', u'specParams': {}, 'deviceType': u'controller', u'deviceId':
u'5151af56-76f6-43c9-9ac5-7df7525ea04b', u'address': {u'slot': u'0x05',
u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function':
u'0x0'}, u'device': u'scsi', u'model': u'virtio-scsi', u'type':
u'controller'}, {u'specParams': {}, 'alias': u'virtio-serial0',
'deviceType': u'controller', u'deviceId':
u'0b738f8b-7f8d-4740-ad24-2458387e330b', u'address': {u'slot': u'0x06',
u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function':
u'0x0'}, u'device': u'virtio-serial', u'type': u'controller'},
{u'specParams': {u'vram': u'32768', u'heads': u'1'}, 'alias': u'video0',
'deviceType': u'video', u'deviceId':
u'a62472d7-007a-403a-9880-d7e62d9e9a02', 'address': {u'slot': u'0x02',
u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function':
u'0x0'}, u'device': u'qxl', u'type': u'video'}, {'device': 'spice',
'specParams': {'displayNetwork': u'ovirtmgmt', 'spiceSecureChannels':
u'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard',
'keyMap': u'en-us', 'displayIp': '10.206.68.16', 'copyPasteEnable':
u'true'}, 'deviceType': 'graphics', 'type': 'graphics', 'tlsPort':
u'5902'},
{u'nicModel': u'pv', u'macAddr': u'00:1a:4a:79:9e:06', u'linkActive':
True,
u'network': u'ovirtmgmt', u'specParams': {u'inbound': {}, u'outbound':
{}},
u'filter': u'vdsm-no-mac-spoofing', 'alias': u'net0', 'deviceType':
u'interface', u'deviceId': u'4c57d9ac-b4cf-4602-9c0f-fd034cb91aba',
u'address': {u'slot': u'0x03', u'bus': u'0x00', u'domain': u'0x0000',
u'type': u'pci', u'function': u'0x0'}, u'device': u'bridge', u'type':
u'interface', 'name': u'vnet2'}, {u'index': u'0', u'iface': u'fdc',
'name':
u'fda', 'alias': u'fdc0-0-0', u'specParams': {u'vmPayload': {u'file':
{u'Unattend.xml':
u'PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4NCjx1bmF0dGVuZCB4bWxucz0idXJuOnNjaGVtYXMtbWljcm9zb2Z0LWNvbTp1bmF0dGVuZCI+DQogICAgPHNldHRpbmdzIHBhc3M9IndpbmRvd3NQRSI+DQogICAgICAgIDxjb21wb25lbnQgbmFtZT0iTWljcm9zb2Z0LVdpbmRvd3MtU2V0dXAiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPFVzZXJEYXRhPg0KICAgICAgICAgICAgICAgIDxQcm9kdWN0S2V5Pg0KICAgICAgICAgICAgICAgICAgICA8S2V5PjwhW0NEQVRBW11dPjwvS2V5Pg0KICAgICAgICAgICAgICAgIDwvUHJvZHVjdEtleT4NCiAgICAgICAgICAgICAgICA8QWNjZXB0RXVsYT50cnVlPC9BY2NlcHRFdWxhPg0KICAgICAgICAgICAgICAgIDxGdWxsTmFtZT4idXNlciI8L0Z1bGxOYW1lPg0KICAgICAgICAgICAgICAgIDxPcmdhbml6YXRpb24+PCFbQ0RBVEFbYm5nbGFiLnBzZWN1cmUubmV0XV0+PC9Pcmdhbml6YXRpb24+DQogICAgICAgICAgICA8L1VzZXJEYXRhPg0KICAgICAgICAgICAgPEltYWdlSW5zdGFsbD4NCiAgICAgICAgICAgICAgICA8T1NJbWFnZT4NCiAgICAgICAgICAgICAgICAgICAgPEluc3RhbGxUb0F2YWlsYWJsZVBhcnRpdGlvbj50cnVlPC9JbnN0YWxsVG9BdmFpbGFibGVQYXJ0aXRpb24+DQogICAgICAgICAgICAgICAgPC9PU0ltYWdlPg0KICAgICAgICAgICAgPC9JbWFnZUluc3RhbGw+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLUludGVybmF0aW9uYWwtQ29yZS1XaW5QRSIgcHJvY2Vzc29yQXJjaGl0ZWN0dXJlPSJ4ODYiIHB1YmxpY0tleVRva2VuPSIzMWJmMzg1NmFkMzY0ZTM1IiBsYW5ndWFnZT0ibmV1dHJhbCIgdmVyc2lvblNjb3BlPSJub25TeFMiIHhtbG5zOndjbT0iaHR0cDovL3NjaGVtYXMubWljcm9zb2Z0LmNvbS9XTUlDb25maWcvMjAwMi9TdGF0ZSIgeG1sbnM6eHNpPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxL1hNTFNjaGVtYS1pbnN0YW5jZSI+DQogICAgICAgICAgICA8U2V0dXBVSUxhbmd1YWdlPg0KICAgICAgICAgICAgICAgIDxVSUxhbmd1YWdlPjwhW0NEQVRBW2VuX1VTXV0+PC9VSUxhbmd1YWdlPg0KICAgICAgICAgICAgPC9TZXR1cFVJTGFuZ3VhZ2U+DQogICAgICAgICAgICA8SW5wdXRMb2NhbGU+PCFbQ0RBVEFbZW5fVVNdXT48L0lucHV0TG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgICAgICA8U3lzdGVtTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9TeXN0ZW1Mb2NhbGU+DQogICAgICAgICAgICA8VXNlckxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvVXNlckxvY2FsZT4NCiAgICAgICAgPC9jb21wb25lbnQ+DQogICAgPC9zZXR0aW5ncz4NCiAgICA8c2V0dGluZ3MgcGFzcz0ic3BlY2lhbGl6ZSI+DQogICAgICAgIDxjb21wb25lbnQgbmFtZT0iTWljcm9zb2Z0LVdpbmRvd3MtU2hlbGwtU2V0dXAiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPERpc3BsYXk+DQogICAgICAgICAgICAgICAgPENvbG9yRGVwdGg+MzI8L0NvbG9yRGVwdGg+DQogICAgICAgICAgICAgICAgPERQST45NjwvRFBJPg0KICAgICAgICAgICAgICAgIDxIb3Jpem9udGFsUmVzb2x1dGlvbj4xMDI0PC9Ib3Jpem9udGFsUmVzb2x1dGlvbj4NCiAgICAgICAgICAgICAgICA8UmVmcmVzaFJhdGU+NzU8L1JlZnJlc2hSYXRlPg0KICAgICAgICAgICAgICAgIDxWZXJ0aWNhbFJlc29sdXRpb24+NzY4PC9WZXJ0aWNhbFJlc29sdXRpb24+DQogICAgICAgICAgICA8L0Rpc3BsYXk+DQogICAgICAgICAgICA8Q29tcHV0ZXJOYW1lPjwhW0NEQVRBW1Rlc3Qtd2luOC0xXV0+PC9Db21wdXRlck5hbWU+DQogICAgICAgICAgICA8VGltZVpvbmU+PCFbQ0RBVEFbR01UIFN0YW5kYXJkIFRpbWVdXT48L1RpbWVab25lPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICAgICAgPGNvbXBvbmVudCBuYW1lPSJNaWNyb3NvZnQtV2luZG93cy1JbnRlcm5hdGlvbmFsLUNvcmUiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElucHV0TG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9JbnB1dExvY2FsZT4NCiAgICAgICAgICAgIDxVc2VyTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9Vc2VyTG9jYWxlPg0KICAgICAgICAgICAgPFN5c3RlbUxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvU3lzdGVtTG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLVVuYXR0ZW5kZWRKb2luIiBwcm9jZXNzb3JBcmNoaXRlY3R1cmU9ImFtZDY0IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElkZW50aWZpY2F0aW9uPg0KICAgICAgICAgICAgICAgIDxDcmVkZW50aWFscz4NCiAgICAgICAgICAgICAgICAgICAgPERvbWFpbj48IVtDREFUQVtdXT48L0RvbWFpbj4NCiAgICAgICAgICAgICAgICAgICAgPFBhc3N3b3JkPjwhW0NEQVRBW11dPjwvUGFzc3dvcmQ+DQogICAgICAgICAgICAgICAgICAgIDxVc2VybmFtZT48IVtDREFUQVtdXT48L1VzZXJuYW1lPg0KICAgICAgICAgICAgICAgIDwvQ3JlZGVudGlhbHM+DQogICAgICAgICAgICAgICAgPEpvaW5Eb21haW4+PCFbQ0RBVEFbXV0+PC9Kb2luRG9tYWluPg0KICAgICAgICAgICAgICAgIDxNYWNoaW5lT2JqZWN0T1U+PCFbQ0RBVEFbXV0+PC9NYWNoaW5lT2JqZWN0T1U+DQogICAgICAgICAgICA8L0lkZW50aWZpY2F0aW9uPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICA8L3NldHRpbmdzPg0KICAgIDxzZXR0aW5ncyBwYXNzPSJvb2JlU3lzdGVtIj4NCiAgICAgICAgPGNvbXBvbmVudCBuYW1lPSJNaWNyb3NvZnQtV2luZG93cy1JbnRlcm5hdGlvbmFsLUNvcmUiIHByb2Nlc3NvckFyY2hpdGVjdHVyZT0ieDg2IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPElucHV0TG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9JbnB1dExvY2FsZT4NCiAgICAgICAgICAgIDxVc2VyTG9jYWxlPjwhW0NEQVRBW2VuX1VTXV0+PC9Vc2VyTG9jYWxlPg0KICAgICAgICAgICAgPFN5c3RlbUxvY2FsZT48IVtDREFUQVtlbl9VU11dPjwvU3lzdGVtTG9jYWxlPg0KICAgICAgICAgICAgPFVJTGFuZ3VhZ2U+PCFbQ0RBVEFbZW5fVVNdXT48L1VJTGFuZ3VhZ2U+DQogICAgICAgIDwvY29tcG9uZW50Pg0KICAgICAgICA8Y29tcG9uZW50IG5hbWU9Ik1pY3Jvc29mdC1XaW5kb3dzLVNoZWxsLVNldHVwIiBwcm9jZXNzb3JBcmNoaXRlY3R1cmU9ImFtZDY0IiBwdWJsaWNLZXlUb2tlbj0iMzFiZjM4NTZhZDM2NGUzNSIgbGFuZ3VhZ2U9Im5ldXRyYWwiIHZlcnNpb25TY29wZT0ibm9uU3hTIiB4bWxuczp3Y209Imh0dHA6Ly9zY2hlbWFzLm1pY3Jvc29mdC5jb20vV01JQ29uZmlnLzIwMDIvU3RhdGUiIHhtbG5zOnhzaT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS9YTUxTY2hlbWEtaW5zdGFuY2UiPg0KICAgICAgICAgICAgPE9PQkU+DQogICAgICAgICAgICAgICAgPFByb3RlY3RZb3VyUEM+MjwvUHJvdGVjdFlvdXJQQz4NCiAgICAgICAgICAgICAgICA8TmV0d29ya0xvY2F0aW9uPldvcms8L05ldHdvcmtMb2NhdGlvbj4NCiAgICAgICAgICAgICAgICA8SGlkZUVVTEFQYWdlPnRydWU8L0hpZGVFVUxBUGFnZT4NCiAgICAgICAgICAgIDwvT09CRT4NCiAgICAgICAgICAgIDxVc2VyQWNjb3VudHM+DQogICAgICAgICAgICAgICAgPEFkbWluaXN0cmF0b3JQYXNzd29yZD4NCiAgICAgICAgICAgICAgICAgICAgPFZhbHVlPjwhW0NEQVRBW0VtYmUxbXBsc11dPjwvVmFsdWU+DQogICAgICAgICAgICAgICAgICAgIDxQbGFpblRleHQ+dHJ1ZTwvUGxhaW5UZXh0Pg0KICAgICAgICAgICAgICAgIDwvQWRtaW5pc3RyYXRvclBhc3N3b3JkPg0KICAgICAgICAgICAgICAgIDxMb2NhbEFjY291bnRzPg0KICAgICAgICAgICAgICAgICAgICA8TG9jYWxBY2NvdW50IHdjbTphY3Rpb249ImFkZCI+DQogICAgICAgICAgICAgICAgICAgICAgICA8UGFzc3dvcmQ+DQogICAgICAgICAgICAgICAgICAgICAgICAgICAgPFZhbHVlPjwhW0NEQVRBW0VtYmUxbXBsc11dPjwvVmFsdWU+DQogICAgICAgICAgICAgICAgICAgICAgICAgICAgPFBsYWluVGV4dD50cnVlPC9QbGFpblRleHQ+DQogICAgICAgICAgICAgICAgICAgICAgICA8L1Bhc3N3b3JkPg0KICAgICAgICAgICAgICAgICAgICAgICAgPEdyb3VwPmFkbWluaXN0cmF0b3JzPC9Hcm91cD4NCiAgICAgICAgICAgICAgICAgICAgICAgIDxOYW1lPnVzZXI8L05hbWU+DQogICAgICAgICAgICAgICAgICAgICAgICA8RGlzcGxheU5hbWU+dXNlcjwvRGlzcGxheU5hbWU+DQogICAgICAgICAgICAgICAgICAgIDwvTG9jYWxBY2NvdW50Pg0KICAgICAgICAgICAgICAgIDwvTG9jYWxBY2NvdW50cz4NCiAgICAgICAgICAgIDwvVXNlckFjY291bnRzPg0KICAgICAgICA8L2NvbXBvbmVudD4NCiAgICA8L3NldHRpbmdzPg0KICAgIDxjcGk6b2ZmbGluZUltYWdlIGNwaTpzb3VyY2U9IndpbTpkOi9zb3VyY2VzL2luc3RhbGwud2ltI1dpbmRvd3MgOCBFTlRFUlBSSVNFIiB4bWxuczpjcGk9InVybjpzY2hlbWFzLW1pY3Jvc29mdC1jb206Y3BpIi8+DQo8L3VuYXR0ZW5kPg0K'}}},
u'readonly': 'True', 'deviceType': u'disk', u'deviceId':
u'c86868ec-4eae-4fb4-b395-165fd3d31ac2', 'address': {u'bus': u'0',
u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'},
u'device': u'floppy', u'shared': u'false', u'path':
u'/var/run/vdsm/payload/523a9aa2-f60c-4cd7-963a-da678e692218.3b185f2c896bd91b66d6a3959677f177.img',
u'type': u'disk'}, {u'index': u'2', u'iface': u'ide', 'name': u'hdc',
'alias': u'ide0-1-0', u'specParams': {u'path': u''}, u'readonly':
'True',
'deviceType': u'disk', u'deviceId':
u'fc33f0e3-3a7c-4dc2-a4c5-0d8134766c4d',
'address': {u'bus': u'1', u'controller': u'0', u'type': u'drive',
u'target':
u'0', u'unit': u'0'}, u'device': u'cdrom', u'shared': u'false', u'path':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111/ovirt-guest-tools-3.5_5.iso',
u'type': u'disk'}, {u'poolID': u'a24369bc-3e57-451b-a21c-422c5aa7b1e5',
'volumeInfo': {'domainID': u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
'volType': 'path', 'leaseOffset': 0, 'volumeID':
u'27589b5c-0c6f-4551-8199-e80c870c9d2a', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224', 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a'},
u'index': 0, u'iface': u'ide', 'apparentsize': '197120', u'specParams':
{},
u'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224', u'readonly':
'False',
'deviceType': u'disk', u'shared': u'false', 'truesize': '200704',
u'type':
u'disk', u'domainID': u'49d4a9cd-946d-41e0-a7ae-f2620f010302',
'reqsize':
'0', u'format': u'cow', u'deviceId':
u'91dce925-129e-4de5-a5af-bbdbe9d80224', u'address': {u'bus': u'0',
u'controller': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'},
u'device': u'disk', 'path':
u'/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a',
u'propagateErrors': u'off', u'optional': u'false', 'name': u'hda',
u'bootOrder': u'1', u'volumeID':
u'27589b5c-0c6f-4551-8199-e80c870c9d2a',
'alias': u'ide0-0-0', 'volumeChain': [{'domainID':
u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'volType': 'path',
'leaseOffset':
0, 'volumeID': u'27589b5c-0c6f-4551-8199-e80c870c9d2a', 'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224', 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/27589b5c-0c6f-4551-8199-e80c870c9d2a'},
{'domainID': u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'volType': 'path',
'leaseOffset': 0, 'volumeID': u'60d7aa2a-9850-43f2-a523-64c9dda8e403',
'leasePath':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403.lease',
'imageID': u'91dce925-129e-4de5-a5af-bbdbe9d80224', 'path':
u'/rhev/data-center/mnt/10.204.206.10:_ovirt/49d4a9cd-946d-41e0-a7ae-f2620f010302/images/91dce925-129e-4de5-a5af-bbdbe9d80224/60d7aa2a-9850-43f2-a523-64c9dda8e403'}]},
{'device': u'usb', 'alias': u'usb0', 'deviceType': 'controller', 'type':
'controller', 'address': {u'slot': u'0x01', u'bus': u'0x00', u'domain':
u'0x0000', u'type': u'pci', u'function': u'0x2'}}, {'device': u'ide',
'alias': u'ide0', 'deviceType': 'controller', 'type': 'controller',
'address': {u'slot': u'0x01', u'bus': u'0x00', u'domain': u'0x0000',
u'type': u'pci', u'function': u'0x1'}}, {'device': u'unix', 'alias':
u'channel0', 'deviceType': u'channel', 'type': u'channel', 'address':
{u'bus': u'0', u'controller': u'0', u'type': u'virtio-serial', u'port':
u'1'}}, {'device': u'unix', 'alias': u'channel1', 'deviceType':
u'channel',
'type': u'channel', 'address': {u'bus': u'0', u'controller': u'0',
u'type':
u'virtio-serial', u'port': u'2'}}, {'device': u'spicevmc', 'alias':
u'channel2', 'deviceType': u'channel', 'type': u'channel', 'address':
{u'bus': u'0', u'controller': u'0', u'type': u'virtio-serial', u'port':
u'3'}}], u'timeOffset': u'19800', u'maxVCpus': u'16',
u'spiceSecureChannels':
u'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard',
u'display': u'qxl'}]
Thread-493090::DEBUG::2015-10-19
07:24:26,128::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
Thread-493091::DEBUG::2015-10-19
07:24:26,239::__init__::481::jsonrpc.JsonRpcServer::(_serveRequest)
Calling
'StoragePool.getSpmStatus' in bridge with {u'storagepoolID':
u'a24369bc-3e57-451b-a21c-422c5aa7b1e5'}
Thread-493091::DEBUG::2015-10-19
07:24:26,240::task::595::Storage.TaskManager.Task::(_updateState)
Task=`013a1544-a6f2-4d68-aee8-1461690a64cd`::moving from state init ->
state
preparing
Thread-493091::INFO::2015-10-19
07:24:26,240::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5',
options=None)
Thread-493091::INFO::2015-10-19
07:24:26,256::logUtils::47::dispatcher::(wrapper) Run and protect:
getSpmStatus, Return response: {'spm_st': {'spmId': 2, 'spmStatus':
'SPM',
'spmLver': 13L}}
Thread-493091::DEBUG::2015-10-19
07:24:26,256::task::1191::Storage.TaskManager.Task::(prepare)
Task=`013a1544-a6f2-4d68-aee8-1461690a64cd`::finished: {'spm_st':
{'spmId':
2, 'spmStatus': 'SPM', 'spmLver': 13L}}
Thread-493091::DEBUG::2015-10-19
07:24:26,256::task::595::Storage.TaskManager.Task::(_updateState)
Task=`013a1544-a6f2-4d68-aee8-1461690a64cd`::moving from state preparing
->
state finished
Thread-493091::DEBUG::2015-10-19
07:24:26,256::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-493091::DEBUG::2015-10-19
07:24:26,257::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-493091::DEBUG::2015-10-19
07:24:26,257::task::993::Storage.TaskManager.Task::(_decref)
Task=`013a1544-a6f2-4d68-aee8-1461690a64cd`::ref 0 aborting False
Thread-493091::DEBUG::2015-10-19
07:24:26,257::__init__::514::jsonrpc.JsonRpcServer::(_serveRequest)
Return
'StoragePool.getSpmStatus' in bridge with {'spmId': 2, 'spmStatus':
'SPM',
'spmLver': 13L}
Thread-493091::DEBUG::2015-10-19
07:24:26,257::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
Thread-493092::DEBUG::2015-10-19
07:24:26,264::__init__::481::jsonrpc.JsonRpcServer::(_serveRequest)
Calling
'StoragePool.getInfo' in bridge with {u'storagepoolID':
u'a24369bc-3e57-451b-a21c-422c5aa7b1e5'}
Thread-493092::DEBUG::2015-10-19
07:24:26,264::task::595::Storage.TaskManager.Task::(_updateState)
Task=`48cbcbae-9b02-48a0-80da-ff7fde9c43b0`::moving from state init ->
state
preparing
Thread-493092::INFO::2015-10-19
07:24:26,265::logUtils::44::dispatcher::(wrapper) Run and protect:
getStoragePoolInfo(spUUID=u'a24369bc-3e57-451b-a21c-422c5aa7b1e5',
options=None)
Thread-493092::DEBUG::2015-10-19
07:24:26,265::resourceManager::198::Storage.ResourceManager.Request::(__init__)
ResName=`Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5`ReqID=`6efea4e0-11ed-45d4-ba50-b382dc2aebc6`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '2632' at
'getStoragePoolInfo'
Thread-493092::DEBUG::2015-10-19
07:24:26,265::resourceManager::542::Storage.ResourceManager::(registerResource)
Trying to register resource
'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5'
for lock type 'shared'
Thread-493092::DEBUG::2015-10-19
07:24:26,266::resourceManager::601::Storage.ResourceManager::(registerResource)
Resource 'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5' is free. Now
locking
as 'shared' (1 active user)
Thread-493092::DEBUG::2015-10-19
07:24:26,266::resourceManager::238::Storage.ResourceManager.Request::(grant)
ResName=`Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5`ReqID=`6efea4e0-11ed-45d4-ba50-b382dc2aebc6`::Granted
request
Thread-493092::DEBUG::2015-10-19
07:24:26,266::task::827::Storage.TaskManager.Task::(resourceAcquired)
Task=`48cbcbae-9b02-48a0-80da-ff7fde9c43b0`::_resourcesAcquired:
Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5 (shared)
Thread-493092::DEBUG::2015-10-19
07:24:26,266::task::993::Storage.TaskManager.Task::(_decref)
Task=`48cbcbae-9b02-48a0-80da-ff7fde9c43b0`::ref 1 aborting False
Dummy-330620::DEBUG::2015-10-19
07:24:26,269::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail)
dd
if=/rhev/data-center/a24369bc-3e57-451b-a21c-422c5aa7b1e5/mastersd/dom_md/inbox
iflag=direct,fullblock count=1 bs=1024000 (cwd None)
Dummy-330620::DEBUG::2015-10-19
07:24:26,303::storage_mailbox::731::Storage.Misc.excCmd::(_checkForMail)
SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0
MB)
copied, 0.0202981 s, 50.4 MB/s\n'; <rc> = 0
Thread-493092::INFO::2015-10-19
07:24:26,331::logUtils::47::dispatcher::(wrapper) Run and protect:
getStoragePoolInfo, Return response: {'info': {'name': 'No Description',
'isoprefix':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111',
'pool_status': 'connected', 'lver': 13L, 'domains':
u'342d943d-bccb-49eb-abf5-be9f5a2afbb5:Active,1484ea07-4269-44c4-a503-fa6bf43d8bd9:Active,49d4a9cd-946d-41e0-a7ae-f2620f010302:Active',
'master_uuid': u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'version': '3',
'spm_id': 2, 'type': 'NFS', 'master_ver': 5}, 'dominfo':
{u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'status': u'Active',
'diskfree':
'24726470656', 'isoprefix':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111',
'alerts': [], 'disktotal': '52710866944', 'version': 0},
u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'status': u'Active',
'diskfree':
'70269272064', 'isoprefix': '', 'alerts': [], 'disktotal':
'96726941696',
'version': 0}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'status':
u'Active', 'diskfree': '2067892011008', 'isoprefix': '', 'alerts': [],
'disktotal': '2291345653760', 'version': 3}}}
Thread-493092::DEBUG::2015-10-19
07:24:26,331::task::1191::Storage.TaskManager.Task::(prepare)
Task=`48cbcbae-9b02-48a0-80da-ff7fde9c43b0`::finished: {'info': {'name':
'No
Description', 'isoprefix':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111',
'pool_status': 'connected', 'lver': 13L, 'domains':
u'342d943d-bccb-49eb-abf5-be9f5a2afbb5:Active,1484ea07-4269-44c4-a503-fa6bf43d8bd9:Active,49d4a9cd-946d-41e0-a7ae-f2620f010302:Active',
'master_uuid': u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'version': '3',
'spm_id': 2, 'type': 'NFS', 'master_ver': 5}, 'dominfo':
{u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'status': u'Active',
'diskfree':
'24726470656', 'isoprefix':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111',
'alerts': [], 'disktotal': '52710866944', 'version': 0},
u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'status': u'Active',
'diskfree':
'70269272064', 'isoprefix': '', 'alerts': [], 'disktotal':
'96726941696',
'version': 0}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'status':
u'Active', 'diskfree': '2067892011008', 'isoprefix': '', 'alerts': [],
'disktotal': '2291345653760', 'version': 3}}}
Thread-493092::DEBUG::2015-10-19
07:24:26,331::task::595::Storage.TaskManager.Task::(_updateState)
Task=`48cbcbae-9b02-48a0-80da-ff7fde9c43b0`::moving from state preparing
->
state finished
Thread-493092::DEBUG::2015-10-19
07:24:26,331::resourceManager::940::Storage.ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources
{u'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5': < ResourceRef
'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5', isValid: 'True' obj:
'None'>}
Thread-493092::DEBUG::2015-10-19
07:24:26,332::resourceManager::977::Storage.ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-493092::DEBUG::2015-10-19
07:24:26,332::resourceManager::616::Storage.ResourceManager::(releaseResource)
Trying to release resource
'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5'
Thread-493092::DEBUG::2015-10-19
07:24:26,332::resourceManager::635::Storage.ResourceManager::(releaseResource)
Released resource 'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5' (0
active
users)
Thread-493092::DEBUG::2015-10-19
07:24:26,332::resourceManager::641::Storage.ResourceManager::(releaseResource)
Resource 'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5' is free, finding
out
if anyone is waiting for it.
Thread-493092::DEBUG::2015-10-19
07:24:26,333::resourceManager::649::Storage.ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.a24369bc-3e57-451b-a21c-422c5aa7b1e5', Clearing records.
Thread-493092::DEBUG::2015-10-19
07:24:26,333::task::993::Storage.TaskManager.Task::(_decref)
Task=`48cbcbae-9b02-48a0-80da-ff7fde9c43b0`::ref 0 aborting False
Thread-493092::DEBUG::2015-10-19
07:24:26,333::__init__::514::jsonrpc.JsonRpcServer::(_serveRequest)
Return
'StoragePool.getInfo' in bridge with {'info': {'name': 'No Description',
'isoprefix':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111',
'pool_status': 'connected', 'lver': 13L, 'domains':
u'342d943d-bccb-49eb-abf5-be9f5a2afbb5:Active,1484ea07-4269-44c4-a503-fa6bf43d8bd9:Active,49d4a9cd-946d-41e0-a7ae-f2620f010302:Active',
'master_uuid': u'49d4a9cd-946d-41e0-a7ae-f2620f010302', 'version': '3',
'spm_id': 2, 'type': 'NFS', 'master_ver': 5}, 'dominfo':
{u'342d943d-bccb-49eb-abf5-be9f5a2afbb5': {'status': u'Active',
'diskfree':
'24726470656', 'isoprefix':
u'/rhev/data-center/mnt/10.204.207.171:_var_lib_exports_iso/342d943d-bccb-49eb-abf5-be9f5a2afbb5/images/11111111-1111-1111-1111-111111111111',
'alerts': [], 'disktotal': '52710866944', 'version': 0},
u'1484ea07-4269-44c4-a503-fa6bf43d8bd9': {'status': u'Active',
'diskfree':
'70269272064', 'isoprefix': '', 'alerts': [], 'disktotal':
'96726941696',
'version': 0}, u'49d4a9cd-946d-41e0-a7ae-f2620f010302': {'status':
u'Active', 'diskfree': '2067892011008', 'isoprefix': '', 'alerts': [],
'disktotal': '2291345653760', 'version': 3}}}
Thread-493092::DEBUG::2015-10-19
07:24:26,334::stompReactor::162::yajsonrpc.StompServer::(send) Sending
response
^C[root@pbuovirt2 ~]# [root@infraesx2 ~]#
[root@infraesx2 ~]#
[root@infraesx2 ~]#
[root@infraesx2 ~]#
[root@infraesx2 ~]# tail -f /var/log/vdsm/
backup/           connectivity.log  mom.log           register.log
supervdsm.log     upgrade.log       vdsm.log
[root@infraesx2 ~]# tail -f /var/log/vdsm/vdsm.log
BindingXMLRPC::INFO::2015-10-26
07:57:03,378::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting
request handler for 127.0.0.1:43211
Thread-816::INFO::2015-10-26
07:57:03,379::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43211 started
Thread-816::INFO::2015-10-26
07:57:03,381::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43211 stopped
Reactor thread::INFO::2015-10-26
07:57:18,397::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
Accepting connection from 127.0.0.1:43212
Reactor thread::DEBUG::2015-10-26
07:57:18,406::protocoldetector::82::ProtocolDetector.Detector::(__init__)
Using required_size=11
Reactor thread::INFO::2015-10-26
07:57:18,406::protocoldetector::118::ProtocolDetector.Detector::(handle_read)
Detected protocol xml from 127.0.0.1:43212
Reactor thread::DEBUG::2015-10-26
07:57:18,406::bindingxmlrpc::1296::XmlDetector::(handle_socket) xml over
http detected from ('127.0.0.1', 43212)
BindingXMLRPC::INFO::2015-10-26
07:57:18,407::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting
request handler for 127.0.0.1:43212
Thread-817::INFO::2015-10-26
07:57:18,408::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43212 started
Thread-817::INFO::2015-10-26
07:57:18,410::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43212 stopped
Thread-818::DEBUG::2015-10-26
07:57:32,985::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest)
Calling
'Host.getCapabilities' in bridge with {}
Thread-818::DEBUG::2015-10-26 07:57:33,005::utils::661::root::(execCmd)
/usr/sbin/tc qdisc show (cwd None)
Thread-818::DEBUG::2015-10-26 07:57:33,015::utils::679::root::(execCmd)
SUCCESS: <err> = ''; <rc> = 0
Thread-818::DEBUG::2015-10-26
07:57:33,026::__init__::534::jsonrpc.JsonRpcServer::(_serveRequest)
Return
'Host.getCapabilities' in bridge with {'HBAInventory': {'iSCSI':
[{'InitiatorName': 'iqn.1994-05.com.redhat:fbb518530'}], 'FC': []},
'packages2': {'kernel': {'release': '229.11.1.el7.x86_64', 'buildtime':
1438823178.0, 'version': '3.10.0'}, 'spice-server': {'release': '9.el7',
'buildtime': 1426031557L, 'version': '0.12.4'}, 'librbd1': {'release':
'2.el7', 'buildtime': 1425594433L, 'version': '0.80.7'}, 'vdsm':
{'release':
'4.git6d8c446.el7', 'buildtime': 1441206355L, 'version': '4.17.4'},
'qemu-kvm': {'release': '23.el7_1.6.1', 'buildtime': 1438078890L,
'version':
'2.1.2'}, 'libvirt': {'release': '16.el7_1.3', 'buildtime': 1431461920L,
'version': '1.2.8'}, 'qemu-img': {'release': '23.el7_1.6.1',
'buildtime':
1438078890L, 'version': '2.1.2'}, 'mom': {'release': '1.el7',
'buildtime':
1436818826L, 'version': '0.5.0'}, 'glusterfs-cli': {'release':
'0.820.git092cc95.el7.centos', 'buildtime': 1441215385L, 'version':
'3.8dev'}}, 'numaNodeDistance': {'1': [20, 10], '0': [10, 20]},
'cpuModel':
'Intel(R) Xeon(R) CPU           E5520  @ 2.27GHz', 'liveMerge': 'true',
'hooks': {'before_vm_start': {'50_hostedengine': {'md5':
'2a6d96c26a3599812be6cf1a13d9f485'}}, 'after_network_setup':
{'30_ethtool_options': {'md5': '9cdcf29a16651eb3abfda900312e8b31'}}},
'vmTypes': ['kvm'], 'selinux': {'mode': '1'}, 'liveSnapshot': 'true',
'kdumpStatus': 0, 'networks': {}, 'bridges': {}, 'uuid':
'33343934-3932-4753-4839-333858425450', 'onlineCpus':
'0,2,4,6,8,10,12,14,1,3,5,7,9,11,13,15', 'nics': {'enp3s0f1': {'addr':
'',
'ipv6gateway': '::', 'ipv6addrs': [], 'mtu': '1500', 'dhcpv4': False,
'netmask': '', 'dhcpv6': False, 'ipv4addrs': [], 'cfg': {'BOOTPROTO':
'none'}, 'hwaddr': '00:26:55:4c:42:d2', 'speed': 0, 'gateway': ''},
'enp3s0f0': {'addr': '', 'ipv6gateway': '::', 'ipv6addrs': [], 'mtu':
'1500', 'dhcpv4': False, 'netmask': '', 'dhcpv6': False, 'ipv4addrs':
[],
'cfg': {'BOOTPROTO': 'none'}, 'hwaddr': '00:26:55:4c:42:d0', 'speed': 0,
'gateway': ''}, 'enp2s0f0': {'addr': '10.206.68.97', 'ipv6gateway':
'::',
'ipv6addrs': ['fe80::226:55ff:fe4c:42cc/64'], 'mtu': '1500', 'dhcpv4':
False, 'netmask': '255.255.254.0', 'dhcpv6': False, 'ipv4addrs':
['10.206.68.97/23'], 'cfg': {'IPV6INIT': 'no', 'NM_CONTROLLED': 'no',
'IPADDR': '10.206.68.97', 'PEERDNS': 'no', 'ONBOOT': 'yes',
'IPV6_AUTOCONF':
'no', 'HWADDR': '00:26:55:4c:42:cc', 'NETMASK': '255.255.254.0',
'BOOTPROTO': 'none', 'DEVICE': 'enp2s0f0', 'PEERNTP': 'yes', 'GATEWAY':
'10.206.69.254'}, 'hwaddr': '00:26:55:4c:42:cc', 'speed': 1000,
'gateway':
'10.206.69.254'}, 'enp2s0f1': {'addr': '', 'ipv6gateway': '::',
'ipv6addrs':
[], 'mtu': '1500', 'dhcpv4': False, 'netmask': '', 'dhcpv6': False,
'ipv4addrs': [], 'cfg': {'BOOTPROTO': 'none'}, 'hwaddr':
'00:26:55:4c:42:ce', 'speed': 0, 'gateway': ''}}, 'software_revision':
'4',
'hostdevPassthrough': 'false', 'clusterLevels': ['3.4', '3.5', '3.6'],
'cpuFlags':
'fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,ht,tm,pbe,syscall,nx,rdtscp,lm,constant_tsc,arch_perfmon,pebs,bts,rep_good,nopl,xtopology,nonstop_tsc,aperfmperf,pni,dtes64,monitor,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,dca,sse4_1,sse4_2,popcnt,lahf_lm,ida,dtherm,tpr_shadow,vnmi,flexpriority,ept,vpid,model_Nehalem,model_Conroe,model_coreduo,model_core2duo,model_Penryn,model_n270',
'ISCSIInitiatorName': 'iqn.1994-05.com.redhat:fbb518530',
'netConfigDirty':
'True', 'supportedENGINEs': ['3.4', '3.5', '3.6'], 'autoNumaBalancing':
1,
'additionalFeatures': [], 'reservedMem': '321', 'bondings': {},
'software_version': '4.17', 'memSize': '23843', 'cpuSpeed': '2266.000',
'numaNodes': {'1': {'totalMemory': '12287', 'cpus': [1, 3, 5, 7, 9, 11,
13,
15]}, '0': {'totalMemory': '12277', 'cpus': [0, 2, 4, 6, 8, 10, 12,
14]}},
'cpuSockets': '2', 'vlans': {}, 'lastClientIface': 'enp2s0f0',
'cpuCores':
'8', 'kvmEnabled': 'true', 'guestOverhead': '65', 'version_name': 'Snow
Man', 'cpuThreads': '16', 'emulatedMachines': ['pc-i440fx-rhel7.1.0',
'rhel6.3.0', 'pc-q35-rhel7.0.0', 'rhel6.1.0', 'rhel6.6.0', 'rhel6.2.0',
'pc', 'pc-q35-rhel7.1.0', 'q35', 'rhel6.4.0', 'rhel6.0.0', 'rhel6.5.0',
'pc-i440fx-rhel7.0.0'], 'rngSources': ['random'], 'operatingSystem':
{'release': '0.999.201509030901.el7.centos', 'version': '3.6', 'name':
'oVirt Node'}}
Thread-818::DEBUG::2015-10-26
07:57:33,027::stompreactor::304::yajsonrpc.StompServer::(send) Sending
response
Thread-819::DEBUG::2015-10-26
07:57:33,034::__init__::503::jsonrpc.JsonRpcServer::(_serveRequest)
Calling
'Host.getHardwareInfo' in bridge with {}
Thread-819::DEBUG::2015-10-26
07:57:33,037::__init__::534::jsonrpc.JsonRpcServer::(_serveRequest)
Return
'Host.getHardwareInfo' in bridge with {'systemProductName': 'ProLiant
DL380
G6', 'systemUUID': '33343934-3932-4753-4839-333858425450',
'systemSerialNumber': 'SGH938XBTP', 'systemFamily': 'ProLiant',
'systemManufacturer': 'HP'}
Thread-819::DEBUG::2015-10-26
07:57:33,038::stompreactor::304::yajsonrpc.StompServer::(send) Sending
response
Reactor thread::INFO::2015-10-26
07:57:33,426::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
Accepting connection from 127.0.0.1:43213
Reactor thread::DEBUG::2015-10-26
07:57:33,434::protocoldetector::82::ProtocolDetector.Detector::(__init__)
Using required_size=11
Reactor thread::INFO::2015-10-26
07:57:33,435::protocoldetector::118::ProtocolDetector.Detector::(handle_read)
Detected protocol xml from 127.0.0.1:43213
Reactor thread::DEBUG::2015-10-26
07:57:33,435::bindingxmlrpc::1296::XmlDetector::(handle_socket) xml over
http detected from ('127.0.0.1', 43213)
BindingXMLRPC::INFO::2015-10-26
07:57:33,435::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting
request handler for 127.0.0.1:43213
Thread-820::INFO::2015-10-26
07:57:33,436::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43213 started
Thread-820::INFO::2015-10-26
07:57:33,438::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43213 stopped
Thread-821::DEBUG::2015-10-26
07:57:35,579::stompreactor::304::yajsonrpc.StompServer::(send) Sending
response
Reactor thread::INFO::2015-10-26
07:57:48,453::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
Accepting connection from 127.0.0.1:43214
Reactor thread::DEBUG::2015-10-26
07:57:48,461::protocoldetector::82::ProtocolDetector.Detector::(__init__)
Using required_size=11
Reactor thread::INFO::2015-10-26
07:57:48,462::protocoldetector::118::ProtocolDetector.Detector::(handle_read)
Detected protocol xml from 127.0.0.1:43214
Reactor thread::DEBUG::2015-10-26
07:57:48,462::bindingxmlrpc::1296::XmlDetector::(handle_socket) xml over
http detected from ('127.0.0.1', 43214)
BindingXMLRPC::INFO::2015-10-26
07:57:48,462::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting
request handler for 127.0.0.1:43214
Thread-822::INFO::2015-10-26
07:57:48,463::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43214 started
Thread-822::INFO::2015-10-26
07:57:48,465::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43214 stopped
Reactor thread::INFO::2015-10-26
07:58:03,480::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
Accepting connection from 127.0.0.1:43215
Reactor thread::DEBUG::2015-10-26
07:58:03,488::protocoldetector::82::ProtocolDetector.Detector::(__init__)
Using required_size=11
Reactor thread::INFO::2015-10-26
07:58:03,489::protocoldetector::118::ProtocolDetector.Detector::(handle_read)
Detected protocol xml from 127.0.0.1:43215
Reactor thread::DEBUG::2015-10-26
07:58:03,489::bindingxmlrpc::1296::XmlDetector::(handle_socket) xml over
http detected from ('127.0.0.1', 43215)
BindingXMLRPC::INFO::2015-10-26
07:58:03,489::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting
request handler for 127.0.0.1:43215
Thread-823::INFO::2015-10-26
07:58:03,490::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43215 started
Thread-823::INFO::2015-10-26
07:58:03,492::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43215 stopped
Reactor thread::INFO::2015-10-26
07:58:18,507::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
Accepting connection from 127.0.0.1:43216
Reactor thread::DEBUG::2015-10-26
07:58:18,515::protocoldetector::82::ProtocolDetector.Detector::(__init__)
Using required_size=11
Reactor thread::INFO::2015-10-26
07:58:18,516::protocoldetector::118::ProtocolDetector.Detector::(handle_read)
Detected protocol xml from 127.0.0.1:43216
Reactor thread::DEBUG::2015-10-26
07:58:18,516::bindingxmlrpc::1296::XmlDetector::(handle_socket) xml over
http detected from ('127.0.0.1', 43216)
BindingXMLRPC::INFO::2015-10-26
07:58:18,516::xmlrpc::73::vds.XMLRPCServer::(handle_request) Starting
request handler for 127.0.0.1:43216
Thread-824::INFO::2015-10-26
07:58:18,517::xmlrpc::84::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43216 started
Thread-824::INFO::2015-10-26
07:58:18,519::xmlrpc::92::vds.XMLRPCServer::(_process_requests) Request
handler for 127.0.0.1:43216 stopped
^C
[root@infraesx2 ~]#
On Mon, Oct 26, 2015 at 1:20 PM, Piotr Kliczewski
<piotr.kliczewski@gmail.com> wrote:
...
Based on provided snippet of a log the engine is not able to connect
to your vdsm due to timeout (by default 2 seconds).
Please provide vdsm log so we can see why it failed.
On Mon, Oct 26, 2015 at 7:14 AM, Budur Nagaraju <nbudoor@gmail.com>
wrote:
...
HI
After installing ovirt 3.6,unable to add ovirt node to the ovirt
application
,below are the logs.
The moment I add  to ovirt application network is getting
disconnected
prior
to that ovirt node was able to reach the gateway without any issues.
any solution that wold resolve my issues ?
2015-10-21 17:44:44,179 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:44:46,179 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:44:46,179 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-40) [] Exception during connection
2015-10-21 17:44:46,179 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
(DefaultQuartzScheduler_Worker-40) [] Command
'GetAllVmStatsVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:46,179 INFO
[org.ovirt.engine.core.vdsbroker.PollVmStatsRefresher]
(DefaultQuartzScheduler_Worker-40) [] Failed to fetch vms info for
host
'infraesx2' - skipping VMs monitoring.
2015-10-21 17:44:46,179 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:44:48,179 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:44:48,179 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-41) [] Exception during connection
2015-10-21 17:44:48,179 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-41) [] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:48,179 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-41) [] Failure to refresh Vds runtime
info:
java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:48,179 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-41) [] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:44:51,182 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:44:53,183 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:44:53,183 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-14) [22712a82] Exception during
connection
2015-10-21 17:44:53,183 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-14) [22712a82] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:53,183 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-14) [22712a82] Failure to refresh Vds
runtime
info: java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:53,183 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-14) [22712a82] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:44:56,187 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:44:58,187 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:44:58,187 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-11) [] Exception during connection
2015-10-21 17:44:58,187 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-11) [] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:58,187 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-11) [] Failure to refresh Vds runtime
info:
java.rmi.ConnectException: Connection timeout
2015-10-21 17:44:58,187 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-11) [] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:45:01,180 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:45:03,180 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:45:03,180 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-64) [] Exception during connection
2015-10-21 17:45:03,180 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
(DefaultQuartzScheduler_Worker-64) [] Command
'GetAllVmStatsVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:03,180 INFO
[org.ovirt.engine.core.vdsbroker.PollVmStatsRefresher]
(DefaultQuartzScheduler_Worker-64) [] Failed to fetch vms info for
host
'infraesx2' - skipping VMs monitoring.
2015-10-21 17:45:03,181 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:45:05,181 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:45:05,181 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-66) [] Exception during connection
2015-10-21 17:45:05,181 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-66) [] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:05,181 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-66) [] Failure to refresh Vds runtime
info:
java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:05,181 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-66) [] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:45:08,191 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:45:10,191 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:45:10,191 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-75) [] Exception during connection
2015-10-21 17:45:10,191 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-75) [] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:10,191 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-75) [] Failure to refresh Vds runtime
info:
java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:10,191 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-75) [] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:45:13,195 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:45:15,195 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:45:15,195 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-94) [] Exception during connection
2015-10-21 17:45:15,195 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-94) [] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:15,195 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-94) [] Failure to refresh Vds runtime
info:
java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:15,195 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-94) [] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:45:18,182 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:45:20,182 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:45:20,182 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-40) [] Exception during connection
2015-10-21 17:45:20,182 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand]
(DefaultQuartzScheduler_Worker-40) [] Command
'GetAllVmStatsVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:20,182 INFO
[org.ovirt.engine.core.vdsbroker.PollVmStatsRefresher]
(DefaultQuartzScheduler_Worker-40) [] Failed to fetch vms info for
host
'infraesx2' - skipping VMs monitoring.
2015-10-21 17:45:20,182 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-21 17:45:22,183 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable] (SSL Stomp
Reactor) []
Retry failed
2015-10-21 17:45:22,183 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(DefaultQuartzScheduler_Worker-60) [] Exception during connection
2015-10-21 17:45:22,183 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.GetCapabilitiesVDSCommand]
(DefaultQuartzScheduler_Worker-60) [] Command
'GetCapabilitiesVDSCommand(HostName = infraesx2,
VdsIdAndVdsVDSCommandParametersBase:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c',
vds='Host[infraesx2,2d74bd31-6894-4c9c-8260-97c305a6998c]'})'
execution
failed: java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:22,183 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-60) [] Failure to refresh Vds runtime
info:
java.rmi.ConnectException: Connection timeout
2015-10-21 17:45:22,183 ERROR
[org.ovirt.engine.core.vdsbroker.HostMonitoring]
(DefaultQuartzScheduler_Worker-60) [] Exception:
org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException:
java.rmi.ConnectException: Connection timeout
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:157)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:120)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33)
[dal.jar:]
        at
org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:467)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.refreshCapabilities(VdsManager.java:634)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refreshVdsRunTimeInfo(HostMonitoring.java:119)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.HostMonitoring.refresh(HostMonitoring.java:84)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:226)
[vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.invokeMethod(JobWrapper.java:81)
[scheduler.jar:]
        at
org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:52)
[scheduler.jar:]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
[quartz.jar:]
        at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
[quartz.jar:]
Caused by: java.rmi.ConnectException: Connection timeout
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:116)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-21 17:45:24,914 INFO
[org.ovirt.engine.core.bll.MaintenanceNumberOfVdssCommand]
(org.ovirt.thread.pool-8-thread-17) [6482a3e8] Running command:
MaintenanceNumberOfVdssCommand internal: false. Entities affected :
ID:
2d74bd31-6894-4c9c-8260-97c305a6998c Type: VDSAction group
MANIPULATE_HOST
with role type ADMIN
2015-10-21 17:45:24,931 INFO
[org.ovirt.engine.core.bll.MaintenanceVdsCommand]
(org.ovirt.thread.pool-8-thread-17) [6482a3e8] Running command:
MaintenanceVdsCommand internal: true. Entities affected :  ID:
2d74bd31-6894-4c9c-8260-97c305a6998c Type: VDS
2015-10-21 17:45:24,941 INFO
[org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
(org.ovirt.thread.pool-8-thread-17) [6482a3e8] START,
SetVdsStatusVDSCommand(HostName = infraesx2,
SetVdsStatusVDSCommandParameters:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c', status='Maintenance',
nonOperationalReason='NONE', stopSpmFailureLogged='false',
maintenanceReason='null'}), log id: c22525
2015-10-21 17:45:24,944 INFO
[org.ovirt.engine.core.vdsbroker.SetVdsStatusVDSCommand]
(org.ovirt.thread.pool-8-thread-17) [6482a3e8] FINISH,
SetVdsStatusVDSCommand, log id: c22525
2015-10-21 17:45:24,949 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-17) [6482a3e8] Correlation ID:
6482a3e8,
Job
ID: 226758ca-59df-489f-af7f-33cc96f97d30, Call Stack: null, Custom
Event
ID:
-1, Message: Host infraesx2 was switched to Maintenance mode by
admin@internal (Reason: Not Specified).
2015-10-21 17:45:31,262 INFO
[org.ovirt.engine.core.bll.RemoveVdsCommand]
(default task-16) [2e9e5834] Lock Acquired to object
'EngineLock:{exclusiveLocks='[2d74bd31-6894-4c9c-8260-97c305a6998c=<VDS,
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2015-10-21 17:45:31,268 INFO
[org.ovirt.engine.core.bll.RemoveVdsCommand]
(org.ovirt.thread.pool-8-thread-20) [2e9e5834] Running command:
RemoveVdsCommand internal: false. Entities affected :  ID:
2d74bd31-6894-4c9c-8260-97c305a6998c Type: VDSAction group
DELETE_HOST
with
role type ADMIN
2015-10-21 17:45:31,289 INFO
[org.ovirt.engine.core.vdsbroker.RemoveVdsVDSCommand]
(org.ovirt.thread.pool-8-thread-20) [2e9e5834] START,
RemoveVdsVDSCommand(
RemoveVdsVDSCommandParameters:{runAsync='true',
hostId='2d74bd31-6894-4c9c-8260-97c305a6998c'}), log id: 4aa64f93
2015-10-21 17:45:31,289 INFO
[org.ovirt.engine.core.vdsbroker.VdsManager]
(org.ovirt.thread.pool-8-thread-20) [2e9e5834] vdsManager::disposing
2015-10-21 17:45:31,290 WARN
[org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker]
(ResponseWorker)
[]
Exception thrown during message processing
2015-10-21 17:45:31,290 INFO
[org.ovirt.engine.core.vdsbroker.RemoveVdsVDSCommand]
(org.ovirt.thread.pool-8-thread-20) [2e9e5834] FINISH,
RemoveVdsVDSCommand,
log id: 4aa64f93
2015-10-21 17:45:31,292 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-20) [2e9e5834] Correlation ID:
2e9e5834,
Call Stack: null, Custom Event ID: -1, Message: Host infraesx2 was
removed
by admin@internal.
2015-10-21 17:45:31,292 INFO
[org.ovirt.engine.core.bll.RemoveVdsCommand]
(org.ovirt.thread.pool-8-thread-20) [2e9e5834] Lock freed to object
'EngineLock:{exclusiveLocks='[2d74bd31-6894-4c9c-8260-97c305a6998c=<VDS,
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2015-10-21 17:45:39,619 INFO
[org.ovirt.engine.core.bll.storage.RemoveStoragePoolCommand]
(org.ovirt.thread.pool-8-thread-19) [6b6695a5] Running command:
RemoveStoragePoolCommand internal: false. Entities affected :  ID:
fef2019c-d087-44f5-852e-40df4f749363 Type: StoragePoolAction group
DELETE_STORAGE_POOL with role type ADMIN
2015-10-21 17:45:39,651 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-19) [6b6695a5] Correlation ID:
6b6695a5,
Job
ID: 37859e0f-296d-4a37-b738-25c890d50d65, Call Stack: null, Custom
Event
ID:
-1, Message: Data Center Test was removed by admin@internal
2015-10-21 17:45:46,964 INFO
[org.ovirt.engine.core.bll.RemoveVdsGroupCommand]
(org.ovirt.thread.pool-8-thread-16) [23932ed9] Running command:
RemoveVdsGroupCommand internal: false. Entities affected :  ID:
32e20320-b0b1-416a-a733-55971bec2798 Type: VdsGroupsAction group
DELETE_CLUSTER with role type ADMIN
2015-10-21 17:45:47,005 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-16) [23932ed9] Correlation ID:
23932ed9,
Call Stack: null, Custom Event ID: -1, Message: Host cluster
infraesx2-Local
was removed by admin@internal
2015-10-21 17:45:53,005 INFO
[org.ovirt.engine.core.bll.RemoveVdsGroupCommand]
(org.ovirt.thread.pool-8-thread-18) [1af7dad2] Running command:
RemoveVdsGroupCommand internal: false. Entities affected :  ID:
00000001-0001-0001-0001-000000000060 Type: VdsGroupsAction group
DELETE_CLUSTER with role type ADMIN
2015-10-21 17:45:53,050 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(org.ovirt.thread.pool-8-thread-18) [1af7dad2] Correlation ID:
1af7dad2,
Call Stack: null, Custom Event ID: -1, Message: Host cluster Default
was
removed by admin@internal
2015-10-21 17:46:03,341 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(default task-11) [] Correlation ID: null, Call Stack: null, Custom
Event
ID: -1, Message: Refresh image list succeeded for domain(s):
ovirt-image-repository (All file type)Last login: Wed Oct 21 17:01:03
2015
from nbudoor-t440p.bnglab.psecure.net
[root@cstlb1 ~]#
[root@cstlb1 ~]#
[root@cstlb1 ~]#
[root@cstlb1 ~]# tail -f /var/log/ovirt-engine/engine.log
2015-10-26 11:37:31,475 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage: Misc
configuration.
2015-10-26 11:37:31,478 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage: Package
installation.
2015-10-26 11:37:31,815 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage: Misc
configuration.
2015-10-26 11:37:31,904 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Setting time.
2015-10-26 11:37:32,687 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Enrolling
certificate.
2015-10-26 11:37:34,255 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Enrolling serial
console
certificate.
2015-10-26 11:37:36,343 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage: Transaction
commit.
2015-10-26 11:37:36,473 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage: Closing up.
2015-10-26 11:37:43,867 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stopping libvirtd.
2015-10-26 11:37:44,014 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Starting vdsm.
2015-10-26 11:38:19,244 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Starting
ovirt-vmconsole-host-sshd.
2015-10-26 11:38:21,052 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage:
Pre-termination.
2015-10-26 11:38:21,072 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Retrieving
installation
logs to:
'/var/log/ovirt-engine/host-deploy/ovirt-host-deploy-20151026113821-infraesx2.bnglab.psecure.net-7ed18269.log'.2015-10-26
11:38:21,381 INFO
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
(VdsDeploy) [7ed18269] Correlation ID: 7ed18269, Call Stack: null,
Custom
Event ID: -1, Message: Installing Host infraesx2. Stage:
Termination.2015-10-26 11:38:21,439 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.972015-10-26
11:38:21,440 WARN
[org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable]
(SSL Stomp Reactor) [] Retry failed
2015-10-26 11:38:21,440 ERROR
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient]
(org.ovirt.thread.pool-8-thread-26) [] Exception during connection
2015-10-26 11:38:21,440 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.TimeBoundPollVDSCommand]
(org.ovirt.thread.pool-8-thread-25) [7ed18269] Error:
org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcRunTimeException:
Connection
issues during send request
2015-10-26 11:38:21,440 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.TimeBoundPollVDSCommand]
(org.ovirt.thread.pool-8-thread-25) [7ed18269] Exception:
java.util.concurrent.ExecutionException:
org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcRunTimeException:
Connection
issues during send request
        at
java.util.concurrent.FutureTask.report(FutureTask.java:122)
[rt.jar:1.7.0_85]
        at java.util.concurrent.FutureTask.get(FutureTask.java:202)
[rt.jar:1.7.0_85]
        at
org.ovirt.engine.core.vdsbroker.vdsbroker.FutureVDSCommand.get(FutureVDSCommand.java:72)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.bll.transport.ProtocolDetector.attemptConnection(ProtocolDetector.java:56)
[bll.jar:]
        at
org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand.installHost(InstallVdsInternalCommand.java:204)
[bll.jar:]
        at
org.ovirt.engine.core.bll.hostdeploy.InstallVdsInternalCommand.executeCommand(InstallVdsInternalCommand.java:93)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1211)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1355)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1979)
[bll.jar:]
        at
org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:174)
[utils.jar:]
        at
org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:116)
[utils.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1392)
[bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:374)
[bll.jar:]
        at
org.ovirt.engine.core.bll.Backend.runAction(Backend.java:475)
[bll.jar:]
        at
org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:457)
[bll.jar:]
        at
org.ovirt.engine.core.bll.Backend.runInternalAction(Backend.java:667)
[bll.jar:]
        at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)
        at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:407)
        at
org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:70)
[wildfly-weld-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:80)
[wildfly-weld-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93)
[wildfly-weld-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)
        at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:407)
        at
org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:55)
[weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at
org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83)
[wildfly-weld-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
[wildfly-ee-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at
org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:52)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:260)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:399)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:243)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:95)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59)
[wildfly-ejb3-8.2.0.Final.jar:8.2.0.Final]
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:326)
        at
org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:448)
        at
org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:326)
        at
org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at
org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185)
        at
org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182)
        at
org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)
        at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
        at
org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)
        at
org.ovirt.engine.core.bll.interfaces.BackendInternal$$$view5.runInternalAction(Unknown
Source) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor184.invoke(Unknown
Source)
[:1.7.0_85]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[rt.jar:1.7.0_85]
        at java.lang.reflect.Method.invoke(Method.java:606)
[rt.jar:1.7.0_85]
        at
org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:414)
[weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at
org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:127)
[weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at
org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56)
[weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at
org.jboss.weld.bean.proxy.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:65)
[weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at
org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100)
[weld-core-impl-2.2.6.Final.jar:2014-10-03 10:05]
        at
org.ovirt.engine.core.bll.BackendCommandObjectsHandler$BackendInternal$BackendLocal$2049259618$Proxy$_$$_Weld$EnterpriseProxy$.runInternalAction(Unknown
Source) [bll.jar:]
        at
org.ovirt.engine.core.bll.CommandBase.runInternalAction(CommandBase.java:2342)
[bll.jar:]
        at
org.ovirt.engine.core.bll.hostdeploy.AddVdsCommand.access$800(AddVdsCommand.java:67)
[bll.jar:]
        at
org.ovirt.engine.core.bll.hostdeploy.AddVdsCommand$3.run(AddVdsCommand.java:196)
[bll.jar:]
        at
org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:92)
[utils.jar:]
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[rt.jar:1.7.0_85]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[rt.jar:1.7.0_85]
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[rt.jar:1.7.0_85]
        at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_85]
Caused by:
org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcRunTimeException:
Connection issues during send request
        at
org.ovirt.engine.core.vdsbroker.jsonrpc.FutureMap.<init>(FutureMap.java:89)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.jsonrpc.JsonRpcVdsServer$3.call(JsonRpcVdsServer.java:1012)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.jsonrpc.JsonRpcVdsServer$3.call(JsonRpcVdsServer.java:1008)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.jsonrpc.JsonRpcVdsServer$FutureCallable.call(JsonRpcVdsServer.java:482)
[vdsbroker.jar:]
        at
org.ovirt.engine.core.vdsbroker.jsonrpc.JsonRpcVdsServer$FutureCallable.call(JsonRpcVdsServer.java:471)
[vdsbroker.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        ... 5 more
Caused by: org.ovirt.vdsm.jsonrpc.client.ClientConnectionException:
java.util.concurrent.ExecutionException: java.net.ConnectException:
Connection refused
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.connect(ReactorClient.java:142)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.JsonRpcClient.getClient(JsonRpcClient.java:115)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.JsonRpcClient.call(JsonRpcClient.java:73)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.engine.core.vdsbroker.jsonrpc.FutureMap.<init>(FutureMap.java:87)
[vdsbroker.jar:]
        ... 10 more
Caused by: java.net.ConnectException: Connection refused
        at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[rt.jar:1.7.0_85]
        at
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:114)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient$1.call(ReactorClient.java:100)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.utils.retry.Retryable.call(Retryable.java:27)
[vdsm-jsonrpc-java-client.jar:]
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[rt.jar:1.7.0_85]
        at
org.ovirt.vdsm.jsonrpc.client.utils.ReactorScheduler.performPendingOperations(ReactorScheduler.java:28)
[vdsm-jsonrpc-java-client.jar:]
        at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.run(Reactor.java:61)
[vdsm-jsonrpc-java-client.jar:]
2015-10-26 11:38:21,446 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.TimeBoundPollVDSCommand]
(org.ovirt.thread.pool-8-thread-25) [7ed18269] Command
'TimeBoundPollVDSCommand(HostName = infraesx2,
TimeBoundPollVDSCommandParameters:{runAsync='true',
hostId='e2931140-c6c1-4d88-81ab-210bbfd23593'})' execution failed:
java.util.concurrent.ExecutionException:
org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcRunTimeException:
Connection
issues during send request
2015-10-26 11:38:26,450 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-26 11:38:26,578 INFO
[org.ovirt.engine.core.bll.network.NetworkConfigurator]
(org.ovirt.thread.pool-8-thread-25) [7ed18269] Engine managed to
communicate
with VDSM agent on host 'infraesx2'
('e2931140-c6c1-4d88-81ab-210bbfd23593')
2015-10-26 11:38:26,953 INFO
[org.ovirt.engine.core.bll.network.host.HostSetupNetworksCommand]
(org.ovirt.thread.pool-8-thread-25) [5f48a291] Lock Acquired to
object
'EngineLock:{exclusiveLocks='[e2931140-c6c1-4d88-81ab-210bbfd23593=<HOST_NETWORK,
ACTION_TYPE_FAILED_SETUP_NETWORKS_IN_PROGRESS>]',
sharedLocks='null'}'
2015-10-26 11:38:26,974 INFO
[org.ovirt.engine.core.bll.network.host.HostSetupNetworksCommand]
(org.ovirt.thread.pool-8-thread-25) [5f48a291] Running command:
HostSetupNetworksCommand internal: true. Entities affected :  ID:
e2931140-c6c1-4d88-81ab-210bbfd23593 Type: VDSAction group
CONFIGURE_HOST_NETWORK with role type ADMIN
2015-10-26 11:38:26,976 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HostSetupNetworksVDSCommand]
(org.ovirt.thread.pool-8-thread-25) [5f48a291] START,
HostSetupNetworksVDSCommand(HostName = infraesx2,
HostSetupNetworksVdsCommandParameters:{runAsync='true',
hostId='e2931140-c6c1-4d88-81ab-210bbfd23593',
vds='Host[infraesx2,e2931140-c6c1-4d88-81ab-210bbfd23593]',
rollbackOnFailure='true', conectivityTimeout='120',
hostNetworkQosSupported='true',
networks='[HostNetwork:{defaultRoute='true',
bonding='false', networkName='ovirtmgmt', nicName='enp2s0f0',
vlan='null',
mtu='0', vmNetwork='true', stp='false', properties='null',
bootProtocol='DHCP', address='10.206.68.97', netmask='255.255.254.0',
gateway='null'}]', removedNetworks='[]', bonds='[]',
removedBonds='[]'}),
log id: 507e585d
2015-10-26 11:38:26,976 INFO
[org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient] (SSL Stomp
Reactor)
[] Connecting to infraesx2.bnglab.psecure.net/10.206.68.97
2015-10-26 11:38:26,981 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HostSetupNetworksVDSCommand]
(org.ovirt.thread.pool-8-thread-25) [5f48a291] FINISH,
HostSetupNetworksVDSCommand, log id: 507e585d
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users