keystone-ldap TypeError: cannot concatenate 'str' and 'NoneType' object

[David O Neill]

Proposed action:
=============
Key / value failed check error.
Should check key exists and warn user of bad users / continue

Bug presented by:
=================
openstack user list --domain customerdata
cannot concatenate 'str' and 'NoneType' objects (HTTP 400) (Request-ID: req-cc0e225d-d033-4dfa-aff8-7311389d4f58)

Trace:
======
(keystone.common.wsgi): 2019-03-11 12:30:47,154 ERROR cannot concatenate 'str' and 'NoneType' objects
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/keystone/common/wsgi.py", line 228, in __call__
    result = method(req, **params)
  File "/usr/lib/python2.7/dist-packages/keystone/common/controller.py", line 235, in wrapper
    return f(self, request, filters, **kwargs)
  File "/usr/lib/python2.7/dist-packages/keystone/identity/controllers.py", line 233, in list_users
    return UserV3.wrap_collection(request.context_dict, refs, hints=hints)
  File "/usr/lib/python2.7/dist-packages/keystone/common/controller.py", line 499, in wrap_collection
    cls.wrap_member(context, ref)
  File "/usr/lib/python2.7/dist-packages/keystone/common/controller.py", line 468, in wrap_member
    cls._add_self_referential_link(context, ref)
  File "/usr/lib/python2.7/dist-packages/keystone/common/controller.py", line 464, in _add_self_referential_link
    ref['links']['self'] = cls.base_url(context) + '/' + ref['id']
TypeError: cannot concatenate 'str' and 'NoneType' objects

Offending Data:
===============
@ line 233 i put LOG.debug( pprint.pformat( refs ) )

grep -b 2 "'id': None," /varlog/keystone/keystone.log

