"test_dualnet_dhcp6_stateless_from_os" failures seen in the gate

[Swaminathan Vasudevan]

"test_dualnet_dhcp6_stateless_from_os" - This test fails in the gate randomly both with DVR and non-DVR routers.

http://logs.openstack.org/79/230079/27/check/gate-tempest-dsvm-neutron-full/1caed8b/logs/testr_results.html.gz

http://logs.openstack.org/85/238485/1/check/gate-tempest-dsvm-neutron-dvr/1059e22/logs/testr_results.html.gz

[Ritesh Anand (ritesh-anand)]

While triaging the issue, I found that:
In tempest/scenario/manager.py ScenarioTest:create_server() calls
servers_client.create_server(name=name, imageRef=image,
                                                   flavorRef=flavor,
                                                   **create_kwargs)['server']
With ports (1 on each subnet) passed in create_kwargs.

However, the returned server does not consistently have proper port mapping.

This port_mapping is needed for fip creation.
As queried here:
ports = self._list_ports(device_id=server['id'], status='ACTIVE',
                                 fixed_ip=ip_addr)

I also noticed some comments in the same function that may be relevant here:
# The instance retrieved on creation is missing network
# details, necessitating retrieval after it becomes active to
# ensure correct details.

The trace in the failed test:
Traceback (most recent call last):
  File "tempest/test.py", line 127, in wrapper
    return f(self, *func_args, **func_kwargs)
  File "tempest/scenario/test_network_v6.py", line 248, in test_dualnet_multi_prefix_dhcpv6_stateless
    dualnet=True)
  File "tempest/scenario/test_network_v6.py", line 158, in _prepare_and_test
    sshv4_2, ips_from_api_2, sid2 = self.prepare_server(networks=net_list)
  File "tempest/scenario/test_network_v6.py", line 126, in prepare_server
    fip = self.create_floating_ip(thing=srv)
  File "tempest/scenario/manager.py", line 778, in create_floating_ip
    port_id, ip4 = self._get_server_port_id_and_ip4(thing)
  File "tempest/scenario/manager.py", line 759, in _get_server_port_id_and_ip4
    % port_map)
  File "/opt/stack/new/tempest/.tox/full/local/lib/python2.7/site-packages/testtools/testcase.py", line 350, in assertEqual
    self.assertThat(observed, matcher, message)
  File "/opt/stack/new/tempest/.tox/full/local/lib/python2.7/site-packages/testtools/testcase.py", line 435, in assertThat
    raise mismatch_error
testtools.matchers._impl.MismatchError: 0 != 1: Found multiple IPv4 addresses: []. Unable to determine which port to target.

[Matt Riedemann (mriedem)]

http://logs.openstack.org/71/231271/8/gate/gate-tempest-dsvm-neutron-full/1be12e3/console.html#_2015-10-29_09_18_25_892

2015-10-29 09:18:25.892 | Captured traceback:
2015-10-29 09:18:25.892 | ~~~~~~~~~~~~~~~~~~~
2015-10-29 09:18:25.892 | Traceback (most recent call last):
2015-10-29 09:18:25.892 | File "tempest/test.py", line 127, in wrapper
2015-10-29 09:18:25.892 | return f(self, *func_args, **func_kwargs)
2015-10-29 09:18:25.892 | File "tempest/scenario/test_network_v6.py", line 242, in test_dualnet_dhcp6_stateless_from_os
2015-10-29 09:18:25.892 | self._prepare_and_test(address6_mode='dhcpv6-stateless', dualnet=True)
2015-10-29 09:18:25.893 | File "tempest/scenario/test_network_v6.py", line 199, in _prepare_and_test
2015-10-29 09:18:25.893 | self.subnets_v6[i].gateway_ip)
2015-10-29 09:18:25.893 | File "tempest/scenario/test_network_v6.py", line 211, in _check_connectivity
2015-10-29 09:18:25.893 | (dest, source.ssh_client.host)
2015-10-29 09:18:25.893 | File "/opt/stack/new/tempest/.tox/full/local/lib/python2.7/site-packages/unittest2/case.py", line 702, in assertTrue
2015-10-29 09:18:25.893 | raise self.failureException(msg)
2015-10-29 09:18:25.893 | AssertionError: False is not true : Timed out waiting for 2003::1 to become reachable from 172.24.5.129

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message:%5C%22AssertionError:%20False%20is%20not%20true%20:%20Timed%20out%20waiting%20for%202003::1%20to%20become%20reachable%20from%5C%22%20AND%20tags:%5C%22console%5C%22%20AND%20NOT%20build_queue:%5C%22periodic-qa%5C%22

