*terrible* speed of savevm/loadvm/delvm
Somewhere between kvm-75 and kvm-78, the
mentioned commands has been slowed down
to insane levels. By "insane" I mean to
take about 10 minutes(!) to save/load a
128MB RAM/1GB HDD VM's state. It used
to require several seconds for much larger
VMs...
Here's a typical sequence of system calls
during savevm:
select(12, [11], [], NULL, NULL) = 1 (in [11])read(11, "\f\0\0\0\0\0\0\0\374\377\377\3771s\0\0\350\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128
close(21) = 0_llseek(12, 1669340278, [1669340278], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340280, [1669340280], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340282, [1669340282], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340284, [1669340284], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340286, [1669340286], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340288, [1669340288], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340290, [1669340290], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340292, [1669340292], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1674259520, [1674259520], SEEK_SET) = 0
write(12, "\200\0\0\0c\343\260\0\200\0\0\0c\343\300\0\200\0\0\0c\343\320\0\200\0\0\0c\343\340\0\200"..., 64) = 64
dup(12) = 21futex(0xf7d621a4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xf7d621a0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0xf7d62120, FUTEX_WAKE_PRIVATE, 1) = 1select(12, [11], [], NULL, NULL) = 1 (in [11])read(11, "\f\0\0\0\0\0\0\0\374\377\377\3771s\0\0\350\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128
close(21) = 0_llseek(12, 1669340294, [1669340294], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340296, [1669340296], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340298, [1669340298], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340300, [1669340300], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340302, [1669340302], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340304, [1669340304], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340306, [1669340306], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340308, [1669340308], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1674259584, [1674259584], SEEK_SET) = 0
write(12, "\200\0\0\0c\3440\0\200\0\0\0c\344@\0\200\0\0\0c\344P\0\200\0\0\0c\344`\0\200"..., 64) = 64
dup(12) = 21futex(0xf7d621a4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xf7d621a0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1select(12, [11], [], NULL, NULL) = 1 (in [11])read(11, "\f\0\0\0\0\0\0\0\374\377\377\3771s\0\0\350\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128
close(21) = 0_llseek(12, 1669340310, [1669340310], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340312, [1669340312], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340314, [1669340314], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340316, [1669340316], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340318, [1669340318], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340320, [1669340320], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340322, [1669340322], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340324, [1669340324], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1674259648, [1674259648], SEEK_SET) = 0
write(12, "\200\0\0\0c\344\260\0\200\0\0\0c\344\300\0\200\0\0\0c\344\320\0\200\0\0\0c\344\340\0\200"..., 64) = 64
dup(12) = 21futex(0xf7d621a4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xf7d621a0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0xf7d62120, FUTEX_WAKE_PRIVATE, 1) = 1select(12, [11], [], NULL, NULL) = 1 (in [11])read(11, "\f\0\0\0\0\0\0\0\374\377\377\3771s\0\0\350\3\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128
close(21) = 0_llseek(12, 1669340326, [1669340326], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340328, [1669340328], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340330, [1669340330], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340332, [1669340332], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340334, [1669340334], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340336, [1669340336], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340338, [1669340338], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1669340340, [1669340340], SEEK_SET) = 0write(12, "\0\1"..., 2) = 2_llseek(12, 1674259712, [1674259712], SEEK_SET) = 0
write(12, "\200\0\0\0c\3450\0\200\0\0\0c\345@\0\200\0\0\0c\345P\0\200\0\0\0c\345`\0\200"...,
64) = 64
dup(12) = 21futex(0xf7d621a4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xf7d621a0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0xf7d62120, FUTEX_WAKE_PRIVATE, 1) = 1
select(12, [11], [], NULL, NULL^C <unfinished ...>
As you see, it writes 2 bytes, llseeks to THE SAME position, writes next 2 bytes and so on. This takes HUGE amount of time, and can be done, in most cases, in a single write without any seeks.
Is it just me or are savevm/loadvm/delvm really THAT broken?
And since migration to disk has been removed too,
there's no way currently to save the VM state...
Thanks!
/mjt
Quoted 10 lines · Michael Tokarev
Somewhere between kvm-75 and kvm-78, the mentioned commands has been slowed down
to insane levels. By "insane" I mean to take about 10 minutes(!) to save/load a 128MB RAM/1GB HDD VM's state. It used
to require several seconds for much larger VMs...Here's a typical sequence of system calls during savevm:
[snip strace]
Quoted 7 lines
As you see, it writes 2 bytes, llseeks to THE SAME position, writes next 2 bytes and so on. This takes HUGE amount of time, and can be done, in most cases, in a single write without any seeks.
Is it just me or are savevm/loadvm/delvm really THAT broken?
It's qcow2 that is broken, with the new default cache=writethrough. Does cache=writeback speed things up?
This is probably block reference counts being updated. There were some batching patches posted, but they have not been applied yet, and are probably insufficient for savevm.
Quoted 2 lines
And since migration to disk has been removed too, there's no way currently to save the VM state...
That's being restored.
Signature · 1 line
error compiling committee.c: too many arguments to function
Avi Kivity wrote Thu, 13 Nov 2008 14:33:16 +0200:
Quoted 18 lines
Quoted 10 lines · Michael Tokarev
Somewhere between kvm-75 and kvm-78, the mentioned commands has been slowed down
to insane levels. By "insane" I mean to take about 10 minutes(!) to save/load a 128MB RAM/1GB HDD VM's state. It used
to require several seconds for much larger VMs...Here's a typical sequence of system calls during savevm:
[snip strace]
Quoted 5 lines
As you see, it writes 2 bytes, llseeks to THE SAME position, writes next 2 bytes and so on. This takes HUGE amount of time, and can be done, in most cases, in a single write without any seeks.
Quoted 5 lines
Quoted 2 lines
Is it just me or are savevm/loadvm/delvm really THAT broken?
It's qcow2 that is broken, with the new default cache=writethrough. Does cache=writeback speed things up?
Please excuse me for this long delay replying...
I tried other solutions meanwhile (migrate to exec:), but did not succeed there either.
Well. While with writeback mode, the speed is definitely better. But it is still very very slow - not THAT terrible, but it still takes several mins to complete a 512MB VM with a single 4Gb qcow2 file.
Quoted 3 lines
This is probably block reference counts being updated. There were some batching patches posted, but they have not been applied yet, and are probably insufficient for savevm.
Oh well.... :(
So it really is that there's no way to "freeze" a vm currently. savevm/loadvm is too slow to be useful, and migrate does not work with local files (yet)...
Quoted 4 lines
Quoted 2 lines
And since migration to disk has been removed too, there's no way currently to save the VM state...
That's being restored.
Thanks! Tried that (current patches), does not quite here yet :)
/mjt
Quoted 11 lines · Michael Tokarev
Quoted 10 lines
Quoted 8 lines
As you see, it writes 2 bytes, llseeks to THE SAME position, writes next 2 bytes and so on. This takes HUGE amount of time, and can be done, in most cases, in a single write without any seeks.
Is it just me or are savevm/loadvm/delvm really THAT broken?
It's qcow2 that is broken, with the new default cache=writethrough. Does cache=writeback speed things up?
Quoted 9 lines
Please excuse me for this long delay replying...
I tried other solutions meanwhile (migrate to exec:), but did not succeed there either.Well. While with writeback mode, the speed is definitely better. But it is still very very slow - not THAT terrible, but it still takes several mins to complete a 512MB VM with a single 4Gb qcow2 file.
Any idea what is happening? Is it disk bound, or cpu bound?
It shouldn't be that slow with writeback.
Signature · 1 line
error compiling committee.c: too many arguments to function
Quoted 5 lines · Avi Kivity
Quoted 4 lines · Michael Tokarev
Quoted 4 lines
Quoted 4 lines
As you see, it writes 2 bytes, llseeks to THE SAME position, writes next 2 bytes and so on. This takes HUGE amount of time, and can be done, in most cases, in a single write without any seeks.
[]
Quoted 1 line
Any idea what is happening? Is it disk bound, or cpu bound?
Yes, see above. llseek(curpos)+write(2bytes) - try doing that for for a more-or-less large file and you'll see ;)
And it seems that this slowness is here for a long time really. It's just that change in default write/cache mode made the problem very obvious.
/mjt