Non-Latin charated in base DN results in backend initialization failure: ERROR 'ascii' codec can't decode byte 0xd0 in position 94: ordinal not in range(128)

[Vladimir Grevtsev]

== Steps to reproduce
Deploy a keystone-ldap charm and provide a following ldap-user DN: "CN=openstack openstack,OU=Технологические пользователи,OU=Users,DC=corp,DC=com"

== Problem statement

cloud: focal-ussuri, latest stable charms

The project I'm working on has an LDAP integration, and I've been given a following base DN: "CN=openstack openstack,OU=Технологические пользователи,OU=Users,DC=corp,DC=com", which I'm supplying as a ldap-user option of keystone-ldap charm.

If I'll remove a non-latin OU part - then Keystone is trying to authenticate, but failing, complaining about invalid bind credentials. Then, if I'll return the "OU=Технологические пользователи" part back, the following occurs in keystone.log:

(keystone.server.flask.request_processing.middleware.auth_context): 2021-06-21 12:23:11,146 ERROR 'ascii' codec can't decode byte 0xd0 in position 94: ordinal not in range(128)
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/keystone/server/flask/request_processing/middleware/auth_context.py", line 103, in _inner
    return method(self, request)
  File "/usr/lib/python3/dist-packages/keystone/server/flask/request_processing/middleware/auth_context.py", line 358, in process_request
    resp = super(AuthContextMiddleware, self).process_request(request)
  File "/usr/lib/python3/dist-packages/keystonemiddleware/auth_token/__init__.py", line 409, in process_request
    data, user_auth_ref = self._do_fetch_token(
  File "/usr/lib/python3/dist-packages/keystonemiddleware/auth_token/__init__.py", line 445, in _do_fetch_token
    data = self.fetch_token(token, **kwargs)
  File "/usr/lib/python3/dist-packages/keystone/server/flask/request_processing/middleware/auth_context.py", line 252, in fetch_token
    self.token = self.token_provider_api.validate_token(
  File "/usr/lib/python3/dist-packages/keystone/common/manager.py", line 115, in wrapped
    __ret_val = __f(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/keystone/token/provider.py", line 145, in validate_token
    token = self._validate_token(token_id)
  File "<decorator-gen-26>", line 2, in _validate_token
  File "/usr/lib/python3/dist-packages/dogpile/cache/region.py", line 1359, in get_or_create_for_user_func
    return self.get_or_create(
  File "/usr/lib/python3/dist-packages/dogpile/cache/region.py", line 957, in get_or_create
    with Lock(
  File "/usr/lib/python3/dist-packages/dogpile/lock.py", line 187, in __enter__
    return self._enter()
  File "/usr/lib/python3/dist-packages/dogpile/lock.py", line 94, in _enter
    generated = self._enter_create(value, createdtime)
 File "/usr/lib/python3/dist-packages/dogpile/lock.py", line 180, in _enter_create
    return self.creator()
  File "/usr/lib/python3/dist-packages/dogpile/cache/region.py", line 915, in gen_value
    created_value = creator(
  File "/usr/lib/python3/dist-packages/keystone/token/provider.py", line 179, in _validate_token
    token.mint(token_id, issued_at)
  File "/usr/lib/python3/dist-packages/keystone/models/token_model.py", line 580, in mint
    self._validate_token_user()
  File "/usr/lib/python3/dist-packages/keystone/models/token_model.py", line 503, in _validate_token_user
    if not self.user_domain.get('enabled'):
  File "/usr/lib/python3/dist-packages/keystone/models/token_model.py", line 139, in user_domain
    if self.user:
  File "/usr/lib/python3/dist-packages/keystone/models/token_model.py", line 133, in user
    self.__user = PROVIDERS.identity_api.get_user(self.user_id)
  File "/usr/lib/python3/dist-packages/keystone/common/manager.py", line 115, in wrapped
    __ret_val = __f(*args, **kwargs)
  File "/usr/lib/python3/dist-packages/keystone/identity/core.py", line 412, in wrapper
    self.domain_configs.setup_domain_drivers(
  File "/usr/lib/python3/dist-packages/keystone/identity/core.py", line 306, in setup_domain_drivers
    self._setup_domain_drivers_from_files(standard_driver,
  File "/usr/lib/python3/dist-packages/keystone/identity/core.py", line 159, in _setup_domain_drivers_from_files
    self._load_config_from_file(
  File "/usr/lib/python3/dist-packages/keystone/identity/core.py", line 125, in _load_config_from_file
    domain_config['cfg'](args=[], project='keystone',
  File "/usr/lib/python3/dist-packages/oslo_config/cfg.py", line 2131, in __call__
    self._namespace = self._parse_cli_opts(args if args is not None
  File "/usr/lib/python3/dist-packages/oslo_config/cfg.py", line 2897, in _parse_cli_opts
    return self._parse_config_files()
  File "/usr/lib/python3/dist-packages/oslo_config/cfg.py", line 2914, in _parse_config_files
    ConfigParser._parse_file(config_file, namespace)
  File "/usr/lib/python3/dist-packages/oslo_config/cfg.py", line 1604, in _parse_file
    parser.parse()
  File "/usr/lib/python3/dist-packages/oslo_config/cfg.py", line 1559, in parse
    return super(ConfigParser, self).parse(f.readlines())
File "/usr/lib/python3.8/encodings/ascii.py", line 26, in decode
    return codecs.ascii_decode(input, self.errors)[0]
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 94: ordinal not in range(128)
(keystone.server.flask.request_processing.middleware.auth_context): 2021-06-21 12:23:14,525 ERROR 'ascii' codec can't decode byte 0xd0 in position 94: ordinal not in range(128)

Apparently, it's trying to read the domain config and something goes wrong at this step (as there's even no authentication attempt being made).

[Vladimir Grevtsev (vlgrevtsev)]

Adding ~field-critical as there's no workaround currently for this issue, and there's no option to avoid using non-Latin characters in the customers LDAP server.

[Vladimir Grevtsev (vlgrevtsev)]

Looks very similar-ish: https://bugs.launchpad.net/keystone/+bug/1641026

[Aurelien Lourot (aurelien-lourot)]

Yes I agree with #2. I think oslo.config calls readlines() on a file for which they most likely haven't specified the encoding (utf-8 would be correct I guess) on doing open(), so Python defaults to thinking it's a pure ascii file and shouts on finding a non-ascii char. Digging.

[Aurelien Lourot (aurelien-lourot)]

Actually oslo.config is doing it right. They are calling open() without specifying the encoding, so that it defaults to the platform's locale. [0]

Some people in the past have been successful at working around this by tweaking Keystone's code to set the default encoding. [1]

And in fact meanwhile several changes have been done in Keystone in this area. I would have expected at least versions of Keystone containing this patch [2] to behave properly, i.e. Keystone >= 15.0.0, i.e. OpenStack >= Stein. But you are hitting this in Ussuri, so I'm still digging.

[0] https://docs.python.org/3/library/functions.html#open
[1] https://bugs.launchpad.net/keystone/+bug/1641026/comments/3
[2] https://github.com/openstack/keystone/commit/eca0829c

[Vladimir Grevtsev (vlgrevtsev)]

For the record: I was trying to poke python-ldap directly (Keystone uses it under the hood):

=====

import ldap

invalid_ldap_password = 'qwe123'
ldap_password = 'abcdef'
connect = ldap.initialize('ldap://ldap.corp.com', trace_level=3)
connect.set_option(ldap.OPT_DEBUG_LEVEL, 255 )
connect.set_option(ldap.OPT_REFERRALS, 0)

======

# trying with invalid password

connect.simple_bind_s("CN=openstack openstack,OU=Технологические пользователи,OU=Users,DC=corp,DC=com", invalid_ldap_password)

*** <ldap.ldapobject.SimpleLDAPObject object at 0x7f34252733d0> ldap://ldap.corp.com - SimpleLDAPObject.result4
((4, 1, -1, 0, 0, 0), {})
=> LDAPError - INVALID_CREDENTIALS: {'desc': 'Invalid credentials', 'info': '80090308: LdapErr: DSID-0C090453, comment: AcceptSecurityContext error, data 52e, v3839'}

# trying with valid password
connect.simple_bind_s("CN=openstack openstack,OU=Технологические пользователи,OU=Users,DC=corp,DC=com", ldap_password)

*** <ldap.ldapobject.SimpleLDAPObject object at 0x7f34252733d0> ldap://ldap.corp.com - SimpleLDAPObject.simple_bind
=> diagnosticMessage: '80090308: LdapErr: DSID-0C090453, comment: AcceptSecurityContext error, data 52e, v3839'
=> result:
5
*** <ldap.ldapobject.SimpleLDAPObject object at 0x7f34252733d0> ldap://ldap.corp.com - SimpleLDAPObject.result4
((5, 1, -1, 0, 0, 0), {})
=> result:
(97, [], 5, [])
(97, [], 5, [])
>>>

[Aurelien Lourot (aurelien-lourot)]

Thanks for having tried this. Yes I think the issue isn't python-ldap but rather in the way Keystone makes use of oslo.config. From the previous sources I mention it feels like Keystone should be responsible for teaching oslo.config about the default encoding to be used, but is not properly doing it. This doesn't involve python-ldap.

[Aurelien Lourot (aurelien-lourot)]

I browsed the current Keystone code, issues and opened reviews, and I believe this issue is still in Keystone and there is no review that attempted to address this, even abandoned.

There are other reviews around Keystone, LDAP and non-ASCII chars but not regarding teaching the encoding to osci.config.

This comment [0] looks like a promising solution and we may want to give it a try.

Adding Keystone as affected project to this bug. This is probably a duplicate of lp:1641026

[0] https://bugs.launchpad.net/keystone/+bug/1641026/comments/6

[Dmitrii Shcherbakov (dmitriis)]

vlgrevtsev, could you check the default environment variables that systemd sets? It should be something like this on a Juju-provisioned machine:

sudo systemctl show-environment
LANG=C.UTF-8
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin

Juju itself does not alter cloud-init defaults so cloud-init should just set the locale to C.UTF-8 and it will be used by all daemons spawned by it:

2021-06-22 16:00:28,183 - handlers.py[DEBUG]: start: modules-config/config-locale: running config-locale with frequency once-per-instance
2021-06-22 16:00:28,183 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/cb2fb8ce-ff5a-43b1-ab7d-dec891b503e9/sem/config_locale - wb: [644] 25 bytes
2021-06-22 16:00:28,184 - helpers.py[DEBUG]: Running config-locale using lock (<FileLock using file '/var/lib/cloud/instances/cb2fb8ce-ff5a-43b1-ab7d-dec891b503e9/sem/config_locale'>)
2021-06-22 16:00:28,184 - util.py[DEBUG]: Reading from /etc/default/locale (quiet=False)
2021-06-22 16:00:28,184 - util.py[DEBUG]: Read 13 bytes from /etc/default/locale
2021-06-22 16:00:28,219 - cc_locale.py[DEBUG]: Setting locale to C.UTF-8
2021-06-22 16:00:28,219 - debian.py[DEBUG]: System has 'LANG=C.UTF-8' requested 'C.UTF-8', skipping regeneration.
2021-06-22 16:00:28,219 - handlers.py[DEBUG]: finish: modules-config/config-locale: SUCCESS: config-locale ran successfully

As a result, daemons started via systemd should get the correct locale settings:

sudo cat /proc/<pid>/environ

The problem may be more involved since python processes in our case are started by Apache and run as WSGI daemon processes (not managed by systemd).

[Vladimir Grevtsev (vlgrevtsev)]

Hi Dmitrii, thanks for looking into this!

root@juju-382713-0-lxd-9:~# sudo systemctl show-environment
LANG=C.UTF-8
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin

Here's an Apache env:

root@juju-382713-0-lxd-9:~# ps auxf | grep apache
root 4115446 0.0 0.0 8164 676 pts/0 S+ 16:32 0:00 \_ grep --color=auto apache
root 3693257 0.0 0.0 13840 5308 ? Ss 10:17 0:00 /usr/sbin/apache2 -k start
www-data 3693262 0.0 0.0 2008176 11784 ? Sl 10:17 0:00 \_ /usr/sbin/apache2 -k start
www-data 3693263 0.0 0.0 2008320 11784 ? Sl 10:17 0:00 \_ /usr/sbin/apache2 -k start

root@juju-382713-0-lxd-9:~# xargs -0 -L1 -a /proc/3693257/environ
APACHE_RUN_DIR=/var/run/apache2
APACHE_PID_FILE=/var/run/apache2/apache2.pid
JOURNAL_STREAM=9:338582662
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/snap/bin
INVOCATION_ID=157dbb53c2aa4eb6b87b1d7e572b2ae8
APACHE_LOCK_DIR=/var/lock/apache2
LANG=C
APACHE_RUN_USER=www-data
APACHE_RUN_GROUP=www-data
APACHE_LOG_DIR=/var/log/apache2
PWD=/

For the record, Keystone workers forked from apache2 process have exactly the same environment variables.

[Dmitrii Shcherbakov (dmitriis)]

It looks like the problem is that WSGI daemon processes have the default C locale.

https://www.gnu.org/software/libc/manual/html_node/Setting-the-Locale.html
"ISO C says that all programs start by default in the standard ‘C’ locale"

I think setting the lang variable on a WSGIDaemonProcess might help.
https://modwsgi.readthedocs.io/en/develop/configuration-directives/WSGIDaemonProcess.html#lang

I would give it a quick test to see if it helps and then we could possibly set it in the charm. If it fixes things, it might be reasonable to query /etc/default/locale or `localectl status` in the charm and set the `lang` option for all for `WSGIDaemonProcess`es.

[David Ames (thedac)]

You might also try setting LANG=C.UTF-8 in /etc/apache2/envvars and restarting apache.

[Vladimir Grevtsev (vlgrevtsev)]

I was able to create a successful LDAP bind with cyrillic DN after adding the following in /etc/apache2/sites-enabled/wsgi-openstack-api.conf and restarting the Apache:

- WSGIDaemonProcess keystone-admin processes=1 threads=1 user=keystone group=keystone \
+ WSGIDaemonProcess keystone-admin processes=1 threads=1 user=keystone group=keystone lang=C.UTF-8 locale=C.UTF-8\

[David Ames (thedac)]

Vladimir, fantastic!

FWIW, I confirmed setting LANG=C.UTF-8 in /etc/apache2/envvars also affects the wsgi processes. So for a complete fix we can either update the WSGI template or update /etc/apache2/envvars.

[David Ames (thedac)]

Proposed fix using Vladimir's approach: https://review.opendev.org/c/openstack/charm-keystone/+/797516

[David Ames (thedac)]

https://review.opendev.org/c/openstack/charm-keystone/+/797516 landed. Marking Fix Committed.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/21.04
Review: https://review.opendev.org/c/openstack/charm-keystone/+/797492

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/charm-keystone/+/797492
Committed: https://opendev.org/openstack/charm-keystone/commit/42ee87a9968506c1eb3d0ca96fce025ab98c53d0
Submitter: "Zuul (22348)"
Branch: stable/21.04

commit 42ee87a9968506c1eb3d0ca96fce025ab98c53d0
Author: David Ames <email address hidden>
Date: Tue Jun 22 10:06:17 2021 -0700

    Set WSGI env with lang=C.UTF-8

    The default apache2 environment, and therefore the default WSGI
    environment, sets LANG=C. For languages beyond the scope of ASCII
    this can create problems.

    Explicitly set the lang and locale to C.UTF-8 which will support all
    UTF-8 language sets.

    Change-Id: I110cc089fa7d51dfd513c630cb28cd49b330bf6f
    Closes-Bug: #1933109
    (cherry picked from commit 7e6647951d2408ceae10170f7c4597f593d68d58)