ldap and fernet token gives ValueError('badly formed hexadecimal UUID string')

[Hans Feldt]

When playing with some keystone deployment alternatives I stumble on a keystone issue:

> 2015-05-27 12:11:52.946 57 DEBUG keystone.common.ldap.core [-] LDAP search: base=ou=Groups,dc=acme,dc=org scope=1 filterstr=(&(&(objectClass=groupOfNames)(member=uid=john,ou=Users,dc=acme,dc=org))(objectClass=groupOfNames)) attrs=['ou', 'cn', 'description'] attrsonly=0 search_s /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:931
> 2015-05-27 12:11:52.946 57 DEBUG keystone.common.ldap.core [-] LDAP unbind unbind_s /usr/lib/python2.7/dist-packages/keystone/common/ldap/core.py:904
> 2015-05-27 12:11:52.946 57 DEBUG keystone.identity.core [-] ID Mapping - Domain ID: default, Default Driver: True, Domains: False, UUIDs: False, Compatible IDs: True _set_domain_id_and_mapping /usr/lib/python2.7/dist-packages/keystone/identity/core.py:492
> 2015-05-27 12:11:52.955 57 ERROR keystone.token.providers.fernet.token_formatters [-] john
> 2015-05-27 12:11:52.955 57 ERROR keystone.common.wsgi [-] badly formed hexadecimal UUID string
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi Traceback (most recent call last):
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/common/wsgi.py", line 239, in __call__
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi result = method(context, **params)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/auth/controllers.py", line 397, in authenticate_for_token
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi parent_audit_id=token_audit_id)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/token/provider.py", line 344, in issue_v3_token
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi parent_audit_id)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/token/providers/fernet/core.py", line 198, in issue_v3_token
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi federated_info=federated_dict)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/token/providers/fernet/token_formatters.py", line 133, in create_token
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi audit_ids)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/token/providers/fernet/token_formatters.py", line 416, in assemble
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi b_user_id = cls.convert_uuid_hex_to_bytes(user_id)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/dist-packages/keystone/token/providers/fernet/token_formatters.py", line 239, in convert_uuid_hex_to_bytes
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi uuid_obj = uuid.UUID(uuid_string)
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi File "/usr/lib/python2.7/uuid.py", line 134, in __init__
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi raise ValueError('badly formed hexadecimal UUID string')
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi ValueError: badly formed hexadecimal UUID string
> 2015-05-27 12:11:52.955 57 TRACE keystone.common.wsgi
> 2015-05-27 12:11:52.958 57 INFO eventlet.wsgi.server [-] 172.17.0.26 - - [27/May/2015 12:11:52] "POST /v3/auth/tokens HTTP/1.1" 500 490 0.029590

Switching to UUID tokens it works. Switching to SQL Identity backend and fernet tokens works.

The combination of LDAP identity backend and fernet tokens gives me the above log for any request with name/password. Reproducable always.

I have a very minimalistic "cloud" setup with only 2 or 3 docker containers. One with the SQL DB, one for Keystone and optionally one for LDAP.

I use Ubuntu 15.04 as base image for my containers that includes Kilo. I've patched keystone with the following changeset to make it work (with LDAP):

commit 2c6db4a3bb9e1718744b0e5b03af050fd2866182
Author: Edmund Rhudy <email address hidden>
Date: Thu May 21 12:42:40 2015 -0400

    Make sure LDAP filter is constructed correctly