1520463 – OSP11 -> OSP12 upgrade: pymysql.err.InternalError seen in /var/log/nova/nova-manage.log during undercloud upgrade

Bug 1520463 - OSP11 -> OSP12 upgrade: pymysql.err.InternalError seen in /var/log/nova/nova-manage.log during undercloud upgrade

Summary: OSP11 -> OSP12 upgrade: pymysql.err.InternalError seen in /var/log/nova/nova-...

Keywords:
Status:	CLOSED EOL
Alias:	None
Product:	Red Hat OpenStack
Classification:	Red Hat
Component:	instack-undercloud
Sub Component:
Version:	12.0 (Pike)
Hardware:	Unspecified
OS:	Unspecified
Priority:	low
Severity:	low
Target Milestone:	async
Target Release:	12.0 (Pike)
Assignee:	Rajesh Tailor
QA Contact:	Arik Chernetsky
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2017-12-04 14:03 UTC by Marius Cornea
Modified:	2019-11-18 11:42 UTC (History)
CC List:	8 users (show)
Fixed In Version:	instack-undercloud-7.4.9-1.el7ost
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2019-01-11 16:26:38 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
nova-manage.log (91.25 KB, text/plain) 2017-12-04 14:03 UTC, Marius Cornea	no flags	Details
View All

Links
System	ID	Priority	Status	Summary	Last Updated
Launchpad	1737175	None	None	None	2017-12-08 13:31:04 UTC
OpenStack gerrit	526675	'None'	MERGED	Run nova online data migration before updating packages	2020-05-06 20:27:20 UTC
OpenStack gerrit	528287	'None'	MERGED	Run nova online data migration before updating packages	2020-05-06 20:27:20 UTC

Description Marius Cornea 2017-12-04 14:03:08 UTC

Created attachment 1362695 [details]
nova-manage.log

Description of problem:
OSP11 -> OSP12 upgrade: pymysql.err.InternalError seen in /var/log/nova/nova-manage.log during undercloud upgrade:

