Bug in DOMINFO command when balloon driver is used on a vm with more then 8 GB of MaxMemory ?

fc lists <fclists@xxxxxxxxx> · Mon, 25 Mar 2013 12:20:47 -0500

Hi ,

I Sent this to the wrong list (libvirt-devel) on friday ... so i am trying to send it to the correct one this time. 
Apologize for double posting.

I also created a ticket on bugzilla.redhat.com for this

https://bugzilla.redhat.com/show_bug.cgi?id=927336

still i am posting it here because is absolutely possible i am doing something wrong and someone here will see it .

Description of the problem:

When the virsh setmem command is used to inflate (or deflate) the balloon on a VM to which 8GB of MaxMemory or more are allocated then the information reported with virsh dominfo , virsh dumpxml after the balloon change has been performed are wrong. 

The actual balloon is inflated correctly though and that is verifiable both in the vm itself and through the "virsh dommemstat" commands.

Platform is Centos 6.4 (problem was present in 6.3 as well starting with libvirt-0.9.10-21.el6.3.7 )

The patch that actually is causing the problem is patch number 398 in the src rpm for libvirt-0.9.10-21.el6.3.7 :
libvirt-Wire-up-handling-for-QMP-s-BALLOON_EVENT.patch  (https://bugzilla.redhat.com/show_bug.cgi?id=884713)

And i verified it by removing the patch and recompiling the rpm , that indeed worked perfectly after that.

The problem exists in every version up to the latest (that is what i am running now) but now the patch is part of the libvirt source code in itself and not a patch in the rpm anymore.

Software used:

# yum list installed | egrep -i "qemu|libvirt"

gpxe-roms-qemu.noarch 0.9.7-6.9.el6 @base 

libvirt.x86_64 0.10.2-18.el6_4.2 @updates

libvirt-client.x86_64 0.10.2-18.el6_4.2 @updates

libvirt-python.x86_64 0.10.2-18.el6_4.2 @updates

qemu-img.x86_64 2:0.12.1.2-2.355.0.1.el6.centos.2 @updates

qemu-kvm.x86_64 2:0.12.1.2-2.355.0.1.el6.centos.2 @updates

qemu-kvm-tools.x86_64 2:0.12.1.2-2.355.0.1.el6.centos.2 @updates

Full example ( long and include debug logs ) :

1) Start VM with 12GB of MAX and CURRENT  (12582912)

(tail -f libvirtd.log | grep -i balloon)

2013-03-22 21:06:34.438+0000: 23180: debug : qemuMonitorSetBalloon:1690 : mon=0x7f3d6c1789e0 newmem=12582912

2013-03-22 21:06:34.438+0000: 23180: debug : virJSONValueToString:1133 : result={"execute":"balloon","arguments":{"value":12884901888},"id":"libvirt-6"}

2013-03-22 21:06:34.438+0000: 23180: debug : qemuMonitorJSONCommandWithFd:265 : Send command '{"execute":"balloon","arguments":{"value":12884901888},"id":"libvirt-6"}' for write with FD -1

2013-03-22 21:06:34.438+0000: 23180: debug : qemuMonitorSend:903 : QEMU_MONITOR_SEND_MSG: mon=0x7f3d6c1789e0 msg={"execute":"balloon","arguments":{"value":12884901888},"id":"libvirt-6"}

2013-03-22 21:06:34.439+0000: 23179: debug : qemuMonitorIOWrite:461 : QEMU_MONITOR_IO_WRITE: mon=0x7f3d6c1789e0 buf={"execute":"balloon","arguments":{"value":12884901888},"id":"libvirt-6"}

# dominfo 2

Id: 2

Name: centos_jt
UUID: bc25a6c4-ba34-a593-47c7-6372999946d6

OS Type: hvm
State: running

CPU(s): 1
CPU time: 26.6s

Max memory: 12582912 KiB
Used memory: 12582912 KiB

Persistent: yes
Autostart: disable

Managed save: no
Security model: none

Security DOI: 0

2) set mem to 8GB (Fail as described)

# setmem 2 --live --config --size 8388608

2013-03-22 21:13:45.522+0000: 23183: debug : qemuMonitorSetBalloon:1690 : mon=0x7f3d6c1789e0 newmem=8388608

2013-03-22 21:13:45.522+0000: 23183: debug : virJSONValueToString:1133 : result={"execute":"balloon","arguments":{"value":8589934592},"id":"libvirt-9"}

