Bug 1416938 - [UPDATES] After minor update traceback in glance log: Unknown column 'images.visibility' in 'field list'
Summary: [UPDATES] After minor update traceback in glance log: Unknown column 'images....
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-glance
Version: 11.0 (Ocata)
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: 11.0 (Ocata)
Assignee: Cyril Roelandt
QA Contact: Avi Avraham
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-26 20:32 UTC by Yurii Prokulevych
Modified: 2017-03-21 14:37 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-03-21 10:58:30 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Yurii Prokulevych 2017-01-26 20:32:55 UTC
Description of problem:
-----------------------
After minor update of RHOS-11 requests to glance fail with 500 error:

glance image-list
/usr/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:303: SubjectAltNameWarning: Certificate for 2620:52:0:13b8:5054:ff:fe3e:1 has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.)
  SubjectAltNameWarning
...
500 Internal Server Error
The server has either erred or is incapable of performing the requested operation.
    (HTTP 500)

Excerpt from glance/api.log
---------------------------
2017-01-26 20:22:54.918 21116 WARNING keystonemiddleware.auth_token [-] Using the in-process token cache is deprecated as of the 4.2.0 release and may be removed in the 5.0.0 release or the 'O' development cycle. The in-process cache causes inconsistent results and high memory usage. When the feature is removed the auth_token middleware will not cache tokens by default which may result in performance issues. It is recommended to use  memcache for the auth_token token cache by setting the memcached_servers option.
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters [req-a4db4bb5-83c4-466e-af65-1c2ab89a212f 101ee44c652844658442455e05bb4f6f 4aa5e67ac7a0473c8813ddb3c86f230a - default default] DBAPIError exception wrapped from (pymysql.err.InternalError) (1054, u"Unknown column 'images.visibility' in 'field list'") [SQL: u'SELECT anon_1.images_created_at AS anon_1_images_created_at, anon_1.images_updated_at AS anon_1_images_updated_at, anon_1.images_deleted_at AS anon_1_images_deleted_at, anon_1.images_deleted AS anon_1_images_deleted, anon_1.images_id AS anon_1_images_id, anon_1.images_name AS anon_1_images_name, anon_1.images_disk_format AS anon_1_images_disk_format, anon_1.images_container_format AS anon_1_images_container_format, anon_1.images_size AS anon_1_images_size, anon_1.images_virtual_size AS anon_1_images_virtual_size, anon_1.images_status AS anon_1_images_status, anon_1.images_visibility AS anon_1_images_visibility, anon_1.images_checksum AS anon_1_images_checksum, anon_1.images_min_disk AS anon_1_images_min_disk, anon_1.images_min_ram AS anon_1_images_min_ram, anon_1.images_owner AS anon_1_images_owner, anon_1.images_protected AS anon_1_images_protected, image_locations_1.created_at AS image_locations_1_created_at, image_locations_1.updated_at AS image_locations_1_updated_at, image_locations_1.deleted_at AS image_locations_1_deleted_at, image_locations_1.deleted AS image_locations_1_deleted, image_locations_1.id AS image_locations_1_id, image_locations_1.image_id AS image_locations_1_image_id, image_locations_1.value AS image_locations_1_value, image_locations_1.meta_data AS image_locations_1_meta_data, image_locations_1.status AS image_locations_1_status, image_tags_1.created_at AS image_tags_1_created_at, image_tags_1.updated_at AS image_tags_1_updated_at, image_tags_1.deleted_at AS image_tags_1_deleted_at, image_tags_1.deleted AS image_tags_1_deleted, image_tags_1.id AS image_tags_1_id, image_tags_1.image_id AS image_tags_1_image_id, image_tags_1.value AS image_tags_1_value, image_properties_1.created_at AS image_properties_1_created_at, image_properties_1.updated_at AS image_properties_1_updated_at, image_properties_1.deleted_at AS image_properties_1_deleted_at, image_properties_1.deleted AS image_properties_1_deleted, image_properties_1.id AS image_properties_1_id, image_properties_1.image_id AS image_properties_1_image_id, image_properties_1.name AS image_properties_1_name, image_properties_1.value AS image_properties_1_value \nFROM (SELECT images.created_at AS images_created_at, images.updated_at AS images_updated_at, images.deleted_at AS images_deleted_at, images.deleted AS images_deleted, images.id AS images_id, images.name AS images_name, images.disk_format AS images_disk_format, images.container_format AS images_container_format, images.size AS images_size, images.virtual_size AS images_virtual_size, images.status AS images_status, images.visibility AS images_visibility, images.checksum AS images_checksum, images.min_disk AS images_min_disk, images.min_ram AS images_min_ram, images.owner AS images_owner, images.protected AS images_protected \nFROM images \nWHERE images.deleted = false AND images.status IN (%(status_1)s, %(status_2)s, %(status_3)s, %(status_4)s, %(status_5)s, %(status_6)s) AND (images.owner = %(owner_1)s OR images.visibility != %(visibility_1)s) ORDER BY images.name ASC, images.created_at ASC, images.id ASC \n LIMIT %(param_1)s) AS anon_1 LEFT OUTER JOIN image_locations AS image_locations_1 ON anon_1.images_id = image_locations_1.image_id LEFT OUTER JOIN image_tags AS image_tags_1 ON anon_1.images_id = image_tags_1.image_id LEFT OUTER JOIN image_properties AS image_properties_1 ON anon_1.images_id = image_properties_1.image_id ORDER BY anon_1.images_name ASC, anon_1.images_created_at ASC, anon_1.images_id ASC'] [parameters: {u'visibility_1': 'community', u'param_1': 20, u'owner_1': u'4aa5e67ac7a0473c8813ddb3c86f230a', u'status_6': 'deactivated', u'status_5': 'deleted', u'status_4': 'pending_delete', u'status_3': 'queued', u'status_2': 'saving', u'status_1': 'active'}]
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     context)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 841, in query
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1029, in _read_query_result
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1312, in read
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 991, in _read_packet
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 393, in check_error
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1054, u"Unknown column 'images.visibility' in 'field list'")
2017-01-26 20:22:55.607 21116 ERROR oslo_db.sqlalchemy.exc_filters 


