Keystone returns HTTP 400 as SQLAlchemy raises None exceptions

[Adam Young]

With RDO-Icehouse (m2 testday packages) on RHEL-6.5,
negative Tempest identity tests fails as Keystone responds with HTTP 400.

For example test tempest.api.identity.admin.v3.test_projects.ProjectsTestJSON.test_project_create_duplicate gives following output:

> Request: POST http://192.168.1.16:35357/v3/projects
> Request Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<Token omitted>'}
> Request Body: {"project": {"enabled": true, "description": null, "name": "project-dup--1737299968", "domain_id": "default"}}
> Response Status: 400
> Response Headers: {'content-length': '143', 'date': 'Tue, 04 Feb 2014 07:47:53 GMT', 'content-type': 'application/json', 'vary': 'X-Auth-Token', 'connection': 'close'}
> Response Body: {"error": {"message": "exceptions must be old-style classes or derived from BaseException, not NoneType", "code": 400, "title": "Bad Request"}}

In keystone.log the exception can be seen as
> keystone.common.wsgi Traceback (most recent call last):
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/common/wsgi.py", line 214, in __call__
> keystone.common.wsgi result = method(context, **params)
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/common/controller.py", line 174, in inner
> keystone.common.wsgi return f(self, context, *args, **kwargs)
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/assignment/controllers.py", line 390, in create_project
> keystone.common.wsgi ref = self.assignment_api.create_project(ref['id'], ref)
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/notifications.py", line 53, in wrapper
> keystone.common.wsgi result = f(*args, **kwargs)
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/assignment/core.py", line 72, in create_project
> keystone.common.wsgi ret = self.driver.create_project(tenant_id, tenant)
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/common/sql/core.py", line 165, in wrapper
> keystone.common.wsgi return method(*args, **kwargs)
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/assignment/backends/sql.py", line 411, in create_project
> keystone.common.wsgi return tenant_ref.to_dict()
> keystone.common.wsgi File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
> keystone.common.wsgi self.gen.next()
> keystone.common.wsgi File "/usr/lib/python2.6/site-packages/keystone/common/sql/core.py", line 156, in transaction
> keystone.common.wsgi yield session
> keystone.common.wsgi File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 405, in __exit__
> keystone.common.wsgi raise
> keystone.common.wsgi TypeError: exceptions must be old-style classes or derived from BaseException, not NoneType
> keystone.common.wsgi

Deployed with packstack, no related configuration changes.

Installed packages:
> openstack-keystone.noarch 2014.1-0.3.b2.el6
> python-keystone.noarch 2014.1-0.3.b2.el6
> python-keystoneclient.noarch 1:0.4.1-3.el6
> python-sqlalchemy0.7.x86_64 0.7.8-1.el6
> python-eventlet.noarch 0.9.17-2.el6
> python-libs.x86_64 2.6.6-51.el6

This is NOT reproducible on Fedora20 with versions:
> openstack-keystone.noarch 2014.1-0.3.b2.fc21
> python-keystone.noarch 2014.1-0.3.b2.fc21
> python-keystoneclient.noarch 1:0.4.1-3.fc20
> python-sqlalchemy.x86_64 0.8.4-1.fc20
> python-eventlet.noarch 0.12.0-2.fc20
> python-libs.x86_64 2.7.5-9.fc20

Neither it happened on Fedora19/20 or RHEL-6.5 with devstack/tempest master branches.

This seems as related to eventlet/tpool etc issues, here with SQLAlchemy.
For example like https://bitbucket.org/eventlet/eventlet/issue/118/exceptions-are-cleared-during

[Adam Young (ayoung)]

keystone.log

APIv2 deprecation warnings filtered out with:
> cat keystone.log | grep -v 'Deprecated: v2 API is deprecated as of Icehouse in favor of v3 API and may be removed in K.' > keystone_filtered.log

[Attila Fazekas (afazekas)]

