1337338 – osp-director-9: ControllerNodesPostDeployment fails due to cinder service that can't communicate with DB (cinder.cmd.volume DBConnectionError)

Bug 1337338 - osp-director-9: ControllerNodesPostDeployment fails due to cinder service that can't communicate with DB (cinder.cmd.volume DBConnectionError)

Summary: osp-director-9: ControllerNodesPostDeployment fails due to cinder service tha...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat OpenStack
Classification:	Red Hat
Component:	rhosp-director
Sub Component:
Version:	9.0 (Mitaka)
Hardware:	x86_64
OS:	Linux
Priority:	high
Severity:	urgent
Target Milestone:	ga
Target Release:	9.0 (Mitaka)
Assignee:	Jiri Stransky
QA Contact:	Arik Chernetsky
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2016-05-18 21:47 UTC by Omri Hochman
Modified:	2020-02-14 17:47 UTC (History)
CC List:	9 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2016-08-24 13:01:13 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Red Hat Product Errata	RHEA-2016:1762	0	normal	SHIPPED_LIVE	Red Hat OpenStack Platform 9 director Advisory	2016-08-24 16:59:57 UTC

Description Omri Hochman 2016-05-18 21:47:07 UTC

osp-director-9: ControllerNodesPostDeployment fails due to cinder service that can't communicate with DB (cinder.cmd.volume DBConnectionError)


Environment ( first ospd-9.0 puddle) : 
---------------------------------------
instack-0.0.8-3.el7ost.noarch
instack-undercloud-4.0.0-2.el7ost.noarch
openstack-heat-common-6.0.0-1.el7ost.noarch
openstack-tripleo-heat-templates-liberty-2.0.0-5.el7ost.noarch
openstack-heat-api-cfn-6.0.0-1.el7ost.noarch
heat-cfntools-1.3.0-2.el7ost.noarch
openstack-tripleo-heat-templates-kilo-2.0.0-5.el7ost.noarch
openstack-tripleo-heat-templates-2.0.0-5.el7ost.noarch
openstack-heat-api-6.0.0-1.el7ost.noarch
openstack-heat-engine-6.0.0-1.el7ost.noarch
python-heatclient-1.0.0-1.el7ost.noarch
openstack-heat-templates-0-0.8.20150605git.el7ost.noarch


[stack@undercloud72 ~]$ heat resource-list overcloud -n 5 | grep -v COMPLETE
+---------------------------------------------+-----------------------------------------------+---------------------------------------------------------------------------------+--------------------+---------------------+---------------------------------------------------------------------------------------------------------------+
| resource_name                               | physical_resource_id                          | resource_type                                                                   | resource_status    | updated_time        | stack_name                                                                                                    |
+---------------------------------------------+-----------------------------------------------+---------------------------------------------------------------------------------+--------------------+---------------------+---------------------------------------------------------------------------------------------------------------+
| ComputeNodesPostDeployment                  | 06e82c09-16f8-48ff-990e-7aec25c1da11          | OS::TripleO::ComputePostDeployment                                              | CREATE_FAILED      | 2016-02-10T18:43:39 | overcloud                                                                                                     |
| ControllerNodesPostDeployment               | 64b64512-c8d1-47b4-b050-2335ac593ee7          | OS::TripleO::ControllerPostDeployment                                           | CREATE_FAILED      | 2016-02-10T18:43:39 | overcloud                                                                                                     |
| ComputePuppetDeployment                     | 93a58c2d-8fb2-4ad3-b22f-156177e21ca7          | OS::Heat::StructuredDeployments                                                 | CREATE_FAILED      | 2016-02-10T19:02:51 | overcloud-ComputeNodesPostDeployment-ylhm7mvo4kpp                                                             |
| ControllerOvercloudServicesDeployment_Step4 | 6e1d7aa8-342e-402d-b7a9-ab4683f6beff          | OS::Heat::StructuredDeployments                                                 | CREATE_FAILED      | 2016-02-10T19:02:54 | overcloud-ControllerNodesPostDeployment-lg7y5d6k44b3                                                          |
| 0                                           | 5965cfa4-9947-48df-8b19-6d7c645d2dc7          | OS::Heat::StructuredDeployment                                                  | CREATE_IN_PROGRESS | 2016-02-10T19:03:38 | overcloud-ComputeNodesPostDeployment-ylhm7mvo4kpp-ComputePuppetDeployment-pvy2zsoqsbbd                        |