Version-Release number of selected component (if applicable):
-------------------------------------------------------------
puppet-glance-10.1.0-0.20170121022050.d66fa43.el7ost.noarch
python-glanceclient-2.5.0-0.20161111191712.d419632.el7ost.noarch
python-glance-store-0.20.1-0.20170118234059.7cb7d26.el7ost.noarch
openstack-glance-14.0.0-0.20170121044011.18acc70.el7ost.noarch
python-glance-14.0.0-0.20170121044011.18acc70.el7ost.noarch


Steps to Reproduce:
-------------------
1. Deploy RHOS-11 ( undercloud with SSL; overcloud + SSL + IPv6 ). 
   Puddle: 2017-01-18.5
2. Setup latest RHOS-11 repos on overcloud
3. Run stack update:
    yes '' | openstack overcloud update stack -i overcloud

Actual results:
---------------
Update succeeds but glance throws 500 error.


Additional info:
----------------
Virtual setup: 3controllers + 1compute + 3ceph

Comment 2 Cyril Roelandt 2017-01-26 21:02:12 UTC
The images.visibility field was introduced in 265659e8c34865331568b069fdb27ea272df4eaa . This commit provides a migration script (glance/db/sqlalchemy/migrate_repo/versions/045_add_visibility.py). I think this DB migration has not been executed.

I'm not exactly sure how these things work in the installer. Do you usually have to do this manually, or is it automagically taken care of?

Comment 3 Yurii Prokulevych 2017-01-26 21:44:31 UTC
So usually 'openstack overcloud update stack' command doesn't require interaction, except breakpoints clearing.

Lucas, can this migration be handled with current way of updates?

Comment 4 Christian Schwede (cschwede) 2017-03-08 11:43:55 UTC
Looks like this just lacks a "glance-manage db upgrade"?

I'm currently testing a small fix, proposed this for testing upstream:

https://review.openstack.org/443080

Comment 5 Christian Schwede (cschwede) 2017-03-13 09:53:26 UTC
Yurii, can you please test again using a newer puddle? The DB schema modification was merged on Jan 20st. The puddle you used (2017-01-18.5) didn't include the modified schema yet, but the update used a package (python-glance-14.0.0-0.20170121044011.18acc70.el7ost.noarch) with the modified schema included.

This should not happen with more recent puddles, and neither when upgrading from OSP10 -> OSP11.

Comment 6 Christian Schwede (cschwede) 2017-03-21 10:58:30 UTC
This should be fixed when using newer releases, closing this one therefore.

Feel free to reopen this one if needed.


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