2013-03-22 21:13:45.522+0000: 23183: debug : qemuMonitorJSONCommandWithFd:265 : Send command '{"execute":"balloon","arguments":{"value":8589934592},"id":"libvirt-9"}' for write with FD -1

2013-03-22 21:13:45.522+0000: 23183: debug : qemuMonitorSend:903 : QEMU_MONITOR_SEND_MSG: mon=0x7f3d6c1789e0 msg={"execute":"balloon","arguments":{"value":8589934592},"id":"libvirt-9"}

2013-03-22 21:13:45.523+0000: 23179: debug : qemuMonitorIOWrite:461 : QEMU_MONITOR_IO_WRITE: mon=0x7f3d6c1789e0 buf={"execute":"balloon","arguments":{"value":8589934592},"id":"libvirt-9"}

2013-03-22 21:13:45.528+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d6c1789e0 buf={"timestamp": {"seconds": 1363986825, "microseconds": 528314}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}

2013-03-22 21:13:45.528+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363986825, "microseconds": 528314}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}]

2013-03-22 21:13:45.528+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363986825, "microseconds": 528314}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}

2013-03-22 21:13:45.528+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d6c1789e0 event={"timestamp": {"seconds": 1363986825, "microseconds": 528314}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}

2013-03-22 21:13:45.528+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:13:45.528+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d6c1789e0

2013-03-22 21:13:45.528+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 12582912 to 12581888 kb

2013-03-22 21:13:46.528+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d6c1789e0 buf={"timestamp": {"seconds": 1363986826, "microseconds": 352941}, "event": "BALLOON_CHANGE", "data": {"actual": 12884901888}}

2013-03-22 21:13:46.528+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363986826, "microseconds": 352941}, "event": "BALLOON_CHANGE", "data": {"actual": 12884901888}}]

2013-03-22 21:13:46.528+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363986826, "microseconds": 352941}, "event": "BALLOON_CHANGE", "data": {"actual": 12884901888}}

2013-03-22 21:13:46.528+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d6c1789e0 event={"timestamp": {"seconds": 1363986826, "microseconds": 352941}, "event": "BALLOON_CHANGE", "data": {"actual": 12884901888}}

2013-03-22 21:13:46.528+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:13:46.528+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d6c1789e0

2013-03-22 21:13:46.528+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 12581888 to 12582912 kb

virsh # dominfo 2

Id: 2
Name: centos_jt

UUID: bc25a6c4-ba34-a593-47c7-6372999946d6
OS Type: hvm

State: running
CPU(s): 1

CPU time: 41.6s
Max memory: 12582912 KiB

Used memory: 12582912 KiB
Persistent: yes

Autostart: disable
Managed save: no

Security model: none
Security DOI: 0

virsh # dommemstat 2

actual 8388608
rss 599916

The Balloon was actually inflated , and in the VM i can see 8GB of Ram available with free

3) setmem to to 3000000 (Fail as described)

2013-03-22 21:18:19.182+0000: 23181: debug : qemuMonitorSetBalloon:1690 : mon=0x7f3d6c1789e0 newmem=3000000

2013-03-22 21:18:19.182+0000: 23181: debug : virJSONValueToString:1133 : result={"execute":"balloon","arguments":{"value":3072000000},"id":"libvirt-63"}

2013-03-22 21:18:19.182+0000: 23181: debug : qemuMonitorJSONCommandWithFd:265 : Send command '{"execute":"balloon","arguments":{"value":3072000000},"id":"libvirt-63"}' for write with FD -1

2013-03-22 21:18:19.182+0000: 23181: debug : qemuMonitorSend:903 : QEMU_MONITOR_SEND_MSG: mon=0x7f3d6c1789e0 msg={"execute":"balloon","arguments":{"value":3072000000},"id":"libvirt-63"}

2013-03-22 21:18:19.183+0000: 23179: debug : qemuMonitorIOWrite:461 : QEMU_MONITOR_IO_WRITE: mon=0x7f3d6c1789e0 buf={"execute":"balloon","arguments":{"value":3072000000},"id":"libvirt-63"}

2013-03-22 21:18:19.184+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d6c1789e0 buf={"timestamp": {"seconds": 1363987099, "microseconds": 184245}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}

2013-03-22 21:18:19.184+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363987099, "microseconds": 184245}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}]