/var/log/messages ( Possible problem with DB) :
------------------------------------------------
May 18 14:38:27 localhost os-collect-config: ser: seluser changed 'unconfined_u' to 'system_u'\u001b[0m\n\u001b[mNotice: /Stage[main]/Redis::Service/Service[redis]/ensure: ensure changed 'stopped' to 'running'\u001b[0m\n\u001b[mNotice: /Stage[main]/Rabbitmq::Config/Rabbitmq_erlang_cookie[/var/lib/rabbitmq/.erlang.cookie]/content: The rabbitmq erlang cookie was changed\u001b[0m\n\u001b[mNotice: /Stage[main]/Rabbitmq::Config/File[rabbitmq.config]/content: content changed '{md5}c8e444b74c6294006936abdaea55a079' to '{md5}ce3bafce73950b85ee5c7efab6a8e263'\u001b[0m\n\u001b[mNotice: /Stage[main]/Rabbitmq::Config/File[rabbitmq.config]/owner: owner changed 'rabbitmq' to 'root'\u001b[0m\n\u001b[mNotice: /Stage[main]/Rabbitmq::Config/File[rabbitmq.config]/group: group changed 'rabbitmq' to 'root'\u001b[0m\n\u001b[mNotice: /File[rabbitmq.config]/seluser: seluser changed 'unconfined_u' to 'system_u'\u001b[0m\n\u001b[mNotice: /Stage[main]/Rabbitmq::Config/File[/etc/security/limits.d/rabbitmq-server.conf]/ensure: defined content as '{md5}5ddc6ba5fcaeddd5b1565e5adfda5236'\u001b[0m\n\u001b[mNotice: /Stage[main]/Main/Package_manifest[/var/lib/tripleo/installed-packages/overcloud_controller2]/ensure: created\u001b[0m\n\u001b[mNotice: /Stage[main]/Mysql::Server::Installdb/Mysql_datadir[/var/lib/mysql]/ensure: created\u001b[0m\n\u001b[mNotice: 
/Stage[main]/Mysql::Server::Service/Service[mysqld]/ensure: ensure changed 'stopped' to 'running'\u001b[0m\n\u001b[mNotice: /Stage[main]/Mysql::Server::Root_password/Mysql_user[root@localhost]/password_hash: defined 'password_hash' as '*2716242C97784044C20637E45E27BD273FB31D7C'\u001b[0m\n\u001b[mNotice: /Stage[main]/Mysql::Server::Root_password/File[/root/.my.cnf]/ensure: defined content as '{md5}9d5f7f85f028c15e8765cd362f8c2958'\u001b[0m\n\u001b[mNotice: /Stage[main]/Mysql::Server::Account_security/Mysql_user[@overcloud-controller-0.localdomain]/ensure: removed\u001b[0m\n\u001b[mNotice: /Stage[main]/Mysql::Server::Account_security/Mysql_database[test]/ensure: removed\u001b[0m\n\u001b[mNotice: /Stage[main]/Nova::Db::Mysql/Openstacklib::Db
-bash: May: command not found
[root@overcloud-controller-0 ~]# May 18 14:38:27 localhost os-collect-config: #033[mNotice: /Stage[main]/Mysql::Server::Service/Service[mysqld]/ensure: ensure changed 'stopped' to 'running'#033[0m
-bash: May: command not found


/var/log/messages :  (cinder service failed to communicate with DB ) 
-------------------------
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 CRITICAL cinder [req-e56f1d26-b593-402e-bd6e-c01ab22b47de - - - - -] DBConnectionError: (p
ymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder Traceback (most recent call last):
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/bin/cinder-api", line 10, in <module>
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     sys.exit(main())
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/cmd/api.py", line 60, in main
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     server = service.WSGIService('osapi_volume')
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/service.py", line 370, in __i
nit__
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     self.app = self.loader.load_app(name)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/oslo_service/wsgi.py", line 353, in 
load_app
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return deploy.loadapp("config:%s" % self.config_path, name=name)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return loadobj(APP, uri, name=name, **kw)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return context.create()
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return self.object_type.invoke(self)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     **context.local_conf)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 55, in fix_call
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     val = callable(*args, **kw)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/api/__init__.py", line 34, in root_app_factory
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return paste.urlmap.urlmap_factory(loader, global_conf, **local_conf)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/urlmap.py", line 25, in urlmap_factory
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     app = loader.get_app(app_name, global_conf=global_conf)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     name=name, global_conf=global_conf).create()
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return self.object_type.invoke(self)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     **context.local_conf)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 55, in fix_call
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     val = callable(*args, **kw)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/api/middleware/auth.py", line 56, in pipeline_factory
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     app = loader.get_app(pipeline[-1])
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     name=name, global_conf=global_conf).create()
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 710, in create
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return self.object_type.invoke(self)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/loadwsgi.py", line 146, in invoke
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return fix_call(context.object, context.global_conf, **context.local_conf)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/paste/deploy/util.py", line 55, in fix_call
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     val = callable(*args, **kw)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/api/openstack/__init__.py", line 72, in factory
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return cls()
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/api/openstack/__init__.py", line 83, in __init__
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     self._setup_routes(mapper, ext_mgr)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/api/v2/router.py", line 50, in _setup_routes
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     self.resources['volumes'] = volumes.create_resource(ext_mgr)
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/api/v2/volumes.py", line 473, in create_resource
May 18 14:46:00 localhost cinder-api: 2016-05-18 18:46:00.791 13079 ERROR cinder     return wsgi.Resource(VolumeController(ext_mgr))
ay 18 14:46:00 localhost cinder-volume: 2016-05-18 18:46:00.832 13108 ERROR cinder.cmd.volume     six.reraise(type(de_ref), de_ref)
May 18 14:46:00 localhost cinder-volume: 2016-05-18 18:46:00.832 13108 ERROR cinder.cmd.volume   File "<string>", line 2, in reraise
May 18 14:46:00 localhost cinder-volume: 2016-05-18 18:46:00.832 13108 ERROR cinder.cmd.volume DBConnectionError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
May 18 14:46:00 localhost cinder-volume: 2016-05-18 18:46:00.832 13108 ERROR cinder.cmd.volume
May 18 14:46:00 localhost cinder-volume: 2016-05-18 18:46:00.864 13108 ERROR cinder.cmd.volume [req-c0089330-c64a-416f-b9b6-957c092a9599 - - - - -] No volume service(s) started successfully, terminating.


/var/log/cinder/cinder-manage.log
------------------------------------
2016-05-18 18:42:36.575 12890 WARNING py.warnings [-] /usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py:241: NotSupportedWarning: Configurat
ion option(s) ['use_tpool'] not supported
  exception.NotSupportedWarning

2016-05-18 18:42:36.607 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 10 attempts left.
2016-05-18 18:42:46.611 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 9 attempts left.
2016-05-18 18:42:56.618 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 8 attempts left.
2016-05-18 18:43:06.626 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 7 attempts left.
2016-05-18 18:43:16.635 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 6 attempts left.
2016-05-18 18:43:26.647 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 5 attempts left.
2016-05-18 18:43:36.659 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 4 attempts left.
2016-05-18 18:43:46.662 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 3 attempts left.
2016-05-18 18:43:56.670 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 2 attempts left.
2016-05-18 18:44:06.676 12890 WARNING oslo_db.sqlalchemy.engines [-] SQL connection failed. 1 attempts left.
2016-05-18 18:44:16.678 12890 CRITICAL cinder [-] DBConnectionError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
2016-05-18 18:44:16.678 12890 ERROR cinder Traceback (most recent call last):
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/bin/cinder-manage", line 10, in <module>
2016-05-18 18:44:16.678 12890 ERROR cinder     sys.exit(main())
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/cmd/manage.py", line 596, in main
2016-05-18 18:44:16.678 12890 ERROR cinder     fn(*fn_args)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/cmd/manage.py", line 214, in sync
2016-05-18 18:44:16.678 12890 ERROR cinder     return db_migration.db_sync(version)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/db/migration.py", line 60, in db_sync
2016-05-18 18:44:16.678 12890 ERROR cinder     engine = db_api.get_engine()
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/db/sqlalchemy/api.py", line 97, in get_engine
2016-05-18 18:44:16.678 12890 ERROR cinder     facade = _create_facade_lazily()
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/cinder/db/sqlalchemy/api.py", line 79, in _create_facade_lazily
2016-05-18 18:44:16.678 12890 ERROR cinder     **dict(CONF.database)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 977, in __init__
2016-05-18 18:44:16.678 12890 ERROR cinder     slave_connection=slave_connection)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 338, in _start
2016-05-18 18:44:16.678 12890 ERROR cinder     engine_args, maker_args)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 362, in _setup_for_connection
2016-05-18 18:44:16.678 12890 ERROR cinder     sql_connection=sql_connection, **engine_kwargs)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py", line 152, in create_engine
2016-05-18 18:44:16.678 12890 ERROR cinder     test_conn = _test_connection(engine, max_retries, retry_interval)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py", line 334, in _test_connection
2016-05-18 18:44:16.678 12890 ERROR cinder     six.reraise(type(de_ref), de_ref)
2016-05-18 18:44:16.678 12890 ERROR cinder   File "<string>", line 2, in reraise
2016-05-18 18:44:16.678 12890 ERROR cinder DBConnectionError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
2016-05-18 18:44:16.678 12890 ERROR cinder

Comment 1 Omri Hochman 2016-05-20 15:00:27 UTC

probably a duplicate of the issue: Bug 1337537 - rhel-osp-director: 9.0 - the overcloud deployment fails because pacemaker isn't the default

Comment 2 Jiri Stransky 2016-06-01 10:04:07 UTC

Yes possibly it could be a duplicate of bug 1337537. Is this still an issue? If so, could you post what `sudo pcs status` prints on one of the controller nodes?

Comment 3 Omri Hochman 2016-06-03 14:30:27 UTC

Unable to reproduce with latest 9 puddles - therefore VERIFIED for now.

Comment 6 errata-xmlrpc 2016-08-24 13:01:13 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHEA-2016-1762.html

Note You need to log in before you can comment on or make changes to this bug.