Bug 1275652

Please re-run on 3.5 vs the same storage and attach the logs, so we can see where the performance supposedly regressed.

Also, it's unclear from the description - is the VM up or down during this operation?

Created attachment 1086886 [details]
3.5 logs

Hi Allon,
We are talking about regular snapshot deletion, not live merge.
The operation in 3.5 took 10 minutes.

Update to the steps to reproduce:
Even without the partitions and file creation it reproduced.

I'm attaching logs from 3.5 with the updated steps to reproduce and also new 3.6 log with the updated steps to reproduce for better comparison. 

BTW, in 3.5 with the new steps to reproduce the operation takes 1 hour 35 min

Created attachment 1086889 [details]
3.6 logs

(In reply to ratamir from comment #2)
> Created attachment 1086886 [details]
> 3.5 logs
> 
> Hi Allon,
> We are talking about regular snapshot deletion, not live merge.
> The operation in 3.5 took 10 minutes.
> 
> Update to the steps to reproduce:
> Even without the partitions and file creation it reproduced.
> 
> I'm attaching logs from 3.5 with the updated steps to reproduce and also new
> 3.6 log with the updated steps to reproduce for better comparison. 
> 
> BTW, in 3.5 with the new steps to reproduce the operation takes 1 hour 35 min

Sorry, in 3.6

Thanks - and Yikes!

Tal - can we please have someone take a look at this?

Maor, please have a look

It looks like the issue is with qemu-img rebase (see [1]).
Basically it is a heavy operation that might take a long time (not sure about 2 hours though).
most of the tasks were waiting for the command to finished.

all the 7 volumes were executed with "qemu-img rebase" around the same time.
only two were finished:
470a1f1c-20d6-4772-aa52-f7fd5e9f2743 : still running
82fe78ed-b315-4190-894b-fe0069fa4d09 : finished      end: 09:57
d7b4cc01-e637-4b9a-ad6d-3fdfce5160f3 : still running
50aa93e3-d061-4c7a-9d28-d417e0eb7ed8 : still running
bcd1832a-3448-4186-b45b-b2ed57c79116 : still running
fcd22d8f-7b18-4854-886d-17f11facdbe2 : still running
eb4ee80b-e846-4c73-80d1-1934b438f523 : finished      end: 10:04


I can notice that in the middle of the process the domain was refreshed, but I don't think it is relevant so much:
(_refreshDomain) Refreshing domain a15a0887-6069-41ba-b293-fbc4dfbea1ff

and the delay after the refresh was a bit long:
'delay': '1.54356'
10:06:51: 'delay': '2.97009'
10:23:11: 'delay': '5.63808'


Raz, "qemu-img rebase" should repors its progress using SIGUSR1. (see https://bugzilla.redhat.com/621482)
Please try to use SIGUSR1 once it happens again on the running "qemu-img rebase" processes and share the output.


[1]
the rebase command: 
/usr/bin/nice -n 19 /usr/bin/ionice -c 3 /usr/bin/qemu-img rebase -t none -T none -f qcow2 -F raw -b ../ab41c149-4a1a-4059-afca-e0393c1d8371/1a3a4c72-caca-4174-825f-fd5fb76ccc85 /rhev/data-center/mnt/10.35.160.108:_Storage_storage__ge3__nfs__1/a15a0887-6069-41ba-b293-fbc4dfbea1ff/images/ab41c149-4a1a-4059-afca-e0393c1d8371/a5a83bc3-6f7b-436f-a982-cb62aeeb0bfb (cwd /rhev/data-center/mnt/10.35.160.108:_Storage_storage__ge3__nfs__1/a15a0887-6069-41ba-b293-fbc4dfbea1ff/images/ab41c149-4a1a-4059-afca-e0393c1d8371

In oVirt testing is done on single release by default. Therefore I'm removing the 4.0 flag. If you think this bug must be tested in 4.0 as well, please re-add the flag. Please note we might not have testing resources to handle the 4.0 clone.

Hi Maor,
based on comment 26 here https://bugzilla.redhat.com/show_bug.cgi?id=621482
I ran:
1) pgrep qemu-img
>> 
8758
8769
8836

2) 
for ((;;)); do kill -SIGUSR1 8758 ; sleep 5; done
for ((;;)); do kill -SIGUSR1 8769 ; sleep 5; done
for ((;;)); do kill -SIGUSR1 8836 ; sleep 5; done

on 3 different sessions and all stuck with no output.

looks like BZ1246114 is already taken care of this issue. Closing it as duplicate

*** This bug has been marked as a duplicate of bug 1246114 ***