glance db_sync requires mysql db to have log_bin_trust_function_creators = 1

Bug #1750705 reported by Sean Feole
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Glance
Undecided
Unassigned
OpenStack Percona Cluster Charm
Medium
James Page
glance (Ubuntu)
Medium
James Page

Bug Description

Upon deploying glance via cs:~openstack-charmers-next/xenial/glance glance appears to throw a CRIT unhandled error, so far I have experienced this on arm64. Not sure about other archs at this point in time. Decided to bug and will investigate further.

Cloud- xenial-queens/proposed

This occurs when the the shared-db-relation hook fires for mysql:shared-db.

unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed CRITI [glance] Unhandled error
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed Traceback (most recent call last):
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/bin/glance-manage", line 10, in <module>
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed sys.exit(main())
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/cmd/manage.py", line 528, in main
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed return CONF.command.action_fn()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/cmd/manage.py", line 360, in sync
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed self.command_object.sync(CONF.command.version)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/cmd/manage.py", line 153, in sync
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed self.expand()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/cmd/manage.py", line 208, in expand
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed self._sync(version=expand_head)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/cmd/manage.py", line 168, in _sync
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed alembic_command.upgrade(a_config, version)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/command.py", line 254, in upgrade
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed script.run_env()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/script/base.py", line 425, in run_env
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed util.load_python_file(self.dir, 'env.py')
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/util/pyfiles.py", line 93, in load_python_file
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed module = load_module_py(module_id, path)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/util/compat.py", line 75, in load_module_py
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed mod = imp.load_source(module_id, path, fp)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/db/sqlalchemy/alembic_migrations/env.py", line 88, in <module>
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed run_migrations_online()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/db/sqlalchemy/alembic_migrations/env.py", line 83, in run_migrations_online
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed context.run_migrations()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "<string>", line 8, in run_migrations
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/runtime/environment.py", line 836, in run_migrations
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed self.get_context().run_migrations(**kw)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/runtime/migration.py", line 330, in run_migrations
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed step.migration_fn(**kw)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/db/sqlalchemy/alembic_migrations/versions/ocata_expand01_add_visibility.py", line 149, in upgrade
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed _add_visibility_column(meta)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/glance/db/sqlalchemy/alembic_migrations/versions/ocata_expand01_add_visibility.py", line 126, in _add_visibility_column
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed op.add_column('images', v_col)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "<string>", line 8, in add_column
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "<string>", line 3, in add_column
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/operations/ops.py", line 1551, in add_column
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed return operations.invoke(op)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/operations/base.py", line 318, in invoke
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed return fn(self, operation)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/operations/toimpl.py", line 123, in add_column
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed schema=schema
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/ddl/impl.py", line 172, in add_column
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed self._exec(base.AddColumn(table_name, column, schema=schema))
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/alembic/ddl/impl.py", line 118, in _exec
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed return conn.execute(construct, *multiparams, **params)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 945, in execute
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed return meth(self, multiparams, params)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/ddl.py", line 68, in _execute_on_connection
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed return connection._execute_ddl(self, multiparams, params)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1002, in _execute_ddl
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed compiled
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1189, in _execute_context
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed context)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1398, in _handle_dbapi_exception
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed util.raise_from_cause(newraise, exc_info)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed reraise(type(exception), exception, tb=exc_tb, cause=cause)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed context)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 470, in do_execute
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed cursor.execute(statement, parameters)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 166, in execute
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed result = self._query(query)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 322, in _query
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed conn.query(q)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 856, in query
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed self._affected_rows = self._read_query_result(unbuffered=unbuffered)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1057, in _read_query_result
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed result.read()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1340, in read
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed first_packet = self.connection._read_packet()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1014, in _read_packet
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed packet.check_error()
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 393, in check_error
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed err.raise_mysql_exception(self._data)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed File "/usr/lib/python2.7/dist-packages/pymysql/err.py", line 107, in raise_mysql_exception
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed raise errorclass(errno, errval)
unit-glance-0: 01:28:22 DEBUG unit.glance/0.shared-db-relation-changed DBError: (pymysql.err.InternalError) (1060, u"Duplicate column name 'visibility'") [SQL: u"ALTER TABLE images ADD COLUMN visibility ENUM('private','public','shared','community')"]

Revision history for this message
Sean Feole (sfeole) wrote :
summary: - glance CRITI Unhandled error
+ glance CRITI Unhandled error DBError Duplicate column name
description: updated
Revision history for this message
Sean Feole (sfeole) wrote : Re: glance CRITI Unhandled error DBError Duplicate column name

At the time of this failure I was using:glance 16.0.0~rc1 ,

cinder-ceph 12.0.0~rc1 waiting 1 cinder-ceph jujucharms 254 ubuntu
glance 16.0.0~rc1 error 1 glance jujucharms 304 ubuntu
keystone waiting 0/1 keystone jujucharms 333 ubuntu

According to: http://reqorts.qa.ubuntu.com/reports/ubuntu-server/cloud-archive/queens_versions.html

Rc2 lives in main, which I did not test yet and can do so today.

Revision history for this message
James Page (james-page) wrote :

