Intermittent "Neutron did not start" failures in the gate

Bug #1819897 reported by Matt Riedemann
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
Fix Released
Medium
Unassigned

Bug Description

Seen here:

http://logs.openstack.org/68/642068/2/gate/tempest-full-py3/3648e00/controller/logs/devstacklog.txt.gz#_2019-03-13_09_43_32_198

2019-03-13 09:42:32.696 | + functions-common:test_with_retry:2261 : timeout 60 sh -c 'while ! wget --no-proxy -q -O- http://198.72.124.14:19696; do sleep 0.5; done'
2019-03-13 09:43:32.198 | + functions-common:test_with_retry:2262 : die 2262 'Neutron did not start'
2019-03-13 09:43:32.203 | + functions-common:die:195 : local exitcode=0
2019-03-13 09:43:32.207 | [Call Trace]
2019-03-13 09:43:32.207 | ./stack.sh:1303:start_neutron_service_and_check
2019-03-13 09:43:32.207 | /opt/stack/devstack/lib/neutron-legacy:504:test_with_retry
2019-03-13 09:43:32.207 | /opt/stack/devstack/functions-common:2262:die
2019-03-13 09:43:32.213 | [ERROR] /opt/stack/devstack/functions-common:2262 Neutron did not start

devstack waits up to 60 seconds to neutron API to start and looking at the API logs it took longer than 2 minutes:

http://logs.openstack.org/68/642068/2/gate/tempest-full-py3/3648e00/controller/logs/screen-q-svc.txt.gz

Starts here:

Mar 13 09:42:31.162711 ubuntu-bionic-inap-mtl01-0003755170 systemd[1]: Started Devstack <email address hidden>.

This is the last API log entry:

Mar 13 09:44:18.906122 ubuntu-bionic-inap-mtl01-0003755170 neutron-server[10000]: DEBUG oslo_service.service [-] ******************************************************************************** {{(pid=10000) log_opt_values /usr/local/lib/python3.6/dist-packages/oslo_config/cfg.py:2577}}

Looks like there is a big jump in time here:

Mar 13 09:42:35.558034 ubuntu-bionic-inap-mtl01-0003755170 neutron-server[10000]: DEBUG oslo_db.sqlalchemy.engines [None req-46b360f6-5a07-4e28-ad6d-7820e1c174b9 None None] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION {{(pid=10000) _check_effective_sql_mode /usr/local/lib/python3.6/dist-packages/oslo_db/sqlalchemy/engines.py:307}}
Mar 13 09:44:18.212177 ubuntu-bionic-inap-mtl01-0003755170 neutron-server[10000]: INFO neutron.plugins.ml2.managers [None req-46b360f6-5a07-4e28-ad6d-7820e1c174b9 None None] Initializing driver for type 'gre'

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22%5BERROR%5D%5C%22%20AND%20message%3A%5C%22Neutron%20did%20not%20start%5C%22%20AND%20tags%3A%5C%22console%5C%22%20AND%20voting%3A1&from=7d

Tags: gate-failure
Revision history for this message
Matt Riedemann (mriedem) wrote :
Download full text (9.5 KiB)

frickler also pointed out these other failures that result in the same devstack timeout but have obvious failures in the neutron API logs:

http://logs.openstack.org/34/642834/1/check/tempest-full/f8a254a/controller/logs/screen-q-svc.txt.gz?level=TRACE

Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service [None req-4fee45c3-a421-4505-9136-36a95fa1d327 None None] Unrecoverable error: please check log for details.: ExtensionsNotFound: Extensions not found: ['subnet-service-types'].
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service Traceback (most recent call last):
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/opt/stack/neutron/neutron/service.py", line 88, in serve_wsgi
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service service.start()
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/opt/stack/neutron/neutron/service.py", line 64, in start
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service self.wsgi_app = _run_wsgi(self.app_name)
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/opt/stack/neutron/neutron/service.py", line 316, in _run_wsgi
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service app = config.load_paste_app(app_name)
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/opt/stack/neutron/neutron/common/config.py", line 125, in load_paste_app
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service app = loader.load_app(app_name)
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/usr/local/lib/python2.7/dist-packages/oslo_service/wsgi.py", line 353, in load_app
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service return deploy.loadapp("config:%s" % self.config_path, name=name)
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/usr/local/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 253, in loadapp
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service return loadobj(APP, uri, name=name, **kw)
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/usr/local/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 278, in loadobj
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service return context.create()
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron-server[3874]: ERROR neutron.service File "/usr/local/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 715, in create
Mar 12 18:16:06.388244 ubuntu-bionic-ovh-bhs1-0003715080 neutron...

Read more...

Revision history for this message
LIU Yulong (dragon889) wrote :

This "ExtensionsNotFound: Extensions not found: ['subnet-service-types']." may only come from this refactor patch:
https://review.openstack.org/#/c/642834

Revision history for this message
LIU Yulong (dragon889) wrote :

And most "Neutron did not start" failures are coming from this:
https://review.openstack.org/#/c/641186
it is trying to rename the process tittle by using this:
https://review.openstack.org/#/c/637019/

This one seems still in progress:
https://review.openstack.org/#/c/639585/

Revision history for this message
Slawek Kaplonski (slaweq) wrote :

I'm closing this bug now as I don't think we still have such issue in the gate currently.

Changed in neutron:
status: Confirmed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.