Re: [Xen-devel] [xen-unstable bisection] complete test-amd64-amd64-xl-qemuu-ovmf-amd64

[Wei Liu <wei.liu2@xxxxxxxxxx>]

On Sun, May 22, 2016 at 05:37:51AM +0000, osstest service owner wrote:
> branch xen-unstable
> xenbranch xen-unstable
> job test-amd64-amd64-xl-qemuu-ovmf-amd64
> testid guest-start/debianhvm.repeat
> 
> Tree: linux git://xenbits.xen.org/linux-pvops.git
> Tree: linuxfirmware git://xenbits.xen.org/osstest/linux-firmware.git
> Tree: qemu git://xenbits.xen.org/qemu-xen-traditional.git
> Tree: qemuu git://xenbits.xen.org/qemu-xen.git
> Tree: xen git://xenbits.xen.org/xen.git
> 
> *** Found and reproduced problem changeset ***
> 
>   Bug is in tree:  xen git://xenbits.xen.org/xen.git
>   Bug introduced:  1542efcea893df874b13b1ea78101e1ff6a55c41
>   Bug not present: c32381352cce9744e640bf239d2704dae4af4fc7
>   Last fail repro: http://logs.test-lab.xenproject.org/osstest/logs/94689/
> 
> 
>   commit 1542efcea893df874b13b1ea78101e1ff6a55c41
>   Author: Wei Liu <wei.liu2@xxxxxxxxxx>
>   Date:   Wed May 18 11:48:25 2016 +0100
>   
>       Config.mk: update ovmf changeset
>       
>       Signed-off-by: Wei Liu <wei.liu2@xxxxxxxxxx>
> 

I did some tests and analysis today.

* Manual tests

Seconds between starting a guest to receiving ping, test three times

  xl create guest.cfg ;\
  s=`date +%s`; date --date="@$s"; \
  while true;  do \
   ping -c 1  -q -W 1 172.16.147.190 2>&1 1>/dev/null;\
   if [ $? = 0 ]; then break; fi ;\
   done;\
  e=`date +%s`; date --date="@$e";\
  expr $e - $s

                          merlot0             tg06
old ovmf, 5000mb ram     98 99 96            33 32 31
old ovmf, 768mb  ram     97 100 100          31 31 32
new ovmf, 5000mb ram     158 158 157         25 26 25
new ovmf, 768mb  ram     151 156 160         26 25 25

Old ovmf refers to 52a99493 (currently in master)
New ovmf refers to b41ef325 (the fingered one)

Tg06 and merlot0 have the same changeset git:983aae0.

Note that the guest runs on tg06 has a different version of Debian, so it is
not really comparable to the guest on merlot0.  Also note that we can't
extrapolate from my manual test that osstest will or will not see timeout on
merlot0 because the technique to test that is not the same.

The conclusions are: we now know the results are consistent and the guest
memory size doesn't affect the time taken to start the guest.

* Osstest report

Pick the ovmf flight that tested the fingered changeset:

http://logs.test-lab.xenproject.org/osstest/logs/94519/test-amd64-amd64-xl-qemuu-ovmf-amd64/17.ts-repeat-test.log

2016-05-18 05:40:26 Z guest debianhvm.guest.osstest 5a:36:0e:37:00:01 22 
link/ip/tcp: ok. (185s) 
2016-05-18 05:44:13 Z guest debianhvm.guest.osstest 5a:36:0e:37:00:01 22 
link/ip/tcp: ok. (184s) 
2016-05-18 05:47:55 Z guest debianhvm.guest.osstest 5a:36:0e:37:00:01 22 
link/ip/tcp: ok. (184s) 
...

The time out for checking if a guest is up is 200 seconds so 180 seconds should
be fine.

The new ovmf failure reported by bisector is the controller timed out when
trying to check if the guest is up.

    
http://logs.test-lab.xenproject.org/osstest/logs/94689/test-amd64-amd64-xl-qemuu-ovmf-amd64/17.ts-repeat-test.log

The old ovmf passed on merlot0:

    
http://logs.test-lab.xenproject.org/osstest/logs/94680/test-amd64-amd64-xl-qemuu-ovmf-amd64/17.ts-repeat-test.log
    2016-05-22 02:49:57 Z guest debianhvm.guest.osstest 5a:36:0e:d8:00:01 22 
link/ip/tcp: ok. (141s) 

The old ovmf passed on other machine:

    
http://logs.test-lab.xenproject.org/osstest/logs/94580/test-amd64-amd64-xl-qemuu-ovmf-amd64/17.ts-repeat-test.log

    2016-05-19 22:45:39 Z guest debianhvm.guest.osstest 5a:36:0e:74:00:3c 22 
link/ip/tcp: ok. (122s) 

The two numbers suggest that merlot is slower than the other machine.

Pick one of the recent test report for OVMF:

http://logs.test-lab.xenproject.org/osstest/logs/94739/test-amd64-amd64-xl-qemuu-ovmf-amd64/17.ts-repeat-test.log

The same metric (guest creation to guest responding to network traffic) is a
lot shorter (on a non-merlot machine):

2016-05-24 14:21:59 Z guest debianhvm.guest.osstest 5a:36:0e:13:00:02 22 
link/ip/tcp: ok. (49s) 
2016-05-24 14:23:28 Z guest debianhvm.guest.osstest 5a:36:0e:13:00:02 22 
link/ip/tcp: ok. (49s) 
2016-05-24 14:25:03 Z guest debianhvm.guest.osstest 5a:36:0e:13:00:02 22 
link/ip/tcp: ok. (48s) 
2016-05-24 14:26:45 Z guest debianhvm.guest.osstest 5a:36:0e:13:00:02 22 
link/ip/tcp: ok. (48s) 
...

It looks like it's getting better.

I don't have a conclusion on this issue because I can't eliminate all
variables.  I'm inclined to push another a newer ovmf changeset to see what
happens, because:

1. merlot is slower than other machine, the time difference is about 20s.
2. new ovmf on other machine already takes ~180s to come up (less than 20s to
   200s timeout).
3. the time taken to come up seems to get shorter, though I didn't see why when
   I skimmed ovmf changelog.

Wei.

_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel