From mboxrd@z Thu Jan 1 00:00:00 1970 From: Michael Tokarev Subject: *terrible* speed of savevm/loadvm/delvm Date: Wed, 12 Nov 2008 20:15:55 +0300 Message-ID: <491B0F4B.9060502@msgid.tls.msk.ru> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit To: KVM list Return-path: Received: from hobbit.corpit.ru ([81.13.33.150]:22414 "EHLO hobbit.corpit.ru" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753304AbYKLRP7 (ORCPT ); Wed, 12 Nov 2008 12:15:59 -0500 Sender: kvm-owner@vger.kernel.org List-ID: 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) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340280, [1669340280], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340282, [1669340282], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340284, [1669340284], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340286, [1669340286], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340288, [1669340288], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340290, [1669340290], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340292, [1669340292], SEEK_SET) = 0 write(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) = 21 futex(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) = 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) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340296, [1669340296], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340298, [1669340298], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340300, [1669340300], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340302, [1669340302], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340304, [1669340304], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340306, [1669340306], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340308, [1669340308], SEEK_SET) = 0 write(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) = 21 futex(0xf7d621a4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xf7d621a0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 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, 1669340310, [1669340310], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340312, [1669340312], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340314, [1669340314], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340316, [1669340316], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340318, [1669340318], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340320, [1669340320], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340322, [1669340322], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340324, [1669340324], SEEK_SET) = 0 write(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) = 21 futex(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) = 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) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340328, [1669340328], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340330, [1669340330], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340332, [1669340332], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340334, [1669340334], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340336, [1669340336], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340338, [1669340338], SEEK_SET) = 0 write(12, "\0\1"..., 2) = 2 _llseek(12, 1669340340, [1669340340], SEEK_SET) = 0 write(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) = 21 futex(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 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