I think you might find there is a previous error related to the creation of triggers in the db:

  File "/usr/lib/python2.7/dist-packages/glance/db/sqlalchemy/alembic_migrations/versions/ocata_expand01_add_visibility.py", line 133, in _add_triggers

DBError: (pymysql.err.InternalError) (1419, u'You do not have the SUPER privilege and binary logging is enabled (you *might* want to use the less safe log_bin_trust_function_creators variable)') [SQL: u"\nCREATE TRIGGER insert_visibility BEFORE INSERT ON images\nFOR EACH ROW\nBEGIN\n -- NOTE(abashmak):\n -- The following IF/ELSE block implements a priority decision tree.\n -- Strict order MUST be followed to correctly cover all the edge cases.\n\n -- Edge case: neither is_public nor visibility specified\n -- (or both specified as NULL):\n IF NEW.is_public <=> NULL AND NEW.visibility <=> NULL THEN\n SIGNAL SQLSTATE '45000' SET MESSAGE_TEXT = 'Invalid visibility value';\n -- Edge case: both is_public and visibility specified:\n ELSEIF NOT(NEW.is_public <=> NULL OR NEW.visibility <=> NULL) THEN\n SIGNAL SQLSTATE '45000' SET MESSAGE_TEXT = 'Invalid visibility value';\n -- Inserting with is_public, set visibility accordingly:\n ELSEIF NOT NEW.is_public <=> NULL THEN\n IF NEW.is_public = 1 THEN\n SET NEW.visibility = 'public';\n ELSE\n SET NEW.visibility = 'shared';\n END IF;\n -- Inserting with visibility, set is_public accordingly:\n ELSEIF NOT NEW.visibility <=> NULL THEN\n IF NEW.visibility = 'public' THEN\n SET NEW.is_public = 1;\n ELSE\n SET NEW.is_public = 0;\n END IF;\n -- Edge case: either one of: is_public or visibility,\n -- is explicitly set to NULL:\n ELSE\n SIGNAL SQLSTATE '45000' SET MESSAGE_TEXT = 'Invalid visibility value';\n END IF;\nEND;\n"]

Revision history for this message
James Page (james-page) wrote :

Need to tie down the exact requirements but:

  set global log_bin_trust_function_creators = 1;

and then dropping and recreating the DB resolves this issue; apparently creation of triggers which include 'unsafe' functions requires this setting.

affects: charm-glance → glance (Ubuntu)
summary: - glance CRITI Unhandled error DBError Duplicate column name
+ glance db_sync requires mysql db to have log_bin_trust_function_creators
+ = 1
Revision history for this message
James Page (james-page) wrote :

Raising glance task - this might not be a glance bug, but its probably worth release noting at least.

Revision history for this message
James Page (james-page) wrote :

Worth noting that:

  https://github.com/openstack/glance/blob/master/doc/source/admin/zero-downtime-db-upgrade.rst

does reference this configuration option for mysql; however the environment detailed here is new, i.e. not being upgraded.

Revision history for this message
James Page (james-page) wrote :
Changed in charm-percona-cluster:
status: New → In Progress
importance: Undecided → Medium
assignee: nobody → James Page (james-page)
milestone: none → 18.02
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to charm-percona-cluster (master)

Reviewed: https://review.openstack.org/546714
Committed: https://git.openstack.org/cgit/openstack/charm-percona-cluster/commit/?id=4b62b587afca4a42608d152ab63c09d22b2c37b0
Submitter: Zuul
Branch: master

commit 4b62b587afca4a42608d152ab63c09d22b2c37b0
Author: James Page <email address hidden>
Date: Wed Feb 21 17:46:37 2018 +0000

    Support expand->migrate->contract db migrations

    In order to support rolling upgrades, OpenStack services
    are moving to a trigger driven approach to db upgrade,
    involving expand, migrate and contract phases.

    This requires that the underlying db supports creation of
    such triggers which requires that:

      log_bin_trust_function_creators = 1

    in the MySQL global configuration.

    Change-Id: Id2cf2dd5a0929270229541e6cd488cd1c0d6103e
    Closes-Bug: 1750705

Changed in charm-percona-cluster:
status: In Progress → Fix Committed
Revision history for this message
James Page (james-page) wrote :

Fixed in glance under bug 1749640

Changed in glance (Ubuntu):
status: New → In Progress
importance: Undecided → Medium
assignee: nobody → James Page (james-page)
Revision history for this message
James Page (james-page) wrote :

Including in rc3 so uploading that to bionic now.

Changed in glance:
status: New → Fix Released
Changed in glance (Ubuntu):
milestone: none → ubuntu-18.02
Revision history for this message
Sean Feole (sfeole) wrote :

Tested the fixes this morning and glance now appears to be installing properly on arm64.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package glance - 2:16.0.0~rc3-0ubuntu1

---------------
glance (2:16.0.0~rc3-0ubuntu1) bionic; urgency=medium

  * New upstream release candidate for OpenStack Queens (LP: #1750705).

 -- James Page <email address hidden> Thu, 22 Feb 2018 14:46:15 +0000

Changed in glance (Ubuntu):
status: In Progress → Fix Released
Ryan Beisner (1chb1n)
Changed in charm-percona-cluster:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Bug attachments