Red Hat Bugzilla – Bug 635527
KVM:qemu-img re-base poor performance(on local storage) when snapshot to a new disk
Last modified: 2013-01-09 18:09:49 EST
Description of problem: base -> snA -> snB -> snC, create a new disk with the same size of base, then rebase snC to base_new.however,It's spent 172 mins on rebasing snC to a new disk. Version-Release number of selected component (if applicable): #rpm -q qemu-kvm qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64 #uname -r 2.6.32-71.el6.x86_64 How reproducible: Steps to Reproduce: 1.Create base image #qemu-img create -opreallocation=metadata -ocluster_size=2M -f "qcow2" rhel6.0rc3_64.qcow2 15G 2.Install guest on rhel6.0rc3_64.qcow2 3.After installed guest on base image.check img #qemu-img info rhel6.0rc3_64.qcow2 image: rhel6.0rc3_64.qcow2 file format: qcow2 virtual size: 15G (16106127360 bytes) disk size: 12G cluster_size: 2097152 4.issue the following commands.(base -> snA -> snB -> snC) #qemu-img create -f qcow2 -F qcow2 -b rhel6.0rc3_64.qcow2 A.qcow2 Formatting 'A.qcow2', fmt=qcow2 size=16106127360 backing_file='rhel6.0rc3_64.qcow2' backing_fmt='qcow2' encryption=off cluster_size=0 # qemu-img create -f qcow2 -F qcow2 -b A.qcow2 B.qcow2 Formatting 'B.qcow2', fmt=qcow2 size=16106127360 backing_file='A.qcow2' backing_fmt='qcow2' encryption=off cluster_size=0 # qemu-img create -f qcow2 -F qcow2 -b B.qcow2 C.qcow2 Formatting 'C.qcow2', fmt=qcow2 size=16106127360 backing_file='B.qcow2' backing_fmt='qcow2' encryption=off cluster_size=0 5. boot snapshot C.qcow,write about 1G file in guest,then shutdown guest. #/usr/libexec/qemu-kvm -M rhel6.0.0 -enable-kvm -m 2G -smp 2 -uuid `uuidgen` -monitor stdio -rtc base=localtime -drive file=/root/zhangjunyitest/C.qcow2,format=qcow2,werror=stop,rerror=stop,id=drive-ide,cache=none,boot=on -device virtio-blk-pci,drive=drive-ide,id=test1 -boot c -netdev tap,id=hostnet0 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=22:11:22:45:66:97 -qmp tcp:0:4444,server,nowait -drive file=/root/boot.iso,if=none,media=cdrom,id=drive-ide0-1-0,readonly=on,format=raw -device ide-drive,drive=drive-ide0-1-0 -device ide-drive,drive=drive-ide0-1-0 -vnc :11 In guest: write about 1G file dd if=/dev/zero of=/root/zhang bs=1M count=1024;cksum zhang > zhang.txt 6.Create a new disk with the same size of base image. #qemu-img create -f qcow2 testrebasetime.qcow2 15G Formatting 'testrebasetime.qcow2', fmt=qcow2 size=16106127360 encryption=off cluster_size=0 7.Rebase snapshot C to base_new. #time qemu-img rebase -b testrebasetime.qcow2 -f qcow2 -F qcow2 C.qcow2 real 172m48.997s user 0m36.703s sys 1m19.921s Actual results: I tried rebase snapshot to new image three times,average costs is around 170 mins. Expected results: Rebase Costs on qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64 should not increased. Additional info: 1. I also tried rebase operation on qemu-kvm-0.12.1.2-2.53.el6.x86_64 rebase snapshotc to new image.Just costs 9 mins. #time qemu-img rebase -b testbasetimeqemu53.qcow2 -f qcow2 -F qcow2 Cqemu53.qcow2 real 9m5.052s user 0m28.208s sys 0m54.080s 2.Do rebase on qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64 compare to qemu-kvm-0.12.1.2-2.53.el6.x86_64. there are a lot of fdatasync() calls.I am not sure this is key reasons. (1) A snip of strace log in the progress of rebase snapshot C to base_new on qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64. pwrite(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512, 2147592704) = 512 fdatasync(3) = 0 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 pwrite(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 65024, 3587637760) = 65024 fdatasync(3) = 0 pwrite(3, "\200\0\0\0\325\237\0\0\200\0\0\0\325\240\0\0\200\0\0\0\325\241\0\0\200\0\0\0\325\242\0\0"..., 512, 6496256) = 512 fdatasync(3) = 0 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 pwrite(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512, 2147592704) = 512 fdatasync(3) = 0 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 pwrite(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 65024, 3587703296) = 65024 fdatasync(3) = 0 pwrite(3, "\200\0\0\0\325\237\0\0\200\0\0\0\325\240\0\0\200\0\0\0\325\241\0\0\200\0\0\0\325\242\0\0"..., 512, 6496256) = 512 fdatasync(3) = 0 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 pwrite(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512, 2147592704) = 512 fdatasync(3) = 0 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 pwrite(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 65024, 3587768832) = 65024 fdatasync(3^C <unfinished ...> (2) A snip of strace log in the progress of rebase snapshot C to base_new on qemu-kvm-0.12.1.2-2.53.el6.x86_64.didn't find fdatasync() calls futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 lseek(3, 10737537024, SEEK_SET) = 10737537024 write(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 12489135104, SEEK_SET) = 12489135104 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 60416) = 60416 lseek(3, 12458069504, SEEK_SET) = 12458069504 write(3, "\200\0\0\2\350P\0\0\200\0\0\2\350Q\0\0\200\0\0\2\350R\0\0\200\0\0\2\350S\0\0"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 lseek(3, 10737537024, SEEK_SET) = 10737537024 write(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 12489202688, SEEK_SET) = 12489202688 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 58368) = 58368 lseek(3, 12458069504, SEEK_SET) = 12458069504 write(3, "\200\0\0\2\350P\0\0\200\0\0\2\350Q\0\0\200\0\0\2\350R\0\0\200\0\0\2\350S\0\0"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 10737537024, SEEK_SET) = 10737537024 write(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 12489273344, SEEK_SET) = 12489273344 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 53248) = 53248 lseek(3, 12458069504, SEEK_SET) = 12458069504 write(3, "\200\0\0\2\350P\0\0\200\0\0\2\350Q\0\0\200\0\0\2\350R\0\0\200\0\0\2\350S\0\0"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 10737537024, SEEK_SET) = 10737537024 write(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 lseek(3, 12489449472, SEEK_SET) = 12489449472 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192 lseek(3, 12458069504, SEEK_SET) = 12458069504 write(3, "\200\0\0\2\350P\0\0\200\0\0\2\350Q\0\0\200\0\0\2\350R\0\0\200\0\0\2\350S\0\0"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 lseek(3, 10737537024, SEEK_SET) = 10737537024 write(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 12489459712, SEEK_SET) = 12489459712 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 63488) = 63488 lseek(3, 12458069504, SEEK_SET) = 12458069504 write(3, "\200\0\0\2\350P\0\0\200\0\0\2\350Q\0\0\200\0\0\2\350R\0\0\200\0\0\2\350S\0\0"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 lseek(3, 10737537024, SEEK_SET) = 10737537024 write(3, "\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"..., 512) = 512 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 futex(0x63ac24, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63ac20, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\34.\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 lseek(3, 12489523712, SEEK_SET) = 12489523712 write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 65024) = 65024 lseek(3, 12458069504, SEEK_SET) = 12458069504 3. I also tried rebase snapshotC to snapshotA on qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64.didn't find didn't find fdatasync() calls. #time qemu-img rebase -b A.qcow2 -f qcow2 -F qcow2 C.qcow2 real 3m1.431s user 0m22.627s sys 0m15.424s A snip of strace futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 select(5, [4], [], NULL, NULL) = 1 (in [4]) read(4, "\f\0\0\0\0\0\0\0\0\0\0\0\233\21\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 128) = 128 futex(0x63eec4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x63eec0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 4.In the progess of rebase on qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64 #top top - 04:29:39 up 3 days, 20:18, 5 users, load average: 1.37, 0.77, 0.32 Tasks: 1 total, 0 running, 1 sleeping, 0 stopped, 0 zombie Cpu(s): 0.1%us, 0.3%sy, 0.0%ni, 85.6%id, 13.9%wa, 0.0%hi, 0.1%si, 0.0%st Mem: 3662032k total, 2378392k used, 1283640k free, 41428k buffers Swap: 4296696k total, 2384k used, 4294312k free, 2020984k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5723 root 20 0 249m 47m 608 D 1.0 1.3 0:02.81 qemu-img #free total used free shared buffers cached Mem: 3662032 2507476 1154556 0 44272 2145884 -/+ buffers/cache: 317320 3344712 Swap: 4296696 2384 4294312 5. host cpu #cat /proc/cpuinfo processor : 0 vendor_id : GenuineIntel cpu family : 6 model : 23 model name : Intel(R) Core(TM)2 Quad CPU Q9550 @ 2.83GHz stepping : 10 cpu MHz : 2826.086 cache size : 6144 KB physical id : 0 siblings : 4 core id : 0 cpu cores : 4 apicid : 0 initial apicid : 0 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 tpr_shadow vnmi flexpriority bogomips : 5652.17 clflush size : 64 cache_alignment : 64 address sizes : 36 bits physical, 48 bits virtual power management: #cat /proc/cpuinfo | grep cores cpu cores : 4
(In reply to comment #0) > 2.Do rebase on qemu-kvm-0.12.1.2-2.113.el6_0.1.x86_64 compare to > qemu-kvm-0.12.1.2-2.53.el6.x86_64. there are a lot of fdatasync() calls.I am > not sure this is key reasons. Yes, it is the reason. The fdatasync is required to guarantee image integrity in case of a crash/power failure, so we can't just remove it again. There is a prototype for an optimization approach to get much of the performance back, but it's an intrusive change and not ready yet.
Reproduce this bug with qemu-kvm-0.12.1.2-2.135.el6.x86_64 on local storage and iscsi storage as following: For local storage: 1. RHEL6.img is previous installed rhel6 guest image # qemu-img info RHEL6.img image: RHEL6.img file format: qcow2 virtual size: 20G (20971520000 bytes) disk size: 6.6G cluster_size: 65536 2. create snapshot chain RHEL6.img -> snA -> snB -> snC # qemu-img create -f qcow2 -F qcow2 -b RHEL6.img snA Formatting 'snA', fmt=qcow2 size=20971520000 backing_file='RHEL6.img' backing_fmt='qcow2' encryption=off cluster_size=0 # qemu-img create -f qcow2 -F qcow2 -b snA snB Formatting 'snB', fmt=qcow2 size=20971520000 backing_file='snA' backing_fmt='qcow2' encryption=off cluster_size=0 # qemu-img create -f qcow2 -F qcow2 -b snB snC Formatting 'snC', fmt=qcow2 size=20971520000 backing_file='snB' backing_fmt='qcow2' encryption=off cluster_size=0 3. create new base image with same size as base # qemu-img create -f qcow2 newbase.img 20G Formatting 'newbase.img', fmt=qcow2 size=21474836480 encryption=off cluster_size=0 4. record time of rebase snapshot c to new base. # time strace -c qemu-img rebase -b newbase.img -f qcow2 -F qcow2 snC % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 61.18 8.712965 104 83632 select 35.52 5.058238 149 33997 fdatasync 2.36 0.335972 1 227702 1639 futex 0.91 0.130272 1 100271 pwrite 0.01 0.001760 0 83637 read 0.01 0.001385 12 117 pread 0.01 0.000869 46 19 munmap 0.00 0.000011 1 22 close 0.00 0.000000 0 22 open 0.00 0.000000 0 8 stat 0.00 0.000000 0 6 fstat 0.00 0.000000 0 8 lseek 0.00 0.000000 0 37 mmap 0.00 0.000000 0 10 mprotect 0.00 0.000000 0 14 brk 0.00 0.000000 0 2 rt_sigaction 0.00 0.000000 0 4 rt_sigprocmask 0.00 0.000000 0 8 8 ioctl 0.00 0.000000 0 1 1 access 0.00 0.000000 0 1 clone 0.00 0.000000 0 1 execve 0.00 0.000000 0 3 fcntl 0.00 0.000000 0 1 getrlimit 0.00 0.000000 0 1 arch_prctl 0.00 0.000000 0 1 set_tid_address 0.00 0.000000 0 1 set_robust_list 0.00 0.000000 0 1 signalfd ------ ----------- ----------- --------- --------- ---------------- 100.00 14.241472 529527 1648 total real 36m21.471s user 0m30.643s sys 0m35.155s Last about 36 mins. For iscsi storage: 1.previous installed rhel6 guest # qemu-img info /dev/vgtest/lvtest image: /dev/vgtest/lvtest file format: qcow2 virtual size: 50G (53687091200 bytes) disk size: 0 cluster_size: 65536 2. create snapshot chain. RHEL6.img -> snA -> snB -> snC # qemu-img create -f qcow2 -F qcow2 -b /dev/vgtest/lvtest /dev/vgtest/snA Formatting '/dev/vgtest/snA', fmt=qcow2 size=53687091200 backing_file='/dev/vgtest/lvtest' backing_fmt='qcow2' encryption=off cluster_size=0 # qemu-img create -f qcow2 -F qcow2 -b /dev/vgtest/snA /dev/vgtest/snB Formatting '/dev/vgtest/snB', fmt=qcow2 size=53687091200 backing_file='/dev/vgtest/snA' backing_fmt='qcow2' encryption=off cluster_size=0 # qemu-img create -f qcow2 -F qcow2 -b /dev/vgtest/snB /dev/vgtest/snC Formatting '/dev/vgtest/snC', fmt=qcow2 size=53687091200 backing_file='/dev/vgtest/snB' backing_fmt='qcow2' encryption=off cluster_size=0 3. create new base image with same size as base image # qemu-img create -f qcow2 /dev/vgtest/newbase 50G Formatting '/dev/vgtest/newbase', fmt=qcow2 size=53687091200 encryption=off cluster_size=0 4. record time to rebase snapshot to base new. # time strace -c qemu-img rebase -b /dev/vgtest/newbase -f qcow2 -F qcow2 /dev/vgtest/snC % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 60.89 5.644797 160 35378 select 24.05 2.229636 162 13728 fdatasync 12.65 1.172540 53297 22 close 2.10 0.194862 2 91233 178 futex 0.24 0.022066 1 39913 pwrite 0.03 0.003153 27 116 pread 0.02 0.001873 0 35383 read 0.01 0.000969 51 19 munmap 0.00 0.000032 1 37 mmap 0.00 0.000000 0 22 open 0.00 0.000000 0 8 stat 0.00 0.000000 0 6 fstat 0.00 0.000000 0 8 lseek 0.00 0.000000 0 10 mprotect 0.00 0.000000 0 14 brk 0.00 0.000000 0 2 rt_sigaction 0.00 0.000000 0 4 rt_sigprocmask 0.00 0.000000 0 8 8 ioctl 0.00 0.000000 0 1 1 access 0.00 0.000000 0 1 clone 0.00 0.000000 0 1 execve 0.00 0.000000 0 3 fcntl 0.00 0.000000 0 1 getrlimit 0.00 0.000000 0 1 arch_prctl 0.00 0.000000 0 1 set_tid_address 0.00 0.000000 0 1 set_robust_list 0.00 0.000000 0 1 signalfd ------ ----------- ----------- --------- --------- ---------------- 100.00 9.269928 215922 187 total real 11m51.648s user 1m33.070s sys 0m18.393s Last about 11 mins. Verify this bug with qemu-kvm-0.12.1.2-2.145.el6.x86_64 as reproduce steps, time spend as following: Local storage: # time strace -c qemu-img rebase -b newbase.img -f qcow2 -F qcow2 snC % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 65.49 17.133394 237964 72 fdatasync 32.66 8.545440 111 76793 select 1.41 0.367682 2 225227 516 futex 0.42 0.109451 3 32383 pwrite 0.02 0.004100 35 117 pread 0.01 0.001906 0 76798 read 0.00 0.000342 31 11 munmap 0.00 0.000017 1 22 open 0.00 0.000009 0 73 brk 0.00 0.000000 0 22 close 0.00 0.000000 0 8 stat 0.00 0.000000 0 6 fstat 0.00 0.000000 0 8 lseek 0.00 0.000000 0 29 mmap 0.00 0.000000 0 10 mprotect 0.00 0.000000 0 2 rt_sigaction 0.00 0.000000 0 4 rt_sigprocmask 0.00 0.000000 0 8 8 ioctl 0.00 0.000000 0 1 1 access 0.00 0.000000 0 1 clone 0.00 0.000000 0 1 execve 0.00 0.000000 0 3 fcntl 0.00 0.000000 0 1 getrlimit 0.00 0.000000 0 1 arch_prctl 0.00 0.000000 0 1 set_tid_address 0.00 0.000000 0 1 set_robust_list 0.00 0.000000 0 1 signalfd ------ ----------- ----------- --------- --------- ---------------- 100.00 26.162341 411604 525 total real 2m45.269s user 0m29.700s sys 0m43.185s Last about 3 mins. For iscsi storage: # time strace -c qemu-img rebase -b /dev/vgtest/newbase -f qcow2 -F qcow2 /dev/vgtest/snC % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 76.30 6.349827 160 39803 select 11.34 0.943855 18151 52 fdatasync 10.39 0.864869 39312 22 close 1.58 0.131680 1 91823 279 futex 0.33 0.027392 2 12534 pwrite 0.03 0.002116 18 116 pread 0.02 0.001531 0 39808 read 0.01 0.001058 96 11 munmap 0.00 0.000325 5 72 brk 0.00 0.000000 0 22 open 0.00 0.000000 0 8 stat 0.00 0.000000 0 6 fstat 0.00 0.000000 0 8 lseek 0.00 0.000000 0 29 mmap 0.00 0.000000 0 10 mprotect 0.00 0.000000 0 2 rt_sigaction 0.00 0.000000 0 4 rt_sigprocmask 0.00 0.000000 0 8 8 ioctl 0.00 0.000000 0 1 1 access 0.00 0.000000 0 1 clone 0.00 0.000000 0 1 execve 0.00 0.000000 0 3 fcntl 0.00 0.000000 0 1 getrlimit 0.00 0.000000 0 1 arch_prctl 0.00 0.000000 0 1 set_tid_address 0.00 0.000000 0 1 set_robust_list 0.00 0.000000 0 1 signalfd ------ ----------- ----------- --------- --------- ---------------- 100.00 8.322653 184349 288 total real 3m19.102s user 1m32.898s sys 0m16.125s Last about 3 mins. So compare above test result, we have performance improvement as 36 mins --> 3 mins (local storage) 11 mins --> 3 mins ( iscsi storage) So this bug has been resolved.
*** Bug 676565 has been marked as a duplicate of this bug. ***
move to verified based on comment#14
Technical note added. If any revisions are required, please edit the "Technical Notes" field accordingly. All revisions will be proofread by the Engineering Content Services team. New Contents: Cause: no metadata caching in the qemu-kvm qcow2 code. Consequence: poor performance of 'qemu-img rebase' Fix: a metadata cache was introduced into the qcow2 code. Result: improved performance of 'qemu-img rebase'.
Technical note updated. If any revisions are required, please edit the "Technical Notes" field accordingly. All revisions will be proofread by the Engineering Content Services team. Diffed Contents: @@ -1,4 +1 @@ -Cause: no metadata caching in the qemu-kvm qcow2 code. +Previously, qemu-kvm did not include metadata caching, which resulted in poor performance for the the qemu-img rebase process. This is now fixed and the QCOW2 code now includes metadata caching, which results in improved performance for the qemu-img rebase process.-Consequence: poor performance of 'qemu-img rebase' -Fix: a metadata cache was introduced into the qcow2 code. -Result: improved performance of 'qemu-img rebase'.
An advisory has been issued which should help the problem described in this bug report. This report is therefore being closed with a resolution of ERRATA. For more information on therefore solution and/or where to find the updated files, please follow the link below. You may reopen this bug report if the solution does not work for you. http://rhn.redhat.com/errata/RHSA-2011-0534.html