{'domain_id': u'8ce102de5ac644288f61838f5e0f46e7',
  'email': <email address hidden>',
  'id': None,
--
 {'domain_id': u'8ce102de5ac644288f61838f5e0f46e7',
  'email': <email address hidden>',
  'id': None,
--
 {'domain_id': u'8ce102de5ac644288f61838f5e0f46e7',
  'email': <email address hidden>',
  'id': None,

Platform:
=========
cat /etc/*-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=16.04
DISTRIB_CODENAME=xenial
DISTRIB_DESCRIPTION="Ubuntu 16.04.5 LTS"
NAME="Ubuntu"
VERSION="16.04.5 LTS (Xenial Xerus)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 16.04.5 LTS"
VERSION_ID="16.04"
HOME_URL="http://www.ubuntu.com/"
SUPPORT_URL="http://help.ubuntu.com/"
BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
VERSION_CODENAME=xenial
UBUNTU_CODENAME=xenial

verions:
========
dpkg --list | grep keystone
ii keystone 2:11.0.3-0ubuntu1~cloud0 all OpenStack identity service - Daemons
ii python-keystone 2:11.0.3-0ubuntu1~cloud0 all OpenStack identity service - Python library
ii python-keystoneauth1 2.18.0-0ubuntu2~cloud0 all authentication library for OpenStack Identity - Python 2.7
ii python-keystoneclient 1:3.10.0-0ubuntu1~cloud0 all client library for the OpenStack Keystone API - Python 2.x
ii python-keystonemiddleware 4.14.0-0ubuntu1.2~cloud0 all Middleware for OpenStack Identity (Keystone) - Python 2.x

[Corey Bryant (corey.bryant)]

Note that 11.0.3 is Ocata. We do have an 11.0.4 package version available. First thing I'd like to check is to see if this is fixed in either 11.0.4 or a future keystone release.

[Corey Bryant (corey.bryant)]

David, just to be clear, is this an issue where the specified domain in 'openstack user list --domain customerdata' does not exist and it should fail gracefully rather than with a traceback? Also it seems that this is not LDAP specific, but please correct me if I'm wrong. I'm deploying stein to see if it recreates there.

[Corey Bryant (corey.bryant)]

I'm not able to recreate this on stein (that is, assuming I understand the problem correctly).

$ openstack domain list
+----------------------------------+----------------+---------+--------------------------+
| ID | Name | Enabled | Description |
+----------------------------------+----------------+---------+--------------------------+
| 36bc721906cc45378233616f4bf2eb11 | default | True | Created by Juju |
| 58e8c54b7ae84efcb7221fd20009bb5a | service_domain | True | Created by Juju |
| 66d858a41571421eb2a745abe5a4d884 | heat | True | Stack projects and users |
| 7cae5f364e914965bffdf76cf08f68aa | admin_domain | True | Created by Juju |
+----------------------------------+----------------+---------+--------------------------+
$ openstack user list --domain admin_domain
+----------------------------------+----------+
| ID | Name |
+----------------------------------+----------+
| 4f224c0a4f634a51a238331bcaf2e0f7 | alt_demo |
| 7d626e7ff5a74cccb9735bfcab792371 | admin |
| e6d1b35119fc44389f639ee014be4cbc | demo |
+----------------------------------+----------+
$ openstack user list --domain does_not_exist
No domain with a name or ID of 'does_not_exist' exists.

[Alok G Singh (alephnull-b)]

Corey, the problem here is the fact that there are users in LDAP with None as id. The existence of a one such user causes `openstack user list --domain dom0` to fail with the error:

TypeError: cannot concatenate 'str' and 'NoneType' objects

HTH.

[Corey Bryant (corey.bryant)]

Thanks Alok. Do you have a work around for this? I'm assuming users with id=None are invalid, but obviously failing to list users is an issue and keystone should be handling that scenario.

[Corey Bryant (corey.bryant)]

Here's a patch to force this failure to occur on Queens:

From 9ef61915093d8892f1d4e750c64a0d043acb8a7d Mon Sep 17 00:00:00 2001
From: Corey Bryant <email address hidden>
Date: Tue, 12 Mar 2019 17:07:04 -0400
Subject: [PATCH] First list_users() to fail due to id=None on Queens

Change-Id: I5516817d053d4ce542f6ed0f1d406dccfaad420c
---
 keystone/identity/controllers.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/keystone/identity/controllers.py b/keystone/identity/controllers.py
index da0f1aecb..b63b02731 100644
--- a/keystone/identity/controllers.py
+++ b/keystone/identity/controllers.py
@@ -70,6 +70,7 @@ class UserV3(controller.V3Controller):
         refs = PROVIDERS.identity_api.list_users(
             domain_scope=domain, hints=hints
         )
+ refs[0]['id'] = None
         return UserV3.wrap_collection(request.context_dict, refs, hints=hints)

     @controller.filterprotected('domain_id', 'enabled', 'name',
--
2.20.1

[Alok G Singh (alephnull-b)]

@Corey, we have no workaround for this error.

[Colleen Murphy (krinkle)]

Is this confirmed for Stein or only for Queens?

[Drew Freiberger (afreiberger)]

This is only confirmed on xenial Ocata.

When querying the domain, as it loops through users returned from the all user query of LDAP, it tries to create mappings in keystone for any new users.

https://github.com/openstack/keystone/blob/stable/ocata/keystone/identity/core.py#L599

This hits the method keystone.identity.mapping_backends.sql.create_id_mapping() If the hash of the domain and the user data exist in id_mappings, it tosses the exception:

https://github.com/openstack/keystone/blob/stable/ocata/keystone/identity/mapping_backends/sql.py#L80

it then tries to fall back to querying the public_id of the existing local_entity which doesn't exist and hence returns None. However, if it would just return that public_id that just tossed as duplicate from this line, it could work around the issue.

https://github.com/openstack/keystone/blob/stable/ocata/keystone/identity/mapping_backends/sql.py#L80

This is the duplicate being detected, why not just return that duplicate ID rather than having to return a reverse lookup of a potentially non-existent object.

Basically, this customer deletes entries from LDAP, then we delete them from the local_users and users tables, and sometimes forget to remove from id_mappings table as well. This is done manually because there's no way to delete a keystone user w/out the user existing in the ldap backend still. (best practice being to disable the user's accountActive flag and leave them in LDAP)

So, operator error working around one bug is creating what appears to be a new bug when the ldap user is recreated.

When we query the id_mappings table, we found 402 entries in id_mapping table that don't belong to the domain any longer in nonlocal_users table or users table. So, these 402 entries could not be re-created as new ldap users.

To reproduce:

create LDAP domain with user foo and query openstack domain so user foo gets a user entry in keystone.
remove user foo from user and nonlocal_user table in mysql database, leaving entry in id_mappings table.
Try to query domain (openstack user list --domain <ldapdom>), user foo should cause a traceback when it tries to recreate the id_mapping.

Ultimately, I believe we have to cleanup the id_mappings table, however, I believe the invalid assumption at the line below is still worth discussion:
https://github.com/openstack/keystone/blob/stable/ocata/keystone/identity/mapping_backends/sql.py#L81

[Drew Freiberger (afreiberger)]

Here's a query I used to determine we have entries in id_mapping table that don't have a matching local_entity in the user/nonlocal_user tables.

select * from id_mapping where public_id not in (select id_mapping.public_id from id_mapping join user on id_mapping.public_id = user.id);

[Corey Bryant (corey.bryant)]

@Colleen, I didn't get around to confirming on stein. The code seems to have changed around enough for the recreate patch above to not work.

[Corey Bryant (corey.bryant)]

s/not to work/not to apply

[Corey Bryant (corey.bryant)]

Sorry I triaged the wrong bug. I'll just mark this as triaged for ocata for now until I, or someone else, has more time to look at other releases.

[Corey Bryant (corey.bryant)]

I mean queens.

[Colleen Murphy (krinkle)]

I can't reproduce this either on Stein or Queens with devstack. Haven't tried with Ocata yet. This is what I tried:

Create new user in LDAP backend:

$ ldapadd -x -w nomoresecret -D cn=Manager,dc=openstack,dc=org \
> -H ldap://localhost -c -f peter.ldif.in
adding new entry "cn=peter,ou=Users,dc=openstack,dc=org"
$ openstack --os-cloud=devstack-admin user list --domain Users
+------------------------------------------------------------------+-------+
| ID | Name |
+------------------------------------------------------------------+-------+
| eb55ea06af4ba6f1b7b90f4746f5c2d3e570a44a23829e9b581fe32d482bf697 | demo |
| fbbc3741707c62db5eed4242978f09089d341df01f827b8a795731a188f166cd | peter |
+------------------------------------------------------------------+-------+

Auth with the user so that an entry gets created in the user and nonlocal_user database:

$ openstack --os-cloud=ldap token issue
...

Delete the user from the LDAP backend:

$ ldapdelete -x -w nomoresecret -D cn=Manager,dc=openstack,dc=org \
> -H ldap://localhost cn=peter,ou=Users,dc=openstack,dc=org

At this point from the API perspective the user is effectively gone:

$ openstack --os-cloud=devstack-admin user list --domain Users
+------------------------------------------------------------------+------+
| ID | Name |
+------------------------------------------------------------------+------+
| eb55ea06af4ba6f1b7b90f4746f5c2d3e570a44a23829e9b581fe32d482bf697 | demo |
+------------------------------------------------------------------+------+

Manually removed the user from the mysql database:

mysql> delete from user where id = 'fbbc3741707c62db5eed4242978f09089d341df01f827b8a795731a188f166cd';
Query OK, 1 row affected (0.01 sec)

mysql> select * from nonlocal_user;
Empty set (0.00 sec)

User list still seems okay:

$ openstack --os-cloud=devstack-admin user list --domain Users
+------------------------------------------------------------------+------+
| ID | Name |
+------------------------------------------------------------------+------+
| eb55ea06af4ba6f1b7b90f4746f5c2d3e570a44a23829e9b581fe32d482bf697 | demo |
+------------------------------------------------------------------+------+
$ sudo systemctl restart memcached
$ openstack --os-cloud=devstack-admin user list --domain Users
+------------------------------------------------------------------+------+
| ID | Name |
+------------------------------------------------------------------+------+
| eb55ea06af4ba6f1b7b90f4746f5c2d3e570a44a23829e9b581fe32d482bf697 | demo |
+------------------------------------------------------------------+------+

Two other comments:

First, in my opinion, manually editing the database table is not supportable. Keystone's behavior after doing that is naturally undefined.

Second, regarding this comment:

> Ultimately, I believe we have to cleanup the id_mappings table, however, I believe the invalid assumption at the line below is s...

[Colleen Murphy (krinkle)]

Is there any update with regard to my comment https://bugs.launchpad.net/keystone/+bug/1819453/comments/15 ? What steps should I take to reproduce this, or can it be closed?