Yes, it is related to the issue with setupNetworks that we work on at
the moment.
On Wed, Mar 8, 2017 at 9:09 AM, Yaniv Kaul <ykaul(a)redhat.com> wrote:
Same issue with unknown message that we've seen before?
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
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.
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'
2017-03-08 00:06:12,662-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (default
task-27) [2a00cec7] SEND
destination:jms.topic.vdsm_requests
reply-to:jms.topic.vdsm_responses
content-length:479
{"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"}�
2017-03-08 00:06:12,662-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient] (default
task-27) [2a00cec7] Message sent: SEND
destination:jms.topic.vdsm_requests
content-length:479
reply-to:jms.topic.vdsm_responses
<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}}}>
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
2017-03-08 00:06:12,889-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message]
(DefaultQuartzScheduler10) [] SEND
destination:jms.topic.vdsm_requests
reply-to:jms.topic.vdsm_responses
content-length:103
{"jsonrpc":"2.0","method":"Host.getAllVmStats","params":{},"id":"13fc6056-2c50-424b-bbf9-b89e455b412b"}�
2017-03-08 00:06:12,889-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient]
(DefaultQuartzScheduler10) [] Message sent: SEND
destination:jms.topic.vdsm_requests
content-length:103
reply-to:jms.topic.vdsm_responses
<JsonRpcRequest id: "13fc6056-2c50-424b-bbf9-b89e455b412b", method:
Host.getAllVmStats, params: {}>
2017-03-08 00:06:12,895-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (SSL Stomp
Reactor) [b23d75f] MESSAGE
content-length:879
destination:jms.topic.vdsm_responses
content-type:application/json
subscription:5221635b-a79f-478f-929a-17af47c83ab0
{"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}]}
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}]}
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
2017-03-08 00:06:12,898-05 DEBUG
[org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
(DefaultQuartzScheduler10) [] 7678dd6d:Up
2017-03-08 00:06:12,898-05 DEBUG
[org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback]
(DefaultQuartzScheduler10) [] Executing batch for procedure UpdateVmDynamic
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]
2017-03-08 00:06:12,900-05 DEBUG
[org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback]
(DefaultQuartzScheduler10) [] Executed batch
2017-03-08 00:06:12,900-05 DEBUG
[org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback]
(DefaultQuartzScheduler10) [] Executing batch for procedure
UpdateVmStatistics
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]
2017-03-08 00:06:12,901-05 DEBUG
[org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback]
(DefaultQuartzScheduler10) [] Executed batch
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
2017-03-08 00:06:12,901-05 DEBUG
[org.ovirt.engine.core.dal.dbbroker.BatchProcedureExecutionConnectionCallback]
(DefaultQuartzScheduler10) [] Executed batch
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.
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.
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.
2017-03-08 00:06:13,093-05 DEBUG
[org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (SSL Stomp
Reactor) [b23d75f] �MESSAGE
content-length:10098
destination:jms.topic.vdsm_responses
content-type:application/json
subscription:5221635b-a79f-478f-929a-17af47c83ab0
{"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
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
content-length:10098
destination:jms.topic.vdsm_responses
content-type:application/json
subscription:5221635b-a79f-478f-929a-17af47c83ab0
{"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
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
at
org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message.parse(Message.java:219)
[vdsm-jsonrpc-java-client.jar:]
at
org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.getMessage(StompCommonClient.java:171)
[vdsm-jsonrpc-java-client.jar:]
at
org.ovirt.vdsm.jsonrpc.client.reactors.stomp.StompCommonClient.processIncoming(StompCommonClient.java:115)
[vdsm-jsonrpc-java-client.jar:]
at
org.ovirt.vdsm.jsonrpc.client.reactors.ReactorClient.process(ReactorClient.java:195)
[vdsm-jsonrpc-java-client.jar:]
at
org.ovirt.vdsm.jsonrpc.client.reactors.SSLClient.process(SSLClient.java:121)
[vdsm-jsonrpc-java-client.jar:]
at
org.ovirt.vdsm.jsonrpc.client.reactors.Reactor.lambda$processChannels$2(Reactor.java:80)
[vdsm-jsonrpc-java-client.jar:]
at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
[rt.jar:1.8.0_121]
On Wed, Mar 8, 2017 at 9:36 AM Daniel Belenky <dbelenky(a)redhat.com> wrote:
>
> Test failed: basic_sanity.hogplug_nic
>
> Link to failed job: test-repo_ovirt_experimental_master/5728
>
> Link to all logs: logs from Jenkins
>
> Error snippet from log:
>
> 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.
>
>
> --
> Daniel Belenky
> RHV DevOps
> Red Hat Israel
> _______________________________________________
> Devel mailing list
> Devel(a)ovirt.org
>
http://lists.ovirt.org/mailman/listinfo/devel
_______________________________________________
Devel mailing list
Devel(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/devel