2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters [req-fa5699b1-390c-4f76-afb9-5f27e1ca6b65 - - - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1054, u"Unknown column 'build_requests.tags' in 'field list'") [SQL: u'SELECT build_requests.created_at AS build_requests_created_at, build_requests.updated_at AS build_requests_updated_at, build_requests.id AS build_requests_id, build_requests.instance_uuid AS build_requests_instance_uuid, build_requests.project_id AS build_requests_project_id, build_requests.instance AS build_requests_instance, build_requests.block_device_mappings AS build_requests_block_device_mappings, build_requests.tags AS build_requests_tags \nFROM build_requests \nWHERE build_requests.instance_uuid IS NULL \n LIMIT %(param_1)s'] [parameters: {u'param_1': 50}]: InternalError: (1054, u"Unknown column 'build_requests.tags' in 'field list'")
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     context)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1054, u"Unknown column 'build_requests.tags' in 'field list'")
2017-12-04 06:18:14.440 24189 ERROR oslo_db.sqlalchemy.exc_filters 
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters [req-fa5699b1-390c-4f76-afb9-5f27e1ca6b65 - - - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1054, u"Unknown column 'services.uuid' in 'field list'") [SQL: u'SELECT services.created_at AS services_created_at, services.updated_at AS services_updated_at, services.deleted_at AS services_deleted_at, services.deleted AS services_deleted, services.id AS services_id, services.uuid AS services_uuid, services.host AS services_host, services.`binary` AS services_binary, services.topic AS services_topic, services.report_count AS services_report_count, services.disabled AS services_disabled, services.disabled_reason AS services_disabled_reason, services.last_seen_up AS services_last_seen_up, services.forced_down AS services_forced_down, services.version AS services_version \nFROM services \nWHERE services.deleted = %(deleted_1)s AND services.uuid IS NULL \n LIMIT %(param_1)s'] [parameters: {u'param_1': 50, u'deleted_1': 0}]: InternalError: (1054, u"Unknown column 'services.uuid' in 'field list'")
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     context)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1054, u"Unknown column 'services.uuid' in 'field list'")
2017-12-04 06:18:14.447 24189 ERROR oslo_db.sqlalchemy.exc_filters 
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters [req-fa5699b1-390c-4f76-afb9-5f27e1ca6b65 - - - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1054, u"Unknown column 'build_requests.tags' in 'field list'") [SQL: u'SELECT build_requests.created_at AS build_requests_created_at, build_requests.updated_at AS build_requests_updated_at, build_requests.id AS build_requests_id, build_requests.instance_uuid AS build_requests_instance_uuid, build_requests.project_id AS build_requests_project_id, build_requests.instance AS build_requests_instance, build_requests.block_device_mappings AS build_requests_block_device_mappings, build_requests.tags AS build_requests_tags \nFROM build_requests \nWHERE build_requests.instance_uuid IS NULL \n LIMIT %(param_1)s'] [parameters: {u'param_1': 50}]: InternalError: (1054, u"Unknown column 'build_requests.tags' in 'field list'")
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     context)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1054, u"Unknown column 'build_requests.tags' in 'field list'")
2017-12-04 06:18:14.573 24189 ERROR oslo_db.sqlalchemy.exc_filters 
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters [req-fa5699b1-390c-4f76-afb9-5f27e1ca6b65 - - - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1054, u"Unknown column 'services.uuid' in 'field list'") [SQL: u'SELECT services.created_at AS services_created_at, services.updated_at AS services_updated_at, services.deleted_at AS services_deleted_at, services.deleted AS services_deleted, services.id AS services_id, services.uuid AS services_uuid, services.host AS services_host, services.`binary` AS services_binary, services.topic AS services_topic, services.report_count AS services_report_count, services.disabled AS services_disabled, services.disabled_reason AS services_disabled_reason, services.last_seen_up AS services_last_seen_up, services.forced_down AS services_forced_down, services.version AS services_version \nFROM services \nWHERE services.deleted = %(deleted_1)s AND services.uuid IS NULL \n LIMIT %(param_1)s'] [parameters: {u'param_1': 50, u'deleted_1': 0}]: InternalError: (1054, u"Unknown column 'services.uuid' in 'field list'")
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     context)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1014, in _read_packet
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1054, u"Unknown column 'services.uuid' in 'field list'")
2017-12-04 06:18:14.577 24189 ERROR oslo_db.sqlalchemy.exc_filters 


Version-Release number of selected component (if applicable):
openstack-nova-scheduler-16.0.2-3.el7ost.noarch
puppet-nova-11.4.0-2.el7ost.noarch
python-novaclient-9.1.1-1.el7ost.noarch
python-nova-16.0.2-3.el7ost.noarch
openstack-nova-api-16.0.2-3.el7ost.noarch
openstack-nova-common-16.0.2-3.el7ost.noarch
openstack-nova-conductor-16.0.2-3.el7ost.noarch
openstack-nova-compute-16.0.2-3.el7ost.noarch
openstack-nova-placement-api-16.0.2-3.el7ost.noarch


How reproducible:
100%

Steps to Reproduce:
1. Deploy OSP11 undercloud
2. Upgrade to OSP12

Actual results:
Upgrade completes fine but errors are observed during the dbsync.

Expected results:
No errors show up during the dbsync.

Additional info:
Attaching the full

Comment 2 Ollie Walsh 2018-06-08 12:24:36 UTC

*** Bug 1585765 has been marked as a duplicate of this bug. ***

Comment 5 Rajesh Tailor 2018-12-03 07:54:43 UTC

The required change is already present in osp12 as a result of import from upstream.

I have checked and found that the commit is present in osp12 branch:
$ git branch --contains 5004fa5c77ceecc8c43ca9af827ec4786fbad394
* rhos-12.0-patches


I am also setting fixed-in-version for the same.

Comment 6 Lon Hohberger 2018-12-03 11:46:30 UTC

According to our records, this should be resolved by instack-undercloud-7.4.12-1.el7ost.  This build is available now.

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