16 hits in 7 days, check and gate, all failures.

[Matt Riedemann (mriedem)]

It looks like when this failed here:

http://logs.openstack.org/71/231271/8/gate/gate-tempest-dsvm-neutron-full/1be12e3/console.html#_2015-10-29_09_18_25_821

The port status was DOWN on 172.24.5.129 which is what we're trying to ssh into.

[Matt Riedemann (mriedem)]

Maybe the floating IP status being DOWN doesn't matter since I see that happens in cases that the test passes too:

http://logs.openstack.org/17/227517/15/check/gate-tempest-dsvm-neutron-full/fc0aae8/logs/tempest.txt.gz#_2015-10-22_20_35_29_627

[Armando Migliaccio (armando-migliaccio)]

This failed 0 times during the past 7 days in the gate queue.

[Armando Migliaccio (armando-migliaccio)]

Again, this failed 0 times during the past 7 days in any queue.

[Armando Migliaccio (armando-migliaccio)]

Marking incomplete, unless this shows up again and new evidence is collected for triaging/troubleshooting.

[Armando Migliaccio (armando-migliaccio)]

This showed up not so long ago:

http://logs.openstack.org/25/269125/10/gate/gate-tempest-dsvm-neutron-full/d94bc79/logs/testr_results.html.gz

bugs have souls.

[Jordan Pittier (jordan-pittier)]

Stumbled upon this today: http://logs.openstack.org/00/295900/3/check/gate-tempest-dsvm-neutron-dvr/93918ea/console.html#_2016-03-27_18_53_46_331

Logstash query

message:"AssertionError: False is not true : Timed out waiting for 2003::1 to become reachable from" AND tags:console

100% failure, 10 hits in the past 7 days.

[Oleg Bondarev (obondarev)]

This might be the culprit: https://bugs.launchpad.net/neutron/+bug/1581918

[Ihar Hrachyshka (ihar-hrachyshka)]

Just happened in stable/mitaka with: http://logs.openstack.org/88/305788/3/check/gate-tempest-dsvm-neutron-dvr/f7c6d69/logs/testr_results.html.gz Since the dnsmasq patch Oleg mentioned was already backported to the branch at the time the job was triggered, I doubt that fixes it.

[Carl Baldwin (carl-baldwin)]

0 hits

[Launchpad Janitor (janitor)]

[Expired for neutron because there has been no activity for 60 days.]

[Dr. Jens Harbott (j-harbott)]

54 hits in the last 7 days. Checked a couple and they all have an error like this:

http://logs.openstack.org/96/384696/1/check/gate-tempest-dsvm-neutron-placement-full-ubuntu-xenial-nv/c19ea11/logs/screen-q-svc.txt.gz?level=ERROR#_2016-10-10_20_45_30_546

/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py:68: SAWarning: An exception has occurred during handling of a previous exception. The previous exception is:
 <class 'oslo_db.exception.DBDeadlock'> (pymysql.err.InternalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'INSERT INTO ipallocations (port_id, ip_address, subnet_id, network_id) VALUES (%(port_id)s, %(ip_address)s, %(subnet_id)s, %(network_id)s)'] [parameters: {'network_id': u'e345189c-5ab3-4696-a860-51874e215e0a', 'subnet_id': '0d3d3a6a-5957-4cd1-bfa3-009a45957589', 'port_id': u'84722cc3-107b-49bb-b422-e858a8fa7b79', 'ip_address': '2003::f816:3eff:feb9:b9a1'}]

[Anindita Das (anindita-das)]

