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
Fix Released
Undecided
Unassigned
OpenStack Percona Cluster Charm
Fix Released
Medium
James Page
glance (Ubuntu)
Fix Released
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  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.