On Thu, Sep 8, 2016 at 3:19 PM, Dan Kenigsberg <danken@redhat.com> wrote:

On Thu, Sep 08, 2016 at 02:23:24PM +0300, Nir Soffer wrote:
> On Thu, Sep 8, 2016 at 2:20 PM, Nir Soffer <nsoffer@redhat.com> wrote:
> > Seen this (new?) failure on master - please check:

Please rebase on top of the recent fix
of https://gerrit.ovirt.org/63516

> >
> > http://jenkins.ovirt.org/job/vdsm_master_check-patch-el7-x86_64/216/console
> >
> > 0:59:51 ======================================================================
> > 10:59:51 FAIL: test_ip_info (network.netinfo_test.TestNetinfo)
> > 10:59:51 ----------------------------------------------------------------------
> > 10:59:51 Traceback (most recent call last):
> > 10:59:51 File
> > "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/testValidation.py",
> > line 97, in wrapper
> > 10:59:51 return f(*args, **kwargs)
> > 10:59:51 File
> > "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/network/netinfo_test.py",
> > line 359, in test_ip_info
> > 10:59:51 [IPV6_ADDR_CIDR]))
> > 10:59:51 AssertionError: Tuples differ: ('192.0.2.2',
> > '255.255.255.0',... != ('192.0.2.2', '255.255.255.0',...
> > 10:59:51
> > 10:59:51 First differing element 2:
> > 10:59:51 ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32']
> > 10:59:51 ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32', '192.0.2.3/24']
> > 10:59:51
> > 10:59:51 ('192.0.2.2',
> > 10:59:51 '255.255.255.0',
> > 10:59:51 - ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32'],
> > 10:59:51 + ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32',
> > '192.0.2.3/24'],
> > 10:59:51 ?
> > ++++++++++++++++
> > 10:59:51
> > 10:59:51 ['2607:f0d0:1002:51::4/64'])
> > 10:59:51 -------------------- >> begin captured logging << --------------------
> > 10:59:51 2016-09-08 10:59:40,924 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip link add name dummy_GX6CE
> > type dummy (cwd None)
> > 10:59:51 2016-09-08 10:59:40,944 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:40,950 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip link set dev dummy_GX6CE up
> > (cwd None)
> > 10:59:51 2016-09-08 10:59:40,968 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:40,971 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip -4 addr add dev dummy_GX6CE
> > 192.0.2.2/24 (cwd None)
> > 10:59:51 2016-09-08 10:59:40,988 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:40,991 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip -4 addr add dev dummy_GX6CE
> > 192.0.2.3/24 (cwd None)
> > 10:59:51 2016-09-08 10:59:41,007 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:41,010 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip -4 addr add dev dummy_GX6CE
> > 198.51.100.9/24 (cwd None)
> > 10:59:51 2016-09-08 10:59:41,037 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:41,040 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip -6 addr add dev dummy_GX6CE
> > 2607:f0d0:1002:51::4/64 (cwd None)
> > 10:59:51 2016-09-08 10:59:41,067 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:41,071 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip -4 addr add dev dummy_GX6CE
> > 198.51.100.11/32 (cwd None)
> > 10:59:51 2016-09-08 10:59:41,090 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 2016-09-08 10:59:41,102 DEBUG [root] (MainThread)
> > /usr/bin/taskset --cpu-list 0-1 /sbin/ip link del dev dummy_GX6CE (cwd
> > None)
> > 10:59:51 2016-09-08 10:59:41,133 DEBUG [root] (MainThread) SUCCESS:
> > <err> = ''; <rc> = 0
> > 10:59:51 --------------------- >> end captured logging << ---------------------
>
> Another instance here:
> http://jenkins.ovirt.org/job/vdsm_master_check-patch-el7-x86_64/212/console
>
> 0:58:52 ======================================================================
> 10:58:52 FAIL: test_ip_info (network.netinfo_test.TestNetinfo)
> 10:58:52 ----------------------------------------------------------------------
> 10:58:52 Traceback (most recent call last):
> 10:58:52 File
> "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/testValidation.py",
> line 97, in wrapper
> 10:58:52 return f(*args, **kwargs)
> 10:58:52 File
> "/home/jenkins/workspace/vdsm_master_check-patch-el7-x86_64/vdsm/tests/network/netinfo_test.py",
> line 359, in test_ip_info
> 10:58:52 [IPV6_ADDR_CIDR]))
> 10:58:52 AssertionError: Tuples differ: ('192.0.2.2',
> '255.255.255.0',... != ('192.0.2.2', '255.255.255.0',...
> 10:58:52
> 10:58:52 First differing element 2:
> 10:58:52 ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32']
> 10:58:52 ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32', '192.0.2.3/24']
> 10:58:52
> 10:58:52 ('192.0.2.2',
> 10:58:52 '255.255.255.0',
> 10:58:52 - ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32'],
> 10:58:52 + ['192.0.2.2/24', '198.51.100.9/24', '198.51.100.11/32',
> '192.0.2.3/24'],
> 10:58:52 ?
> ++++++++++++++++
> 10:58:52
> 10:58:52 ['2607:f0d0:1002:51::4/64'])
> 10:58:52 -------------------- >> begin captured logging << --------------------
> 10:58:52 2016-09-08 10:58:42,213 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip link add name dummy_8awuY
> type dummy (cwd None)
> 10:58:52 2016-09-08 10:58:42,221 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,224 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip link set dev dummy_8awuY up
> (cwd None)
> 10:58:52 2016-09-08 10:58:42,237 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,240 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip -4 addr add dev dummy_8awuY
> 192.0.2.2/24 (cwd None)
> 10:58:52 2016-09-08 10:58:42,250 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,252 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip -4 addr add dev dummy_8awuY
> 192.0.2.3/24 (cwd None)
> 10:58:52 2016-09-08 10:58:42,259 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,260 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip -4 addr add dev dummy_8awuY
> 198.51.100.9/24 (cwd None)
> 10:58:52 2016-09-08 10:58:42,267 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,269 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip -6 addr add dev dummy_8awuY
> 2607:f0d0:1002:51::4/64 (cwd None)
> 10:58:52 2016-09-08 10:58:42,276 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,278 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip -4 addr add dev dummy_8awuY
> 198.51.100.11/32 (cwd None)
> 10:58:52 2016-09-08 10:58:42,289 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 2016-09-08 10:58:42,293 DEBUG [root] (MainThread)
> /usr/bin/taskset --cpu-list 0-31 /sbin/ip link del dev dummy_8awuY
> (cwd None)
> 10:58:52 2016-09-08 10:58:42,322 DEBUG [root] (MainThread) SUCCESS:
> <err> = ''; <rc> = 0
> 10:58:52 --------------------- >> end captured logging << ---------------------

This looks like a new one... I suspect that the kernel is sending multiple identical events.

We can try and fix it by waiting for a specific IP.