[ovs-dev] [PATCH] tests: Report core dumps during tests as failures.

Jarno Rajahalme jrajahalme at nicira.com
Fri May 30 20:12:15 UTC 2014


Ben,

How about just running something like this as the last test:

find tests -name core -print

and creating a test failure on non-empty output, even if no other test failures were found?

  Jarno

On May 29, 2014, at 5:16 PM, Jarno Rajahalme <jrajahalme at nicira.com> wrote:

> On May 29, 2014, at 3:06 PM, Ben Pfaff <blp at nicira.com> wrote:
> 
>> Jarno, you might want to take a look at this, since it is a simple
>> patch that improves the test cases in a way that you suggested.
>> 
> 
> And I wondered why was this not in yet!
> 
> Comments below:
> 
>> On Wed, May 21, 2014 at 5:05 PM, Ben Pfaff <blp at nicira.com> wrote:
>>> This will only catch core dumps in tests that start and stop ovs-vswitchd,
>>> but that covers the ones most likely to have problems.
>>> 
>>> Suggested-by: Jarno Rajahalme <jrajahalme at nicira.com>
>>> Signed-off-by: Ben Pfaff <blp at nicira.com>
>>> ---
>>> tests/ofproto-macros.at |   20 +++++++++++++++++++-
>>> 1 file changed, 19 insertions(+), 1 deletion(-)
>>> 
>>> diff --git a/tests/ofproto-macros.at b/tests/ofproto-macros.at
>>> index 4b16907..7e9d10e 100644
>>> --- a/tests/ofproto-macros.at
>>> +++ b/tests/ofproto-macros.at
>>> @@ -98,6 +98,20 @@ check_logs () {
>>> /|ERR|/p
>>> /|EMER|/p" ovs-vswitchd.log ovsdb-server.log
>>> }
>>> +
>>> +check_cores () {
>>> +    for core in core*; do
>>> +        if test -f "$core"; then
>>> +            echo "$core: core dumped during test"
>>> +
>>> +            # If "file" is installed then this is likely to give a little
>>> +            # extra information about it, such as the program's name and
>>> +            # command line.  If "file" isn't installed then it should be
>>> +            # harmless
>>> +            (file "./$core") 2>/dev/null
>>> +        fi
>>> +    done
>>> +}
> 
> 
> I made a deliberate core-producing error to test this out. As a result I have three core files:
> 
> $ ls -l tests/testsuite.dir/*/core
> -rw------- 1 jrajahalme jrajahalme 20344832 May 29 16:53 tests/testsuite.dir/0352/core
> -rw------- 1 jrajahalme jrajahalme 20353024 May 29 16:53 tests/testsuite.dir/0353/core
> -rw------- 1 jrajahalme jrajahalme 20357120 May 29 16:53 tests/testsuite.dir/0764/core
> 
> But I don’t seem to find the string “core dumped” from the make output, nor from testsuite.log. Where should it be?
> 
> 
> Just to make sure these were from ovs-vswitchd:
> 
> $ file tests/testsuite.dir/0352/core
> tests/testsuite.dir/0352/core: ELF 64-bit LSB core file x86-64, version 1 (SYSV), SVR4-style, from 'ovs-vswitchd --detach --no-chdir --pidfile --enable-dummy --disable-system --lo'
> 
> 
> Here is the relevant part of the testsuite.log:
> 
> #                             -*- compilation -*-
> 352. learn.at:327: testing learning action - self-modifying flow with idle_timeout ...
> ./learn.at:328: ovsdb-tool create conf.db $abs_top_srcdir/vswitchd/vswitch.ovsschema
> ./learn.at:328: ovsdb-server --detach --no-chdir --pidfile --log-file --remote=punix:$OVS_RUNDIR/db.sock
> stderr:
> 2014-05-29T23:53:33Z|00001|vlog|INFO|opened log file /home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovsdb-server.log
> ./learn.at:328: sed < stderr '
> /vlog|INFO|opened log file/d
> /ovsdb_server|INFO|ovsdb-server (Open vSwitch)/d'
> ./learn.at:328: ovs-vsctl --no-wait init
> ./learn.at:328: ovs-vswitchd --detach --no-chdir --pidfile --enable-dummy --disable-system --log-file -vvconn -vofproto_dpif
> stderr:
> 2014-05-29T23:53:33Z|00001|vlog|INFO|opened log file /home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.log
> 2014-05-29T23:53:33Z|00002|reconnect|INFO|unix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/db.sock: connecting...
> 2014-05-29T23:53:33Z|00003|reconnect|INFO|unix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/db.sock: connected
> ./learn.at:328: sed < stderr '
> /vlog|INFO|opened log file/d
> /vswitchd|INFO|ovs-vswitchd (Open vSwitch)/d
> /reconnect|INFO|/d
> /ofproto|INFO|using datapath ID/d
> /ofproto|INFO|datapath ID changed to fedcba9876543210/d'
> ./learn.at:328: ovs-vsctl -- add-br br0 -- set bridge br0 datapath-type=dummy other-config:datapath-id=fedcba9876543210 other-config:hwaddr=aa:55:aa:55:00:00 protocols=[OpenFlow10,OpenFlow11,OpenFlow12,OpenFlow13,OpenFlow14,OpenFlow15] fail-mode=secure --  
> ./learn.at:333: ovs-ofctl add-flow br0 'actions=load:3->NXM_NX_REG0[0..15],learn(table=0,idle_timeout=5,priority=65535,NXM_OF_ETH_SRC[],NXM_OF_VLAN_TCI[0..11],output:NXM_NX_REG0[0..15]),output:2'
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> warped
> 2014-05-29T23:53:37Z|00001|jsonrpc|WARN|unix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.7393.ctl: receive error: Connection reset by peer
> 2014-05-29T23:53:37Z|00002|unixctl|WARN|error communicating with unix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.7393.ctl: Connection reset by peer
> ovs-appctl: ovs-vswitchd: transaction error (Connection reset by peer)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ovs-appctl: cannot read pidfile "/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.pid" (No such process)
> ./learn.at:362: (ovs-ofctl dump-ports br0 2; ovs-ofctl dump-ports br0 3) | sed 's/ (xid=0x[0-9a-fA-F]*)//'
> --- /dev/null	2014-05-01 09:59:01.499999924 -0700
> +++ /home/jrajahalme/openvswitch/tests/testsuite.dir/at-groups/352/stderr	2014-05-29 16:53:39.034074996 -0700
> @@ -0,0 +1,2 @@
> +ovs-ofctl: /home/jrajahalme/openvswitch/tests/testsuite.dir/0352/br0.mgmt: failed to open socket (Connection refused)
> +ovs-ofctl: /home/jrajahalme/openvswitch/tests/testsuite.dir/0352/br0.mgmt: failed to open socket (Connection refused)
> --- -	2014-05-29 16:53:39.039011059 -0700
> +++ /home/jrajahalme/openvswitch/tests/testsuite.dir/at-groups/352/stdout	2014-05-29 16:53:39.034074996 -0700
> @@ -1,7 +1 @@
> -OFPST_PORT reply: 1 ports
> -  port  2: rx pkts=0, bytes=0, drop=0, errs=0, frame=0, over=0, crc=0
> -           tx pkts=2, bytes=120, drop=0, errs=0, coll=0
> -OFPST_PORT reply: 1 ports
> -  port  3: rx pkts=0, bytes=0, drop=0, errs=0, frame=0, over=0, crc=0
> -           tx pkts=18, bytes=1080, drop=0, errs=0, coll=0
> 
> ovsdb-server.log:
>> 2014-05-29T23:53:33.664Z|00001|vlog|INFO|opened log file /home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovsdb-server.log
>> 2014-05-29T23:53:33.668Z|00002|ovsdb_server|INFO|ovsdb-server (Open vSwitch) 2.3.90
> ovs-vswitchd.log:
>> 2014-05-29T23:53:33.680Z|00001|vlog|INFO|opened log file /home/jrajahalme/openvswitch/tests/testsuite.dir/0352/ovs-vswitchd.log
>> 2014-05-29T23:53:33.680Z|00002|reconnect|INFO|unix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/db.sock: connecting...
>> 2014-05-29T23:53:33.681Z|00003|reconnect|INFO|unix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/db.sock: connected
>> 2014-05-29T23:53:33.682Z|00004|bridge|INFO|ovs-vswitchd (Open vSwitch) 2.3.90
>> 2014-05-29T23:53:33.690Z|00005|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports recirculation
>> 2014-05-29T23:53:33.691Z|00006|ofproto_dpif|INFO|dummy at ovs-dummy: MPLS label stack length probed as 3
>> 2014-05-29T23:53:33.692Z|00007|bridge|INFO|bridge br0: added interface br0 on port 65534
>> 2014-05-29T23:53:33.692Z|00008|bridge|INFO|bridge br0: using datapath ID fedcba9876543210
>> 2014-05-29T23:53:33.692Z|00009|connmgr|INFO|br0: added service controller "punix:/home/jrajahalme/openvswitch/tests/testsuite.dir/0352/br0.mgmt"
>> 2014-05-29T23:53:33.693Z|00010|ofproto_dpif|DBG|need revalidate in ofproto_wait_cb()
>> 2014-05-29T23:53:33.698Z|00011|bridge|INFO|bridge br0: added interface p3 on port 3
>> 2014-05-29T23:53:33.698Z|00012|bridge|INFO|bridge br0: added interface p2 on port 2
>> 2014-05-29T23:53:33.698Z|00013|bridge|INFO|bridge br0: added interface p1 on port 1
>> 2014-05-29T23:53:33.699Z|00014|ofproto_dpif|DBG|need revalidate in ofproto_wait_cb()
>> 2014-05-29T23:53:33.705Z|00015|vconn|DBG|unix: sent (Success): OFPT_HELLO (OF1.5) (xid=0x1):
>> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
>> 2014-05-29T23:53:33.706Z|00016|vconn|DBG|unix: received: OFPT_HELLO (xid=0x1):
>> version bitmap: 0x01
>> 2014-05-29T23:53:33.706Z|00017|vconn|DBG|unix: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
>> 2014-05-29T23:53:33.706Z|00018|vconn|DBG|unix: received: OFPT_FLOW_MOD (xid=0x2): ADD actions=load:0x3->NXM_NX_REG0[0..15],learn(table=0,idle_timeout=5,priority=65535,NXM_OF_ETH_SRC[],NXM_OF_VLAN_TCI[0..11],output:NXM_NX_REG0[0..15]),output:2
>> 2014-05-29T23:53:33.706Z|00019|ofproto_dpif|DBG|need revalidate in ofproto_wait_cb()
>> 2014-05-29T23:53:33.706Z|00020|vconn|DBG|unix: received: OFPT_BARRIER_REQUEST (xid=0x3):
>> 2014-05-29T23:53:33.706Z|00021|vconn|DBG|unix: sent (Success): OFPT_BARRIER_REPLY (xid=0x3):
>> 2014-05-29T23:53:33.707Z|00022|connmgr|INFO|br0<->unix: 1 flow_mods in the last 0 s (1 adds)
>> 2014-05-29T23:53:36.997Z|00023|ofproto_dpif|DBG|need revalidate in ofproto_wait_cb()
> ./cleanup: line 1: kill: (7393) - No such process
> 352. learn.at:327: 352. learning action - self-modifying flow with idle_timeout (learn.at:327): FAILED (learn.at:362)
> 
> 
>>> m4_divert_pop([PREPARE_TESTS])
>>> 
>>> # OVS_VSWITCHD_STOP([WHITELIST])
>>> @@ -108,8 +122,12 @@ m4_divert_pop([PREPARE_TESTS])
>>> # commands to delete any warnings that are actually expected, e.g.:
>>> #
>>> #   OVS_VSWITCHD_STOP(["/expected error/d"])
>>> +#
>>> +# Also tries to check for core dumps, although this only works if your system
>>> +# produces its core dumps in the current directory and gives them names that
>>> +# begin with "core".
>>> m4_define([OVS_VSWITCHD_STOP],
>>> -  [AT_CHECK([check_logs $1])
>>> +  [AT_CHECK([check_logs $1 && check_cores])
>>>   AT_CHECK([ovs-appctl -t ovs-vswitchd exit])
>>>   AT_CHECK([ovs-appctl -t ovsdb-server exit])])
>>> 
>>> --
>>> 1.7.10.4
>>> 
>> 
>> 
>> 
>> -- 
>> "I don't normally do acked-by's.  I think it's my way of avoiding
>> getting blamed when it all blows up."               Andrew Morton

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openvswitch.org/pipermail/ovs-dev/attachments/20140530/3017e9e8/attachment-0005.html>


More information about the dev mailing list