http://logs.openstack.org/72/385072/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/9f79eb8/console.html#_2016-10-17_15_50_55_879518

2016-10-17 15:50:55.879518 | Captured traceback:
2016-10-17 15:50:55.879534 | ~~~~~~~~~~~~~~~~~~~
2016-10-17 15:50:55.879565 | Traceback (most recent call last):
2016-10-17 15:50:55.879593 | File "tempest/test.py", line 100, in wrapper
2016-10-17 15:50:55.879618 | return f(self, *func_args, **func_kwargs)
2016-10-17 15:50:55.879657 | File "tempest/scenario/test_network_v6.py", line 256, in test_dualnet_multi_prefix_dhcpv6_stateless
2016-10-17 15:50:55.879674 | dualnet=True)
2016-10-17 15:50:55.879706 | File "tempest/scenario/test_network_v6.py", line 203, in _prepare_and_test
2016-10-17 15:50:55.879729 | self.subnets_v6[i]['gateway_ip'])
2016-10-17 15:50:55.879761 | File "tempest/scenario/test_network_v6.py", line 213, in _check_connectivity
2016-10-17 15:50:55.879783 | (dest, source.ssh_client.host)
2016-10-17 15:50:55.879826 | File "/opt/stack/new/tempest/.tox/tempest/local/lib/python2.7/site-packages/unittest2/case.py", line 702, in assertTrue
2016-10-17 15:50:55.879857 | raise self.failureException(msg)
2016-10-17 15:50:55.879898 | AssertionError: False is not true : Timed out waiting for 2003::1 to become reachable from 172.24.5.4

http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22AssertionError:%20False%20is%20not%20true%20:%20Timed%20out%20waiting%20for%202003::1%20to%20become%20reachable%20from%5C%22%20AND%20tags:%5C%22console%5C%22%20AND%20NOT%20build_queue:%5C%22periodic-qa%5C%22

53 hits in last 7days

[Miguel Lavalle (minsel)]

0 hits over the past 7 days using:

http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22AssertionError:%20False%20is%20not%20true%20:%20Timed%20out%20waiting%20for%202003::1%20to%20become%20reachable%20from%5C%22%20AND%20tags:%5C%22console%5C%22%20AND%20NOT%20build_queue:%5C%22periodic-qa%5C%22

Closing it

[Dr. Jens Harbott (j-harbott)]

Still happening, e.g.:

http://logs.openstack.org/22/416822/1/check/gate-tempest-dsvm-full-devstack-plugin-ceph-ubuntu-xenial/564002b/

[Ihar Hrachyshka (ihar-hrachyshka)]

4 hits in last 7 days.

[Miguel Lavalle (minsel)]

Using this search:

http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22AssertionError:%20False%20is%20not%20true%20:%20Timed%20out%20waiting%20for%202003::1%20to%20become%20reachable%20from%5C%22%20AND%20tags:%5C%22console%5C%22%20AND%20NOT%20build_queue:%5C%22periodic-qa%5C%22

We are finding 0 hits for this bug. Also, Elastic recheck has 0 hits as of today:

Bug 1509004 - "test_dualnet_dhcp6_stateless_from_os" failures seen in the gate
0 fails in 24 hrs / 0 fails in 10 days
Projects: (neutron - Confirmed)
No matches
Logstash Launchpad

We are going to monitor this bug for one more week and close it if we don't see any hits.

[Miguel Lavalle (minsel)]

I have continued watching this bug over the past 14 days. The search:

http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22AssertionError:%20False%20is%20not%20true%20:%20Timed%20out%20waiting%20for%202003::1%20to%20become%20reachable%20from%5C%22%20AND%20tags:%5C%22console%5C%22%20AND%20NOT%20build_queue:%5C%22periodic-qa%5C%22

Only produced 2 hits, both in networking-sfc. One of the hits is is in a non-voting job: gate-tempest-dsvm-networking-sfc-multinode-ubuntu-xenial-nv. The other one is in gate-tempest-dsvm-networking-sfc-ubuntu-xenial, with a patchset that is failing many other tests.

Closing this bug