Bug 1520463

Summary: OSP11 -> OSP12 upgrade: pymysql.err.InternalError seen in /var/log/nova/nova-manage.log during undercloud upgrade
Product: Red Hat OpenStack Reporter: Marius Cornea <mcornea>
Component: instack-undercloudAssignee: Rajesh Tailor <ratailor>
Status: CLOSED EOL QA Contact: Arik Chernetsky <achernet>
Severity: low Docs Contact:
Priority: low    
Version: 12.0 (Pike)CC: dbecker, lyarwood, mbooth, mburns, morazi, owalsh, ratailor, rhel-osp-director-maint
Target Milestone: asyncKeywords: TestOnly, Triaged, ZStream
Target Release: 12.0 (Pike)   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: instack-undercloud-7.4.9-1.el7ost Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-01-11 16:26:38 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
nova-manage.log none

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.