Re: [vpp-dev] [csit-dev] vpp-csit-verify-virl-master - some more build failures

[Dave Wallace]

Jan,

Unfortunately the Build Artifacts for these test failures have been 
purged. The LF Infra team has plans to implement a log serverwhere all 
test logs will be available (logs.fd.io) for 6 months but that 
functionality is not currently available. Vanessa is scheduled to work 
on it after she has completed the transition from vagrant to packer for 
minion VMimages.

Therefore the syslog outputwhich would indicate the reason for the VPP 
restart failure is not availablebecause it is also elided from 
theconsole output by the robot framework.

I have run dut_setup.sh in a VIRL VM for several thousand iterations 
with the sleep time set to 2 seconds without a restart failure.  If I 
set the sleep time to 1 second, I can get a restart failure within 100 
iterations.

Based on the existing data, my current conclusion is that the restart 
failure was not directly related to the 3 second sleep duration. I have 
also not seen this failure today in any other verify job. Therefore the 
best we can do at this point is to continue to monitor the 
vpp-csit-verify-virl-master job failures for the same error signature 
and hopefully retrieve the output.xml file before it gets purged.

Thanks,
-daw-

On 10/21/16 11:46 AM, Dave Wallace wrote:
Jan,

I see thatthere is a "sleep 3" in 
...csit/resources/libraries/bash/dut_setup.sh after the vpp service 
restart in order to allow VPP tocomplete the restart case.  I'm 
wondering if VPP sometimes takes longer thanthat to restart?

Do you recall if there was ever an attempt to find a determinant test 
to verify that VPP has completed initialization?

I'm going to do some VPP restart testing on the VIRL testbed using the 
images built as part of 
https://jenkins.fd.io/job/vpp-csit-verify-virl-master/1851/. However 
if my theory is correct, I'm not comfortable resolving the problem by 
simply extending the sleep time.

IMHO, theVPP restart/initialization time should bemeasuredand verified 
tobe within a specified period of time. It may be necessary to add 
instrumentation to VPP to achieve this goal.There should really be a 
separateset of unit tests (with different hugepage allocations) which 
pass/failprior to feature testing.  At the very least, we should not 
be waiting an arbitrary amount of time during test setup and the 
actualtime to restart/complete initialization should be measured and 
logged.

Thanks,
-daw-

On 10/21/16 10:00 AM, Jan Gelety -X (jgelety - PANTHEON TECHNOLOGIES 
at Cisco) wrote:

Hello Dave,

I had a look to failed CSIT runs under https://gerrit.fd.io/r/#/c/3511/ :

https://jenkins.fd.io/job/vpp-csit-verify-virl-master/1851/

https://jenkins.fd.io/job/vpp-csit-verify-virl-master/1853/

In both cases the timeout exception occurred during test case or test 
suite setup phase after restarting vpp (part of the script dut_setup.sh):

Command_done_exec] 'cat /etc/vpp/startup.conf'

[Command_start_exec] 'sudo -S service vpp restart'

[Command_outputs]

Current contents of stderr buffer:

It seems that one of the DUTs has stop to communicate and not 
responding even after cca 30s later in the tear down of the test… But 
there was not a crash of DUT/VM as the frozen process for 
dut_setup.sh script is still there when the connection is working 
again (the next test case setup phase):

20:54:26.422 FAIL timeout: Timeout exception.

Current contents of stdout buffer:

[Command_desc] Starting 
/tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

[Command_start_exec] 'dpkg -l vpp\*'

[Command_outputs] Desired=Unknown/Install/Remove/Purge/Hold

| 
Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend

|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)

||/ Name           Version                      Architecture Description

+++-==============-============================-============-=============================================

ii vpp            16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--executables

ii vpp-dbg        16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--debug symbols

ii vpp-dev        16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--development support

ii vpp-dpdk-dev   16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--development support

ii vpp-dpdk-dkms  16.12-rc0~238-g0d1509f~b1851 amd64 DPDK 2.1 
igb_uio_driver

ii vpp-lib        16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--runtime libraries

ii vpp-plugins    16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--runtime plugins

[Command_done_exec] 'dpkg -l vpp\*'

[Command_start_exec] 'ps aux | grep vpp'

[Command_outputs]

USER PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND

root 10323 99.3  0.8 2477148 33580 ?       Rsl  14:54   0:13 
/usr/bin/vpp -c /etc/vpp/startup.conf

root 10461  0.0  0.0  47296  3684 ?        Ss   14:54   0:00 sudo -Sn 
bash /tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

root 10462  0.0  0.0  11540  2964 ?        S    14:54   0:00 bash 
/tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

root 10465  0.0  0.0  13232   924 ?        S    14:54   0:00 grep vpp

[Command_done_exec] 'ps aux | grep vpp'

...

(the next tests case setup phase)

20:55:06.951 FAIL timeout: Timeout exception.

Current contents of stdout buffer:

[Command_desc] Starting 
/tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

[Command_start_exec] 'dpkg -l vpp\*'

[Command_outputs] Desired=Unknown/Install/Remove/Purge/Hold

| 
Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend

|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)

||/ Name           Version                      Architecture Description

+++-==============-============================-============-=============================================

ii vpp            16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--executables

ii vpp-dbg        16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--debug symbols

ii vpp-dev        16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--development support

ii vpp-dpdk-dev   16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--development support

ii vpp-dpdk-dkms  16.12-rc0~238-g0d1509f~b1851 amd64 DPDK 2.1 
igb_uio_driver

ii vpp-lib        16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--runtime libraries

ii vpp-plugins    16.12-rc0~238-g0d1509f~b1851 amd64 Vector Packet 
Processing--runtime plugins

[Command_done_exec] 'dpkg -l vpp\*'

[Command_start_exec] 'ps aux | grep vpp'

[Command_outputs]

USER PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND

root 10323 25.7  0.8 2477148 35604 ?       Ssl  14:54   0:13 
/usr/bin/vpp -c /etc/vpp/startup.conf

root 10461  0.0  0.0  47296  3684 ?        Ss   14:54   0:00 sudo -Sn 
bash /tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

root 10462  0.0  0.0  11540  2964 ?        S    14:54   0:00 bash 
/tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

root 10467  0.0  0.0  47296  3648 ?        S    14:54   0:00 sudo -S 
service vpp restart

root 10468  0.0  0.0  25176  1332 ?        S    14:54   0:00 
systemctl restart vpp.service

root 10482  0.0  0.0  47296  3700 ?        Ss   14:54   0:00 sudo -Sn 
bash /tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

root 10483  0.0  0.0  11540  2960 ?        S    14:54   0:00 bash 
/tmp/openvpp-testing/resources/libraries/bash/dut_setup.sh

root 10486  0.0  0.0  13232  1012 ?        S    14:54   0:00 grep vpp

[Command_done_exec] 'ps aux | grep vpp'

[Command_start_exec] 'cat /etc/vpp/startup.conf'

[Command_outputs]

Regards,

Jan


_______________________________________________
vpp-dev mailing list
vpp-dev@lists.fd.io
https://lists.fd.io/mailman/listinfo/vpp-dev