Bug 730062 - Invalid string in json text passed to libvirt on SPICE_DISCONNECTED event.
Summary: Invalid string in json text passed to libvirt on SPICE_DISCONNECTED event.
Status: CLOSED DUPLICATE of bug 697441
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: qemu-kvm
Version: 6.2
Hardware: Unspecified
OS: Linux
Target Milestone: rc
: ---
Assignee: David Blechter
QA Contact: Virtualization Bugs
Depends On:
TreeView+ depends on / blocked
Reported: 2011-08-11 16:33 UTC by Marian Krcmarik
Modified: 2013-01-10 00:13 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Last Closed: 2011-08-26 14:04:40 UTC

Attachments (Terms of Use)

Description Marian Krcmarik 2011-08-11 16:33:09 UTC
Description of problem
Libvirt sometimes complains about getting Invalid string in json text from Qemu Monitor on SPICE_DISCONNECTED event.
For the exact message, please see attachment where I attached several examples of such message.
it's noticeable when using many VM through RHEVM, after disconnecting spice client from VM. Once one wanna try to connect again, User Portal complains about: "Unexpected exception", vdsm complains about libvirt error, and libvirt complains about wrong json text of  SPICE_DISCONNECTED event. Those messages are repeating in logs till the VM is shutdowned. Nothing interesting in qemu output (attaching as well).

Version-Release number of selected component (if applicable):
RHEVM (beta1 - ic136)
Guest: Windows7x32 (with 3.0-14 guest tools), 30GB disk (thin provisioning), latest updates.

How reproducible:
It's (when you are trying long enough).

Steps to Reproduce:
1. Connect to a VM through RHEVM User Portal using spice client.
2. Disconnect from VM (close spice client).
3. Repeat Step 1. and 2. till User Portal prints Unexpected exception and does not open spice session.
Actual results:
UP: UNexcepted Exception.

thread-154788::ERROR::2011-08-11 18:26:26,120::utils::369::vm.Vm::(collect) vmId=`8829251f-09f1-4dc6-a1a1-ec10dfa2f353`::Stats function failed: <AdvancedStatsFunction _highWrite at 0x1cd5880>
Traceback (most recent call last):
  File "/usr/share/vdsm/utils.py", line 366, in collect
  File "/usr/share/vdsm/utils.py", line 250, in __call__
    retValue = self._function(*args, **kwargs)
  File "/usr/share/vdsm/libvirtvm.py", line 65, in _highWrite
    self._vm._dom.blockInfo(vmDrive.path, 0)
  File "/usr/share/vdsm/libvirtvm.py", line 327, in f
    ret = attr(*args, **kwargs)
  File "/usr/share/vdsm/libvirtconnection.py", line 63, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1284, in blockInfo
    if ret is None: raise libvirtError ('virDomainGetBlockInfo() failed', dom=self)
libvirtError: internal error cannot parse json {"timestamp": {"seconds": 1313077093, "microseconds": 689265}, "event": "SPICE_DISCONNECTED", "data": {"server": {"port": "5900", "family": "ipv4", "host": ""}, "client": {"port": "38645", "family":{"ip"timv4", ":ost": "10.34{29.89""se{"timestamp": {"seconds": 1313077093, "microseconds": 689265}, "event": "SPICE_DISCONNECTED", "data": {"server": {"port": "5900", "family": "ipv4", "host": ""}, "client": {"port": "38645", "family":{"ip"timv4", ":ost": "10.34{29.89""seconds": 1313077093, "microseconds": 689245}, "event": "__com.redh{"timestamp": {"seconds":data": {"server": {"auth": "spice", "port": "5901", "family": "ipv4", "host": ""}, "client": {"port": "35077", "family": "ipv4", "host": ""}}}: lexical error: invalid string in json text.
          ort": "38645", "family":{"ip"timv4", ":ost": "10.34{29.89""s
                     (right here) ------^

7034: debug : qemuMonitorSend:793 : Attempt to send command while error is set internal error cannot parse json {"timestamp": {"seconds": 1313077093, "microseconds": 689265}, "event": "SPICE_DISCONNECTED", "data": {"server": {"port": "5900", "family": "ipv4", "host": ""}, "client": {"port": "38645", "family":{"ip"timv4", ":ost": "10.34{29.89""se{"timestamp": {"seconds": 1313077093, "microseconds": 689265}, "event": "SPICE_DISCONNECTED", "data": {"server": {"port": "5900", "family": "ipv4", "host": ""}, "client": {"port": "38645", "family":{"ip"timv4", ":ost": "10.34{29.89""seconds": 1313077093, "microseconds": 689245}, "event": "__com.redh{"timestamp": {"seconds":data": {"server": {"auth": "spice", "port": "5901", "family": "ipv4", "host": ""}, "client": {"port": "35077", "family": "ipv4", "host": ""}}}: lexical error: invalid string in json text.
          ort": "38645", "family":{"ip"timv4", ":ost": "10.34{29.89""s
                     (right here) ------^

Expected results:
No error

Additional info:

Comment 3 Suqin Huang 2011-08-16 04:44:23 UTC
segment fault while I try to reproduce this bug, but no core file generated.

/usr/libexec/qemu-kvm -drive file=/usr/local/staf/test/RHEV/kvm-new/autotest/client/tests/kvm/images/RHEL-Server-6.1-64-virtio.raw,index=0,if=none,id=drive-virtio-disk1,media=disk,cache=none,format=raw,aio=native -device virtio-blk-pci,bus=pci.0,addr=0x4,drive=drive-virtio-disk1,id=virtio-disk1 -device virtio-net-pci,netdev=idoq0tcT,mac=9a:5e:b5:68:17:d8,id=ndev00idoq0tcT,bus=pci.0,addr=0x3 -netdev tap,id=idoq0tcT,vhost=on,ifname=t0-205512-G596,script=/usr/local/staf/test/RHEV/kvm-new/autotest/client/tests/kvm/scripts/qemu-ifup-switch,downscript=no -m 2048 -smp 2,cores=2,threads=1,sockets=1 -cpu Nehalem -rtc base=utc,clock=host,driftfix=none -M rhel6.2.0 -boot c -no-kvm-pit-reinjection -enable-kvm -monitor stdio -chardev socket,id=serial-rhel5,path=/tmp/serial-rhel5,server,nowait -device isa-serial,chardev=serial-rhel5 -vga qxl -spice port=8000,disable-ticketing -device virtio-serial -chardev spicevmc,id=vdagent,debug=0,name=vdagent -device virtserialport,chardev=vdagent,name=com.redhat.spice.0

Comment 4 Suqin Huang 2011-08-24 08:22:19 UTC
Add more info:

1. host

processor	: 3
vendor_id	: GenuineIntel
cpu family	: 6
model		: 23
model name	: Intel(R) Core(TM)2 Quad CPU    Q9400  @ 2.66GHz
stepping	: 10
cpu MHz		: 1998.000
cache size	: 3072 KB
physical id	: 0
siblings	: 4
core id		: 3
cpu cores	: 4
apicid		: 3
initial apicid	: 3
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good aperfmperf pni dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm sse4_1 xsave lahf_lm dts tpr_shadow vnmi flexpriority
bogomips	: 5333.31
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual

2. result 
handle_dev_input: cursor disconnect
Segmentation fault (core dumped)

3. cmd
/usr/libexec/qemu-kvm -drive file='/home/RHEL-Server-6.1-64-virtio.qcow2',index=0,if=none,id=drive-virtio-disk1,media=disk,cache=none,format=qcow2,aio=native -device virtio-blk-pci,bus=pci.0,addr=0x4,drive=drive-virtio-disk1,id=virtio-disk1 -device virtio-net-pci,netdev=idJkKN3Y,mac=9a:d2:9c:3e:bc:a8,id=ndev00idJkKN3Y,bus=pci.0,addr=0x3 -netdev tap,id=idJkKN3Y,vhost=on,ifname='t0-133520-E44x',script='/home/Auto/autotest/client/tests/kvm/scripts/qemu-ifup-switch',downscript='no' -m 2048 -smp 4,cores=2,threads=1,sockets=2 -cpu Penryn -rtc base=utc,clock=host,driftfix=none -M rhel6.1.0 -boot order=cdn,once=n,menu=off   -usbdevice tablet -no-kvm-pit-reinjection -enable-kvm -spice port=8000,disable-ticketing -vga qxl -monitor stdio -qmp tcp:0:4444,server

Comment 5 Luiz Capitulino 2011-08-26 14:04:12 UTC

The segfault fault you describe might not be related to this bug. I suggest you open a separate bz to track it.

Comment 6 Luiz Capitulino 2011-08-26 14:04:40 UTC

*** This bug has been marked as a duplicate of bug 697441 ***

Note You need to log in before you can comment on or make changes to this bug.