[libvirt] Bug in DOMINFO command when balloon driver is used on a vm with more then 8 GB of MaxMemory ?
fc lists
fclists at pr-z.info
Fri Mar 22 22:11:25 UTC 2013
Hi ,
I have been banging my head on this for the last 8 hours ... and i really
need to know if is really a bug or i am doing something wrong.
Description of the problem:
When the virsh setmem command is used to inflate 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.
I *think* that is because the dommestat command will perform a proper query
to find out the amount of ram currently used (and i can see that in the
logs when issuing a dommestat command)
2013-03-22 21:22:41.820+0000: 23181: debug : virJSONValueToString:1133 :
result={"execute":"query-balloon","id":"libvirt-9"}
2013-03-22 21:22:41.820+0000: 23181: debug :
qemuMonitorJSONCommandWithFd:265 : Send command
'{"execute":"query-balloon","id":"libvirt-9"}' for write with FD -1
2013-03-22 21:22:41.820+0000: 23181: debug : qemuMonitorSend:903 :
QEMU_MONITOR_SEND_MSG: mon=0x7f3d643eb5a0
msg={"execute":"query-balloon","id":"libvirt-9"}
2013-03-22 21:22:41.820+0000: 23179: debug : qemuMonitorIOWrite:461 :
QEMU_MONITOR_IO_WRITE: mon=0x7f3d643eb5a0
buf={"execute":"query-balloon","id":"libvirt-9"}
but no entries are shown in the log for qemu-monitor when virsh dominfo is
run, how does dominfo gather those informations?
I am going to raise a ticket on RED HAT bugzilla for this but was hoping to
get some feedback here first to avoid raising a ticket for something that
maybe i just misunderstood.
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
# 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=0x1685ce0
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=0x1686770
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
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=0x1688320
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=0x1685ce0
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=0x1686770
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 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
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=0x1686360
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=0x16826e0
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/libvir-list/attachments/20130322/8442c4b0/attachment-0001.htm>
More information about the libvir-list
mailing list