Public bug reported:
I'm testing the live migration workflows moving from Mitaka to Newton.
In my scenario, I have two keystone server VM, and haproxy in front of
them. Both are running Mitaka and are fully functional. During the
upgrade I run Rally to repeatedly create and then delete users. Rally is
performing these 15 at a time as fast as possible.
During the upgrade, while both are still running Mitaka, I add the
Newton code to a new filesystem path, and I put the Newton version of
configuration in place. I perform db_sync --expand call which is
successful. I then perform a db_sync --migrate call, also successful
(successful means the db_sync command exited 0 and the user
creation/deletion does not experience a failure). Next I perform a
rolling restart of Keystone services, disabling each keystone from the
haproxy before restarting it. Again, success.
However, to finalize the upgrade, there is a db_sync call to --contract.
Both servers are running new Newton code at this point, and rally
continues. During the --contract call some small number of the user
create/delete actions are failing with:
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters [req-88df4389
-f5f8-4332-a0d7-33eefa20a8ac 243ffe0eeb67454a83b8b0b21525bf3a f2970151809044f2aa
78fc75e43e3dc6 - default default] DBAPIError exception wrapped from (pymysql.err
.InternalError) (1054, u"Unknown column 'password.created_at' in 'field list'")
[SQL: u'SELECT password.id AS password_id, password.local_user_id AS password_lo
cal_user_id, password.password AS password_password, password.created_at AS pass
word_created_at, password.expires_at AS password_expires_at, password.self_servi
ce AS password_self_service, local_user_1.id AS local_user_1_id \nFROM (SELECT u
ser.id AS user_id \nFROM user \nWHERE user.id = %(param_1)s) AS anon_1 INNER JOI
N local_user AS local_user_1 ON anon_1.user_id = local_user_1.user_id INNER JOIN
password ON local_user_1.id = password.local_user_id ORDER BY local_user_1.id,
password.created_at'] [parameters: {u'param_1': u'90602d52e1904e43bce1c2b82e46f2
6d'}]
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters Traceback (mo
st recent call last):
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File "/opt/
openstack/current/keystone/local/lib/python2.7/site-packages/sqlalchemy/engine/b
ase.py", line 1139, in _execute_context
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters context)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File "/opt/
openstack/current/keystone/local/lib/python2.7/site-packages/sqlalchemy/engine/d
efault.py", line 450, in do_execute
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters cursor.ex
ecute(statement, parameters)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File "/opt/
openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/cursors.py",
line 167, in execute
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters result =
self._query(query)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/cursors.py",
line 323, in _query
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
conn.query(q)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 836, in query
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 1020, in _read_query_result
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
result.read()
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 1303, in read
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
first_packet = self.connection._read_packet()
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 982, in _read_packet
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
packet.check_error()
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 394, in check_error
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
err.raise_mysql_exception(self._data)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/err.py",
line 120, in raise_mysql_exception
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
_check_mysql_exception(errinfo)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/err.py",
line 115, in _check_mysql_exception
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters raise
InternalError(errno, errorvalue)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
InternalError: (1054, u"Unknown column 'password.created_at' in 'field list'")
Speaking on IRC, this may be related to https://review.openstack.org/#/c/367025/
** Affects: keystone
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Identity (keystone).
https://bugs.launchpad.net/bugs/1636495
Title:
Failures during db_sync --contract during Mitaka to Newton (live)
upgrade
Status in OpenStack Identity (keystone):
New
Bug description:
I'm testing the live migration workflows moving from Mitaka to Newton.
In my scenario, I have two keystone server VM, and haproxy in front of
them. Both are running Mitaka and are fully functional. During the
upgrade I run Rally to repeatedly create and then delete users. Rally
is performing these 15 at a time as fast as possible.
During the upgrade, while both are still running Mitaka, I add the
Newton code to a new filesystem path, and I put the Newton version of
configuration in place. I perform db_sync --expand call which is
successful. I then perform a db_sync --migrate call, also successful
(successful means the db_sync command exited 0 and the user
creation/deletion does not experience a failure). Next I perform a
rolling restart of Keystone services, disabling each keystone from the
haproxy before restarting it. Again, success.
However, to finalize the upgrade, there is a db_sync call to
--contract. Both servers are running new Newton code at this point,
and rally continues. During the --contract call some small number of
the user create/delete actions are failing with:
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
[req-88df4389
-f5f8-4332-a0d7-33eefa20a8ac 243ffe0eeb67454a83b8b0b21525bf3a
f2970151809044f2aa
78fc75e43e3dc6 - default default] DBAPIError exception wrapped from
(pymysql.err
.InternalError) (1054, u"Unknown column 'password.created_at' in 'field
list'")
[SQL: u'SELECT password.id AS password_id, password.local_user_id AS
password_lo
cal_user_id, password.password AS password_password, password.created_at AS
pass
word_created_at, password.expires_at AS password_expires_at,
password.self_servi
ce AS password_self_service, local_user_1.id AS local_user_1_id \nFROM
(SELECT u
ser.id AS user_id \nFROM user \nWHERE user.id = %(param_1)s) AS anon_1 INNER
JOI
N local_user AS local_user_1 ON anon_1.user_id = local_user_1.user_id INNER
JOIN
password ON local_user_1.id = password.local_user_id ORDER BY
local_user_1.id,
password.created_at'] [parameters: {u'param_1':
u'90602d52e1904e43bce1c2b82e46f2
6d'}]
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters Traceback
(mo
st recent call last):
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/
openstack/current/keystone/local/lib/python2.7/site-packages/sqlalchemy/engine/b
ase.py", line 1139, in _execute_context
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
context)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/
openstack/current/keystone/local/lib/python2.7/site-packages/sqlalchemy/engine/d
efault.py", line 450, in do_execute
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
cursor.ex
ecute(statement, parameters)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/
openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/cursors.py",
line 167, in execute
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters result
= self._query(query)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/cursors.py",
line 323, in _query
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
conn.query(q)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 836, in query
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 1020, in _read_query_result
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
result.read()
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 1303, in read
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
first_packet = self.connection._read_packet()
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 982, in _read_packet
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
packet.check_error()
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/connections.py",
line 394, in check_error
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
err.raise_mysql_exception(self._data)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/err.py",
line 120, in raise_mysql_exception
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
_check_mysql_exception(errinfo)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters File
"/opt/openstack/current/keystone/local/lib/python2.7/site-packages/pymysql/err.py",
line 115, in _check_mysql_exception
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters raise
InternalError(errno, errorvalue)
2016-10-25 10:53:22.797 13980 ERROR oslo_db.sqlalchemy.exc_filters
InternalError: (1054, u"Unknown column 'password.created_at' in 'field list'")
Speaking on IRC, this may be related to
https://review.openstack.org/#/c/367025/
To manage notifications about this bug go to:
https://bugs.launchpad.net/keystone/+bug/1636495/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
