Comment 3 for bug 1415522

Revision history for this message
Rajeev Grover (rajeev-grover) wrote :

Too early to conclude anything but from an analysis of the failing job http://logs.openstack.org/22/149122/3/check/check-tempest-dsvm-neutron-dvr/35e420c/logs/testr_results.html.gz noticed a few things:

a) Most of the failing tests appear to be towards the end of the test suite consisting of 1667+ test

b) It appears the test cases timeout while the L-3 agent is still in the middle of configuring the iptables for the floatingip. Here are couple of timing correlations I found in this particular test job.

c) While looking at these Mike brought up the point that there is a large accumulation of namespaces towards the tail end of the test suite. These accumulated namespaces could slow down the L-3 agent significantly.

http://logs.openstack.org/22/149122/3/check/check-tempest-dsvm-neutron-dvr/35e420c/logs/testr_results.html.gz

--> test_network_basic_ops[compute,gate,network,smoke]

2015-01-26 03:33:00,337 8115 DEBUG [tempest.scenario.manager] checking network connections to IP 172.24.4.119 with user: cirros
2015-01-26 03:35:00,550 8115 ERROR [tempest.scenario.manager] Public network connectivity check failed
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager Traceback (most recent call last):
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager File "tempest/scenario/manager.py", line 501, in check_public_network_connectivity
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager should_connect=should_connect)
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager File "tempest/scenario/manager.py", line 485, in check_vm_connectivity
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager msg=msg)
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager File "/usr/local/lib/python2.7/dist-packages/unittest2/case.py", line 678, in assertTrue
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager raise self.failureException(msg)
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager AssertionError: False is not true : Timed out waiting for 172.24.4.119 to become reachable
2015-01-26 03:35:00.550 8115 TRACE tempest.scenario.manager

---> From L-3 agent log:

2015-01-26 03:35:03.970 DEBUG neutron.agent.linux.utils [req-8ba4a420-10d9-4581-86a0-8fbcd866a745 TestNetworkBasicOps-82148639 TestNetworkBasicOps-1630875080]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-190c5c9d-4c95-4a77-8efd-cc205e776caf', 'iptables-save', '-c']
Exit code: 0
Stdout: # Generated by iptables-save v1.4.21 on Mon Jan 26 03:35:03 2015
*raw
:PREROUTING ACCEPT [3:714]
:OUTPUT ACCEPT [1:84]
:neutron-vpn-agen-OUTPUT - [0:0]
:neutron-vpn-agen-PREROUTING - [0:0]
[3:714] -A PREROUTING -j neutron-vpn-agen-PREROUTING
[1:84] -A OUTPUT -j neutron-vpn-agen-OUTPUT
COMMIT
# Completed on Mon Jan 26 03:35:03 2015
# Generated by iptables-save v1.4.21 on Mon Jan 26 03:35:03 2015
*nat
:PREROUTING ACCEPT [2:393]
:INPUT ACCEPT [2:393]
:OUTPUT ACCEPT [0:0]
:POSTROUTING ACCEPT [0:0]
:neutron-postrouting-bottom - [0:0]
:neutron-vpn-agen-OUTPUT - [0:0]
:neutron-vpn-agen-POSTROUTING - [0:0]
:neutron-vpn-agen-PREROUTING - [0:0]
:neutron-vpn-agen-float-snat - [0:0]
:neutron-vpn-agen-snat - [0:0]
[2:393] -A PREROUTING -j neutron-vpn-agen-PREROUTING
[0:0] -A OUTPUT -j neutron-vpn-agen-OUTPUT
[0:0] -A POSTROUTING -j neutron-vpn-agen-POSTROUTING
[0:0] -A POSTROUTING -j neutron-postrouting-bottom
[0:0] -A neutron-postrouting-bottom -m comment --comment "Perform source NAT on outgoing traffic." -j neutron-vpn-agen-snat
[0:0] -A neutron-vpn-agen-OUTPUT -d 172.24.4.119/32 -j DNAT --to-destination 10.100.0.3
[0:0] -A neutron-vpn-agen-PREROUTING -d 169.254.169.254/32 -p tcp -m tcp --dport 80 -j REDIRECT --to-ports 9697
[0:0] -A neutron-vpn-agen-PREROUTING -d 172.24.4.119/32 -j DNAT --to-destination 10.100.0.3
[0:0] -A neutron-vpn-agen-float-snat -s 10.100.0.3/32 -j SNAT --to-source 172.24.4.119
[0:0] -A neutron-vpn-agen-snat -j neutron-vpn-agen-float-snat
COMMIT
# Completed on Mon Jan 26 03:35:03 2015

