<div dir="ltr">Same issue with unknown message that we've seen before?<div><div>2017-03-08 00:06:12,648-05 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugNicVDSCommand] (default task-27) [2a00cec7] START, HotPlugNicVDSCommand(HostName = lago-basic-suite-master-host1, VmNicDeviceVDSParameters:{runAsync='true', hostId='19f3a57f-a9e1-4e13-b62a-39d92eb76ab6', vm.vm_name='vm0', nic='VmNetworkInterface:{id='36489e46-0717-4e6a-b123-1c0999624eba', networkName='null', vnicProfileName='null', vnicProfileId='4682b9a6-e613-4302-ae0f-ce2997488dce', speed='1000', type='3', macAddress='00:1a:4a:16:01:52', active='true', linked='true', portMirroring='false', vmId='7678dd6d-8e91-4c40-b078-4f4d79103d4e', vmName='null', vmTemplateId='null', QoSName='null', remoteNetworkName='null'}', vmDevice='VmDevice:{id='VmDeviceId:{deviceId='36489e46-0717-4e6a-b123-1c0999624eba', vmId='7678dd6d-8e91-4c40-b078-4f4d79103d4e'}', device='bridge', type='INTERFACE', specParams='[]', address='', managed='true', plugged='true', readOnly='false', deviceAlias='', customProperties='[]', snapshotId='null', logicalName='null', hostDevice='null'}'}), log id: 6031c6c8</div><div>2017-03-08 00:06:12,657-05 DEBUG [org.ovirt.engine.core.utils.timer.FixedDelayJobListener] (DefaultQuartzScheduler2) [] Rescheduling DEFAULT.org.ovirt.engine.core.bll.HaAutoStartVmsRunner.startFailedAutoStartVms#-9223372036854775793 as there is no unfired trigger.</div><div>2017-03-08 00:06:12,660-05 DEBUG [org.ovirt.engine.core.vdsbroker.builder.vminfo.VmInfoBuildUtils] (default task-27) [2a00cec7] VNIC 'eth1' is using profile 'VnicProfile:{id='4682b9a6-e613-4302-ae0f-ce2997488dce', networkId='861dd3dc-e67f-408b-a1d8-9a459573f04b', networkQosId='null', portMirroring='false', passthrough='false', migratable='false', customProperties='[]', description='null', networkFilterId='58bf8d93-0325-03e7-007f-000000000159'}' on network 'ovirtmgmt'</div><div>2017-03-08 00:06:12,662-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (default task-27) [2a00cec7] SEND</div><div>destination:jms.topic.vdsm_requests</div><div>reply-to:jms.topic.vdsm_responses</div><div>content-length:479</div><div><br></div><div>{"jsonrpc":"2.0","method":"VM.hotplugNic","params":{"vmID":"7678dd6d-8e91-4c40-b078-4f4d79103d4e","params":{"vmId":"7678dd6d-8e91-4c40-b078-4f4d79103d4e","nic":{"filter":"vdsm-no-mac-spoofing","nicModel":"pv","filterParameters":[],"type":"interface","specParams":{"inbound":{},"outbound":{}},"device":"bridge","linkActive":"true","deviceId":"36489e46-0717-4e6a-b123-1c0999624eba","macAddr":"00:1a:4a:16:01:52","network":"ovirtmgmt"}}},"id":"f1bda13b-5833-4306-9f0d-fc65fd8e909b"}�</div><div>2017-03-08 00:06:12,662-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient] (default task-27) [2a00cec7] Message sent: SEND</div><div>destination:jms.topic.vdsm_requests</div><div>content-length:479</div><div>reply-to:jms.topic.vdsm_responses</div><div><br></div><div><JsonRpcRequest id: "f1bda13b-5833-4306-9f0d-fc65fd8e909b", method: VM.hotplugNic, params: {vmID=7678dd6d-8e91-4c40-b078-4f4d79103d4e, params={vmId=7678dd6d-8e91-4c40-b078-4f4d79103d4e, nic={filter=vdsm-no-mac-spoofing, nicModel=pv, filterParameters=[], type=interface, specParams={inbound={}, outbound={}}, device=bridge, linkActive=true, deviceId=36489e46-0717-4e6a-b123-1c0999624eba, macAddr=00:1a:4a:16:01:52, network=ovirtmgmt}}}></div><div>2017-03-08 00:06:12,889-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (DefaultQuartzScheduler10) [] START, GetAllVmStatsVDSCommand(HostName = lago-basic-suite-master-host1, VdsIdVDSCommandParametersBase:{runAsync='true', hostId='19f3a57f-a9e1-4e13-b62a-39d92eb76ab6'}), log id: 381b2e14</div><div>2017-03-08 00:06:12,889-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (DefaultQuartzScheduler10) [] SEND</div><div>destination:jms.topic.vdsm_requests</div><div>reply-to:jms.topic.vdsm_responses</div><div>content-length:103</div><div><br></div><div>{"jsonrpc":"2.0","method":"Host.getAllVmStats","params":{},"id":"13fc6056-2c50-424b-bbf9-b89e455b412b"}�</div><div>2017-03-08 00:06:12,889-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient] (DefaultQuartzScheduler10) [] Message sent: SEND</div><div>destination:jms.topic.vdsm_requests</div><div>content-length:103</div><div>reply-to:jms.topic.vdsm_responses</div><div><br></div><div><JsonRpcRequest id: "13fc6056-2c50-424b-bbf9-b89e455b412b", method: Host.getAllVmStats, params: {}></div><div>2017-03-08 00:06:12,895-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (SSL Stomp Reactor) [b23d75f] MESSAGE</div><div>content-length:879</div><div>destination:jms.topic.vdsm_responses</div><div>content-type:application/json</div><div>subscription:5221635b-a79f-478f-929a-17af47c83ab0</div><div><br></div><div>{"jsonrpc": "2.0", "id": "13fc6056-2c50-424b-bbf9-b89e455b412b", "result": [{"username": "Unknown", "displayInfo": [{"tlsPort": "-1", "ipAddress": "192.168.201.4", "type": "vnc", "port": "5900"}, {"tlsPort": "5901", "ipAddress": "192.168.201.4", "type": "spice", "port": "-1"}], "hash": "910760387343530858", "acpiEnable": "true", "displayIp": "192.168.201.4", "guestFQDN": "", "vmId": "7678dd6d-8e91-4c40-b078-4f4d79103d4e", "pid": "19411", "timeOffset": "0", "session": "Unknown", "displaySecurePort": "-1", "displayPort": "5900", "memUsage": "0", "guestIPs": "", "vcpuQuota": "-1", "kvmEnable": "true", "displayType": "vnc", "cpuUser": "0.00", "vmJobs": {}, "monitorResponse": "0", "elapsedTime": "437", "vmType": "kvm", "cpuSys": "0.00", "status": "Up", "guestCPUCount": -1, "appsList": [], "clientIp": "", "statusTime": "4295791390", "vmName": "vm0", "vcpuPeriod": 100000}]}</div><div>2017-03-08 00:06:12,895-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) [] Message received: {"jsonrpc": "2.0", "id": "13fc6056-2c50-424b-bbf9-b89e455b412b", "result": [{"username": "Unknown", "displayInfo": [{"tlsPort": "-1", "ipAddress": "192.168.201.4", "type": "vnc", "port": "5900"}, {"tlsPort": "5901", "ipAddress": "192.168.201.4", "type": "spice", "port": "-1"}], "hash": "910760387343530858", "acpiEnable": "true", "displayIp": "192.168.201.4", "guestFQDN": "", "vmId": "7678dd6d-8e91-4c40-b078-4f4d79103d4e", "pid": "19411", "timeOffset": "0", "session": "Unknown", "displaySecurePort": "-1", "displayPort": "5900", "memUsage": "0", "guestIPs": "", "vcpuQuota": "-1", "kvmEnable": "true", "displayType": "vnc", "cpuUser": "0.00", "vmJobs": {}, "monitorResponse": "0", "elapsedTime": "437", "vmType": "kvm", "cpuSys": "0.00", "status": "Up", "guestCPUCount": -1, "appsList": [], "clientIp": "", "statusTime": "4295791390", "vmName": "vm0", "vcpuPeriod": 100000}]}</div><div>2017-03-08 00:06:12,896-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (DefaultQuartzScheduler10) [] FINISH, GetAllVmStatsVDSCommand, return: {7678dd6d-8e91-4c40-b078-4f4d79103d4e=org.ovirt.engine.core.vdsbroker.monitoring.VdsmVm@cfaba8fb}, log id: 381b2e14</div><div>2017-03-08 00:06:12,898-05 DEBUG [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler10) [] 7678dd6d:Up </div><div>2017-03-08 00:06:12,898-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Executing batch for procedure UpdateVmDynamic</div><div>2017-03-08 00:06:12,898-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Mapped params: [v_vm_guid, v_app_list, v_guest_cur_user_name, v_console_cur_user_name, v_console_user_id, v_guest_os, v_migrating_to_vds, v_run_on_vds, v_status, v_vm_host, v_vm_ip, v_vm_fqdn, v_last_start_time, v_last_stop_time, v_acpi_enable, v_session, v_boot_sequence, v_utc_diff, v_client_ip, v_guest_requested_memory, v_exit_status, v_pause_status, v_exit_message, v_guest_agent_nics_hash, v_last_watchdog_event, v_last_watchdog_action, v_is_run_once, v_cpu_name, v_guest_agent_status, v_current_cd, v_reason, v_exit_reason, v_guest_cpu_count, v_emulated_machine, v_spice_port, v_spice_tls_port, v_spice_ip, v_vnc_port, v_vnc_ip, v_guest_timezone_name, v_guest_timezone_offset, v_guestos_arch, v_guestos_codename, v_guestos_distribution, v_guestos_kernel_version, v_guestos_type, v_guestos_version, v_guest_containers]</div><div>2017-03-08 00:06:12,900-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Executed batch</div><div>2017-03-08 00:06:12,900-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Executing batch for procedure UpdateVmStatistics</div><div>2017-03-08 00:06:12,900-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Mapped params: [v_vm_guid, v_cpu_sys, v_cpu_user, v_elapsed_time, v_usage_cpu_percent, v_usage_mem_percent, v_usage_network_percent, v_disks_usage, v_guest_mem_buffered, v_guest_mem_cached]</div><div>2017-03-08 00:06:12,901-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Executed batch</div><div>2017-03-08 00:06:12,901-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Executing batch for procedure Updatedisk_image_dynamic_by_disk_id_and_vm_id</div><div>2017-03-08 00:06:12,901-05 DEBUG [org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback] (DefaultQuartzScheduler10) [] Executed batch</div><div>2017-03-08 00:06:12,902-05 DEBUG [org.ovirt.engine.core.utils.timer.FixedDelayJobListener] (DefaultQuartzScheduler10) [] Rescheduling DEFAULT.org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher.poll#-9223372036854775735 as there is no unfired trigger.</div><div>2017-03-08 00:06:12,956-05 DEBUG [org.ovirt.engine.core.utils.timer.FixedDelayJobListener] (DefaultQuartzScheduler9) [] Rescheduling DEFAULT.org.ovirt.engine.core.bll.ColdRebootAutoStartVmsRunner.startFailedAutoStartVms#-9223372036854775733 as there is no unfired trigger.</div><div>2017-03-08 00:06:12,972-05 DEBUG [org.ovirt.engine.core.utils.timer.FixedDelayJobListener] (DefaultQuartzScheduler3) [] Rescheduling DEFAULT.org.ovirt.engine.core.vdsbroker.VdsManager.onTimer#-9223372036854775741 as there is no unfired trigger.</div><div>2017-03-08 00:06:13,093-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (SSL Stomp Reactor) [b23d75f] �MESSAGE</div><div>content-length:10098</div><div>destination:jms.topic.vdsm_responses</div><div>content-type:application/json</div><div>subscription:5221635b-a79f-478f-929a-17af47c83ab0</div><div><br></div><div>{"jsonrpc": "2.0", "id": "f1bda13b-5833-4306-9f0d-fc65fd8e909b", "result": {"acpiEnable": "true", "emulatedMachine": "pc-i440fx-rhel7.3.0", "afterMigrationStatus": "", "pid": "19411", "memGuaranteedSize": 256, "transparentHugePages": "false", "timeOffset": "0", "cpuType": "Westmere", "smp": "1", "guestNumaNodes": [{"nodeIndex": 0, "cpus": "0", "memory": "512"}], "smartcardEnable": "true", "custom": {}, "vmType": "kvm", "memSize": 512, "smpCoresPerSocket": "1", "vmName": "vm0", "nice": "0", "status": "Up", "maxMemSize": 4096, "bootMenuEnable": "false", "vmId": "7678dd6d-8e91-4c40-b078-4f4d79103d4e", "smpThreadsPerCore": "1", "agentChannelName": "ovirt-guest-agent.0", "guestDiskMapping": {}, "kvmEnable": "true", "pitReinjection": "false", "displayNetwork": "ovirtmgmt", "devices": [{"alias": "sound0", "specParams": {}, "deviceId": "f503494f-ffb4-4d20-b53a-a43e600cc86</div><div>2017-03-08 00:06:13,094-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (SSL Stomp Reactor) [b23d75f] Message received: �MESSAGE</div><div>content-length:10098</div><div>destination:jms.topic.vdsm_responses</div><div>content-type:application/json</div><div>subscription:5221635b-a79f-478f-929a-17af47c83ab0</div><div><br></div><div>{"jsonrpc": "2.0", "id": "f1bda13b-5833-4306-9f0d-fc65fd8e909b", "result": {"acpiEnable": "true", "emulatedMachine": "pc-i440fx-rhel7.3.0", "afterMigrationStatus": "", "pid": "19411", "memGuaranteedSize": 256, "transparentHugePages": "false", "timeOffset": "0", "cpuType": "Westmere", "smp": "1", "guestNumaNodes": [{"nodeIndex": 0, "cpus": "0", "memory": "512"}], "smartcardEnable": "true", "custom": {}, "vmType": "kvm", "memSize": 512, "smpCoresPerSocket": "1", "vmName": "vm0", "nice": "0", "status": "Up", "maxMemSize": 4096, "bootMenuEnable": "false", "vmId": "7678dd6d-8e91-4c40-b078-4f4d79103d4e", "smpThreadsPerCore": "1", "agentChannelName": "ovirt-guest-agent.0", "guestDiskMapping": {}, "kvmEnable": "true", "pitReinjection": "false", "displayNetwork": "ovirtmgmt", "devices": [{"alias": "sound0", "specParams": {}, "deviceId": "f503494f-ffb4-4d20-b53a-a43e600cc86</div><div>2017-03-08 00:06:13,094-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.Reactor] (SSL Stomp Reactor) [b23d75f] Unable to process messages Unrecognized message received : org.ovirt.vdsm.jsonrpc.client.ClientConnectionException: Unrecognized message received </div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message.parse(Message.java:219) [vdsm-jsonrpc-java-client.jar:]</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.getMessage(StompCommonClient.java:171) [vdsm-jsonrpc-java-client.jar:]</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.processIncoming(StompCommonClient.java:115) [vdsm-jsonrpc-java-client.jar:]</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.process(ReactorClient.java:195) [vdsm-jsonrpc-java-client.jar:]</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.process(SSLClient.java:121) [vdsm-jsonrpc-java-client.jar:]</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.lambda$processChannels$2(Reactor.java:80) [vdsm-jsonrpc-java-client.jar:]</div><div><span class="Apple-tab-span" style="white-space:pre"> </span>at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184) [rt.jar:1.8.0_121]</div></div></div><br><div class="gmail_quote"><div dir="ltr">On Wed, Mar 8, 2017 at 9:36 AM Daniel Belenky <<a href="mailto:dbelenky@redhat.com">dbelenky@redhat.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr" class="gmail_msg"><b class="gmail_msg">Test failed: </b>basic_sanity.hogplug_nic<div class="gmail_msg"><br class="gmail_msg"></div><div class="gmail_msg"><b class="gmail_msg">Link to failed job: </b><a href="http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experimental_master/5728/" class="gmail_msg" target="_blank">test-repo_ovirt_experimental_master/5728</a></div><div class="gmail_msg"><br class="gmail_msg"></div><div class="gmail_msg"><b class="gmail_msg">Link to all logs:</b> <a href="http://jenkins.ovirt.org/view/experimental%20jobs/job/test-repo_ovirt_experimental_master/5728/artifact/exported-artifacts/basic-suit-master-el7/" class="gmail_msg" target="_blank">logs from Jenkins</a></div><div class="gmail_msg"><b class="gmail_msg"><br class="gmail_msg"></b></div><div class="gmail_msg"><b class="gmail_msg">Error snippet from log:</b></div><div class="gmail_msg"><b class="gmail_msg"></b><blockquote style="margin:0px 0px 0px 40px;border:none;padding:0px" class="gmail_msg"><div class="gmail_msg"><pre style="box-sizing:border-box;white-space:pre-wrap;word-wrap:break-word;margin-top:0px;margin-bottom:0px;color:rgb(51,51,51);font-size:14px" class="gmail_msg">Traceback (most recent call last):
File "/usr/lib64/python2.7/unittest/case.py", line 369, in run
testMethod()
File "/usr/lib/python2.7/site-packages/nose/case.py", line 197, in runTest
self.test(*self.arg)
File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 129, in wrapped_test
test()
File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 59, in wrapper
return func(get_test_prefix(), *args, **kwargs)
File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 68, in wrapper
return func(prefix.virt_env.engine_vm().get_api(), *args, **kwargs)
File "/home/jenkins/workspace/test-repo_ovirt_experimental_master/ovirt-system-tests/basic-suite-master/test-scenarios/004_basic_sanity.py", line 457, in hotplug_nic
api.vms.get(VM0_NAME).nics.add(nic2_params)
File "/usr/lib/python2.7/site-packages/ovirtsdk/infrastructure/brokers.py", line 33398, in add
headers={"Correlation-Id":correlation_id, "Expect":expect}
File "/usr/lib/python2.7/site-packages/ovirtsdk/infrastructure/proxy.py", line 79, in add
return self.request('POST', url, body, headers, cls=cls)
File "/usr/lib/python2.7/site-packages/ovirtsdk/infrastructure/proxy.py", line 122, in request
persistent_auth=self.__persistent_auth
File "/usr/lib/python2.7/site-packages/ovirtsdk/infrastructure/connectionspool.py", line 79, in do_request
persistent_auth)
File "/usr/lib/python2.7/site-packages/ovirtsdk/infrastructure/connectionspool.py", line 162, in __do_request
raise errors.RequestError(response_code, response_reason, response_body)
RequestError:
status: 400
reason: Bad Request
detail: Network error during communication with the Host.</pre></div></blockquote></div><div class="gmail_msg"><div class="gmail_msg"><br class="gmail_msg"></div>-- <br class="gmail_msg"><div class="m_4950503365524934719gmail_signature gmail_msg"><div dir="ltr" class="gmail_msg"><div class="gmail_msg"><div dir="ltr" class="gmail_msg"><div class="gmail_msg"><div dir="ltr" class="gmail_msg"><div class="gmail_msg"><div class="gmail_msg"><div class="gmail_msg"><span style="background-color:rgb(255,255,255)" class="gmail_msg"><span style="color:rgb(0,0,0)" class="gmail_msg"><i class="gmail_msg">Daniel Belenky<br class="gmail_msg"></i></span></span></div><span style="background-color:rgb(255,255,255)" class="gmail_msg"><span style="color:rgb(0,0,0)" class="gmail_msg"><i class="gmail_msg">RHV DevOps<br class="gmail_msg"></i></span></span></div><span style="background-color:rgb(255,255,255)" class="gmail_msg"><span style="color:rgb(0,0,0)" class="gmail_msg"><i class="gmail_msg">Red Hat Israel<br class="gmail_msg"></i></span></span></div></div></div></div></div></div></div>
</div></div>
_______________________________________________<br class="gmail_msg">
Devel mailing list<br class="gmail_msg">
<a href="mailto:Devel@ovirt.org" class="gmail_msg" target="_blank">Devel@ovirt.org</a><br class="gmail_msg">
<a href="http://lists.ovirt.org/mailman/listinfo/devel" rel="noreferrer" class="gmail_msg" target="_blank">http://lists.ovirt.org/mailman/listinfo/devel</a></blockquote></div>