Description:-
============
Compute Component pipeline[1] - standalone jobs is failing during deployment because nova_wait_for_api_service container failed to start.
[1] http://dashboard-ci.tripleo.org/d/FE8Hf29Wz/component-pipeline?orgId=1
Error Snippet
=============
https://logserver.rdoproject.org/openstack-component-compute/opendev.org/openstack/tripleo-ci/master/periodic-tripleo-ci-centos-8-standalone-full-tempest-scenario-compute-master/b952891/job-output.txt
~~~
2020-04-12 08:56:08.172835 | primary | TASK [tripleo_deploy : Standalone deploy] **************************************
2020-04-12 08:56:08.172988 | primary | Sunday 12 April 2020 08:56:08 +0000 (0:00:00.038) 0:05:56.618 **********
2020-04-12 09:40:46.931226 | primary | fatal: [undercloud]: FAILED! => {
2020-04-12 09:40:46.931323 | primary | "ansible_job_id": "20702334658.13401",
2020-04-12 09:40:46.931346 | primary | "changed": false,
2020-04-12 09:40:46.931363 | primary | "cmd": "openstack tripleo deploy --templates $DEPLOY_TEMPLATES --standalone --yes --output-dir $DEPLOY_OUTPUT_DIR --stack $DEPLOY_STACK --standalone-role $DEPLOY_STANDALONE_ROLE --timeout $DEPLOY_TIMEOUT_ARG -e /usr/share/openstack-tripleo-heat-templates/environments/standalone/standalone-tripleo.yaml -e /home/zuul/containers-prepare-parameters.yaml -e /home/zuul/standalone_parameters.yaml -e /usr/share/openstack-tripleo-heat-templates/environments/low-memory-usage.yaml -r $DEPLOY_ROLES_FILE --deployment-user $DEPLOY_DEPLOYMENT_USER --local-ip $DEPLOY_LOCAL_IP >/home/zuul/standalone_deploy.log 2>&1",
2020-04-12 09:40:46.931378 | primary | "delta": "0:44:26.857745",
2020-04-12 09:40:46.931419 | primary | "end": "2020-04-12 09:40:36.728046",
2020-04-12 09:40:46.931439 | primary | "finished": 1,
2020-04-12 09:40:46.931456 | primary | "rc": 1,
2020-04-12 09:40:46.931471 | primary | "start": "2020-04-12 08:56:09.870301"
2020-04-12 09:40:46.931479 | primary | }
2020-04-12 09:40:46.931486 | primary |
2020-04-12 09:40:46.931493 | primary | MSG:
2020-04-12 09:40:46.931500 | primary |
2020-04-12 09:40:46.931509 | primary | non-zero return code
2020-04-12 09:40:46.938472 | primary |
2020-04-12 09:40:46.938541 | primary | PLAY RECAP *********************************************************************
2020-04-12 09:40:46.938570 | primary | undercloud : ok=82 changed=35 unreachable=0 failed=1 skipped=87 rescued=0 ignored=0
~~~
https://logserver.rdoproject.org/openstack-component-compute/opendev.org/openstack/tripleo-ci/master/periodic-tripleo-ci-centos-8-standalone-full-tempest-scenario-compute-master/b952891/logs/undercloud/home/zuul/standalone_deploy.log.txt.gz
~~~
TASK [tripleo_container_manage : Check podman create status] *******************
Sunday 12 April 2020 09:35:21 +0000 (0:00:00.486) 0:34:00.684 **********
FAILED - RETRYING: Check podman create status (60 retries left).
.
.
FAILED - RETRYING: Check podman create status (1 retries left).
ok: [standalone] => (item=None)
ok: [standalone]
TASK [tripleo_container_manage : Print the containers that failed to start] ****
Sunday 12 April 2020 09:40:34 +0000 (0:00:00.207) 0:39:13.523 **********
fatal: [standalone]: FAILED! => changed=false
msg: '[''nova_wait_for_api_service''] failed to start, check logs in /var/log/containers/stdouts/'
NO MORE HOSTS LEFT *************************************************************
PLAY RECAP *********************************************************************
standalone : ok=938 changed=457 unreachable=0 failed=1 skipped=657 rescued=0 ignored=0
~~~
https://logserver.rdoproject.org/openstack-component-compute/opendev.org/openstack/tripleo-ci/master/periodic-tripleo-ci-centos-8-standalone-full-tempest-scenario-compute-master/b952891/logs/undercloud/var/log/containers/stdouts/nova_wait_for_api_service.log.txt.gz
~~~
2020-04-12T09:35:24.323446648+00:00 stdout F DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): 192.168.24.1:8774
2020-04-12T09:35:27.218690625+00:00 stdout F DEBUG:urllib3.connectionpool:http://192.168.24.1:8774 "GET / HTTP/1.1" 500 531
2020-04-12T09:35:27.219942369+00:00 stdout F DEBUG:keystoneauth.session:RESP: [500] Connection: close Content-Length: 531 Content-Type: text/html; charset=iso-8859-1 Date: Sun, 12 Apr 2020 09:35:24 GMT Server: Apache
2020-04-12T09:35:27.219990956+00:00 stdout F DEBUG:keystoneauth.session:RESP BODY: Omitted, Content-Type is set to text/html; charset=iso-8859-1. Only application/json responses have their bodies logged.
2020-04-12T09:35:27.220253158+00:00 stdout F INFO:nova_wait_for_api_service:Waiting for nova-api service
2020-04-12T09:35:37.237495916+00:00 stdout F DEBUG:keystoneauth.session:REQ: curl -g -i -X GET http://192.168.24.1:8774 -H "Accept: application/json" -H "User-Agent: python-novaclient" -H "X-Auth-Token: {SHA256}6797e09a04499fdf85ad2caa71b34d174f1fbfe2dca1883bdc0ef20cc0f1c5e8" -H "X-OpenStack-Nova-API-Version: 2.11"
2020-04-12T09:35:37.240204660+00:00 stdout F DEBUG:urllib3.connectionpool:Resetting dropped connection: 192.168.24.1
2020-04-12T09:35:37.249796241+00:00 stdout F DEBUG:urllib3.connectionpool:http://192.168.24.1:8774 "GET / HTTP/1.1" 500 531
2020-04-12T09:35:37.250845874+00:00 stdout F DEBUG:keystoneauth.session:RESP: [500] Connection: close Content-Length: 531 Content-Type: text/html; charset=iso-8859-1 Date: Sun, 12 Apr 2020 09:35:37 GMT Server: Apache
2020-04-12T09:35:37.250929726+00:00 stdout F DEBUG:keystoneauth.session:RESP BODY: Omitted, Content-Type is set to text/html; charset=iso-8859-1. Only application/json responses have their bodies logged.
2020-04-12T09:35:37.251308182+00:00 stdout F INFO:nova_wait_for_api_service:Waiting for nova-api service
~~~
Current Behavior
================
500 error and awaiting for nova-api to come up.
~~~
2020-04-12T09:35:37.249796241+00:00 stdout F DEBUG:urllib3.connectionpool:http://192.168.24.1:8774 "GET / HTTP/1.1" 500 531
2020-04-12T09:35:37.250845874+00:00 stdout F DEBUG:keystoneauth.session:RESP: [500] Connection: close Content-Length: 531 Content-Type: text/html; charset=iso-8859-1 Date: Sun, 12 Apr 2020 09:35:37 GMT Server: Apache
2020-04-12T09:35:37.250929726+00:00 stdout F DEBUG:keystoneauth.session:RESP BODY: Omitted, Content-Type is set to text/html; charset=iso-8859-1. Only application/json responses have their bodies logged.
2020-04-12T09:35:37.251308182+00:00 stdout F INFO:nova_wait_for_api_service:Waiting for nova-api service
~~~
Expected behavior:-
=================
Good example - From 07th April:-
https://logserver.rdoproject.org/openstack-component-compute/opendev.org/openstack/tripleo-ci/master/periodic-tripleo-ci-centos-8-standalone-full-tempest-scenario-compute-master/4ec30d8/logs/undercloud/var/log/containers/stdouts/nova_wait_for_api_service.log.txt.gz
~~
2020-04-07T08:18:37.239408061+00:00 stdout F DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): 192.168.24.1:8774
2020-04-07T08:18:41.383153403+00:00 stdout F DEBUG:urllib3.connectionpool:http://192.168.24.1:8774 "GET / HTTP/1.1" 200 None
2020-04-07T08:18:41.384520749+00:00 stdout F DEBUG:keystoneauth.session:RESP: [200] Connection: Keep-Alive Content-Encoding: gzip Content-Type: application/json Date: Tue, 07 Apr 2020 08:18:37 GMT Keep-Alive: timeout=15, max=100 Server: Apache Transfer-Encoding: chunked Vary: Accept-Encoding
2020-04-07T08:18:41.384587373+00:00 stdout F DEBUG:keystoneauth.session:RESP BODY: {"versions": [{"id": "v2.0", "status": "SUPPORTED", "version": "", "min_version": "", "updated": "2011-01-21T11:33:21Z", "links": [{"rel": "self", "href": "http://192.168.24.1:8774/v2/"}]}, {"id": "v2.1", "status": "CURRENT", "version": "2.85", "min_version": "2.1", "updated": "2013-07-23T11:33:21Z", "links": [{"rel": "self", "href": "http://192.168.24.1:8774/v2.1/"}]}]}
2020-04-07T08:18:41.387128150+00:00 stdout F INFO:nova_wait_for_api_service:Nova-api service active
~~~
Main error snippet:-
https:/ /logserver. rdoproject. org/openstack- component- compute/ opendev. org/openstack/ tripleo- ci/master/ periodic- tripleo- ci-centos- 8-standalone- full-tempest- scenario- compute- master/ b952891/ logs/undercloud /var/log/ containers/ httpd/nova- api/nova_ api_wsgi_ error.log. txt.gz
~~~ cgi-bin/ nova/nova- api'. cgi-bin/ nova/nova- api'. cgi-bin/ nova/nova- api", line 6, in <module> openstack. compute. wsgi import init_application python3. 6/site- packages/ nova/api/ openstack/ compute/ __init_ _.py", line 21, in <module> openstack. compute. routes import APIRouterV21 # noqa python3. 6/site- packages/ nova/api/ openstack/ compute/ routes. py", line 43, in <module> openstack. compute import flavors_extraspecs python3. 6/site- packages/ nova/api/ openstack/ compute/ flavors_ extraspecs. py", line 24, in <module> validation. extra_specs import validators python3. 6/site- packages/ nova/api/ validation/ extra_specs/ validators. py", line 23, in <module> validation. extra_specs import base python3. 6/site- packages/ nova/api/ validation/ extra_specs/ base.py" , line 15, in <module> rror: No module named 'dataclasses'
[Sun Apr 12 09:35:27.215667 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] mod_wsgi (pid=25): Failed to exec Python script file '/var/www/
[Sun Apr 12 09:35:27.215757 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] mod_wsgi (pid=25): Exception occurred processing WSGI script '/var/www/
[Sun Apr 12 09:35:27.216907 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] Traceback (most recent call last):
[Sun Apr 12 09:35:27.216963 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] File "/var/www/
[Sun Apr 12 09:35:27.216970 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] from nova.api.
[Sun Apr 12 09:35:27.216978 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] File "/usr/lib/
[Sun Apr 12 09:35:27.216982 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] from nova.api.
[Sun Apr 12 09:35:27.216988 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] File "/usr/lib/
[Sun Apr 12 09:35:27.216992 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] from nova.api.
[Sun Apr 12 09:35:27.216998 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] File "/usr/lib/
[Sun Apr 12 09:35:27.217002 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] from nova.api.
[Sun Apr 12 09:35:27.217008 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] File "/usr/lib/
[Sun Apr 12 09:35:27.217012 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] from nova.api.
[Sun Apr 12 09:35:27.217018 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] File "/usr/lib/
[Sun Apr 12 09:35:27.217022 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] import dataclasses
[Sun Apr 12 09:35:27.217038 2020] [wsgi:error] [pid 25] [remote 192.168.24.1:41778] ModuleNotFoundE
~~~