---> test_dhcp6_stateless_from_os[compute,network]

2015-01-26 03:35:23.908 8113 TRACE tempest.common.ssh
2015-01-26 03:35:23,909 8113 ERROR [tempest.scenario.manager] Initializing SSH connection to 172.24.4.117 failed
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager Traceback (most recent call last):
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager File "tempest/scenario/manager.py", line 317, in get_remote_client
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager linux_client.validate_authentication()
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager File "tempest/common/utils/linux/remote_client.py", line 55, in validate_authentication
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager self.ssh_client.test_connection_auth()
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager File "tempest/common/ssh.py", line 151, in test_connection_auth
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager connection = self._get_ssh_connection()
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager File "tempest/common/ssh.py", line 88, in _get_ssh_connection
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager password=self.password)
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager SSHTimeout: Connection to the 172.24.4.117 via SSH timed out.
2015-01-26 03:35:23.909 8113 TRACE tempest.scenario.manager User: cirros, Password: None

---> From L-3 agent log:

Command: ['sudo', '/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-1f8d3856-b065-446c-9d73-38b763c962e1', 'iptables-save', '-c']
Exit code: 0
Stdout: # Generated by iptables-save v1.4.21 on Mon Jan 26 03:35:27 2015
*raw
:PREROUTING ACCEPT [3:714]
:OUTPUT ACCEPT [1:84]
:neutron-vpn-agen-OUTPUT - [0:0]
:neutron-vpn-agen-PREROUTING - [0:0]
[3:714] -A PREROUTING -j neutron-vpn-agen-PREROUTING
[1:84] -A OUTPUT -j neutron-vpn-agen-OUTPUT
COMMIT
# Completed on Mon Jan 26 03:35:27 2015
# Generated by iptables-save v1.4.21 on Mon Jan 26 03:35:27 2015
*nat
:PREROUTING ACCEPT [2:393]
:INPUT ACCEPT [2:393]
:OUTPUT ACCEPT [0:0]
:POSTROUTING ACCEPT [0:0]
:neutron-postrouting-bottom - [0:0]
:neutron-vpn-agen-OUTPUT - [0:0]
:neutron-vpn-agen-POSTROUTING - [0:0]
:neutron-vpn-agen-PREROUTING - [0:0]
:neutron-vpn-agen-float-snat - [0:0]
:neutron-vpn-agen-snat - [0:0]
[2:393] -A PREROUTING -j neutron-vpn-agen-PREROUTING
[0:0] -A OUTPUT -j neutron-vpn-agen-OUTPUT
[0:0] -A POSTROUTING -j neutron-vpn-agen-POSTROUTING
[0:0] -A POSTROUTING -j neutron-postrouting-bottom
[0:0] -A neutron-postrouting-bottom -m comment --comment "Perform source NAT on outgoing traffic." -j neutron-vpn-agen-snat
[0:0] -A neutron-vpn-agen-OUTPUT -d 172.24.4.117/32 -j DNAT --to-destination 10.100.0.3
[0:0] -A neutron-vpn-agen-PREROUTING -d 169.254.169.254/32 -p tcp -m tcp --dport 80 -j REDIRECT --to-ports 9697
[0:0] -A neutron-vpn-agen-PREROUTING -d 172.24.4.117/32 -j DNAT --to-destination 10.100.0.3
[0:0] -A neutron-vpn-agen-float-snat -s 10.100.0.3/32 -j SNAT --to-source 172.24.4.117
[0:0] -A neutron-vpn-agen-snat -j neutron-vpn-agen-float-snat
COMMIT