Upgrading the sqlalchemy to >=0.8.1 solves this issue: https://review.openstack.org/#/c/89009/

[Matt Riedemann (mriedem)]

Hmm, the bug says this:

"Neither it happened on Fedora19/20 or RHEL-6.5 with devstack/tempest master branches."

We run Tempest against Icehouse on RHEL 6.5 and Fedora 19 internally and haven't seen any problems with this. On RHEL 6.5 we're using sqlalchemy 0.7.9. On fc19 we use what's in the distro, which is I think 0.8.2.

But if this was a problem for icehouse with rhel 6.5 and sqlalchemy 0.7.9 we should have seen it also.

[Attila Fazekas (afazekas)]

Are you sure you do not have newer sqlalchemy on your system ?
In my devstack job, first the rpm version gets installed by devstack.
At he end I have the following installed sql related rpm installed:
 # rpm -qa |grep sql
 postgresql-libs-8.4.20-1.el6_5.x86_64
 sqlite-3.6.20-1.el6.x86_64
 postgresql-8.4.20-1.el6_5.x86_64
 python-sqlalchemy0.7-0.7.8-1.el6.x86_64
 python-sqlalchemy-0.5.5-3.el6_2.noarch
 mysql-server-5.1.73-3.el6_5.x86_64
 mysql-libs-5.1.73-3.el6_5.x86_64
 postgresql-devel-8.4.20-1.el6_5.x86_64
 mysql-5.1.73-3.el6_5.x86_64

But at keystone installation the system decides to upgrade:
2014-04-20 06:31:28.110 | Downloading/unpacking SQLAlchemy>=0.7.8,<=0.9.99 (from keystone==2014.2.dev155.g0773c4e)
2014-04-20 06:31:28.112 | Storing download in cache at /var/cache/pip/http%3A%2F%2Frhos-qe-mirror-qeos.usersys.redhat.com%2Fpypi%2Fpackages%2Fsource%2FS%2FSQLAlchemy%2FSQLAlchemy-0.9.4.tar.gz
2014-04-20 06:31:28.114 | Running setup.py egg_info for package SQLAlchemy
Strange, but looks like it does not likes python-sqlalchemy0.7-0.7.8-1.el6.x86_64.

At the end this command indicates the '0.9.4' was installed.
# python
Python 2.6.6 (r266:84292, Nov 21 2013, 10:50:32)
[GCC 4.4.7 20120313 (Red Hat 4.4.7-4)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import sqlalchemy
>>> sqlalchemy.__version__
'0.9.4'
>>>

Are you sure, nothing upgrades your sqlalchemy in your job?

(Fedora is not affected by this issue, since it has newer sqlalchemy )

[Matt Riedemann (mriedem)]

We're not using EPEL so we package these ourselves, but these are the versions we're running with for Tempest with Icehouse:

[root@rhel62 ~]# cat /etc/redhat-release
Red Hat Enterprise Linux Server release 6.5 (Santiago)
[root@rhel62 ~]# rpm -q python-sqlalchemy
python-sqlalchemy-0.7.9-1.ibm.x86_64
[root@rhel62 ~]# rpm -q python-migrate
python-migrate-0.9-2.ibm.el6.noarch
[root@rhel62 ~]# rpm -q python-keystone
python-keystone-2014.1-201404180245.ibm.el6.105.noarch
[root@rhel62 ~]#

[Attila Fazekas (afazekas)]

Thank you.

According to the global-requirements.txt the minimum eventlet version is eventlet>=0.13.0.
The 0.13.0 was added because of py 3 compatibility, but the reasons for 0.12.0 includes eventlet related exception handling issues. The eventlet in EPEL is older.

[Dolph Mathews (dolph)]

It doesn't sound like there's anything to fix in keystone then, if this is due to dependency version(s) already documented as unsupported.

[Dolph Mathews (dolph)]

Downstream issue in RDO: https://bugzilla.redhat.com/show_bug.cgi?id=1061329