2013-03-22 21:18:19.184+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363987099, "microseconds": 184245}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}

2013-03-22 21:18:19.184+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d6c1789e0 event={"timestamp": {"seconds": 1363987099, "microseconds": 184245}, "event": "BALLOON_CHANGE", "data": {"actual": 12883853312}}

2013-03-22 21:18:19.184+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:18:19.184+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d6c1789e0

2013-03-22 21:18:19.191+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 12582912 to 12581888 kb

2013-03-22 21:18:20.184+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d6c1789e0 buf={"timestamp": {"seconds": 1363987100, "microseconds": 184128}, "event": "BALLOON_CHANGE", "data": {"actual": 11874074624}}

2013-03-22 21:18:20.184+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363987100, "microseconds": 184128}, "event": "BALLOON_CHANGE", "data": {"actual": 11874074624}}]

2013-03-22 21:18:20.184+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363987100, "microseconds": 184128}, "event": "BALLOON_CHANGE", "data": {"actual": 11874074624}}

2013-03-22 21:18:20.184+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d6c1789e0 event={"timestamp": {"seconds": 1363987100, "microseconds": 184128}, "event": "BALLOON_CHANGE", "data": {"actual": 11874074624}}

2013-03-22 21:18:20.184+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:18:20.184+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d6c1789e0

2013-03-22 21:18:20.184+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 12581888 to 11595776 kb

2013-03-22 21:18:21.184+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d6c1789e0 buf={"timestamp": {"seconds": 1363987100, "microseconds": 224930}, "event": "BALLOON_CHANGE", "data": {"actual": 11661934592}}

2013-03-22 21:18:21.184+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363987100, "microseconds": 224930}, "event": "BALLOON_CHANGE", "data": {"actual": 11661934592}}]

2013-03-22 21:18:21.184+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363987100, "microseconds": 224930}, "event": "BALLOON_CHANGE", "data": {"actual": 11661934592}}

2013-03-22 21:18:21.184+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d6c1789e0 event={"timestamp": {"seconds": 1363987100, "microseconds": 224930}, "event": "BALLOON_CHANGE", "data": {"actual": 11661934592}}

2013-03-22 21:18:21.184+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:18:21.184+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d6c1789e0

2013-03-22 21:18:21.184+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 11595776 to 11388608

virsh # dominfo 2 
Id: 2

Name: centos_jt
UUID: bc25a6c4-ba34-a593-47c7-6372999946d6

OS Type: hvm
State: running

CPU(s): 1
CPU time: 53.0s

Max memory: 12582912 KiB
Used memory: 11388608 KiB

Persistent: yes
Autostart: disable

Managed save: no
Security model: none

Security DOI: 0

virsh # dommemstat 2
actual 3000000

rss 599036

4) Restart the SAME vm with 4GB of Current and Max (4194304)

2013-03-22 21:20:58.894+0000: 23182: debug : qemuMonitorSetBalloon:1690 : mon=0x7f3d643eb5a0 newmem=4194304

2013-03-22 21:20:58.894+0000: 23182: debug : virJSONValueToString:1133 : result={"execute":"balloon","arguments":{"value":4294967296},"id":"libvirt-6"}

2013-03-22 21:20:58.894+0000: 23182: debug : qemuMonitorJSONCommandWithFd:265 : Send command '{"execute":"balloon","arguments":{"value":4294967296},"id":"libvirt-6"}' for write with FD -1

2013-03-22 21:20:58.894+0000: 23182: debug : qemuMonitorSend:903 : QEMU_MONITOR_SEND_MSG: mon=0x7f3d643eb5a0 msg={"execute":"balloon","arguments":{"value":4294967296},"id":"libvirt-6"}

2013-03-22 21:20:58.894+0000: 23179: debug : qemuMonitorIOWrite:461 : QEMU_MONITOR_IO_WRITE: mon=0x7f3d643eb5a0 buf={"execute":"balloon","arguments":{"value":4294967296},"id":"libvirt-6"}

virsh # dominfo 3

Id: 3
Name: centos_jt

UUID: bc25a6c4-ba34-a593-47c7-6372999946d6
OS Type: hvm

State: running
CPU(s): 1

CPU time: 15.4s
Max memory: 4194304 KiB

Used memory: 4194304 KiB
Persistent: yes

Autostart: disable
Managed save: no

Security model: none
Security DOI: 0

virsh # dommemstat 3

actual 4194304
rss 431384

5) reduce ram to 1GB (Works)

virsh # setmem 3 --live --config --size 1048576 

2013-03-22 21:26:08.783+0000: 23183: debug : qemuMonitorSetBalloon:1690 : mon=0x7f3d643eb5a0 newmem=1048576

2013-03-22 21:26:08.783+0000: 23183: debug : virJSONValueToString:1133 : result={"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-11"}

2013-03-22 21:26:08.783+0000: 23183: debug : qemuMonitorJSONCommandWithFd:265 : Send command '{"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-11"}' for write with FD -1

2013-03-22 21:26:08.783+0000: 23183: debug : qemuMonitorSend:903 : QEMU_MONITOR_SEND_MSG: mon=0x7f3d643eb5a0 msg={"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-11"}

2013-03-22 21:26:08.784+0000: 23179: debug : qemuMonitorIOWrite:461 : QEMU_MONITOR_IO_WRITE: mon=0x7f3d643eb5a0 buf={"execute":"balloon","arguments":{"value":1073741824},"id":"libvirt-11"}

2013-03-22 21:26:08.789+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d643eb5a0 buf={"timestamp": {"seconds": 1363987568, "microseconds": 789570}, "event": "BALLOON_CHANGE", "data": {"actual": 4293918720}}

2013-03-22 21:26:08.789+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363987568, "microseconds": 789570}, "event": "BALLOON_CHANGE", "data": {"actual": 4293918720}}]

2013-03-22 21:26:08.789+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363987568, "microseconds": 789570}, "event": "BALLOON_CHANGE", "data": {"actual": 4293918720}}

2013-03-22 21:26:08.789+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d643eb5a0 event={"timestamp": {"seconds": 1363987568, "microseconds": 789570}, "event": "BALLOON_CHANGE", "data": {"actual": 4293918720}}

2013-03-22 21:26:08.789+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:26:08.789+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d643eb5a0

2013-03-22 21:26:08.789+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 4194304 to 4193280 kb

2013-03-22 21:26:09.789+0000: 23179: debug : qemuMonitorIOProcess:353 : QEMU_MONITOR_IO_PROCESS: mon=0x7f3d643eb5a0 buf={"timestamp": {"seconds": 1363987569, "microseconds": 408889}, "event": "BALLOON_CHANGE", "data": {"actual": 1073741824}}

2013-03-22 21:26:09.789+0000: 23179: debug : qemuMonitorJSONIOProcessLine:152 : Line [{"timestamp": {"seconds": 1363987569, "microseconds": 408889}, "event": "BALLOON_CHANGE", "data": {"actual": 1073741824}}]

2013-03-22 21:26:09.789+0000: 23179: debug : virJSONValueFromString:975 : string={"timestamp": {"seconds": 1363987569, "microseconds": 408889}, "event": "BALLOON_CHANGE", "data": {"actual": 1073741824}}

2013-03-22 21:26:09.789+0000: 23179: debug : qemuMonitorJSONIOProcessLine:167 : QEMU_MONITOR_RECV_EVENT: mon=0x7f3d643eb5a0 event={"timestamp": {"seconds": 1363987569, "microseconds": 408889}, "event": "BALLOON_CHANGE", "data": {"actual": 1073741824}}

2013-03-22 21:26:09.789+0000: 23179: debug : qemuMonitorJSONIOProcessEvent:138 : handle BALLOON_CHANGE handler=0x4b4de0 data="">

2013-03-22 21:26:09.789+0000: 23179: debug : qemuMonitorEmitBalloonChange:1151 : mon=0x7f3d643eb5a0

2013-03-22 21:26:09.789+0000: 23179: debug : qemuProcessHandleBalloonChange:1248 : Updating balloon from 4193280 to 1048576 kb

virsh # dominfo 3

Id: 3
Name: centos_jt

UUID: bc25a6c4-ba34-a593-47c7-6372999946d6
OS Type: hvm

State: running
CPU(s): 1

CPU time: 28.6s
Max memory: 4194304 KiB

Used memory: 1048576 KiB
Persistent: yes

Autostart: disable
Managed save: no

Security model: none
Security DOI: 0

virsh # dommemstat 3

actual 1048576
rss 411740

_______________________________________________
libvirt-users mailing list
libvirt-users@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/libvirt-users